WPA Supplicant connection / EAPOL not doing its magic
Mike van Niekerk
mvniekerk
Wed Oct 28 08:04:52 PDT 2009
Hi all
I need pointers as what is causing a problem on a WEXT-driver WPA2 connection.
This is my methodology:
1) Disconnect from any connections via the DISCONNECT command
2) Send the settings/keys for an AP to wpa_supplicant with ADD NETWORK et al
3) Enable the network
4) If wpa_supplicant is not SCANNING/DISCONNECTED, then fire RECONNECT
The wpa_supplicant goes all the way to being ASSOCIATED, but the EAPOL
part is lacking:
State: ASSOCIATING -> ASSOCIATED
CTRL-EVENT-STATE-CHANGE id=0 state=4
CTRL_IFACE monitor send - hexdump(len=38): 2f 64 61 74 61 2f 6d 69 73
63 2f 77 69 66 69 2f 73 6f 63 6b 65 74 73 2f 77 70 61 5f 63 74 72 6c
5f 34 38 2d 32 00
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
Associated to a new BSS: BSSID=00:22:6b:59:de:a6
No keys have been configured - skip key clearing
Associated with 00:22:6b:59:de:a6
CTRL_IFACE monitor send - hexdump(len=38): 2f 64 61 74 61 2f 6d 69 73
63 2f 77 69 66 69 2f 73 6f 63 6b 65 74 73 2f 77 70 61 5f 63 74 72 6c
5f 34 38 2d 32 00
WPA: Association event - clear replay counter
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
Setting authentication timeout: 30 sec 0 usec
Cancelling scan request
RX ctrl_iface - hexdump_ascii(len=9):
41 50 5f 53 43 41 4e 20 31 AP_SCAN 1
>>>IF AP_SCAN 1
RX ctrl_iface - hexdump_ascii(len=12):
53 43 41 4e 5f 52 45 53 55 4c 54 53 SCAN_RESULTS
>>>IF SCAN_RESULTS
RX ctrl_iface - hexdump_ascii(len=12):
53 43 41 4e 5f 52 45 53 55 4c 54 53 SCAN_RESULTS
>>>IF SCAN_RESULTS
EAPOL: startWhen --> 0
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: txStart
KEY_MGMT: PSK
WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
This will ultimately time out.
The bummer is - when saving this config to the config file, rebooting
the devices so that wpa_supplicant must pick up its state from the
config file (saved by the parameters given above), it works:
State: SCANNING -> ASSOCIATING
CTRL-EVENT-STATE-CHANGE id=-1 state=3
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
wpa_driver_wext_associate
D/StatusBar( 42): updateResources
W/ActivityManager( 42): Unable to start service Intent {
action=com.android.ussd.IExtendedNetworkService }: not found
D/PhoneApp( 90): Resetting audio state/mode: IDLE
D/dalvikvm( 92): GC freed 2676 objects / 179256 bytes in 156ms
unifi0: wlan0: link is up
I/ActivityManager( 42): Start proc com.android.mms for broadcast
com.android.mms/.transaction.SmsReceiver: pid=114 uid=10004
gids={3003}
I/ActivityManager( 42): processNextBroadcast: waiting for
ProcessRecord{436d7b60 114:com.android.mms/10004}
unifi0: Associated with "android-test"
Setting authentication timeout: 20 sec 0 usec
EAPOL: External notification - EAP success=0
EAPOL: External notification - EAP fail=0
EAPOL: External notification - portControl=Auto
RSN: Ignored PMKID candidate without preauth flag
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b06 len=8
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b04 len=12
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
Wireless event: cmd=0x8b1a len=20
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Wireless event: cmd=0x8c07 len=30
AssocReq IE wireless event - hexdump(len=22): 30 14 01 00 00 0f ac 02
01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Wireless event: cmd=0x8c08 len=61
AssocResp IE wireless event - hexdump(len=53): 01 08 82 84 8b 96 24 30
48 6c 32 04 0c 12 18 60 dd 09 00 10 18 02 00 f0 00 00 00 dd 18 00 50
f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
Wireless event: cmd=0x8b15 len=20
Wireless event: new AP: 00:22:6b:59:de:a6
Received 816 bytes of scan results (3 BSSes)
wpa_driver_wext_update_beacon_ies: - hexdump(len=26): 30 18 01 00 00
0f ac 02 02 00 00 0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00
Association info event
req_ies - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04
01 00 00 0f ac 02 00 00
resp_ies - hexdump(len=53): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12
18 60 dd 09 00 10 18 02 00 f0 00 00 00 dd 18 00 50 f2 02 01 01 80 00
03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
beacon_ies - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac
04 00 0f ac 02 01 00 00 0f ac 02 0c 00
WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 02 01
00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: set AP RSN IE - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00
0f ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00
WPA: clearing AP WPA IE
State: ASSOCIATING -> ASSOCIATED
CTRL-EVENT-STATE-CHANGE id=0 state=4
wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
WEXT: Operstate: linkmode=-1, operstate=5
Associated to a new BSS: BSSID=00:22:6b:59:de:a6
No keys have been configured - skip key clearing
Associated with 00:22:6b:59:de:a6
WPA: Association event - clear replay counter
EAPOL: External notification - portEnabled=0
EAPOL: External notification - portValid=0
EAPOL: External notification - EAP success=0
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
Setting authentication timeout: 30 sec 0 usec
Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
RX EAPOL from 00:22:6b:59:de:a6
RX EAPOL - hexdump(len=99): 02 03 00 5f 02 00 8a 00 10 00 00 00 00 00
00 00 03 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94 5e cf 68
21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 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
Setting authentication timeout: 20 sec 0 usec
D/BT HSHFP( 90): Starting BluetoothHeadsetService
IEEE 802.1X RX: version=2 type=3 length=95
EAPOL-Key type=2
key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
key_nonce - hexdump(len=32): de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82
20 7d ee 94 5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 02 03 00 5f 02 00 8a 00 10 00 00
00 00 00 00 00 03 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94
5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 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
State: ASSOCIATED -> 4WAY_HANDSHAKE
CTRL-EVENT-STATE-CHANGE id=0 state=5
WPA: RX message 1 of 4-Way Handshake from 00:22:6b:59:de:a6 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: Renewed SNonce - hexdump(len=32): e4 89 15 2c 95 7e 42 77 c4 77
82 7d d5 05 ab 37 4a 02 22 3c bd 1c 50 a6 2f e3 73 61 3d da cb f7
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 02 01
00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00
00 00 00 00 00 03 e4 89 15 2c 95 7e 42 77 c4 77 82 7d d5 05 ab 37 4a
02 22 3c bd 1c 50 a6 2f e3 73 61 3d da cb f7 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 f5 22 96 db f3 8f c3 97 f8 a1 ba 50 38 11 b2 dd 00 16 30 14 01 00
00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
W/SurfaceComposerClient( 42): lock_layer timed out (is the CPU
pegged?) layer=0, lcblk=0x41045020, state=00000000 (was 00000013)
W/SurfaceComposerClient( 42): lock_layer() timed out but didn't
appear to need to be locked and we recovered (layer=0,
lcblk=0x41045020, state=00000000)
D/HomeLoaders( 92): load applications
D/HomeLoaders( 92): loading user items
D/HomeLoaders( 92): --> starting workspace loader
D/dalvikvm( 42): GC freed 4152 objects / 184960 bytes in 181ms
RX EAPOL from 00:22:6b:59:de:a6
RX EAPOL - hexdump(len=99): 02 03 00 5f 02 00 8a 00 10 00 00 00 00 00
00 00 04 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94 5e cf 68
21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 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
IEEE 802.1X RX: version=2 type=3 length=95
EAPOL-Key type=2
key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 04
Iunifi0: siwencodeext: flags=0x1, alg=3, ext_flags=0xA, key_len=16,
//system/bin/wpa_supplicant( 83): key_nonce - hexdump(len=32): de
3b 4f 84 5e 7c a7 34 d2 28unifi0: addr=00:22:6B:59:DE:A6
be a2 82 20 7d ee 94 5e cf 68 2unifi0: SETKEYS: key 0, len 16, CSS=00:0f:ac:04
addr=00:22:6b:59:d
1 0e 13 d8 2b 03 bc 57 f9 f0 3e b5
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 02 03 00 5f 02 00 8a 00 10 00 00
00 00 00 00 00 04 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94
5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 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
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
CTRL-EVENT-STATE-CHANGE id=0 state=5
WPA: RX message 1 of 4-Way Handshake from 00:22:6b:59:de:a6 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=64): [REMOVED]
WPA: WPunifi0: siwencodeext: flags=0x3, alg=2, ext_flags=0x6, key_len=32,
A IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00
0f ac 04 01 00 00 0f ac 02 00 00
WPA: Sending EAPOL-Key 2/4
WPA: TX EAPOL-Key - hexdump(len=121unifi0: addr=FF:FF:FF:FF:FF:FF
): 01 03 00 75 02 01 0a 00 00 00unifi0: SETKEYS: key 2, len 32, CSS=00:0f:ac:02
addr=ff:ff:ff:ff:f
00 00 00 00 00 00 04 e4 89 15 2c 95 7e 42 77 c4 77 82 7d d5 05 ab 37
4a 02 22 3c bd 1c 50 a6 2f e3 73 61 3d da cb f7 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 79 e1 08 ab 87 01 bf 6b b0 63 3a ea 3e ca 40 d7 00 16 30 14 01
00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
D/StatusBar( 42): updateResources
D/HomeLoaders( 92): --> starting applications loader
RX EAPOL from 00:22:6b:59:de:a6
RX EAPOL - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00 00 00 00
00 00 05 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94 5e cf 68
21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 94 5e cf 68 21 0e 13 d8 2b 03 bc
57 f9 f0 3e b6 89 27 02 00 00 00 00 00 00 00 00 00 00 00 00 00 b3 56
25 be f9 22 cc eb bf eb f1 8b 32 17 a3 76 00 50 f7 aa 30 4a a3 7f 62
c8 01 40 71 91 45 5c 7d 4f ee 18 0b c7 6f 1e 37 03 cf 9b 5b 9c fb c9
0c 70 9d 1b f9 cd 84 d4 4a b7 75 d7 0f 3a 24 f6 2b 55 24 e2 bb 6a a5
79 11 4a bd eb 8d f7 e3 6b 16 c8 f3 09 0c 34 9d f4 56 6c 18 fd 64 7d
72 09 a9 53
IEEE 802.1X RX: version=2 type=3 length=175
EAPOL-Key type=2
key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
key_length=16 key_data_length=80
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 05
key_nonce - hexdump(len=32): de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82
20 7d ee 94 5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5
key_iv - hexdump(len=16): 94 5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b6
key_rsc - hexdump(len=8): 89 27 02 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): b3 56 25 be f9 22 cc eb bf eb f1 8b 32 17 a3 76
WPA: RX EAPOL-Key - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00
00 00 00 00 00 05 de 3b 4f 84 5e 7c a7 34 d2 28 be a2 82 20 7d ee 94
5e cf 68 21 0e 13 d8 2b 03 bc 57 f9 f0 3e b5 94 5e cf 68 21 0e 13 d8
2b 03 bc 57 f9 f0 3e b6 89 27 02 00 00 00 00 00 00 00 00 00 00 00 00
00 b3 56 25 be f9 22 cc eb bf eb f1 8b 32 17 a3 76 00 50 f7 aa 30 4a
a3 7f 62 c8 01 40 71 91 45 5c 7d 4f ee 18 0b c7 6f 1e 37 03 cf 9b 5b
9c fb c9 0c 70 9d 1b f9 cd 84 d4 4a b7 75 d7 0f 3a 24 f6 2b 55 24 e2
bb 6a a5 79 11 4a bd eb 8d f7 e3 6b 16 c8 f3 09 0c 34 9d f4 56 6c 18
fd 64 7d 72 09 a9 53
RSN: encrypted key data - hexdump(len=80): f7 aa 30 4a a3 7f 62 c8 01
40 71 91 45 5c 7d 4f ee 18 0b c7 6f 1e 37 03 cf 9b 5b 9c fb c9 0c 70
9d 1b f9 cd 84 d4 4a b7 75 d7 0f 3a 24 f6 2b 55 24 e2 bb 6a a5 79 11
4a bd eb 8d f7 e3 6b 16 c8 f3 09 0c 34 9d f4 56 6c 18 fd 64 7d 72 09
a9 53
WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
CTRL-EVENT-STATE-CHANGE id=0 state=5
WPA: RX message 3 of 4-Way Handshake from 00:22:6b:59:de:a6 (ver=2)
WPA: IE KeyData - hexdump(len=72): 30 18 01 00 00 0f ac 02 02 00 00 0f
ac 04 00 0f ac 02 01 00 00 0f ac 02 0c 00 dd 26 00 0f ac 01 02 00 3f
9f 7f 18 d9 fc 46 ee 6d 44 ed de 02 df ff 27 26 82 71 ef 28 29 5a af
e9 2b 2a 50 e2 4c c1 ff dd 00 00 00 00 00
WPA: Sending EAPOL-Key 4/4
WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 00 00 00 00
00 00 00 00 00 05 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 00 00 00 00 00 00 00 00 00 00 00 00 00
00 7f 91 72 7c 83 86 a9 4c da 28 08 42 1b 61 a0 94 00 00
WPA: Installing PTK to the driver.
wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
I/ActivityManager( 42): Start proc com.android.inputmethod.latin for
service com.android.inputmethod.latin/.LatinIME: pid=129 uid=10002
gids={3003}
EAPOL: External notification - portValid=1
State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
CTRL-EVENT-STATE-CHANGE id=0 state=6
RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
WPA: Group Key - hexdump(len=32): [REMOVED]
WPA: Installing GTK to the driver (keyidx=2 tx=0).
WPA: RSC - hexdump(len=6): 89 27 02 00 00 00
wpa_driver_wext_set_key: alg=2 key_idx=2 set_tx=0 seq_len=6 key_len=32
D/HomeLoaders( 92): --> wait for applications loader
WPA: Key negotiation completed with 00:22:6b:59:de:a6 [PTK=CCMP GTK=TKIP]
Cancelling authentication timeout
State: GROUP_HANDSHAKE -> COMPLETED
CTRL-EVENT-STATE-CHANGE id=0 state=7
CTRL-EVENT-CONNECTED - Connection to 00:22:6b:59:de:a6 completed
(auth) [id=0 id_str=]
wpa_driver_wext_set_operstate: operstate 0->1 (UP)
WEXT: Operstate: linkmode=-1, operstate=6
EAPOL: External notification - portValid=1
EAPOL: External notification - EAP success=1
EAPOL: SUPP_PAE entering state AUTHENTICATING
EAPOL: SUPP_BE entering state SUCCESS
EAP: EAP entering state DISABLED
EAPOL: SUPP_PAE entering state AUTHENTICATED
EAPOL: SUPP_BE entering state IDLE
RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
D/dalvikvm( 90): GC freed 4328 objects / 246824 bytes in 327ms
CTRL_IFACE monitor attached - hexdump(len=38): 2f 64 61 74 61 2f 6d 69
73 63 2f 77 69 66 69 2f 73 6f 63 6b 65 74 73 2f 77 70 61 5f 63 74 72
6c 5f 34 32 2d 32 00
Thus -> Give it config settings = No show
--> Save same config settings, close, reboot, reread from config file
= working connection.
I hope someone can help me.
Best regards
Mike
More information about the Hostap
mailing list