Question regarding WPA-PSK 4-way EAPOLs (wpa-supplicant 0.3.9)

Wed Sep 28 14:56:07 PDT 2005

Hi,

I've got ap_scan=2, so that the driver does site selection and cipher suite/RSN IE generation.
Once associated, the driver does supply the appropriate Assoc req/resp IEs to the wpa_supplicant, afterwhich
a EVENT_ASSOC is generated.
1st EAPOL from the AP (Cisco 1200) is received, and when wpa_supplicant generates the 2nd EAPOL, there
seems to be something wrong with it (AP repeating 1st EAPOL).
I've checked that the wpa_supplicant has the right passphrase (using debug msgs), and also that it has
the right MAC Address (of the wireless device).
All fields in EAPOL seem ok and according to spec, but could it be that the MIC Calculated is wrong?

Is there a way or some special DBG msgs to look for?
If I have the 1st EAPOL and it's S Nonce, can I calculate and see if the MIC calculated was right?
Could this be related to WME being enabled on both driver and AP ?

I've seen an earlier thread about this, but that ended with the guy disabling WME and that was it.
(I do wish to keep using WME).

Please if anyone has a feeling he might help, I'd be grateful :)

I've also got another question...
While trying PSK association with another AP with WME disabled, I've seen that the wpa_supplicant,
once receiving the 3rd EAPOL (from the AP) which contains the APs RSN IE (or part of it), prints a msg
that it couldn't find an AP with this RSN IE (probably since ap_scan=2 therefore no beacon/probeRsp IE 
are kept in memory).
It then tries to retrieve scan_results from the driver.
Assuming I do not wish this to happen and still have ap_scan=2, what am I missing here?
Is this a must ? (APs IE kept for EAPOL handshake?)
Is the driver Assoc REQ RSN IE not enough?
I would love to hear any information that would help me out a bit...

Anyways, thanks alot for taking the time to read and help ;)

BTW, I'm using a custom driver (hoping to integrate with wpa_suppl)

THANKS!
 Eitan

p.s: attached is a sample output regarding my 2nd question:

wpa_driver_get_mac_addr called
Jan 01 00:24:53.904949: Own MAC address: 08:00:28:55:05:80
Jan 01 00:24:53.927562: Setting scan request: 0 sec 100000 usec
Jan 01 00:24:54.040282: Trying to associate with SSID 'eitanTI'
Jan 01 00:24:54.041033: Cancelling scan request
Jan 01 00:24:54.050638: Automatic auth_alg selection: 0x1
Jan 01 00:24:54.063035: WPA: Set cipher suites based on configuration
Jan 01 00:24:54.063682: WPA: Selected cipher suites: group 14 pairwise 8 key_mgmt 2
Jan 01 00:24:54.064168: WPA: using GTK TKIP
Jan 01 00:24:54.069987: WPA: using PTK TKIP
Jan 01 00:24:54.074992: WPA: using KEY_MGMT WPA-PSK
Jan 01 00:24:54.075500: WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:54.090225: No keys have been configured - skip key clearing
params->ssid = eitanTI
wpa_supplicant - Disassociated
Jan 01 00:24:54.130590: Added BSSID 00:00:00:00:00:00 into blacklist
Jan 01 00:24:54.131363: EAPOL: External notification - portEnabled=0
Jan 01 00:24:54.137866: EAPOL: External notification - portValid=0
Jan 01 00:24:54.149640: EAPOL: External notification - EAP success=0
Jan 01 00:24:54.155344: Setting authentication timeout: 5 sec 0 usec
Jan 01 00:24:54.155977: EAPOL: External notification - EAP success=0
Jan 01 00:24:54.168323: EAPOL: External notification - EAP fail=0
Jan 01 00:24:54.174245: EAPOL: External notification - portControl=Auto
Jan 01 00:24:54.180862: EAPOL: SUPP_BE entering state IDLE
Jan 01 00:24:54.180856: EAPOL: SUPP_BE entering state INITIALIZE
Jan 01 00:24:54.186872: Disconnect event - remove keys
wpa_supplicant - Associated
Jan 01 00:24:54.583190: NDIS: ReqFixed=0x3 RespFixed=0x7 off_req=44 off_resp=102 len_req=58 len_resp=17
Jan 01 00:24:54.583971: NDIS: association information - IE overflow
Jan 01 00:24:54.584432: NDIS: Request IEs - hexdump(len=58): 00 07 65 69 74 61 6e 54 49 01 05 82 84 8b 96 2c 32 08 0c 12 18 24 30 48 60 6
c dd 06 00 40 96 01 01 00 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:54.599533: NDIS: Response IEs - hexdump(len=17): 01 05 82 84 8b 96 2c 32 08 0c 12 18 24 30 48 60 6c
Jan 01 00:24:54.604994: Association info event
Jan 01 00:24:54.610791: req_ies - hexdump(len=58): 00 07 65 69 74 61 6e 54 49 01 05 82 84 8b 96 2c 32 08 0c 12 18 24 30 48 60 6c dd 06 00
 40 96 01 01 00 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:54.616532: resp_ies - hexdump(len=17): 01 05 82 84 8b 96 2c 32 08 0c 12 18 24 30 48 60 6c
Jan 01 00:24:54.621699: assoc_wpa_ie - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:54.632331: Association event - clear replay counter
Jan 01 00:24:54.638659: Associated to a new BSS: BSSID=00:50:f1:12:98:55
Jan 01 00:24:54.643801: No keys have been configured - skip key clearing
Jan 01 00:24:54.660194: Network configuration found for the current AP
Jan 01 00:24:54.666130: WPA: Using WPA IE from AssocReq to set cipher suites
Jan 01 00:24:54.666582: WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2
Jan 01 00:24:54.671693: WPA: using GTK TKIP
Jan 01 00:24:54.677510: WPA: using PTK TKIP
Jan 01 00:24:54.677948: WPA: using KEY_MGMT WPA-PSK
Jan 01 00:24:54.682960: WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:54.689032: EAPOL: External notification - EAP success=0
Jan 01 00:24:54.700082: EAPOL: External notification - EAP fail=0
Jan 01 00:24:54.705792: EAPOL: External notification - portControl=Auto
Jan 01 00:24:54.716884: Associated with 00:50:f1:12:98:55
Jan 01 00:24:54.721902: EAPOL: External notification - portEnabled=0
Jan 01 00:24:54.728342: EAPOL: External notification - portValid=0
Jan 01 00:24:54.739382: EAPOL: External notification - EAP success=0
Jan 01 00:24:54.750410: EAPOL: External notification - portEnabled=1
Jan 01 00:24:54.750863: EAPOL: SUPP_PAE entering state CONNECTING
Jan 01 00:24:54.755880: EAPOL: txStart
Jan 01 00:24:54.760786: WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
Jan 01 00:24:54.761222: EAPOL: SUPP_BE entering state IDLE
Jan 01 00:24:54.767002: EAP: EAP entering state INITIALIZE
Jan 01 00:24:54.767408: EAP: EAP entering state IDLE
Jan 01 00:24:54.789537: Setting authentication timeout: 10 sec 0 usec
wpa_supplicant - EAPOL
Jan 01 00:24:54.800496: RX EAPOL from 00:50:f1:12:98:55
Jan 01 00:24:54.805727: RX EAPOL - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00 00 01 c2 3c 66 f7 c1 29 6a cc 5c 3e 93 a
6 d9 38 9a b1 3e b7 95 8c f8 4a 83 d0 ff 92 4a 31 d7 13 24 46 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 01 00:24:54.817356: Setting authentication timeout: 10 sec 0 usec
Jan 01 00:24:54.822392: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Jan 01 00:24:54.828197: IEEE 802.1X RX: version=1 type=3 length=95
Jan 01 00:24:54.828619:   EAPOL-Key type=254
Jan 01 00:24:54.833561: WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 00 00 00 00 00 00 00 01 c2 3c 66 f7 c1 29 6a cc 5
c 3e 93 a6 d9 38 9a b1 3e b7 95 8c f8 4a 83 d0 ff 92 4a 31 d7 13 24 46 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Jan 01 00:24:54.845105: WPA: RX message 1 of 4-Way Handshake from 00:50:f1:12:98:55 (ver=1)
Jan 01 00:24:54.861156: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=29 idleWhile=59
Jan 01 00:24:54.934523: WPA: Renewed SNonce - hexdump(len=32): a8 b2 84 c6 a1 92 54 e8 d5 c7 39 26 b0 2d 5f 5f 71 57 fa 18 83 02 05 0b 32
 7a ab c1 79 24 34 a1
Jan 01 00:24:54.950769: WPA: PMK - hexdump(len=32): bb 68 12 f4 e0 0f 3a 25 4e bf 53 30 01 14 4b f0 5f 21 30 e8 bd 5c 33 f3 19 d8 7c 20 f
2 f8 c1 88
Jan 01 00:24:54.957045: WPA: PTK - hexdump(len=64): c9 55 3b 7f dd d5 c2 08 48 88 74 be 37 8f b6 75 ec 1d 55 09 ce dc 16 22 cf 1a ec 46 c
4 b4 5c c8 d2 bb a9 1a c5 ef 18 fe 9c d9 05 7d 08 8b 10 93 58 b2 bb 50 c7 24 1d 7b 73 4d cc 41 ba 54 e3 dc
Jan 01 00:24:54.968295: WPA: EAPOL-Key MIC - hexdump(len=16): a8 23 07 65 8f 5c a2 39 4f 30 b8 9c 5d b3 ca 31
Jan 01 00:24:54.973536: WPA: Sending EAPOL-Key 2/4
Jan 01 00:24:54.979308: WPA: TX EAPOL-Key 2/4 - hexdump(len=137): 00 50 f1 12 98 55 08 00 28 55 05 80 88 8e 01 03 00 77 fe 01 09 00 20 00
 00 00 00 00 00 00 01 a8 b2 84 c6 a1 92 54 e8 d5 c7 39 26 b0 2d 5f 5f 71 57 fa 18 83 02 05 0b 32 7a ab c1 79 24 34 a1 00 00 00 00 00 00 0
0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 a8 23 07 65 8f 5c a2 39 4f 30 b8 9c 5d b3 ca 31 00 18 dd 16
00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02

Jan 01 00:24:55.050127: RX EAPOL from 00:50:f1:12:98:55
Jan 01 00:24:55.055387: RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 00 00 00 00 00 00 00 02 c2 3c 66 f7 c1 29 6a cc 5c 3e 93
a6 d9 38 9a b1 3e b7 95 8c f8 4a 83 d0 ff 92 4a 31 d7 13 24 46 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 00 00 00 00 00 00 00 61 ca 5b 05 a9 8f 93 bd 25 a5 72 41 d5 be 78 7c 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 0
0 50 f2 02
Jan 01 00:24:55.071822: EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Jan 01 00:24:55.077680: IEEE 802.1X RX: version=1 type=3 length=119
Jan 01 00:24:55.082634:   EAPOL-Key type=254
Jan 01 00:24:55.083070: WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 00 00 00 00 00 00 00 02 c2 3c 66 f7 c1 29 6a cc 5c 3e 93 a6 d9 38 9a b1 3e b7 95 8c f8 4a 83 d0 ff 92 4a 31 d7 13 24 46 00 00 00 00 00
 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 61 ca 5b 05 a9 8f 93 bd 25 a5 72 41 d5 be 78 7c 00 18 d
d 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:55.100422: WPA: RX message 3 of 4-Way Handshake from 00:50:f1:12:98:55 (ver=1)
Jan 01 00:24:55.105557: WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Jan 01 00:24:55.110847: WPA: No WPA/RSN IE for this AP known. Trying to get from scan results
wpa_driver_get_scan_results called - not implemented and SHOULD NOT BE CALLED if ap_scan=2 !
Jan 01 00:24:55.116771: Scan results: 99
Jan 01 00:24:55.121931: WPA: Could not find AP from the scan results
Jan 01 00:24:55.127913: WPA: Sending EAPOL-Key 4/4
Jan 01 00:24:55.132928: WPA: TX EAPOL-Key 4/4 - hexdump(len=113): 00 50 f1 12 98 55 08 00 28 55 05 80 88 8e 01 03 00 5f fe 01 09 00 20 00
 00 00 00 00 00 00 02 a8 b2 84 c6 a1 92 54 e8 d5 c7 39 26 b0 2d 5f 5f 71 57 fa 18 83 02 05 0b 32 7a ab c1 79 24 34 a1 00 00 00 00 00 00 0
0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 d8 64 4d 39 ff 07 0c 64 21 2e 06 22 0c 8d e6 6c 00 00
Jan 01 00:24:55.164962: WPA: Installing PTK to the driver.
Jan 01 00:24:55.176379: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_cesta_set_key called
wpa_alg = 2, set_tx = 1
key_idx = 0, addr = 50:f1:12:98:55:45
Jan 01 00:24:55.870130: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=28 idleWhile=58
Jan 01 00:24:56.880123: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=27 idleWhile=57
Jan 01 00:24:57.890125: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=26 idleWhile=56
Jan 01 00:24:58.900153: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=25 idleWhile=55
Jan 01 00:24:59.910248: EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=24 idleWhile=54
Jan 01 00:25:00.200501: Signal 2 received - terminating
wpa_supplicant - Disassociated