Re: change wpa-psk authentication timeout



I split the log in 2 for clarity.
The second part (wpa_supplicant.log_close) contains the log of a
successful authentication (i moved closer to the AP).

Thanks,

Fabio Airoldi.

(P.S.: in the previous message I forgot to write that my network card is
a Intel Corporation Wireless WiFi Link 5100)
Failed to initiate AP scan.
Failed to initiate AP scan.
Trying to associate with 00:13:1a:59:82:81 (SSID='internet' freq=2437 MHz)
Associated with 00:13:1a:59:82:81
CTRL-EVENT-EAP-STARTED EAP authentication started
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:140CD00D:SSL routines:SSL_use_RSAPrivateKey_ASN1:ASN1 lib
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Failed to initiate AP scan.
Trying to associate with 00:13:1a:59:82:81 (SSID='internet' freq=2437 MHz)
Associated with 00:13:1a:59:82:81
CTRL-EVENT-EAP-STARTED EAP authentication started
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:140CD00D:SSL routines:SSL_use_RSAPrivateKey_ASN1:ASN1 lib
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
WPA: Key negotiation completed with 00:13:1a:59:82:81 [PTK=CCMP GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:13:1a:59:82:81 completed (auth) [id=0 id_str=]
Trying to associate with 00:13:1a:47:38:91 (SSID='internet' freq=2437 MHz)
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Associated with 00:13:1a:47:38:91
CTRL-EVENT-EAP-STARTED EAP authentication started
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
WPA: Key negotiation completed with 00:13:1a:47:38:91 [PTK=CCMP GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:13:1a:47:38:91 completed (reauth) [id=0 id_str=]
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Failed to initiate AP scan.
Failed to initiate AP scan.
Trying to associate with 00:13:1a:59:82:81 (SSID='internet' freq=2437 MHz)
Associated with 00:13:1a:59:82:81
CTRL-EVENT-EAP-STARTED EAP authentication started
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:140CD00D:SSL routines:SSL_use_RSAPrivateKey_ASN1:ASN1 lib
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
WPA: Key negotiation completed with 00:13:1a:59:82:81 [PTK=CCMP GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:13:1a:59:82:81 completed (auth) [id=0 id_str=]
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Failed to initiate AP scan.
Failed to initiate AP scan.
Trying to associate with 00:13:1a:59:82:81 (SSID='internet' freq=2437 MHz)
Associated with 00:13:1a:59:82:81
CTRL-EVENT-EAP-STARTED EAP authentication started
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:140CD00D:SSL routines:SSL_use_RSAPrivateKey_ASN1:ASN1 lib
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
WPA: Key negotiation completed with 00:13:1a:59:82:81 [PTK=CCMP GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:13:1a:59:82:81 completed (auth) [id=0 id_str=]
Trying to associate with 00:13:1a:59:82:81 (SSID='internet' freq=2437 MHz)
Associated with 00:13:1a:59:82:81
CTRL-EVENT-EAP-STARTED EAP authentication started
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:0D09A00D:asn1 encoding routines:d2i_PrivateKey:ASN1 lib
OpenSSL: pending error: error:140CA00D:SSL routines:SSL_use_PrivateKey_ASN1:ASN1 lib
OpenSSL: pending error: error:0D06C03A:asn1 encoding routines:ASN1_D2I_EX_PRIMITIVE:nested asn1 error
OpenSSL: pending error: error:0D08303A:asn1 encoding routines:ASN1_TEMPLATE_NOEXP_D2I:nested asn1 error
OpenSSL: pending error: error:140CD00D:SSL routines:SSL_use_RSAPrivateKey_ASN1:ASN1 lib
CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected
OpenSSL: tls_connection_handshake - Failed to read possible Application Data error:00000000:lib(0):func(0):reason(0)
CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
WPA: Key negotiation completed with 00:13:1a:59:82:81 [PTK=CCMP GTK=TKIP]
CTRL-EVENT-CONNECTED - Connection to 00:13:1a:59:82:81 completed (auth) [id=0 id_str=]
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Failed to initiate AP scan.
Failed to initiate AP scan.
Failed to initiate AP scan.
Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
Associated with 00:11:f5:ca:38:8e
Authentication with 00:11:f5:ca:38:8e timed out.
Failed to initiate AP scan.
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
Associated with 00:11:f5:ca:38:8e
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Authentication with 00:00:00:00:00:00 timed out.
Failed to initiate AP scan.
Failed to initiate AP scan.
Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
Associated with 00:11:f5:ca:38:8e
Authentication with 00:11:f5:ca:38:8e timed out.
Failed to initiate AP scan.
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-TERMINATING - signal 15 received
1257875822.119524: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.
1257875822.121409: Initializing interface 'wlan0' conf 'N/A' driver 'wext' ctrl_interface 'N/A' bridge 'N/A'
1257875822.121429: Initializing interface (2) 'wlan0'
1257875822.241929: Interface wlan0 set UP - waiting a second for the driver to complete initialization
1257875823.242771: SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
1257875823.242856:   capabilities: key_mgmt 0xf enc 0xf flags 0x0
1257875823.249868: WEXT: Operstate: linkmode=1, operstate=5
1257875823.253331: Own MAC address: 00:24:d6:2e:7c:14
1257875823.253417: wpa_driver_wext_set_wpa
1257875823.253466: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875823.253513: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
1257875823.253550: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
1257875823.253587: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
1257875823.253624: wpa_driver_wext_set_countermeasures
1257875823.253657: wpa_driver_wext_set_drop_unencrypted
1257875823.253687: RSN: flushing PMKID list in the driver
1257875823.253749: Setting scan request: 0 sec 100000 usec
1257875823.256164: EAPOL: SUPP_PAE entering state DISCONNECTED
1257875823.256209: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1257875823.256234: EAPOL: SUPP_BE entering state INITIALIZE
1257875823.256263: EAP: EAP entering state DISABLED
1257875823.256319: Added interface wlan0
1257875823.256469: Ignore event for foreign ifindex 3
1257875823.256527: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875823.256557: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875823.256593: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875823.256623: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875823.256649: Wireless event: cmd=0x8b06 len=12
1257875823.259941: Setting scan request: 0 sec 0 usec
1257875823.260051: State: DISCONNECTED -> SCANNING
1257875823.260146: Starting AP scan (broadcast SSID)
1257875823.260179: Trying to get current scan results first without requesting a new scan to speed up initial association
1257875823.260269: Received 831 bytes of scan results (2 BSSes)
1257875823.260309: CTRL-EVENT-SCAN-RESULTS 
1257875823.260377: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875823.260418: No suitable AP found.
1257875823.260446: Setting scan request: 0 sec 0 usec
1257875823.260484: Starting AP scan (broadcast SSID)
1257875823.260630: Scan requested (ret=-1) - scan timeout 5 seconds
1257875823.260668: Failed to initiate AP scan.
1257875823.260733: Setting scan request: 10 sec 0 usec
1257875823.260994: Setting scan request: 0 sec 0 usec
1257875823.261093: Starting AP scan (broadcast SSID)
1257875823.261214: Scan requested (ret=-1) - scan timeout 5 seconds
1257875823.261250: Failed to initiate AP scan.
1257875823.261318: Setting scan request: 10 sec 0 usec
1257875824.257565: EAPOL: disable timer tick
1257875828.265523: Scan timeout - try to get results
1257875828.265707: Received 835 bytes of scan results (2 BSSes)
1257875828.265756: CTRL-EVENT-SCAN-RESULTS 
1257875828.265880: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875828.265925: No suitable AP found.
1257875828.265960: Setting scan request: 5 sec 0 usec
1257875833.271272: No enabled networks - do not scan
1257875833.271377: State: SCANNING -> INACTIVE
1257875837.336402: key_mgmt: 0x2
1257875837.336430: scan_ssid=1 (0x1)
1257875837.336450: PSK (ASCII passphrase) - hexdump_ascii(len=12): [REMOVED]
1257875837.336466: ssid - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875837.347906: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1257875837.348351: Setting scan request: 0 sec 0 usec
1257875837.348502: State: INACTIVE -> SCANNING
1257875837.348738: Starting AP scan (specific SSID)
1257875837.348755: Scan SSID - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875837.348957: Scan requested (ret=0) - scan timeout 5 seconds
1257875840.590459: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875840.590568: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875840.590602: Wireless event: cmd=0x8b19 len=16
1257875840.590782: Received 835 bytes of scan results (2 BSSes)
1257875840.590838: CTRL-EVENT-SCAN-RESULTS 
1257875840.590913: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875840.590956: Selecting BSS from priority group 0
1257875840.590985: Try to find WPA-enabled AP
1257875840.591013: 0: 02:21:91:1c:49:29 ssid='Amby' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1257875840.591060:    skip - SSID mismatch
1257875840.591089: 1: 00:11:f5:ca:38:8e ssid='default' wpa_ie_len=28 rsn_ie_len=24 caps=0x11
1257875840.591134:    selected based on RSN IE
1257875840.591164:    selected WPA AP 00:11:f5:ca:38:8e ssid='default'
1257875840.591201: Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
1257875840.591234: Cancelling scan request
1257875840.591265: WPA: clearing own WPA/RSN IE
1257875840.591341: Automatic auth_alg selection: 0x1
1257875840.591388: RSN: using IEEE 802.11i/D9.0
1257875840.591420: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
1257875840.591452: WPA: set AP WPA IE - hexdump(len=30): dd 1c 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 04 00 50 f2 02 01 00 00 50 f2 02 0c 00
1257875840.591497: 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
1257875840.591541: WPA: using GTK TKIP
1257875840.591572: WPA: using PTK CCMP
1257875840.591604: WPA: using KEY_MGMT WPA-PSK
1257875840.591635: 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
1257875840.591676: No keys have been configured - skip key clearing
1257875840.591705: wpa_driver_wext_set_drop_unencrypted
1257875840.591737: State: SCANNING -> ASSOCIATING
1257875840.591832: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875840.591875: WEXT: Operstate: linkmode=-1, operstate=5
1257875840.591924: wpa_driver_wext_associate
1257875840.591977: wpa_driver_wext_set_psk
1257875840.594702: Setting authentication timeout: 20 sec 0 usec
1257875840.594760: EAPOL: External notification - EAP success=0
1257875840.594827: EAPOL: External notification - EAP fail=0
1257875840.594859: EAPOL: External notification - portControl=Auto
1257875840.594898: RSN: Ignored PMKID candidate without preauth flag
1257875840.594936: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875840.594971: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875840.595058: Wireless event: cmd=0x8b06 len=12
1257875840.595104: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875840.595161: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875840.595186: Wireless event: cmd=0x8b04 len=16
1257875840.607577: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875840.607616: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875840.607626: Wireless event: cmd=0x8c02 len=255
1257875840.607638: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=000764656661756c74010802040b160c12182432043048606c30140100000fac020100000fac040100000fac020000dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd060010180202f0dd180050f2020101880003a4000027a4000042435e0062322f00)'
1257875840.607649: Association info event
1257875840.607657: req_ies - hexdump(len=56): 00 07 64 65 66 61 75 6c 74 01 08 02 04 0b 16 0c 12 18 24 32 04 30 48 60 6c 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 07 00 50 f2 02 00 01 00
1257875840.607674: resp_ies - hexdump(len=50): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 dd 06 00 10 18 02 02 f0 dd 18 00 50 f2 02 01 01 88 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
1257875840.607690: 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
1257875840.665529: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257875840.665570: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875840.665580: Wireless event: cmd=0x8b15 len=24
1257875840.665589: Wireless event: new AP: 00:11:f5:ca:38:8e
1257875840.665599: State: ASSOCIATING -> ASSOCIATED
1257875840.665661: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875840.665672: WEXT: Operstate: linkmode=-1, operstate=5
1257875840.666031: Associated to a new BSS: BSSID=00:11:f5:ca:38:8e
1257875840.666042: No keys have been configured - skip key clearing
1257875840.666052: Associated with 00:11:f5:ca:38:8e
1257875840.666061: WPA: Association event - clear replay counter
1257875840.666070: WPA: Clear old PTK
1257875840.666077: EAPOL: External notification - portEnabled=0
1257875840.666087: EAPOL: External notification - portValid=0
1257875840.666096: EAPOL: External notification - EAP success=0
1257875840.666105: EAPOL: External notification - portEnabled=1
1257875840.666113: EAPOL: SUPP_PAE entering state CONNECTING
1257875840.666121: EAPOL: enable timer tick
1257875840.666130: EAPOL: SUPP_BE entering state IDLE
1257875840.666140: Setting authentication timeout: 10 sec 0 usec
1257875840.666150: Cancelling scan request
1257875840.666161: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257875840.666171: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875841.599618: RX EAPOL from 00:11:f5:ca:38:8e
1257875841.599714: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 27 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875841.599802: Setting authentication timeout: 10 sec 0 usec
1257875841.599846: IEEE 802.1X RX: version=2 type=3 length=117
1257875841.599880:   EAPOL-Key type=2
1257875841.599903:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1257875841.599930:   key_length=16 key_data_length=22
1257875841.599953:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1257875841.599982:   key_nonce - hexdump(len=32): 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 27
1257875841.600019:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257875841.600099:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1257875841.600127:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1257875841.600154:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257875841.600189: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 27 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875841.600324: State: ASSOCIATED -> 4WAY_HANDSHAKE
1257875841.600467: WPA: RX message 1 of 4-Way Handshake from 00:11:f5:ca:38:8e (ver=2)
1257875841.600502: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875841.600537: RSN: PMKID from Authenticator - hexdump(len=16): 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875841.600568: RSN: no matching PMKID found
1257875841.602661: WPA: Renewed SNonce - hexdump(len=32): a7 e6 84 eb ed 4a 31 85 16 87 40 32 3d 86 72 0b c4 bc cc 15 19 66 49 40 7a c8 9d 03 0e 23 7e 1e
1257875841.602743: WPA: PTK derivation - A1=00:24:d6:2e:7c:14 A2=00:11:f5:ca:38:8e
1257875841.602772: WPA: PMK - hexdump(len=32): [REMOVED]
1257875841.602796: WPA: PTK - hexdump(len=64): [REMOVED]
1257875841.602823: 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
1257875841.602859: WPA: Sending EAPOL-Key 2/4
1257875841.602888: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 a7 e6 84 eb ed 4a 31 85 16 87 40 32 3d 86 72 0b c4 bc cc 15 19 66 49 40 7a c8 9d 03 0e 23 7e 1e 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 6c 7c 0b 29 66 31 9a 97 b3 e8 d5 89 b5 a7 c9 42 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1257875843.668598: EAPOL: startWhen --> 0
1257875843.668647: EAPOL: disable timer tick
1257875843.668659: EAPOL: SUPP_PAE entering state CONNECTING
1257875843.668671: EAPOL: enable timer tick
1257875843.668685: EAPOL: txStart
1257875843.668697: WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
1257875844.002452: Setting scan request: 0 sec 0 usec
1257875844.002583: Starting AP scan (broadcast SSID)
1257875844.003211: Scan requested (ret=0) - scan timeout 30 seconds
1257875844.003280: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257875844.003312: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875844.003339: Wireless event: cmd=0x8b19 len=16
1257875844.003459: Received 833 bytes of scan results (2 BSSes)
1257875844.003500: CTRL-EVENT-SCAN-RESULTS 
1257875844.003566: wpa_driver_wext_get_signal_quality: level -70 (146), qual 40 (70)
1257875844.003600: wpa_supplicant_event_scan_results: qual 40 (70)  qv=1  bv=1
1257875844.003626: Selecting BSS from priority group 0
1257875844.003649: Try to find current BSSID 00:11:f5:ca:38:8e
1257875844.003674:    skip - BSSID mismatch
1257875844.003696:    found
1257875844.003717: Try to find WPA-enabled AP
1257875844.003740: 0: 02:21:91:1c:49:29 ssid='Amby' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1257875844.003767:    skip - SSID mismatch
1257875844.003790: 1: 00:11:f5:ca:38:8e ssid='default' wpa_ie_len=28 rsn_ie_len=24 caps=0x11
1257875844.003819:    selected based on RSN IE
1257875844.003842:    matched associated BSSID
1257875844.003864:    selected WPA AP 00:11:f5:ca:38:8e ssid='default'
1257875844.003889: Already associated with the selected AP.
1257875851.601047: Authentication with 00:11:f5:ca:38:8e timed out.
1257875851.601148: Added BSSID 00:11:f5:ca:38:8e into blacklist
1257875851.601183: wpa_driver_wext_disassociate
1257875851.604717: No keys have been configured - skip key clearing
1257875851.604796: State: 4WAY_HANDSHAKE -> DISCONNECTED
1257875851.604973: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875851.605014: WEXT: Operstate: linkmode=-1, operstate=5
1257875851.605055: EAPOL: External notification - portEnabled=0
1257875851.605090: EAPOL: SUPP_PAE entering state DISCONNECTED
1257875851.605115: EAPOL: SUPP_BE entering state INITIALIZE
1257875851.605142: EAPOL: External notification - portValid=0
1257875851.605167: EAPOL: External notification - EAP success=0
1257875851.605203: Setting scan request: 0 sec 0 usec
1257875851.605716: State: DISCONNECTED -> SCANNING
1257875851.605819: Starting AP scan (specific SSID)
1257875851.605857: Scan SSID - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875851.606028: Scan requested (ret=-1) - scan timeout 30 seconds
1257875851.606084: Failed to initiate AP scan.
1257875851.606150: Setting scan request: 10 sec 0 usec
1257875851.606197: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875851.606229: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875851.606256: Wireless event: cmd=0x8b15 len=24
1257875851.606282: Wireless event: new AP: 00:00:00:00:00:00
1257875851.606372: Added BSSID 00:00:00:00:00:00 into blacklist
1257875851.606403: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
1257875851.606431: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875851.617832: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
1257875851.617914: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
1257875851.617949: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
1257875851.617984: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875851.618095: Driver did not support SIOCSIWENCODEEXT
1257875851.618133: State: SCANNING -> DISCONNECTED
1257875851.618252: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875851.618311: WEXT: Operstate: linkmode=-1, operstate=5
1257875851.618358: EAPOL: External notification - portEnabled=0
1257875851.618390: EAPOL: External notification - portValid=0
1257875851.618417: EAPOL: External notification - EAP success=0
1257875851.618450: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875851.618481: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875861.607171: State: DISCONNECTED -> SCANNING
1257875861.607310: Starting AP scan (broadcast SSID)
1257875861.607355: Scan requested (ret=0) - scan timeout 30 seconds
1257875863.005550: No keys have been configured - skip key clearing
1257875863.005611: State: SCANNING -> DISCONNECTED
1257875863.005733: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875863.005777: WEXT: Operstate: linkmode=-1, operstate=5
1257875863.005827: EAPOL: External notification - portEnabled=0
1257875863.005863: EAPOL: External notification - portValid=0
1257875863.005894: EAPOL: External notification - EAP success=0
1257875864.858256: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875864.858388: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875864.858423: Wireless event: cmd=0x8b19 len=16
1257875864.858524: Received 835 bytes of scan results (2 BSSes)
1257875864.858591: CTRL-EVENT-SCAN-RESULTS 
1257875873.701115: EAPOL: startWhen --> 0
1257875873.701213: EAPOL: disable timer tick
1257875874.003878: Setting scan request: 0 sec 0 usec
1257875874.004018: State: DISCONNECTED -> SCANNING
1257875874.004126: Starting AP scan (broadcast SSID)
1257875874.004237: Scan requested (ret=0) - scan timeout 30 seconds
1257875877.230156: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875877.230251: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875877.230303: Wireless event: cmd=0x8b19 len=16
1257875877.230472: Received 835 bytes of scan results (2 BSSes)
1257875877.230533: CTRL-EVENT-SCAN-RESULTS 
1257875879.909533: No keys have been configured - skip key clearing
1257875879.909561: State: SCANNING -> DISCONNECTED
1257875879.909595: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875879.909607: WEXT: Operstate: linkmode=-1, operstate=5
1257875879.909627: EAPOL: External notification - portEnabled=0
1257875879.909639: EAPOL: External notification - portValid=0
1257875879.909649: EAPOL: External notification - EAP success=0
1257875879.910602: key_mgmt: 0x2
1257875879.910623: scan_ssid=1 (0x1)
1257875879.910636: PSK (ASCII passphrase) - hexdump_ascii(len=12): [REMOVED]
1257875879.910651: ssid - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875879.918948: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1257875879.919389: Setting scan request: 0 sec 0 usec
1257875879.919605: State: DISCONNECTED -> SCANNING
1257875879.919913: Starting AP scan (specific SSID)
1257875879.920000: Scan SSID - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875879.920315: Scan requested (ret=0) - scan timeout 30 seconds
1257875883.168721: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875883.168812: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875883.168839: Wireless event: cmd=0x8b19 len=16
1257875883.169005: Received 835 bytes of scan results (2 BSSes)
1257875883.169049: CTRL-EVENT-SCAN-RESULTS 
1257875883.169119: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875883.169151: Selecting BSS from priority group 0
1257875883.169175: Try to find WPA-enabled AP
1257875883.169198: 0: 02:21:91:1c:49:29 ssid='Amby' wpa_ie_len=24 rsn_ie_len=0 caps=0x11
1257875883.169227:    skip - SSID mismatch
1257875883.169250: 1: 00:11:f5:ca:38:8e ssid='default' wpa_ie_len=28 rsn_ie_len=24 caps=0x11
1257875883.169279:    selected based on RSN IE
1257875883.169333:    selected WPA AP 00:11:f5:ca:38:8e ssid='default'
1257875883.169368: Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
1257875883.169396: Cancelling scan request
1257875883.169422: WPA: clearing own WPA/RSN IE
1257875883.169458: Automatic auth_alg selection: 0x1
1257875883.169495: RSN: using IEEE 802.11i/D9.0
1257875883.169522: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
1257875883.169549: WPA: set AP WPA IE - hexdump(len=30): dd 1c 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 04 00 50 f2 02 01 00 00 50 f2 02 0c 00
1257875883.169589: 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
1257875883.169627: WPA: using GTK TKIP
1257875883.169653: WPA: using PTK CCMP
1257875883.169679: WPA: using KEY_MGMT WPA-PSK
1257875883.169705: 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
1257875883.169741: No keys have been configured - skip key clearing
1257875883.169764: wpa_driver_wext_set_drop_unencrypted
1257875883.169791: State: SCANNING -> ASSOCIATING
1257875883.169887: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875883.169919: WEXT: Operstate: linkmode=-1, operstate=5
1257875883.169961: wpa_driver_wext_associate
1257875883.170003: wpa_driver_wext_set_psk
1257875883.170717: Setting authentication timeout: 20 sec 0 usec
1257875883.172275: EAPOL: External notification - EAP success=0
1257875883.172542: EAPOL: External notification - EAP fail=0
1257875883.172775: EAPOL: External notification - portControl=Auto
1257875883.173016: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875883.173254: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875883.173510: Wireless event: cmd=0x8b06 len=12
1257875883.173745: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875883.173978: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875883.174213: Wireless event: cmd=0x8b04 len=16
1257875883.176261: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875883.176332: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875883.176383: Wireless event: cmd=0x8c02 len=255
1257875883.176412: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=000764656661756c74010802040b160c12182432043048606c30140100000fac020100000fac040100000fac020000dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd060010180202f0dd180050f2020101880003a4000027a4000042435e0062322f00)'
1257875883.176505: Association info event
1257875883.176529: req_ies - hexdump(len=56): 00 07 64 65 66 61 75 6c 74 01 08 02 04 0b 16 0c 12 18 24 32 04 30 48 60 6c 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 07 00 50 f2 02 00 01 00
1257875883.176577: resp_ies - hexdump(len=50): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 dd 06 00 10 18 02 02 f0 dd 18 00 50 f2 02 01 01 88 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
1257875883.176747: 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
1257875883.181190: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257875883.181268: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875883.181295: Wireless event: cmd=0x8b15 len=24
1257875883.181322: Wireless event: new AP: 00:11:f5:ca:38:8e
1257875883.181348: State: ASSOCIATING -> ASSOCIATED
1257875883.181457: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875883.181490: WEXT: Operstate: linkmode=-1, operstate=5
1257875883.181547: Associated to a new BSS: BSSID=00:11:f5:ca:38:8e
1257875883.181575: No keys have been configured - skip key clearing
1257875883.181602: Associated with 00:11:f5:ca:38:8e
1257875883.181628: WPA: Association event - clear replay counter
1257875883.181650: WPA: Clear old PTK
1257875883.181672: EAPOL: External notification - portEnabled=0
1257875883.181698: EAPOL: External notification - portValid=0
1257875883.181723: EAPOL: External notification - EAP success=0
1257875883.181747: EAPOL: External notification - portEnabled=1
1257875883.181771: EAPOL: SUPP_PAE entering state CONNECTING
1257875883.181793: EAPOL: enable timer tick
1257875883.181817: EAPOL: SUPP_BE entering state IDLE
1257875883.181844: Setting authentication timeout: 10 sec 0 usec
1257875883.181873: Cancelling scan request
1257875883.181904: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257875883.181936: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875884.169538: RX EAPOL from 00:11:f5:ca:38:8e
1257875884.169629: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875884.169716: Setting authentication timeout: 10 sec 0 usec
1257875884.169747: IEEE 802.1X RX: version=2 type=3 length=117
1257875884.169775:   EAPOL-Key type=2
1257875884.169797:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1257875884.169825:   key_length=16 key_data_length=22
1257875884.169850:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1257875884.169879:   key_nonce - hexdump(len=32): 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 28
1257875884.169918:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257875884.169950:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1257875884.169979:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1257875884.170007:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257875884.170080: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 28 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875884.170185: State: ASSOCIATED -> 4WAY_HANDSHAKE
1257875884.170313: WPA: RX message 1 of 4-Way Handshake from 00:11:f5:ca:38:8e (ver=2)
1257875884.170354: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875884.170388: RSN: PMKID from Authenticator - hexdump(len=16): 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257875884.170421: RSN: no matching PMKID found
1257875884.172443: WPA: Renewed SNonce - hexdump(len=32): ce 42 78 84 15 72 d3 16 c5 dc e3 11 ef 76 75 46 3f 65 87 e6 46 d0 8e 68 4e 60 1f 3b 34 fb bb 55
1257875884.172521: WPA: PTK derivation - A1=00:24:d6:2e:7c:14 A2=00:11:f5:ca:38:8e
1257875884.172553: WPA: PMK - hexdump(len=32): [REMOVED]
1257875884.172578: WPA: PTK - hexdump(len=64): [REMOVED]
1257875884.172604: 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
1257875884.172671: WPA: Sending EAPOL-Key 2/4
1257875884.172704: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 ce 42 78 84 15 72 d3 16 c5 dc e3 11 ef 76 75 46 3f 65 87 e6 46 d0 8e 68 4e 60 1f 3b 34 fb bb 55 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 12 cf 88 9a 24 8c 29 fb 82 d0 14 a7 e6 79 cb d3 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1257875886.184599: EAPOL: startWhen --> 0
1257875886.184716: EAPOL: disable timer tick
1257875886.184748: EAPOL: SUPP_PAE entering state CONNECTING
1257875886.184777: EAPOL: enable timer tick
1257875886.184810: EAPOL: txStart
1257875886.184838: WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
1257875894.170807: Authentication with 00:11:f5:ca:38:8e timed out.
1257875894.170862: BSSID 00:11:f5:ca:38:8e blacklist count incremented to 2
1257875894.170880: wpa_driver_wext_disassociate
1257875894.179538: No keys have been configured - skip key clearing
1257875894.179961: State: 4WAY_HANDSHAKE -> DISCONNECTED
1257875894.183527: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875894.183840: WEXT: Operstate: linkmode=-1, operstate=5
1257875894.184099: EAPOL: External notification - portEnabled=0
1257875894.184361: EAPOL: SUPP_PAE entering state DISCONNECTED
1257875894.184607: EAPOL: SUPP_BE entering state INITIALIZE
1257875894.184845: EAPOL: External notification - portValid=0
1257875894.185091: EAPOL: External notification - EAP success=0
1257875894.185352: Setting scan request: 0 sec 0 usec
1257875894.185608: State: DISCONNECTED -> SCANNING
1257875894.185912: Starting AP scan (broadcast SSID)
1257875894.186342: Scan requested (ret=-1) - scan timeout 30 seconds
1257875894.186605: Failed to initiate AP scan.
1257875894.186886: Setting scan request: 10 sec 0 usec
1257875894.187138: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875894.187403: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875894.187643: Wireless event: cmd=0x8b15 len=24
1257875894.187877: Wireless event: new AP: 00:00:00:00:00:00
1257875894.188119: BSSID 00:00:00:00:00:00 blacklist count incremented to 2
1257875894.188386: CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
1257875894.188621: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875894.188867: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
1257875894.189112: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
1257875894.189378: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
1257875894.189624: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875894.189914: Driver did not support SIOCSIWENCODEEXT
1257875894.190157: State: SCANNING -> DISCONNECTED
1257875894.190483: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875894.190729: WEXT: Operstate: linkmode=-1, operstate=5
1257875894.190977: EAPOL: External notification - portEnabled=0
1257875894.191222: EAPOL: External notification - portValid=0
1257875894.191482: EAPOL: External notification - EAP success=0
1257875894.191724: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875894.191962: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875904.188395: State: DISCONNECTED -> SCANNING
1257875904.189047: Starting AP scan (specific SSID)
1257875904.189412: Scan SSID - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257875904.189859: Scan requested (ret=0) - scan timeout 30 seconds
1257875905.002953: No keys have been configured - skip key clearing
1257875905.011878: State: SCANNING -> DISCONNECTED
1257875905.012242: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875905.015565: WEXT: Operstate: linkmode=-1, operstate=5
1257875905.015827: EAPOL: External notification - portEnabled=0
1257875905.016073: EAPOL: External notification - portValid=0
1257875905.016325: EAPOL: External notification - EAP success=0
1257875907.461136: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875907.461236: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875907.461266: Wireless event: cmd=0x8b19 len=16
1257875907.461365: Received 835 bytes of scan results (2 BSSes)
1257875907.461413: CTRL-EVENT-SCAN-RESULTS 
1257875916.216010: EAPOL: startWhen --> 0
1257875916.216145: EAPOL: disable timer tick
1257875924.003114: Setting scan request: 0 sec 0 usec
1257875924.003258: State: DISCONNECTED -> SCANNING
1257875924.003354: Starting AP scan (broadcast SSID)
1257875924.003450: Scan requested (ret=0) - scan timeout 30 seconds
1257875927.230370: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875927.230492: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875927.230522: Wireless event: cmd=0x8b19 len=16
1257875927.230696: Received 835 bytes of scan results (2 BSSes)
1257875927.230746: CTRL-EVENT-SCAN-RESULTS 
1257875927.230746: CTRL-EVENT-SCAN-RESULTS 
1257875978.249031: CTRL-EVENT-TERMINATING - signal 15 received
1257875978.249134: Removing interface wlan0
1257875978.249162: State: SCANNING -> DISCONNECTED
1257875978.249299: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257875978.249339: WEXT: Operstate: linkmode=-1, operstate=5
1257875978.249389: No keys have been configured - skip key clearing
1257875978.249420: EAPOL: External notification - portEnabled=0
1257875978.249449: EAPOL: External notification - portValid=0
1257875978.249476: wpa_driver_wext_set_wpa
1257875978.249513: wpa_driver_wext_set_drop_unencrypted
1257875978.249542: wpa_driver_wext_set_countermeasures
1257875978.249572: No keys have been configured - skip key clearing
1257875978.254361: Removed BSSID 00:00:00:00:00:00 from blacklist (clear)
1257875978.254420: Removed BSSID 00:11:f5:ca:38:8e from blacklist (clear)
1257875978.254570: Cancelling scan request
1257875978.254603: Cancelling authentication timeout
1257875978.254962: WEXT: Operstate: linkmode=0, operstate=6
1257875978.314714: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.
1257875978.316661: Initializing interface 'wlan0' conf 'N/A' driver 'wext' ctrl_interface 'N/A' bridge 'N/A'
1257875978.316686: Initializing interface (2) 'wlan0'
1257875978.349414: Interface wlan0 set UP - waiting a second for the driver to complete initialization
1257875979.349948: SIOCGIWRANGE: WE(compiled)=22 WE(source)=21 enc_capa=0xf
1257875979.350042:   capabilities: key_mgmt 0xf enc 0xf flags 0x0
1257875979.356129: WEXT: Operstate: linkmode=1, operstate=5
1257875979.360087: Own MAC address: 00:24:d6:2e:7c:14
1257875979.360155: wpa_driver_wext_set_wpa
1257875979.360197: wpa_driver_wext_set_key: alg=0 key_idx=0 set_tx=0 seq_len=0 key_len=0
1257875979.360238: wpa_driver_wext_set_key: alg=0 key_idx=1 set_tx=0 seq_len=0 key_len=0
1257875979.360274: wpa_driver_wext_set_key: alg=0 key_idx=2 set_tx=0 seq_len=0 key_len=0
1257875979.360309: wpa_driver_wext_set_key: alg=0 key_idx=3 set_tx=0 seq_len=0 key_len=0
1257875979.360344: wpa_driver_wext_set_countermeasures
1257875979.360376: wpa_driver_wext_set_drop_unencrypted
1257875979.360405: RSN: flushing PMKID list in the driver
1257875979.360466: Setting scan request: 0 sec 100000 usec
1257875979.362737: EAPOL: SUPP_PAE entering state DISCONNECTED
1257875979.362778: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1257875979.362802: EAPOL: SUPP_BE entering state INITIALIZE
1257875979.362832: EAP: EAP entering state DISABLED
1257875979.362884: Added interface wlan0
1257875979.363024: Ignore event for foreign ifindex 3
1257875979.363095: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875979.363125: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875979.363162: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257875979.363191: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257875979.363218: Wireless event: cmd=0x8b06 len=12
1257875979.366479: Setting scan request: 0 sec 0 usec
1257875979.366572: State: DISCONNECTED -> SCANNING
1257875979.366664: Starting AP scan (broadcast SSID)
1257875979.366696: Trying to get current scan results first without requesting a new scan to speed up initial association
1257875979.366810: Received 829 bytes of scan results (2 BSSes)
1257875979.366846: CTRL-EVENT-SCAN-RESULTS 
1257875979.366911: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875979.366948: No suitable AP found.
1257875979.366972: Setting scan request: 0 sec 0 usec
1257875979.367005: Starting AP scan (broadcast SSID)
1257875979.367173: Scan requested (ret=-1) - scan timeout 5 seconds
1257875979.367212: Failed to initiate AP scan.
1257875979.367273: Setting scan request: 10 sec 0 usec
1257875979.367502: Setting scan request: 0 sec 0 usec
1257875979.367581: Starting AP scan (broadcast SSID)
1257875979.367695: Scan requested (ret=-1) - scan timeout 5 seconds
1257875979.367730: Failed to initiate AP scan.
1257875979.367792: Setting scan request: 10 sec 0 usec
1257875980.364139: EAPOL: disable timer tick
1257875984.371823: Scan timeout - try to get results
1257875984.371983: Received 835 bytes of scan results (2 BSSes)
1257875984.372021: CTRL-EVENT-SCAN-RESULTS 
1257875984.372173: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257875984.372205: No suitable AP found.
1257875984.372232: Setting scan request: 5 sec 0 usec
1257875989.377540: No enabled networks - do not scan
1257875989.377633: State: SCANNING -> INACTIVE
1257876000.002206: Setting scan request: 0 sec 0 usec
1257876000.002345: State: INACTIVE -> SCANNING
1257876000.002436: Starting AP scan (broadcast SSID)
1257876000.002533: Scan requested (ret=0) - scan timeout 5 seconds
1257876003.228369: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257876003.228466: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876003.228494: Wireless event: cmd=0x8b19 len=16
1257876003.228664: Received 835 bytes of scan results (2 BSSes)
1257876003.228708: CTRL-EVENT-SCAN-RESULTS 
1257876003.228776: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257876003.228809: No suitable AP found.
1257876003.228835: Setting scan request: 5 sec 0 usec
1257876008.234149: No enabled networks - do not scan
1257876008.234253: State: SCANNING -> INACTIVE
1257876015.554520: key_mgmt: 0x2
1257876015.554550: scan_ssid=1 (0x1)
1257876015.554564: PSK (ASCII passphrase) - hexdump_ascii(len=12): [REMOVED]
1257876015.554579: ssid - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257876015.563344: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1257876015.563764: Setting scan request: 0 sec 0 usec
1257876015.563952: State: INACTIVE -> SCANNING
1257876015.564247: Starting AP scan (specific SSID)
1257876015.564296: Scan SSID - hexdump_ascii(len=7):
     64 65 66 61 75 6c 74                              default         
1257876015.564569: Scan requested (ret=0) - scan timeout 30 seconds
1257876018.807177: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257876018.807327: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876018.807369: Wireless event: cmd=0x8b19 len=16
1257876018.807565: Received 835 bytes of scan results (2 BSSes)
1257876018.807647: CTRL-EVENT-SCAN-RESULTS 
1257876018.807751: wpa_supplicant_event_scan_results: qual 0 (0)  qv=0  bv=0
1257876018.807804: Selecting BSS from priority group 0
1257876018.807836: Try to find WPA-enabled AP
1257876018.807865: 0: 00:11:f5:ca:38:8e ssid='default' wpa_ie_len=28 rsn_ie_len=24 caps=0x11
1257876018.807920:    selected based on RSN IE
1257876018.807955:    selected WPA AP 00:11:f5:ca:38:8e ssid='default'
1257876018.807998: Trying to associate with 00:11:f5:ca:38:8e (SSID='default' freq=2417 MHz)
1257876018.808033: Cancelling scan request
1257876018.808065: WPA: clearing own WPA/RSN IE
1257876018.808117: Automatic auth_alg selection: 0x1
1257876018.808161: RSN: using IEEE 802.11i/D9.0
1257876018.808192: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
1257876018.808223: WPA: set AP WPA IE - hexdump(len=30): dd 1c 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 04 00 50 f2 02 01 00 00 50 f2 02 0c 00
1257876018.808266: 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
1257876018.808408: WPA: using GTK TKIP
1257876018.808438: WPA: using PTK CCMP
1257876018.808463: WPA: using KEY_MGMT WPA-PSK
1257876018.808489: 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
1257876018.808525: No keys have been configured - skip key clearing
1257876018.808551: wpa_driver_wext_set_drop_unencrypted
1257876018.808579: State: SCANNING -> ASSOCIATING
1257876018.808696: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257876018.808735: WEXT: Operstate: linkmode=-1, operstate=5
1257876018.808795: wpa_driver_wext_associate
1257876018.808839: wpa_driver_wext_set_psk
1257876018.810464: Setting authentication timeout: 20 sec 0 usec
1257876018.810565: EAPOL: External notification - EAP success=0
1257876018.810596: EAPOL: External notification - EAP fail=0
1257876018.810621: EAPOL: External notification - portControl=Auto
1257876018.810656: RSN: Ignored PMKID candidate without preauth flag
1257876018.810691: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257876018.810719: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876018.810744: Wireless event: cmd=0x8b06 len=12
1257876018.810771: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257876018.810797: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876018.810821: Wireless event: cmd=0x8b04 len=16
1257876018.816640: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1257876018.816706: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876018.816732: Wireless event: cmd=0x8c02 len=255
1257876018.816758: WEXT: Custom wireless event: 'ASSOCINFO(ReqIEs=000764656661756c74010802040b160c12182432043048606c30140100000fac020100000fac040100000fac020000dd070050f202000100 RespIEs=010882848b962430486c32040c121860dd060010180202f0dd180050f2020101880003a4000027a4000042435e0062322f00)'
1257876018.816790: Association info event
1257876018.816814: req_ies - hexdump(len=56): 00 07 64 65 66 61 75 6c 74 01 08 02 04 0b 16 0c 12 18 24 32 04 30 48 60 6c 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 07 00 50 f2 02 00 01 00
1257876018.816861: resp_ies - hexdump(len=50): 01 08 82 84 8b 96 24 30 48 6c 32 04 0c 12 18 60 dd 06 00 10 18 02 02 f0 dd 18 00 50 f2 02 01 01 88 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
1257876018.816907: 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
1257876018.843318: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257876018.843404: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876018.843431: Wireless event: cmd=0x8b15 len=24
1257876018.843456: Wireless event: new AP: 00:11:f5:ca:38:8e
1257876018.843483: State: ASSOCIATING -> ASSOCIATED
1257876018.843625: wpa_driver_wext_set_operstate: operstate 0->0 (DORMANT)
1257876018.843659: WEXT: Operstate: linkmode=-1, operstate=5
1257876018.843718: Associated to a new BSS: BSSID=00:11:f5:ca:38:8e
1257876018.843747: No keys have been configured - skip key clearing
1257876018.843774: Associated with 00:11:f5:ca:38:8e
1257876018.843799: WPA: Association event - clear replay counter
1257876018.843822: WPA: Clear old PTK
1257876018.843844: EAPOL: External notification - portEnabled=0
1257876018.843872: EAPOL: External notification - portValid=0
1257876018.843896: EAPOL: External notification - EAP success=0
1257876018.843921: EAPOL: External notification - portEnabled=1
1257876018.843945: EAPOL: SUPP_PAE entering state CONNECTING
1257876018.843967: EAPOL: enable timer tick
1257876018.843991: EAPOL: SUPP_BE entering state IDLE
1257876018.844018: Setting authentication timeout: 10 sec 0 usec
1257876018.844068: Cancelling scan request
1257876018.844098: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1257876018.844127: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876019.809977: RX EAPOL from 00:11:f5:ca:38:8e
1257876019.810116: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257876019.810239: Setting authentication timeout: 10 sec 0 usec
1257876019.810294: IEEE 802.1X RX: version=2 type=3 length=117
1257876019.810330:   EAPOL-Key type=2
1257876019.810353:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1257876019.810380:   key_length=16 key_data_length=22
1257876019.810403:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1257876019.810429:   key_nonce - hexdump(len=32): 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29
1257876019.810465:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257876019.810495:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1257876019.810522:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1257876019.810549:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1257876019.810583: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257876019.810677: State: ASSOCIATED -> 4WAY_HANDSHAKE
1257876019.810821: WPA: RX message 1 of 4-Way Handshake from 00:11:f5:ca:38:8e (ver=2)
1257876019.810856: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257876019.810890: RSN: PMKID from Authenticator - hexdump(len=16): 01 ef fd c9 f6 b2 97 b1 71 aa b7 b6 18 75 06 04
1257876019.810920: RSN: no matching PMKID found
1257876019.813061: WPA: Renewed SNonce - hexdump(len=32): 5a 99 a1 ba 08 24 b2 3a c2 43 6f 35 8f 48 35 4c 45 52 e1 95 d1 e8 b8 f3 ee 7d ee 7d 26 42 e4 1e
1257876019.813142: WPA: PTK derivation - A1=00:24:d6:2e:7c:14 A2=00:11:f5:ca:38:8e
1257876019.813172: WPA: PMK - hexdump(len=32): [REMOVED]
1257876019.813196: WPA: PTK - hexdump(len=64): [REMOVED]
1257876019.813223: 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
1257876019.813260: WPA: Sending EAPOL-Key 2/4
1257876019.813289: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 5a 99 a1 ba 08 24 b2 3a c2 43 6f 35 8f 48 35 4c 45 52 e1 95 d1 e8 b8 f3 ee 7d ee 7d 26 42 e4 1e 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 5b be a9 0d a4 75 28 45 86 85 5d 38 25 e8 a6 34 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1257876019.815737: RX EAPOL from 00:11:f5:ca:38:8e
1257876019.815787: RX EAPOL - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 2a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4f 4e 4b 61 2d b1 71 05 62 bb 70 5f 9f d3 58 db 00 50 7a 74 f2 0a b2 fb 6f fb 4f cb 24 02 c9 a5 4d 1a 65 eb 8d 8a db 46 2b cd 31 57 01 3a f1 82 4c 96 52 3a d4 c6 ec 1d 58 98 6e 56 17 93 8d dd 33 6c d3 e5 01 e8 de dd c8 c0 6e 28 e7 44 3f 41 f8 a8 c1 fa 6e 8d c2 cd 9c 9f 33 a3 db 38 c1 41 e5 78
1257876019.815888: IEEE 802.1X RX: version=2 type=3 length=175
1257876019.815913:   EAPOL-Key type=2
1257876019.815936:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1257876019.815963:   key_length=16 key_data_length=80
1257876019.815985:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
1257876019.816012:   key_nonce - hexdump(len=32): 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29
1257876019.816072:   key_iv - hexdump(len=16): 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 2a
1257876019.816103:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1257876019.816154:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1257876019.816183:   key_mic - hexdump(len=16): 4f 4e 4b 61 2d b1 71 05 62 bb 70 5f 9f d3 58 db
1257876019.816216: WPA: RX EAPOL-Key - hexdump(len=179): 02 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 84 fb 44 d0 99 01 45 0b 70 25 48 a3 65 3b 67 cf 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 29 8a f0 0b d8 00 63 0d 2d c8 f4 1d 2c cf 23 e8 2a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4f 4e 4b 61 2d b1 71 05 62 bb 70 5f 9f d3 58 db 00 50 7a 74 f2 0a b2 fb 6f fb 4f cb 24 02 c9 a5 4d 1a 65 eb 8d 8a db 46 2b cd 31 57 01 3a f1 82 4c 96 52 3a d4 c6 ec 1d 58 98 6e 56 17 93 8d dd 33 6c d3 e5 01 e8 de dd c8 c0 6e 28 e7 44 3f 41 f8 a8 c1 fa 6e 8d c2 cd 9c 9f 33 a3 db 38 c1 41 e5 78
1257876019.816331: RSN: encrypted key data - hexdump(len=80): 7a 74 f2 0a b2 fb 6f fb 4f cb 24 02 c9 a5 4d 1a 65 eb 8d 8a db 46 2b cd 31 57 01 3a f1 82 4c 96 52 3a d4 c6 ec 1d 58 98 6e 56 17 93 8d dd 33 6c d3 e5 01 e8 de dd c8 c0 6e 28 e7 44 3f 41 f8 a8 c1 fa 6e 8d c2 cd 9c 9f 33 a3 db 38 c1 41 e5 78
1257876019.816427: WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
1257876019.816455: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1257876019.816478: WPA: RX message 3 of 4-Way Handshake from 00:11:f5:ca:38:8e (ver=2)
1257876019.816504: 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 01 00 45 de 41 0a 57 e3 dd b1 f2 15 96 44 ac b0 36 df a8 8b 70 7b 47 62 b9 72 9a 6a 60 dc 2f c9 14 40 dd 00 00 00 00 00
1257876019.816560: WPA: Sending EAPOL-Key 4/4
1257876019.816590: 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 1f ce 7b 49 19 8d b5 72 fc 40 2b d0 e3 83 56 5f 00 00
1257876019.816690: WPA: Installing PTK to the driver.
1257876019.816719: wpa_driver_wext_set_key: alg=3 key_idx=0 set_tx=1 seq_len=6 key_len=16
1257876019.935852: EAPOL: External notification - portValid=1
1257876019.935931: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1257876019.936058: RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
1257876019.936095: WPA: Group Key - hexdump(len=32): [REMOVED]
1257876019.936120: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32).
1257876019.936143: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
1257876019.936171: wpa_driver_wext_set_key: alg=2 key_idx=1 set_tx=0 seq_len=6 key_len=32
1257876019.936225: WPA: Key negotiation completed with 00:11:f5:ca:38:8e [PTK=CCMP GTK=TKIP]
1257876019.936255: Cancelling authentication timeout
1257876019.936281: State: GROUP_HANDSHAKE -> COMPLETED
1257876019.936379: CTRL-EVENT-CONNECTED - Connection to 00:11:f5:ca:38:8e completed (auth) [id=0 id_str=]
1257876019.936410: wpa_driver_wext_set_operstate: operstate 0->1 (UP)
1257876019.936436: WEXT: Operstate: linkmode=-1, operstate=6
1257876019.937921: EAPOL: External notification - portValid=1
1257876019.937959: EAPOL: External notification - EAP success=1
1257876019.937983: EAPOL: SUPP_PAE entering state AUTHENTICATING
1257876019.938006: EAPOL: SUPP_BE entering state SUCCESS
1257876019.938029: EAP: EAP entering state DISABLED
1257876019.938073: EAPOL: SUPP_PAE entering state AUTHENTICATED
1257876019.938096: EAPOL: SUPP_BE entering state IDLE
1257876019.938119: EAPOL authentication completed successfully
1257876019.938167: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1257876019.938199: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876021.940706: EAPOL: startWhen --> 0
1257876021.940809: EAPOL: disable timer tick
1257876030.003642: Setting scan request: 0 sec 0 usec
1257876030.003785: Starting AP scan (broadcast SSID)
1257876030.003979: Scan requested (ret=0) - scan timeout 30 seconds
1257876034.106955: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1257876034.107102: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1257876034.107160: Wireless event: cmd=0x8b19 len=16
1257876034.107489: Received 834 bytes of scan results (2 BSSes)
1257876034.107536: CTRL-EVENT-SCAN-RESULTS 
1257876034.107604: wpa_driver_wext_get_signal_quality: level -52 (146), qual 58 (70)
1257876034.107638: wpa_supplicant_event_scan_results: qual 58 (70)  qv=1  bv=1
1257876034.107663: Selecting BSS from priority group 0
1257876034.107686: Try to find current BSSID 00:11:f5:ca:38:8e
1257876034.107712:    found
1257876034.107733: Try to find WPA-enabled AP
1257876034.107756: 0: 00:11:f5:ca:38:8e ssid='default' wpa_ie_len=28 rsn_ie_len=24 caps=0x11
1257876034.107786:    selected based on RSN IE
1257876034.107809:    matched associated BSSID
1257876034.107832:    selected WPA AP 00:11:f5:ca:38:8e ssid='default'
1257876034.107858: Already associated with the selected AP.


[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]