madwifi WPA

Tue Jul 6 12:11:27 PDT 2004

I'm trying to test the madwifi driver (checked out from CVS today) with 
wpa_supplicant (latest CVS snapshot). I'm using a Cisco CB21AG card and 
kernel 2.4.26, using PEAP/MSCHAPv2

One thing that may make my situation unique is that I have APs with multiple 
SSIDs (each on a different VLAN), one of which has a beaconing SSID and no 
WEP, one of which has WEP, and another of which has WPA.

I'm getting this odd sort of loop in which I seem to be getting a successful 
authentication, but then it all starts over.

Here's the slightly abridged output of wpa_supplicant, along with my 
interpretation of what might be happening. if someone could shed any more 
light on it, I'd appreciate it.

------->here it associates and does a successful EAP. RADIUS logs show a 
normal authentication.

Trying to associate with 00:0c:85:60:f1:f1 (SSID='ornlwpa' freq=2437 MHz)
Cancelling scan request
WPA: using IEEE 802.11i/D3.0
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 01
wpa_driver_madwifi_del_key: keyidx=0
wpa_driver_madwifi_del_key: keyidx=1
wpa_driver_madwifi_del_key: keyidx=2
wpa_driver_madwifi_del_key: keyidx=3
wpa_driver_madwifi_del_key: keyidx=0
wpa_driver_madwifi_set_drop_unencrypted: enabled=1
wpa_driver_madwifi_associate
Setting authentication timeout: 5 sec 0 usec
EAPOL: External notification - portControl=Auto
Wireless event: cmd=0x8b1a len=19
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:0c:85:60:f1:f1
Association event - clear replay counter
Associated to a new BSS: BSSID=00:0c:85:60:f1:f1
wpa_driver_madwifi_del_key: keyidx=0
wpa_driver_madwifi_del_key: keyidx=1
wpa_driver_madwifi_del_key: keyidx=2
wpa_driver_madwifi_del_key: keyidx=3
wpa_driver_madwifi_del_key: keyidx=0
EAPOL: External notification - portValid=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: txStart
EAPOL: SUPP_BE entering state IDLE
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
Setting authentication timeout: 10 sec 0 usec
RX EAPOL from 00:0c:85:60:f1:f1
Setting authentication timeout: 70 sec 0 usec
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_PAE entering state RESTART
EAP: EAP entering state INITIALIZE
EAP: EAP entering state IDLE
WPA: EAPOL frame too short, len 46, expecting at least 99
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=1 id=1
EAP: EAP entering state IDENTITY
EAP: EAP-Request Identity data - hexdump_ascii(len=0):
EAP: using real identity - hexdump_ascii(len=9):
? ? ?74 65 73 74 5f 75 73 65 72 ? ? ? ? ? ? ? ? ? ? ? ?test_user
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=1 id=2
EAP: EAP entering state IDENTITY
EAP: EAP-Request Identity data - hexdump_ascii(len=0):
EAP: using real identity - hexdump_ascii(len=9):
? ? ?74 65 73 74 5f 75 73 65 72 ? ? ? ? ? ? ? ? ? ? ? ?test_user
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
WPA: EAPOL frame too short, len 46, expecting at least 99
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=3
EAP: EAP entering state GET_METHOD
EAP-PEAP: Force old label for key derivation
EAP-PEAP: Phase2 type: MSCHAPV2
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=6) - Flags 0x21
EAP-PEAP: Start (server ver=1, own ver=1)
EAP-PEAP: Using PEAP version 1
SSL: (where=0x10 ret=0x1)
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:before/connect initialization
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client hello A
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read server hello A
SSL: SSL_connect - want more data
SSL: 100 bytes left to be sent out (of total 100 bytes)
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
WPA: EAPOL frame too short, len 46, expecting at least 99
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=4
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=1380) - Flags 0xc1
EAP-PEAP: TLS Message Length: 2174
SSL: Need 804 bytes more input data
SSL: Building ACK
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
IEEE 802.1X RX: version=1 type=0 length=1380
WPA: EAPOL frame (type 0) discarded, not a Key frame
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=5
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=810) - Flags 0x01
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server hello A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server certificate A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read server done A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write client key exchange A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write change cipher spec A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 write finished A
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 flush data
SSL: (where=0x1002 ret=0xffffffff)
SSL: SSL_connect:error in SSLv3 read finished A
SSL: SSL_connect - want more data
SSL: 190 bytes left to be sent out (of total 190 bytes)
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
IEEE 802.1X RX: version=1 type=0 length=810
WPA: EAPOL frame (type 0) discarded, not a Key frame
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=6
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=61) - Flags 0x81
EAP-PEAP: TLS Message Length: 51
SSL: (where=0x1001 ret=0x1)
SSL: SSL_connect:SSLv3 read finished A
SSL: (where=0x20 ret=0x1)
SSL: (where=0x1002 ret=0x1)
SSL: No data to be sent out
EAP-PEAP: TLS done, proceed to Phase 2
EAP-PEAP: using label 'client EAP encryption' in key derivation
EAP-PEAP: Derived key - hexdump(len=64): 00 89 59 76 a4 e6 28 b0 c3 ee 2e e8 
12 fa 85 ab 4a e9 2a e8 8c 78 22 fd bd 9c 33 81 58 41 64 84 1a 63 ae a0 ea 8e 
e0 14 06 63 f9 64 e6 45 c9 85 90 79 1b ae 17 52 65 28 5b f7 78 26 6f 0d 47 55
SSL: Building ACK
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
WPA: EAPOL frame too short, len 65, expecting at least 99
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=7
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=72) - Flags 0x01
EAP-PEAP: received 66 bytes encrypted data for Phase 2
EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=5): 01 00 00 05 01
EAP-PEAP: received Phase 2: code=1 identifier=0 length=5
EAP-PEAP: Phase 2 Request: type=1
EAP: using real identity - hexdump_ascii(len=9):
? ? ?74 65 73 74 5f 75 73 65 72 ? ? ? ? ? ? ? ? ? ? ? ?test_user
EAP-PEAP: Encrypting Phase 2 data - hexdump(len=14): 02 07 00 0e 01 74 65 73 
74 5f 75 73 65 72
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
WPA: EAPOL frame too short, len 76, expecting at least 99
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=8
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=96) - Flags 0x01
EAP-PEAP: received 90 bytes encrypted data for Phase 2
EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=34): 01 08 00 22 1a 01 08 00 1d 
10 21 f3 ea 40 50 df cd 23 73 3a 88 e8 99 aa df 36 70 69 79 2d 64 65 73 6b
EAP-PEAP: received Phase 2: code=1 identifier=8 length=34
EAP-PEAP: Phase 2 Request: type=26
EAP-PEAP: Phase 2 EAP packet
EAP-MSCHAPV2: Received challenge
EAP-MSCHAPV2: Authentication Servername - hexdump_ascii(len=8):
? ? ?70 69 79 2d 64 65 73 6b ? ? ? ? ? ? ? ? ? ? ? ? ? piy-desk
EAP-MSCHAPV2: Generating Challenge Response
EAP-MSCHAPV2: auth_challenge - hexdump(len=16): 21 f3 ea 40 50 df cd 23 73 3a 
88 e8 99 aa df 36
EAP-MSCHAPV2: peer_challenge - hexdump(len=16): b7 d9 e1 c8 f3 69 49 92 f9 27 
a2 e4 97 d1 f2 e1
EAP-MSCHAPV2: username - hexdump_ascii(len=9):
? ? ?74 65 73 74 5f 75 73 65 72 ? ? ? ? ? ? ? ? ? ? ? ?test_user
EAP-MSCHAPV2: password - hexdump_ascii(len=4):
? ? ?74 65 73 74 ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? ? test
EAP-MSCHAPV2: response - hexdump(len=24): e4 7b 88 e9 08 d9 74 36 96 c7 91 0c 
cd f2 a8 43 87 6f c6 d1 95 f3 14 7f
EAP-PEAP: Encrypting Phase 2 data - hexdump(len=68): 02 08 00 44 1a 02 08 00 
3f 31 b7 d9 e1 c8 f3 69 49 92 f9 27 a2 e4 97 d1 f2 e1 00 00 00 00 00 00 00 00 
e4 7b 88 e9 08 d9 74 36 96 c7 91 0c cd f2 a8 43 87 6f c6 d1 95 f3 14 7f 00 74 
65 73 74 5f 75 73 65 72
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
IEEE 802.1X RX: version=1 type=0 length=96
WPA: EAPOL frame (type 0) discarded, not a Key frame
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Request method=25 id=9
EAP: EAP entering state METHOD
EAP-PEAP: Received packet(len=120) - Flags 0x01
EAP-PEAP: received 114 bytes encrypted data for Phase 2
EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=55): 01 08 00 37 1a 03 08 00 32 
53 3d 31 35 44 32 46 34 41 36 34 38 33 38 45 36 38 37 44 42 33 36 45 33 46 32 
43 44 44 46 43 32 35 34 34 45 33 33 46 36 43 30 4d 3d 4f 4b
EAP-PEAP: received Phase 2: code=1 identifier=8 length=55
EAP-PEAP: Phase 2 Request: type=26
EAP-PEAP: Phase 2 EAP packet
EAP-MSCHAPV2: Received success
EAP-MSCHAPV2: Success message - hexdump(len=4): 4d 3d 4f 4b
EAP-MSCHAPV2: Authentication succeeded
EAP-PEAP: Encrypting Phase 2 data - hexdump(len=6): 02 08 00 06 1a 03
EAP: EAP entering state SEND_RESPONSE
EAP: EAP entering state IDLE
IEEE 802.1X RX: version=1 type=0 length=120
WPA: EAPOL frame (type 0) discarded, not a Key frame
EAPOL: SUPP_BE entering state RESPONSE
EAPOL: txSuppRsp
EAPOL: SUPP_BE entering state RECEIVE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Received EAP-Packet frame
EAPOL: SUPP_BE entering state REQUEST
EAPOL: getSuppRsp
EAP: EAP entering state RECEIVED
EAP: Received EAP-Success
EAP: EAP entering state SUCCESS
WPA: EAPOL frame too short, len 46, expecting at least 99
EAPOL: SUPP_BE entering state RECEIVE
EAPOL: SUPP_BE entering state SUCCESS
EAPOL: SUPP_BE entering state IDLE
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=95
? EAPOL-Key type=254
WPA: RX message 1 of 4-Way Handshake from 00:0c:85:60:f1:f1 (ver=1)
WPA: WPA IE for msg 2/4 - 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 01
WPA: Renewed SNonce - hexdump(len=32): cd 34 cf b4 a4 84 d0 e5 1b 14 95 7b b3 
c9 21 be b5 29 92 59 f3 b8 9e 41 ce dc 9b b0 ea 54 7a ac
WPA: PMK from EAPOL state machines - hexdump(len=32): 00 89 59 76 a4 e6 28 b0 
c3 ee 2e e8 12 fa 85 ab 4a e9 2a e8 8c 78 22 fd bd 9c 33 81 58 41 64 84
WPA: PMK - hexdump(len=32): 00 89 59 76 a4 e6 28 b0 c3 ee 2e e8 12 fa 85 ab 4a 
e9 2a e8 8c 78 22 fd bd 9c 33 81 58 41 64 84
WPA: PTK - hexdump(len=64): 7e 65 0a 6f 04 ec ea 8c ff 89 4b e5 cb 22 0b 59 5d 
21 1c 04 7d d0 dd e0 51 33 3b 92 03 cb 28 4c 91 71 4b c9 6b 9e 8c d9 25 1f a6 
fd 0a 3e 29 b6 a1 e6 f2 82 e4 2e 9f ab fe ca 81 58 a1 92 69 49
WPA: EAPOL-Key MIC - hexdump(len=16): b5 fd 4d 4a ba 5c 5e 32 36 74 31 be 67 
08 0b ed
WPA: Sending EAPOL-Key 2/4
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=119
? EAPOL-Key type=254
WPA: RX message 3 of 4-Way Handshake from 00:0c:85:60:f1:f1 (ver=1)
WPA: Sending EAPOL-Key 4/4
WPA: Installing PTK to the driver.
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_madwifi_set_key: alg=TKIP key_idx=0 set_tx=1 seq_len=6 key_len=32
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=127
? EAPOL-Key type=254
WPA: RX message 1 of Group Key Handshake from 00:0c:85:60:f1:f1 (ver=1)
WPA: Group Key - hexdump(len=32): 97 15 a8 09 da 59 64 b4 f8 f3 87 49 e6 b2 a4 
a0 16 c8 30 8a 5f 69 80 00 51 55 54 f4 e4 e9 43 a4
WPA: Installing GTK to the driver (keyidx=1 tx=0).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_madwifi_set_key: alg=TKIP key_idx=1 set_tx=0 seq_len=6 key_len=32
WPA: Sending EAPOL-Key 2/2
WPA: Key negotiation completed with 00:0c:85:60:f1:f1
Cancelling authentication timeout
EAPOL: External notification - portValid=1
EAPOL: SUPP_PAE entering state AUTHENTICATED

------> When I use wpa_supplicant 0.2.2 with the hostap driver, it stops here 
and the card is then working. the next log I ever see is when the group key 
changes.

--> but immediately here I get this. Is my AP confused and restarting the 
negotiations? or is the Radius server doing this?

RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=127
? EAPOL-Key type=254
WPA: RX message 1 of Group Key Handshake from 00:0c:85:60:f1:f1 (ver=1)
WPA: Group Key - hexdump(len=32): 97 15 a8 09 da 59 64 b4 f8 f3 87 49 e6 b2 a4 
a0 16 c8 30 8a 5f 69 80 00 51 55 54 f4 e4 e9 43 a4
WPA: Installing GTK to the driver (keyidx=1 tx=0).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_madwifi_set_key: alg=TKIP key_idx=1 set_tx=0 seq_len=6 key_len=32
WPA: Sending EAPOL-Key 2/2
WPA: Key negotiation completed with 00:0c:85:60:f1:f1
Cancelling authentication timeout
EAPOL: External notification - portValid=1
RX EAPOL from 00:0c:85:60:f1:f1
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
IEEE 802.1X RX: version=1 type=3 length=127
? EAPOL-Key type=254
WPA: RX message 1 of Group Key Handshake from 00:0c:85:60:f1:f1 (ver=1)
WPA: Group Key - hexdump(len=32): 97 15 a8 09 da 59 64 b4 f8 f3 87 49 e6 b2 a4 
a0 16 c8 30 8a 5f 69 80 00 51 55 54 f4 e4 e9 43 a4
WPA: Installing GTK to the driver (keyidx=1 tx=0).
WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
wpa_driver_madwifi_set_key: alg=TKIP key_idx=1 set_tx=0 seq_len=6 key_len=32
WPA: Sending EAPOL-Key 2/2
WPA: Key negotiation completed with 00:0c:85:60:f1:f1
Cancelling authentication timeout
EAPOL: External notification - portValid=1
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:00:00:00:00:00
Setting scan request: 0 sec 100000 usec
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: SUPP_BE entering state INITIALIZE
EAP: EAP entering state DISABLED
EAPOL: External notification - portValid=0
Disconnect event - remove keys
wpa_driver_madwifi_del_key: keyidx=0
wpa_driver_madwifi_del_key: keyidx=1
wpa_driver_madwifi_del_key: keyidx=2
wpa_driver_madwifi_del_key: keyidx=3
wpa_driver_madwifi_del_key: keyidx=0
Starting AP scan (broadcast SSID)
Wireless event: cmd=0x8b1a len=12

--> at this point it starts all over again scanning for an AP, so I killed it

Signal 2 received - terminating
wpa_driver_madwifi_del_key: keyidx=0
wpa_driver_madwifi_del_key: keyidx=1
wpa_driver_madwifi_del_key: keyidx=2
wpa_driver_madwifi_del_key: keyidx=3
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
wpa_driver_madwifi_set_wpa: enabled=0
wpa_driver_madwifi_set_drop_unencrypted: enabled=0
wpa_driver_madwifi_set_countermeasures: enabled=0

anyone have any insight into this or want more information?

thanks,

Derek