wpa_supplicant on bonding slave

Sun Feb 8 11:04:53 PST 2009

On Fri, 06 Feb 2009 18:33:35 +0000, Brian J. Murrell wrote:
> 
> OK.  I tried to send that here.  Got moderated due to file size.  The
> log can be found at: http://brian.interlinx.bc.ca/wpa_supplicant.debug

OK.  Just in case there is a fear of fetching random web URLs, I will try 
to post enough of the log here to be useful, within the limits of the 
25KB max. message size for this list.

79.448350: Initializing interface 'eth2' conf '/var/tmp/wpa_supplicant.conf' driver 'default' ctrl_interface 'N/A' bridge 'bond0'
79.448465: Configuration file '/var/tmp/wpa_supplicant.conf' -> '/var/tmp/wpa_supplicant.conf'
79.448479: Reading configuration file '/var/tmp/wpa_supplicant.conf'
79.448549: Line: 1 - start of a new network block
79.448579: ssid - hexdump_ascii(len=9):
     69 6c 69 6e 78 5f 77 70 61                        ilinx_wpa       
79.448619: key_mgmt: 0x2
79.448628: pairwise: 0x10
79.448635: group: 0x8
79.448643: PSK - hexdump(len=32): [REMOVED]
79.448684: Priority group 0
79.448693:    id=0 ssid='ilinx_wpa'
79.448702: Initializing interface (2) 'eth2'
79.454328: EAPOL: SUPP_PAE entering state DISCONNECTED
79.454341: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
79.454346: EAPOL: SUPP_BE entering state INITIALIZE
79.454359: EAP: EAP entering state DISABLED
79.454375: EAPOL: External notification - portEnabled=0
79.454398: EAPOL: External notification - portValid=0
79.454545: SIOCGIWRANGE: WE(compiled)=22 WE(source)=18 enc_capa=0xf
79.454558:   capabilities: key_mgmt 0xf enc 0xf
79.454646: WEXT: Operstate: linkmode=1, operstate=5
79.465880: Own MAC address: 00:0e:35:eb:cf:e1
79.465910: Receiving packets from bridge interface 'bond0'
79.477866: wpa_driver_wext_set_wpa
79.478109: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
79.478128: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
79.478139: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
79.478151: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
79.478160: wpa_driver_wext_set_countermeasures
79.478167: wpa_driver_wext_set_drop_unencrypted
79.478204: Setting scan request: 0 sec 100000 usec
79.478224: Added interface eth2
79.478305: RTM_NEWLINK: operstate=0 ifi_flags=0x11803 ([UP][LOWER_UP])
79.478314: Wireless event: cmd=0x8b06 len=8
79.480807: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
79.480819: Wireless event: cmd=0x8b15 len=20
79.480824: Wireless event: new AP: 00:00:00:00:00:00
79.480848: Added BSSID 00:00:00:00:00:00 into blacklist
79.480879: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
79.480885: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
79.491232: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
79.491255: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
79.491265: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
79.491274: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
79.491284: State: DISCONNECTED -> DISCONNECTED
79.491290: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
79.491309: WEXT: Operstate: linkmode=-1, operstate=5
79.491321: EAPOL: External notification - portEnabled=0
79.491328: EAPOL: External notification - portValid=0
79.491338: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
79.491346: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
79.581916: State: DISCONNECTED -> SCANNING
79.581928: Starting AP scan (broadcast SSID)
79.581932: Trying to get current scan results first without requesting a new scan to speed up initial association
79.582052: Received 679 bytes of scan results (3 BSSes)
79.582059: Scan results: 3
79.582066: Selecting BSS from priority group 0
79.582070: Try to find WPA-enabled AP
79.582075: 0: 00:12:17:41:37:c8 ssid='ilinx_wpa' wpa_ie_len=0 rsn_ie_len=26 caps=0x11
79.582089:    selected based on RSN IE
79.582093:    selected WPA AP 00:12:17:41:37:c8 ssid='ilinx_wpa'
79.582100: Try to find non-WPA AP
79.582126: Trying to associate with 00:12:17:41:37:c8 (SSID='ilinx_wpa' freq=2437 MHz)
79.582132: Cancelling scan request
79.582137: WPA: clearing own WPA/RSN IE
79.582141: Automatic auth_alg selection: 0x1
79.582166: RSN: using IEEE 802.11i/D9.0
79.582171: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
79.582178: WPA: clearing AP WPA IE
79.582183: 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 00 00
79.582208: WPA: using GTK TKIP
79.582213: WPA: using PTK CCMP
79.582219: WPA: using KEY_MGMT WPA-PSK
79.582224: WPA: Set own WPA IE default - 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
79.582243: No keys have been configured - skip key clearing
79.582248: wpa_driver_wext_set_drop_unencrypted
79.582256: State: SCANNING -> ASSOCIATING
79.582261: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
79.582271: WEXT: Operstate: linkmode=-1, operstate=5
79.582292: wpa_driver_wext_associate
79.583800: Setting authentication timeout: 10 sec 0 usec
79.583815: EAPOL: External notification - EAP success=0
79.583823: EAPOL: External notification - EAP fail=0
79.583828: EAPOL: External notification - portControl=Auto
79.583839: RSN: Ignored PMKID candidate without preauth flag
79.583872: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
79.583881: Wireless event: cmd=0x8b06 len=8
79.583889: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
79.583895: Wireless event: cmd=0x8b04 len=12
79.583905: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
79.583911: Wireless event: cmd=0x8b1a len=17
80.468638: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
80.468682: Wireless event: cmd=0x8b19 len=8
80.470369: Received 676 bytes of scan results (3 BSSes)
80.470384: Scan results: 3
80.470408: Selecting BSS from priority group 0
80.470413: Try to find WPA-enabled AP
80.470418: 0: 00:12:17:41:37:c8 ssid='ilinx_wpa' wpa_ie_len=0 rsn_ie_len=26 caps=0x11
80.470432:    selected based on RSN IE
80.470437:    selected WPA AP 00:12:17:41:37:c8 ssid='ilinx_wpa'
80.470444: Try to find non-WPA AP
80.470448: Already associated with the selected AP.
80.470456: RSN: Ignored PMKID candidate without preauth flag
80.470466: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
80.470473: Wireless event: cmd=0x8b06 len=8
80.470481: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
80.470487: Wireless event: cmd=0x8b04 len=12
80.470494: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
80.470499: Wireless event: cmd=0x8b1a len=17
80.496178: Ignore event for foreign ifindex 4
80.496195: RTM_NEWLINK: operstate=0 ifi_flags=0x11803 ([UP][LOWER_UP])
80.496203: Wireless event: cmd=0x8b15 len=20
80.496222: Wireless event: new AP: 00:12:17:41:37:c8
80.496231: State: ASSOCIATING -> ASSOCIATED
80.496238: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
80.496244: WEXT: Operstate: linkmode=-1, operstate=5
80.496274: Associated to a new BSS: BSSID=00:12:17:41:37:c8
80.496281: No keys have been configured - skip key clearing
80.496289: Associated with 00:12:17:41:37:c8
80.496293: WPA: Association event - clear replay counter
80.496298: EAPOL: External notification - portEnabled=0
80.496306: EAPOL: External notification - portValid=0
80.496311: EAPOL: External notification - EAP success=0
80.496315: EAPOL: External notification - portEnabled=1
80.496320: EAPOL: SUPP_PAE entering state CONNECTING
80.496324: EAPOL: SUPP_BE entering state IDLE
80.496331: Setting authentication timeout: 10 sec 0 usec
80.496340: Cancelling scan request
80.496348: RTM_NEWLINK: operstate=0 ifi_flags=0x11803 ([UP][LOWER_UP])
80.496361: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
80.756854: Ignore event for foreign ifindex 4
81.478757: RX EAPOL from 00:12:17:41:37:c8
81.478791: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f 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 16 dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
81.478886: Setting authentication timeout: 10 sec 0 usec
81.478908: IEEE 802.1X RX: version=2 type=3 length=117
81.478914:   EAPOL-Key type=2
81.478918:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
81.478926:   key_length=16 key_data_length=22
81.478931:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
81.478941:   key_nonce - hexdump(len=32): 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f
81.478980:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
81.478995:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
81.479004:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
81.479014:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
81.479030: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f 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 16 dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
81.479134: State: ASSOCIATED -> 4WAY_HANDSHAKE
81.479141: WPA: RX message 1 of 4-Way Handshake from 00:12:17:41:37:c8 (ver=2)
81.479155: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
81.479174: RSN: PMKID from Authenticator - hexdump(len=16): 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
81.479187: RSN: no matching PMKID found
81.482180: WPA: Renewed SNonce - hexdump(len=32): ef 9f 7e a0 a9 35 f6 1f 64 a1 0b 80 8a 99 96 4c 84 2a 3d 11 25 79 cf db f9 b8 95 99 a1 79 18 02
81.482267: WPA: PMK - hexdump(len=32): [REMOVED]
81.482274: WPA: PTK - hexdump(len=64): [REMOVED]
81.482279: 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
81.482299: WPA: Sending EAPOL-Key 2/4
81.482310: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 ef 9f 7e a0 a9 35 f6 1f 64 a1 0b 80 8a 99 96 4c 84 2a 3d 11 25 79 cf db f9 b8 95 99 a1 79 18 02 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 ea 46 23 d6 8e 34 85 ba 82 fd 58 ff d7 83 ac 9b 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
81.486481: RX EAPOL from 00:12:17:41:37:c8
81.486493: RX EAPOL - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60 69 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 cb 94 79 da 5b 9e a1 4d d8 ac 0d 1e ba 47 80 af 00 50 bc a7 20 88 7f 44 dd 91 7b d9 a3 22 30 16 2c e4 95 16 fc 7c 10 ad b2 0d a6 4e 17 8f 38 db 11 95 3d 6a b1 84 1e a1 14 52 fc 43 56 d3 bd 4c 94 5a f9 16 9d 79 1c a2 f1 d6 f0 8d 3a 37 ae 79 06 d1 3a 7f 92 8c dc 9b cb ec b3 c0 61 0b 39 5a c4 30
81.486598: IEEE 802.1X RX: version=2 type=3 length=175
81.486604:   EAPOL-Key type=2
81.486608:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
81.486616:   key_length=16 key_data_length=80
81.486629:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
81.486638:   key_nonce - hexdump(len=32): 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f
81.486658:   key_iv - hexdump(len=16): 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60
81.486670:   key_rsc - hexdump(len=8): 69 03 00 00 00 00 00 00
81.486679:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
81.486687:   key_mic - hexdump(len=16): cb 94 79 da 5b 9e a1 4d d8 ac 0d 1e ba 47 80 af
81.486700: WPA: RX EAPOL-Key - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 5f 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60 69 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 cb 94 79 da 5b 9e a1 4d d8 ac 0d 1e ba 47 80 af 00 50 bc a7 20 88 7f 44 dd 91 7b d9 a3 22 30 16 2c e4 95 16 fc 7c 10 ad b2 0d a6 4e 17 8f 38 db 11 95 3d 6a b1 84 1e a1 14 52 fc 43 56 d3 bd 4c 94 5a f9 16 9d 79 1c a2 f1 d6 f0 8d 3a 37 ae 79 06 d1 3a 7f 92 8c dc 9b cb ec b3 c0 61 0b 39 5a c4 30
81.486808: RSN: encrypted key data - hexdump(len=80): bc a7 20 88 7f 44 dd 91 7b d9 a3 22 30 16 2c e4 95 16 fc 7c 10 ad b2 0d a6 4e 17 8f 38 db 11 95 3d 6a b1 84 1e a1 14 52 fc 43 56 d3 bd 4c 94 5a f9 16 9d 79 1c a2 f1 d6 f0 8d 3a 37 ae 79 06 d1 3a 7f 92 8c dc 9b cb ec b3 c0 61 0b 39 5a c4 30
81.486905: WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
81.486913: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
81.486918: WPA: RX message 3 of 4-Way Handshake from 00:12:17:41:37:c8 (ver=2)
81.486925: 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 00 00 dd 26 00 0f ac 01 02 00 57 01 3f 32 dc d4 6c 34 8d 7b 84 3a 42 1a c6 15 85 30 e2 c7 df 8f 88 c8 ec 7d ca 10 88 42 0f 8a dd 00 00 00 00 00
81.486972: WPA: Sending EAPOL-Key 4/4
81.486983: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 00 00 00 00 00 00 00 00 00 02 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 2f e1 8a db 12 d7 9f ed fb 9f b8 1e 63 e8 0d 1c 00 00
81.487058: WPA: Installing PTK to the driver.
81.487064: wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
81.487114: EAPOL: External notification - portValid=1
81.487122: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
81.487127: RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
81.487133: WPA: Group Key - hexdump(len=32): [REMOVED]
81.487138: WPA: Installing GTK to the driver (keyidx=2 tx=0).
81.487143: WPA: RSC - hexdump(len=6): 69 03 00 00 00 00
81.487152: wpa_driver_wext_set_key: alg=2 key_idx=2 set_tx=0 seq_len=6 key_len=32
81.487191: WPA: Key negotiation completed with 00:12:17:41:37:c8 [PTK=CCMP GTK=TKIP]
81.487204: Cancelling authentication timeout
81.487209: State: GROUP_HANDSHAKE -> COMPLETED
81.487221: CTRL-EVENT-CONNECTED - Connection to 00:12:17:41:37:c8 completed (auth) [id=0 id_str=]
81.487226: wpa_driver_wext_set_operstate: operstate 0->1 (UP)
81.487232: WEXT: Operstate: linkmode=-1, operstate=6
81.487979: EAPOL: External notification - portValid=1
81.487986: EAPOL: External notification - EAP success=1
81.487991: EAPOL: SUPP_PAE entering state AUTHENTICATING
81.487995: EAPOL: SUPP_BE entering state SUCCESS
81.487999: EAP: EAP entering state DISABLED
81.488003: EAPOL: SUPP_PAE entering state AUTHENTICATED
81.488007: EAPOL: SUPP_BE entering state IDLE
81.488035: RTM_NEWLINK: operstate=1 ifi_flags=0x11843 ([UP][RUNNING][LOWER_UP])
81.488065: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
83.461886: EAPOL: startWhen --> 0
90.499143: RTM_NEWLINK: operstate=1 ifi_flags=0x11803 ([UP][LOWER_UP])
90.499174: WEXT: Operstate: linkmode=-1, operstate=6
90.499921: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
90.499934: RTM_NEWLINK: operstate=1 ifi_flags=0x11843 ([UP][RUNNING][LOWER_UP])
90.499941: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
90.502082: RTM_NEWLINK: operstate=1 ifi_flags=0x1843 ([UP][RUNNING])
90.502097: Wireless event: cmd=0x8b15 len=20
90.502102: Wireless event: new AP: 00:00:00:00:00:00
90.502120: Setting scan request: 0 sec 100000 usec
90.502131: Added BSSID 00:12:17:41:37:c8 into blacklist
90.502140: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
90.502145: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
90.511137: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
90.511160: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
90.511173: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
90.511197: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
90.511209: State: COMPLETED -> DISCONNECTED
90.511215: wpa_driver_wext_set_operstate: operstate 1->0 (DORMANT)
90.511221: WEXT: Operstate: linkmode=-1, operstate=5
90.511238: EAPOL: External notification - portEnabled=0
90.511243: EAPOL: SUPP_PAE entering state DISCONNECTED
90.511247: EAPOL: SUPP_BE entering state INITIALIZE
90.511254: EAPOL: External notification - portValid=0
90.511259: EAPOL: External notification - EAP success=0
90.511270: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
90.511278: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
90.605868: State: DISCONNECTED -> SCANNING
90.605882: Starting AP scan (broadcast SSID)
91.508082: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.508101: Wireless event: cmd=0x8b19 len=8
91.512862: Received 452 bytes of scan results (2 BSSes)
91.512892: Scan results: 2
91.512901: Selecting BSS from priority group 0
91.512906: Try to find WPA-enabled AP
91.512910: 0: 00:12:17:41:37:c8 ssid='ilinx_wpa' wpa_ie_len=0 rsn_ie_len=26 caps=0x11
91.512924:    selected based on RSN IE
91.512928:    selected WPA AP 00:12:17:41:37:c8 ssid='ilinx_wpa'
91.512936: Try to find non-WPA AP
91.512950: Trying to associate with 00:12:17:41:37:c8 (SSID='ilinx_wpa' freq=2437 MHz)
91.512957: Cancelling scan request
91.512962: WPA: clearing own WPA/RSN IE
91.512966: Automatic auth_alg selection: 0x1
91.512981: RSN: using IEEE 802.11i/D9.0
91.512986: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
91.512993: WPA: clearing AP WPA IE
91.512998: 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 00 00
91.513020: WPA: using GTK TKIP
91.513031: WPA: using PTK CCMP
91.513037: WPA: using KEY_MGMT WPA-PSK
91.513042: WPA: Set own WPA IE default - 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
91.513061: No keys have been configured - skip key clearing
91.513066: wpa_driver_wext_set_drop_unencrypted
91.513075: State: SCANNING -> ASSOCIATING
91.513080: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
91.513086: WEXT: Operstate: linkmode=-1, operstate=5
91.513102: wpa_driver_wext_associate
91.513144: Setting authentication timeout: 10 sec 0 usec
91.513153: EAPOL: External notification - EAP success=0
91.513161: EAPOL: External notification - EAP fail=0
91.513165: EAPOL: External notification - portControl=Auto
91.513177: Ignore event for foreign ifindex 4
91.513184: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.513191: Wireless event: cmd=0x8b06 len=8
91.513198: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.513207: Wireless event: cmd=0x8b04 len=12
91.513214: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.513220: Wireless event: cmd=0x8b1a len=17
91.514948: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.514962: Wireless event: cmd=0x8b06 len=8
91.514971: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.514976: Wireless event: cmd=0x8b04 len=12
91.514983: RTM_NEWLINK: operstate=0 ifi_flags=0x1803 ([UP])
91.514988: Wireless event: cmd=0x8b1a len=17
91.533303: RTM_NEWLINK: operstate=0 ifi_flags=0x11803 ([UP][LOWER_UP])
91.533315: Wireless event: cmd=0x8b15 len=20
91.533320: Wireless event: new AP: 00:12:17:41:37:c8
91.533327: State: ASSOCIATING -> ASSOCIATED
91.533333: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
91.533339: WEXT: Operstate: linkmode=-1, operstate=5
91.533360: Associated to a new BSS: BSSID=00:12:17:41:37:c8
91.533379: No keys have been configured - skip key clearing
91.533387: Associated with 00:12:17:41:37:c8
91.533392: WPA: Association event - clear replay counter
91.533396: EAPOL: External notification - portEnabled=0
91.533403: EAPOL: External notification - portValid=0
91.533408: EAPOL: External notification - EAP success=0
91.533413: EAPOL: External notification - portEnabled=1
91.533417: EAPOL: SUPP_PAE entering state CONNECTING
91.533422: EAPOL: SUPP_BE entering state IDLE
91.533428: Setting authentication timeout: 10 sec 0 usec
91.533439: Cancelling scan request
91.533447: RTM_NEWLINK: operstate=0 ifi_flags=0x11803 ([UP][LOWER_UP])
91.533454: RTM_NEWLINK, IFLA_IFNAME: Interface 'eth2' added
91.760635: Ignore event for foreign ifindex 4
92.514643: RX EAPOL from 00:12:17:41:37:c8
92.514660: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60 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 16 dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
92.514764: Setting authentication timeout: 10 sec 0 usec
92.514775: IEEE 802.1X RX: version=2 type=3 length=117
92.514781:   EAPOL-Key type=2
92.514786:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
92.514794:   key_length=16 key_data_length=22
92.514799:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
92.514809:   key_nonce - hexdump(len=32): 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60
92.514828:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
92.514841:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
92.514850:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
92.514864:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
92.514878: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 17 ac 76 b2 5b a9 e3 dc db 31 97 3c 92 5a 39 66 22 75 29 e1 ca e3 93 e5 e0 63 71 35 22 14 41 60 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 16 dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
92.514964: State: ASSOCIATED -> 4WAY_HANDSHAKE
92.514970: WPA: RX message 1 of 4-Way Handshake from 00:12:17:41:37:c8 (ver=2)
92.514978: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
92.514996: RSN: PMKID from Authenticator - hexdump(len=16): 0b 8e 0b 0e 86 e0 b2 86 ac 77 ca 14 51 24 65 9e
92.515010: RSN: no matching PMKID found