EAP-TLV: Earlier failure - force failed Phase 2
Adam Jacobs
AJacobs at mocana.com
Mon Jan 4 19:29:02 PST 2016
Okay, here's some better logging showing the failure. I reproduced this by starting wpa_supplicant manually, with the same flags as DBUS uses plus -dd. It does appear the problem is cryptobinding-related.
I still haven't found a combination of options that reproduces the failure without using NetworkManager, but I've only tried a few.
Also, the failure seems to happen pretty consistently after around 30 minutes.
1451963600.200010: wlan0: BSS: Remove id 134 BSSID f8:4f:57:13:f3:6d SSID 'QA-testnet' due to wpa_bss_flush_by_age
1451963600.200048: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/134'
1451963600.200123: wlan0: BSS: Remove id 136 BSSID f8:4f:57:13:f3:6b SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200136: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/136'
1451963600.200173: wlan0: BSS: Remove id 137 BSSID f8:4f:57:13:f3:6c SSID 'key-testnet' due to wpa_bss_flush_by_age
1451963600.200184: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/137'
1451963600.200218: wlan0: BSS: Remove id 113 BSSID 00:1d:7e:ce:85:97 SSID 'demonet' due to wpa_bss_flush_by_age
1451963600.200229: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/113'
1451963600.200261: wlan0: BSS: Remove id 138 BSSID f8:4f:57:13:f3:64 SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200272: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/138'
1451963600.200304: wlan0: BSS: Remove id 139 BSSID 84:61:a0:d8:68:00 SSID 'Sandwiches2' due to wpa_bss_flush_by_age
1451963600.200314: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/139'
1451963600.200347: wlan0: BSS: Remove id 127 BSSID c0:25:5c:de:10:8f SSID 'Mocana-SECURE' due to wpa_bss_flush_by_age
1451963600.200357: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/127'
1451963600.200388: wlan0: BSS: Remove id 98 BSSID c0:25:5c:de:10:8b SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200399: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/98'
1451963600.200429: wlan0: BSS: Remove id 128 BSSID c0:25:5c:de:10:8d SSID 'QA-testnet' due to wpa_bss_flush_by_age
1451963600.200440: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/128'
1451963600.200469: wlan0: BSS: Remove id 126 BSSID c0:25:5c:de:10:8c SSID 'key-testnet' due to wpa_bss_flush_by_age
1451963600.200480: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/126'
1451963600.200509: wlan0: BSS: Remove id 129 BSSID 84:b8:02:22:98:80 SSID 'EONCRNA' due to wpa_bss_flush_by_age
1451963600.200520: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/129'
1451963600.200550: wlan0: BSS: Remove id 118 BSSID 84:b8:02:22:98:81 SSID 'EONCRNA-Guest' due to wpa_bss_flush_by_age
1451963600.200561: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/118'
1451963600.200590: wlan0: BSS: Remove id 140 BSSID 34:a8:4e:1c:b3:21 SSID 'EONCRNA-Guest' due to wpa_bss_flush_by_age
1451963600.200601: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/140'
1451963600.200630: wlan0: BSS: Remove id 141 BSSID 24:a2:e1:ee:14:a8 SSID 'Edutect Wireless Network' due to wpa_bss_flush_by_age
1451963600.200641: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/141'
1451963600.200670: wlan0: BSS: Remove id 124 BSSID f8:4f:57:13:f3:6e SSID 'Mocana-GUEST' due to wpa_bss_flush_by_age
1451963600.200680: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/124'
1451963600.200710: wlan0: BSS: Remove id 131 BSSID c0:25:5c:de:10:8e SSID 'Mocana-GUEST' due to wpa_bss_flush_by_age
1451963600.200720: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/131'
1451963600.200757: p2p-dev-wlan0: BSS: Remove id 134 BSSID f8:4f:57:13:f3:6d SSID 'QA-testnet' due to wpa_bss_flush_by_age
1451963600.200771: p2p-dev-wlan0: BSS: Remove id 136 BSSID f8:4f:57:13:f3:6b SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200785: p2p-dev-wlan0: BSS: Remove id 137 BSSID f8:4f:57:13:f3:6c SSID 'key-testnet' due to wpa_bss_flush_by_age
1451963600.200798: p2p-dev-wlan0: BSS: Remove id 113 BSSID 00:1d:7e:ce:85:97 SSID 'demonet' due to wpa_bss_flush_by_age
1451963600.200811: p2p-dev-wlan0: BSS: Remove id 138 BSSID f8:4f:57:13:f3:64 SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200824: p2p-dev-wlan0: BSS: Remove id 139 BSSID 84:61:a0:d8:68:00 SSID 'Sandwiches2' due to wpa_bss_flush_by_age
1451963600.200837: p2p-dev-wlan0: BSS: Remove id 127 BSSID c0:25:5c:de:10:8f SSID 'Mocana-SECURE' due to wpa_bss_flush_by_age
1451963600.200850: p2p-dev-wlan0: BSS: Remove id 98 BSSID c0:25:5c:de:10:8b SSID 'NoFrags' due to wpa_bss_flush_by_age
1451963600.200863: p2p-dev-wlan0: BSS: Remove id 128 BSSID c0:25:5c:de:10:8d SSID 'QA-testnet' due to wpa_bss_flush_by_age
1451963600.200876: p2p-dev-wlan0: BSS: Remove id 126 BSSID c0:25:5c:de:10:8c SSID 'key-testnet' due to wpa_bss_flush_by_age
1451963600.200889: p2p-dev-wlan0: BSS: Remove id 129 BSSID 84:b8:02:22:98:80 SSID 'EONCRNA' due to wpa_bss_flush_by_age
1451963600.200902: p2p-dev-wlan0: BSS: Remove id 118 BSSID 84:b8:02:22:98:81 SSID 'EONCRNA-Guest' due to wpa_bss_flush_by_age
1451963600.200916: p2p-dev-wlan0: BSS: Remove id 140 BSSID 34:a8:4e:1c:b3:21 SSID 'EONCRNA-Guest' due to wpa_bss_flush_by_age
1451963600.200930: p2p-dev-wlan0: BSS: Remove id 141 BSSID 24:a2:e1:ee:14:a8 SSID 'Edutect Wireless Network' due to wpa_bss_flush_by_age
1451963600.200943: p2p-dev-wlan0: BSS: Remove id 124 BSSID f8:4f:57:13:f3:6e SSID 'Mocana-GUEST' due to wpa_bss_flush_by_age
1451963600.200959: p2p-dev-wlan0: BSS: Remove id 131 BSSID c0:25:5c:de:10:8e SSID 'Mocana-GUEST' due to wpa_bss_flush_by_age
1451963600.205178: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
1451963657.605411: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/3) [a{sv}]
1451963657.605461: wlan0: Add radio work 'scan'@0x555b677d8300
1451963657.605474: wlan0: First radio work item in the queue - schedule start immediately
1451963657.605673: wlan0: Starting radio work 'scan'@0x555b677d8300 after 0.000196 second wait
1451963657.605859: wlan0: nl80211: scan request
1451963657.605900: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1451963657.606464: Scan requested (ret=0) - scan timeout 30 seconds
1451963657.606504: nl80211: Event message available
1451963657.606523: nl80211: Ignored event (cmd=33) for foreign interface (ifindex 3 wdev 0x0)
1451963657.606539: nl80211: Drv Event 33 (NL80211_CMD_TRIGGER_SCAN) received for wlan0
1451963657.606554: wlan0: nl80211: Scan trigger
1451963657.606570: wlan0: Event SCAN_STARTED (47) received
1451963657.606585: wlan0: Own scan request started a scan in 0.000087 seconds
1451963657.611014: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
1451963659.208171: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1451963659.208233: nl80211: Event message available
1451963659.208267: nl80211: Ignored event (cmd=34) for foreign interface (ifindex 3 wdev 0x0)
1451963659.208285: nl80211: Drv Event 34 (NL80211_CMD_NEW_SCAN_RESULTS) received for wlan0
1451963659.208304: wlan0: nl80211: New scan results available
1451963659.208323: nl80211: Scan probed for SSID ''
1451963659.208352: nl80211: Scan included frequencies: 2412 2417 2422 2427 2432 2437 2442 2447 2452 2457 2462 5180 5200 5220 5240 5260 5280 5300 5320 5745 5765 5785 5805 5825
1451963659.208447: wlan0: Event SCAN_RESULTS (3) received
1451963659.208462: wlan0: Scan completed in 1.601878 seconds
1451963659.208658: nl80211: Associated on 5785 MHz
1451963659.208711: nl80211: Associated with 3c:0e:23:8e:48:3f
1451963659.208843: nl80211: Received scan results (31 BSSes)
1451963659.209113: nl80211: Scan results indicate BSS status with 3c:0e:23:8e:48:3f as associated
1451963659.209242: wlan0: BSS: Start scan result update 20
1451963659.209394: wlan0: BSS: Add new id 146 BSSID f8:4f:57:13:f3:6b SSID 'NoFrags'
1451963659.209417: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/146'
1451963659.209611: wlan0: BSS: Add new id 147 BSSID f8:4f:57:13:f3:6d SSID 'QA-testnet'
1451963659.209635: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/147'
1451963659.209812: wlan0: BSS: Add new id 148 BSSID f8:4f:57:13:f3:6c SSID 'key-testnet'
1451963659.209836: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/148'
1451963659.210008: wlan0: BSS: Add new id 149 BSSID 00:1d:7e:ce:85:97 SSID 'demonet'
1451963659.210031: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/149'
1451963659.210178: wlan0: BSS: Add new id 150 BSSID f8:4f:57:13:f3:64 SSID 'NoFrags'
1451963659.210201: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/150'
1451963659.210355: wlan0: BSS: Add new id 151 BSSID 30:b5:c2:3e:70:be SSID 'surfsup'
1451963659.210377: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/151'
1451963659.210477: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.210497: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.210607: wlan0: BSS: Add new id 152 BSSID 84:b8:02:22:98:80 SSID 'EONCRNA'
1451963659.210629: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/152'
1451963659.210804: wlan0: BSS: Add new id 153 BSSID 84:b8:02:22:98:81 SSID 'EONCRNA-Guest'
1451963659.210828: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/153'
1451963659.210982: wlan0: BSS: Add new id 154 BSSID 34:a8:4e:1c:b3:21 SSID 'EONCRNA-Guest'
1451963659.211005: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/154'
1451963659.211202: wlan0: BSS: Add new id 155 BSSID f8:4f:57:13:f3:6e SSID 'Mocana-GUEST'
1451963659.211226: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/155'
1451963659.211556: wlan0: BSS: Add new id 156 BSSID 24:de:c6:79:d4:81 SSID 'vlguest'
1451963659.211607: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/156'
1451963659.211903: BSS: last_scan_res_used=31/64
1451963659.211956: wlan0: New scan results available (own=1 ext=0)
1451963659.212044: bgscan simple: scan result notification
1451963659.212087: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.212115: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.212141: WPS: AP[0] e4:f4:c6:14:7b:9d type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.212171: WPS: AP[1] 30:b5:c2:3e:70:be type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.212199: WPS: AP[2] 30:b5:c2:3e:70:bf type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.212225: WPS: AP[3] e4:f4:c6:14:7b:9e type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.212266: wlan0: Radio work 'scan'@0x555b677d8300 done in 1.606589 seconds
1451963659.212294: wlan0: Selecting BSS from priority group 0
1451963659.212335: wlan0: 0: 74:a0:2f:63:4f:ef ssid='ETSYguest' wpa_ie_len=0 rsn_ie_len=20 caps=0x1111 level=-66
1451963659.212365: wlan0: skip - SSID mismatch
1451963659.212406: wlan0: 1: 74:a0:2f:63:4f:ee ssid='CarrierPigeon' wpa_ie_len=0 rsn_ie_len=24 caps=0x1111 level=-66
1451963659.212434: wlan0: skip - SSID mismatch
1451963659.212473: wlan0: 2: 74:a0:2f:63:4f:ed ssid='MostlyHarmless' wpa_ie_len=0 rsn_ie_len=20 caps=0x1111 level=-67
1451963659.212500: wlan0: skip - SSID mismatch
1451963659.212538: wlan0: 3: 3c:0e:23:8e:48:3f ssid='Mocana-SECURE' wpa_ie_len=0 rsn_ie_len=20 caps=0x1011 level=-60
1451963659.212748: wlan0: selected based on RSN IE
1451963659.212923: wlan0: selected BSS 3c:0e:23:8e:48:3f ssid='Mocana-SECURE'
1451963659.213083: p2p-dev-wlan0: Updating scan results from sibling
1451963659.213563: nl80211: Received scan results (31 BSSes)
1451963659.213906: p2p-dev-wlan0: BSS: Start scan result update 18
1451963659.214135: p2p-dev-wlan0: BSS: Add new id 146 BSSID f8:4f:57:13:f3:6b SSID 'NoFrags'
1451963659.214262: p2p-dev-wlan0: BSS: Add new id 147 BSSID f8:4f:57:13:f3:6d SSID 'QA-testnet'
1451963659.214308: p2p-dev-wlan0: BSS: Add new id 148 BSSID f8:4f:57:13:f3:6c SSID 'key-testnet'
1451963659.214366: p2p-dev-wlan0: BSS: Add new id 149 BSSID 00:1d:7e:ce:85:97 SSID 'demonet'
1451963659.214405: p2p-dev-wlan0: BSS: Add new id 150 BSSID f8:4f:57:13:f3:64 SSID 'NoFrags'
1451963659.214439: p2p-dev-wlan0: BSS: Add new id 151 BSSID 30:b5:c2:3e:70:be SSID 'surfsup'
1451963659.214474: p2p-dev-wlan0: BSS: Add new id 152 BSSID 84:b8:02:22:98:80 SSID 'EONCRNA'
1451963659.214522: p2p-dev-wlan0: BSS: Add new id 153 BSSID 84:b8:02:22:98:81 SSID 'EONCRNA-Guest'
1451963659.214559: p2p-dev-wlan0: BSS: Add new id 154 BSSID 34:a8:4e:1c:b3:21 SSID 'EONCRNA-Guest'
1451963659.214617: p2p-dev-wlan0: BSS: Add new id 155 BSSID f8:4f:57:13:f3:6e SSID 'Mocana-GUEST'
1451963659.214658: p2p-dev-wlan0: BSS: Add new id 156 BSSID 24:de:c6:79:d4:81 SSID 'vlguest'
1451963659.214690: BSS: last_scan_res_used=31/64
1451963659.214727: p2p-dev-wlan0: New scan results available (own=0 ext=0)
1451963659.214765: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.214795: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.214821: WPS: AP[0] 30:b5:c2:3e:70:be type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.214851: WPS: AP[1] 30:b5:c2:3e:70:bf type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.214878: WPS: AP[2] e4:f4:c6:14:7b:9d type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.214905: WPS: AP[3] e4:f4:c6:14:7b:9e type=0 tries=0 last_attempt=-1 sec ago blacklist=0
1451963659.214963: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
1451963659.215324: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/2
1451963659.215707: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/1
1451963659.215992: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/0
1451963659.216207: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/3
1451963659.216381: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/4
1451963659.216586: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/5
1451963659.216842: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/6
1451963659.217052: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/84
1451963659.217268: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/133
1451963659.217511: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/135
1451963659.217768: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/16
1451963659.217914: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/17
1451963659.218045: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/24
1451963659.218187: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/144
1451963659.218446: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/130
1451963659.218587: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/101
1451963659.218726: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/54
1451963659.218991: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/36
1451963659.219247: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/145
1451963659.219483: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/142
1451963659.252932: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/146) [s]
1451963659.253312: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/147) [s]
1451963659.253640: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/148) [s]
1451963659.253958: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/149) [s]
1451963659.258493: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/150) [s]
1451963659.258789: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/151) [s]
1451963659.258872: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.258886: WPS: Unknown Vendor Extension (Vendor ID 9442)
1451963659.259057: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/153) [s]
1451963659.259255: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/152) [s]
1451963659.259504: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/154) [s]
1451963659.259728: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/155) [s]
1451963659.269528: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/156) [s]
1451963720.274518: wlan0: BSS: Remove id 69 BSSID 24:de:c6:79:d4:90 SSID 'vlcorp' due to wpa_bss_flush_by_age
1451963720.274581: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/69'
1451963720.274702: wlan0: BSS: Remove id 106 BSSID 24:de:c6:79:d4:92 SSID 'vlmobile' due to wpa_bss_flush_by_age
1451963720.274739: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/106'
1451963720.274790: wlan0: BSS: Remove id 143 BSSID 84:18:3a:02:46:68 SSID 'RS_20_7.1' due to wpa_bss_flush_by_age
1451963720.274811: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/143'
1451963720.274868: p2p-dev-wlan0: BSS: Remove id 69 BSSID 24:de:c6:79:d4:90 SSID 'vlcorp' due to wpa_bss_flush_by_age
1451963720.274893: p2p-dev-wlan0: BSS: Remove id 106 BSSID 24:de:c6:79:d4:92 SSID 'vlmobile' due to wpa_bss_flush_by_age
1451963720.274912: p2p-dev-wlan0: BSS: Remove id 143 BSSID 84:18:3a:02:46:68 SSID 'RS_20_7.1' due to wpa_bss_flush_by_age
1451963720.279823: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
1451963729.285604: l2_packet_receive: src=3c:0e:23:8e:48:3f len=57
1451963729.285691: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.285710: RX EAPOL - hexdump(len=57): 02 00 00 35 01 01 00 35 01 00 6e 65 74 77 6f 72 6b 69 64 3d 4d 6f 63 61 6e 61 2d 53 45 43 55 52 45 2c 6e 61 73 69 64 3d 57 69 72 65 6c 65 73 73 2c 70 6f 72 74 69 64 3d 31
1451963729.285751: EAPOL: Received EAP-Packet frame
1451963729.285766: EAPOL: SUPP_PAE entering state RESTART
1451963729.285779: EAP: EAP entering state INITIALIZE
1451963729.285792: EAP: maintaining EAP method data for fast reauthentication
1451963729.285806: EAPOL: enable timer tick
1451963729.285824: EAP: EAP entering state IDLE
1451963729.285838: EAPOL: SUPP_PAE entering state AUTHENTICATING
1451963729.285852: EAPOL: SUPP_BE entering state REQUEST
1451963729.285866: EAPOL: getSuppRsp
1451963729.285880: EAP: EAP entering state RECEIVED
1451963729.285907: EAP: Received EAP-Request id=1 method=1 vendor=0 vendorMethod=0
1451963729.285923: EAP: EAP entering state IDENTITY
1451963729.285939: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started
1451963729.285953: EAP: Status notification: started (param=)
1451963729.286060: EAP: EAP-Request Identity data - hexdump_ascii(len=48):
00 6e 65 74 77 6f 72 6b 69 64 3d 4d 6f 63 61 6e _networkid=Mocan
61 2d 53 45 43 55 52 45 2c 6e 61 73 69 64 3d 57 a-SECURE,nasid=W
69 72 65 6c 65 73 73 2c 70 6f 72 74 69 64 3d 31 ireless,portid=1
1451963729.286185: EAP: using real identity - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.286236: EAP: EAP entering state SEND_RESPONSE
1451963729.286259: EAP: EAP entering state IDLE
1451963729.286280: EAPOL: SUPP_BE entering state RESPONSE
1451963729.286300: EAPOL: txSuppRsp
1451963729.286320: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.286343: TX EAPOL - hexdump(len=16): 01 00 00 0c 02 01 00 0c 01 61 6a 61 63 6f 62 73
1451963729.286429: EAPOL: SUPP_BE entering state RECEIVE
1451963729.298687: l2_packet_receive: src=3c:0e:23:8e:48:3f len=10
1451963729.298755: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.298773: RX EAPOL - hexdump(len=10): 02 00 00 06 01 02 00 06 19 20
1451963729.298797: EAPOL: Received EAP-Packet frame
1451963729.298810: EAPOL: SUPP_BE entering state REQUEST
1451963729.298823: EAPOL: getSuppRsp
1451963729.298837: EAP: EAP entering state RECEIVED
1451963729.298860: EAP: Received EAP-Request id=2 method=25 vendor=0 vendorMethod=0
1451963729.298875: EAP: EAP entering state GET_METHOD
1451963729.298892: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25
1451963729.298905: EAP: Status notification: accept proposed method (param=PEAP)
1451963729.299014: EAP: Using previous method data for fast re-authentication
1451963729.299036: EAP: Initialize selected EAP method: vendor 0 method 25 (PEAP)
1451963729.299065: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
1451963729.299089: EAP: EAP entering state METHOD
1451963729.299114: SSL: Received packet(len=6) - Flags 0x20
1451963729.299136: EAP-PEAP: Start (server ver=0, own ver=0)
1451963729.299156: EAP-PEAP: Using PEAP version 0
1451963729.299217: SSL: (where=0x10 ret=0x1)
1451963729.299474: SSL: (where=0x1001 ret=0x1)
1451963729.299505: SSL: SSL_connect:before/connect initialization
1451963729.299563: OpenSSL: TX ver=0x0 content_type=256
1451963729.299588: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.299614: OpenSSL: TX ver=0x301 content_type=22
1451963729.299635: OpenSSL: Message - hexdump(len=220): [REMOVED]
1451963729.299657: SSL: (where=0x1001 ret=0x1)
1451963729.299677: SSL: SSL_connect:unknown state
1451963729.299700: SSL: (where=0x1002 ret=0xffffffff)
1451963729.299720: SSL: SSL_connect:error in unknown state
1451963729.299745: SSL: SSL_connect - want more data
1451963729.299766: SSL: 225 bytes pending from ssl_out
1451963729.299790: SSL: 225 bytes left to be sent out (of total 225 bytes)
1451963729.299816: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x555b677d8300
1451963729.299844: EAP: EAP entering state SEND_RESPONSE
1451963729.299866: EAP: EAP entering state IDLE
1451963729.299889: EAPOL: SUPP_BE entering state RESPONSE
1451963729.299910: EAPOL: txSuppRsp
1451963729.299931: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.299955: TX EAPOL - hexdump(len=239): 01 00 00 eb 02 02 00 eb 19 80 00 00 00 e1 16 03 01 00 dc 01 00 00 d8 03 01 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 20 1f 48 00 00 c8 d4 6a ba 00 99 d0 0a 30 3d ea 8c 3a 69 c8 1e 66 54 98 7e ce 77 c3 25 ae c3 af 43 00 62 c0 14 c0 0a 00 39 00 38 00 37 00 36 00 88 00 87 00 86 00 85 c0 0f c0 05 00 35 00 84 c0 13 c0 09 00 33 00 32 00 31 00 30 00 9a 00 99 00 98 00 97 00 45 00 44 00 43 00 42 c0 0e c0 04 00 2f 00 96 00 41 c0 11 c0 07 c0 0c c0 02 00 05 00 04 c0 12 c0 08 00 16 00 13 00 10 00 0d c0 0d c0 03 00 0a 00 ff 01 00 00 2d 00 0b 00 04 03 00 01 02 00 0a 00 1c 00 1a 00 17 00 19 00 1c 00 1b 00 18 00 1a 00 16 00 0e 00 0d 00 0b 00 0c 00 09 00 0a 00 0f 00 01 01
1451963729.300207: EAPOL: SUPP_BE entering state RECEIVE
1451963729.310898: l2_packet_receive: src=3c:0e:23:8e:48:3f len=159
1451963729.310987: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.311007: RX EAPOL - hexdump(len=159): 02 00 00 9b 01 03 00 9b 19 80 00 00 00 91 16 03 01 00 51 02 00 00 4d 03 01 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd 20 1f 48 00 00 c8 d4 6a ba 00 99 d0 0a 30 3d ea 8c 3a 69 c8 1e 66 54 98 7e ce 77 c3 25 ae c3 af 43 c0 14 00 00 05 ff 01 00 01 00 14 03 01 00 01 01 16 03 01 00 30 61 18 9d a5 c8 e2 5d c0 95 fe 04 73 ac 89 c0 10 55 93 59 5b f1 96 58 b1 8d ab 09 c5 d5 d7 85 7b 4c 32 58 38 ed 9a eb da 7f 8f 48 22 a6 86 02 fc
1451963729.311089: EAPOL: Received EAP-Packet frame
1451963729.311104: EAPOL: SUPP_BE entering state REQUEST
1451963729.311119: EAPOL: getSuppRsp
1451963729.311134: EAP: EAP entering state RECEIVED
1451963729.311158: EAP: Received EAP-Request id=3 method=25 vendor=0 vendorMethod=0
1451963729.311174: EAP: EAP entering state METHOD
1451963729.311195: SSL: Received packet(len=155) - Flags 0x80
1451963729.311209: SSL: TLS Message Length: 145
1451963729.311240: OpenSSL: RX ver=0x0 content_type=256
1451963729.311275: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.311299: OpenSSL: RX ver=0x301 content_type=22
1451963729.311353: OpenSSL: Message - hexdump(len=81): [REMOVED]
1451963729.311387: SSL: (where=0x1001 ret=0x1)
1451963729.311411: SSL: SSL_connect:unknown state
1451963729.311425: OpenSSL: RX ver=0x0 content_type=256
1451963729.311438: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.311451: OpenSSL: RX ver=0x301 content_type=20
1451963729.311464: OpenSSL: Message - hexdump(len=1): [REMOVED]
1451963729.311709: OpenSSL: RX ver=0x0 content_type=256
1451963729.311726: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.311776: OpenSSL: RX ver=0x301 content_type=22
1451963729.311789: OpenSSL: Message - hexdump(len=16): [REMOVED]
1451963729.311801: SSL: (where=0x1001 ret=0x1)
1451963729.311813: SSL: SSL_connect:unknown state
1451963729.311826: OpenSSL: TX ver=0x0 content_type=256
1451963729.311838: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.311852: OpenSSL: TX ver=0x301 content_type=20
1451963729.311863: OpenSSL: Message - hexdump(len=1): [REMOVED]
1451963729.311879: SSL: (where=0x1001 ret=0x1)
1451963729.311890: SSL: SSL_connect:unknown state
1451963729.311937: OpenSSL: TX ver=0x0 content_type=256
1451963729.311949: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.311962: OpenSSL: TX ver=0x301 content_type=22
1451963729.311973: OpenSSL: Message - hexdump(len=16): [REMOVED]
1451963729.311984: SSL: (where=0x1001 ret=0x1)
1451963729.311995: SSL: SSL_connect:unknown state
1451963729.312007: SSL: (where=0x1001 ret=0x1)
1451963729.312018: SSL: SSL_connect:unknown state
1451963729.312040: SSL: (where=0x20 ret=0x1)
1451963729.312052: SSL: (where=0x1002 ret=0x1)
1451963729.312064: SSL: 59 bytes pending from ssl_out
1451963729.312081: SSL: No Application Data included
1451963729.312093: SSL: 59 bytes left to be sent out (of total 59 bytes)
1451963729.312107: EAP-PEAP: TLS done, proceed to Phase 2
1451963729.312118: EAP-PEAP: using label 'client EAP encryption' in key derivation
1451963729.312227: OpenSSL: Using internal PRF
1451963729.312239: EAP-PEAP: Derived key - hexdump(len=64): [REMOVED]
1451963729.312252: EAP-PEAP: Derived Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.312286: EAP-PEAP: Workaround - allow outer EAP-Success to terminate PEAP resumption
1451963729.312298: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=COND_SUCC eapRespData=0x555b677937b0
1451963729.312314: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.312346: EAP: EAP entering state SEND_RESPONSE
1451963729.312358: EAP: EAP entering state IDLE
1451963729.312370: EAPOL: SUPP_BE entering state RESPONSE
1451963729.312381: EAPOL: txSuppRsp
1451963729.312394: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.312407: TX EAPOL - hexdump(len=69): 01 00 00 41 02 03 00 41 19 00 14 03 01 00 01 01 16 03 01 00 30 f9 64 5b 0c c2 ab 90 ea a0 b9 16 4a 37 6d f8 e2 a1 dc b9 99 e9 37 1f 57 0c 67 d6 01 d8 ed 82 bc 07 bd 60 e1 5f 7a 47 38 f8 83 ac 9d 6d 78 34 c1
1451963729.312483: EAPOL: SUPP_BE entering state RECEIVE
1451963729.319731: l2_packet_receive: src=3c:0e:23:8e:48:3f len=47
1451963729.319795: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.319816: RX EAPOL - hexdump(len=47): 02 00 00 2b 01 05 00 2b 19 00 17 03 01 00 20 b5 d2 47 17 de b2 ad 91 4e 02 55 3b 4d 07 7a 32 b2 8a 1b ab 9f d2 2b 16 57 fd 7c 7e d4 44 98 5a
1451963729.319862: EAPOL: Received EAP-Packet frame
1451963729.319880: EAPOL: SUPP_BE entering state REQUEST
1451963729.319896: EAPOL: getSuppRsp
1451963729.319912: EAP: EAP entering state RECEIVED
1451963729.319935: EAP: Received EAP-Request id=5 method=25 vendor=0 vendorMethod=0
1451963729.319955: EAP: EAP entering state METHOD
1451963729.319977: SSL: Received packet(len=43) - Flags 0x00
1451963729.320022: EAP-PEAP: received 37 bytes encrypted data for Phase 2
1451963729.320058: OpenSSL: RX ver=0x0 content_type=256
1451963729.320081: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.320104: EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=1): 01
1451963729.320119: EAP-PEAP: received Phase 2: code=1 identifier=5 length=5
1451963729.320133: EAP-PEAP: Phase 2 Request: type=1
1451963729.320146: EAP: using real identity - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.320186: EAP-PEAP: Encrypting Phase 2 data - hexdump(len=12): [REMOVED]
1451963729.320213: OpenSSL: TX ver=0x0 content_type=256
1451963729.320232: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.320252: OpenSSL: TX ver=0x0 content_type=256
1451963729.320271: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.320292: SSL: 74 bytes left to be sent out (of total 74 bytes)
1451963729.320313: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x555b677acd90
1451963729.320337: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.320396: EAP: EAP entering state SEND_RESPONSE
1451963729.320414: EAP: EAP entering state IDLE
1451963729.320432: EAPOL: SUPP_BE entering state RESPONSE
1451963729.320452: EAPOL: txSuppRsp
1451963729.320469: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.320487: TX EAPOL - hexdump(len=84): 01 00 00 50 02 05 00 50 19 00 17 03 01 00 20 cd 33 91 31 e1 01 15 e1 eb 0b f6 8b f0 63 71 1b 2a 29 22 24 20 18 4b 9b a2 52 c5 c3 7e 53 15 e6 17 03 01 00 20 b5 fc 76 b6 b9 72 50 91 c5 72 25 fb a5 09 3a 41 bb 79 18 c6 e5 21 b3 75 a2 18 e3 2b 54 5f 78 13
1451963729.320590: EAPOL: SUPP_BE entering state RECEIVE
1451963729.328439: l2_packet_receive: src=3c:0e:23:8e:48:3f len=63
1451963729.328518: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.328534: RX EAPOL - hexdump(len=63): 02 00 00 3b 01 06 00 3b 19 00 17 03 01 00 30 05 ba 86 0e 5b a7 5a 27 1d f9 b2 05 ee 77 06 84 46 ab 6a db 5a f8 10 30 f3 a1 1f ee 3f ee fa f7 39 40 0c d2 2d 2a b7 dc a4 8e b4 ae fc 79 17 96
1451963729.328573: EAPOL: Received EAP-Packet frame
1451963729.328586: EAPOL: SUPP_BE entering state REQUEST
1451963729.328598: EAPOL: getSuppRsp
1451963729.328612: EAP: EAP entering state RECEIVED
1451963729.328633: EAP: Received EAP-Request id=6 method=25 vendor=0 vendorMethod=0
1451963729.328648: EAP: EAP entering state METHOD
1451963729.328664: SSL: Received packet(len=59) - Flags 0x00
1451963729.328678: EAP-PEAP: received 53 bytes encrypted data for Phase 2
1451963729.328704: OpenSSL: RX ver=0x0 content_type=256
1451963729.328739: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.328765: EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=16): 01 06 00 10 fe 00 01 37 00 00 00 22 00 00 00 01
1451963729.328794: EAP-PEAP: received Phase 2: code=1 identifier=6 length=20
1451963729.328808: EAP-PEAP: Phase 2 Request: type=1
1451963729.328820: EAP: using real identity - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.328851: EAP-PEAP: Encrypting Phase 2 data - hexdump(len=12): [REMOVED]
1451963729.328871: OpenSSL: TX ver=0x0 content_type=256
1451963729.328884: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.328899: OpenSSL: TX ver=0x0 content_type=256
1451963729.328911: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.328926: SSL: 74 bytes left to be sent out (of total 74 bytes)
1451963729.328942: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x555b677acd90
1451963729.328958: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.328996: EAP: EAP entering state SEND_RESPONSE
1451963729.329009: EAP: EAP entering state IDLE
1451963729.329022: EAPOL: SUPP_BE entering state RESPONSE
1451963729.329033: EAPOL: txSuppRsp
1451963729.329046: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.329059: TX EAPOL - hexdump(len=84): 01 00 00 50 02 06 00 50 19 00 17 03 01 00 20 75 83 4b 53 bd 61 9b b8 f5 65 8d 7f fb de cd 3d fa 00 41 7f 46 6e 8e 2a ac 5f 76 a2 44 21 28 bc 17 03 01 00 20 92 8f cb 83 6d 76 ea 66 52 0b 73 a7 a2 c6 ac 58 de 3c 75 33 cf a1 82 e2 9f 0d 82 04 f3 f8 14 08
1451963729.329147: EAPOL: SUPP_BE entering state RECEIVE
1451963729.336516: l2_packet_receive: src=3c:0e:23:8e:48:3f len=79
1451963729.336594: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.336611: RX EAPOL - hexdump(len=79): 02 00 00 4b 01 07 00 4b 19 00 17 03 01 00 40 91 06 2d 02 8d c9 30 0f c5 3b e9 8a c0 d6 f9 3c c7 07 52 df 7e 3e be 1f d4 e9 ef 2d 39 c6 fb 60 75 41 4b da 2c d8 5b 9b bd 5a 7f 3e f8 9b e2 fc f0 dc 13 8f 5a ee c5 32 b6 ab f6 46 11 8c f9 f0
1451963729.336656: EAPOL: Received EAP-Packet frame
1451963729.336669: EAPOL: SUPP_BE entering state REQUEST
1451963729.336680: EAPOL: getSuppRsp
1451963729.336694: EAP: EAP entering state RECEIVED
1451963729.336714: EAP: Received EAP-Request id=7 method=25 vendor=0 vendorMethod=0
1451963729.336729: EAP: EAP entering state METHOD
1451963729.336746: SSL: Received packet(len=75) - Flags 0x00
1451963729.336761: EAP-PEAP: received 69 bytes encrypted data for Phase 2
1451963729.336786: OpenSSL: RX ver=0x0 content_type=256
1451963729.336820: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.336845: EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=31): 1a 01 07 00 1e 10 08 e6 ff ea ab fa ef 05 f4 e0 44 c8 56 5c 8d 6d 52 41 44 49 55 53 2d 30 31
1451963729.336875: EAP-PEAP: received Phase 2: code=1 identifier=7 length=35
1451963729.336889: EAP-PEAP: Phase 2 Request: type=26
1451963729.336902: EAP-MSCHAPV2: RX identifier 7 mschapv2_id 7
1451963729.336917: EAP-MSCHAPV2: Received challenge
1451963729.336928: EAP-MSCHAPV2: Authentication Servername - hexdump_ascii(len=9):
52 41 44 49 55 53 2d 30 31 RADIUS-01
1451963729.336958: EAP-MSCHAPV2: Generating Challenge Response
1451963729.336971: Get randomness: len=16 entropy=340
1451963729.338033: MSCHAPV2: Identity - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.338073: MSCHAPV2: Username - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.338100: MSCHAPV2: auth_challenge - hexdump(len=16): 08 e6 ff ea ab fa ef 05 f4 e0 44 c8 56 5c 8d 6d
1451963729.338118: MSCHAPV2: peer_challenge - hexdump(len=16): 9f a2 ac c1 04 a0 36 6b fd 49 42 dd ea c7 93 fe
1451963729.338135: MSCHAPV2: username - hexdump_ascii(len=7):
61 6a 61 63 6f 62 73 ajacobs
1451963729.338162: MSCHAPV2: password - hexdump_ascii(len=12): [REMOVED]
1451963729.338193: MSCHAPV2: NT Response - hexdump(len=24): 4e 48 06 ec d8 1c ee 1a 47 1c a6 34 1c d6 79 ee f4 49 06 68 57 eb ab 76
1451963729.338219: MSCHAPV2: Auth Response - hexdump(len=20): a4 fc cb e6 86 12 e4 ff 4f 89 4a 39 58 83 42 6e 13 a9 e1 e9
1451963729.338240: MSCHAPV2: Master Key - hexdump(len=16): [REMOVED]
1451963729.338253: EAP-MSCHAPV2: TX identifier 7 mschapv2_id 7 (response)
1451963729.338267: EAP-PEAP: Encrypting Phase 2 data - hexdump(len=66): [REMOVED]
1451963729.338286: OpenSSL: TX ver=0x0 content_type=256
1451963729.338300: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.338315: OpenSSL: TX ver=0x0 content_type=256
1451963729.338327: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.338342: SSL: 138 bytes left to be sent out (of total 138 bytes)
1451963729.338358: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x555b677b4420
1451963729.338374: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.338412: EAP: EAP entering state SEND_RESPONSE
1451963729.338424: EAP: EAP entering state IDLE
1451963729.338437: EAPOL: SUPP_BE entering state RESPONSE
1451963729.338449: EAPOL: txSuppRsp
1451963729.338461: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.338475: TX EAPOL - hexdump(len=148): 01 00 00 90 02 07 00 90 19 00 17 03 01 00 20 11 87 2f 26 02 4e 92 93 40 56 ac ad e6 a5 47 cc 8b a2 7d 13 69 5d 09 7f 47 41 66 2b a7 43 ef 20 17 03 01 00 60 3a 1a 92 13 aa fd 40 a6 b3 a4 7b 67 3e bb ca 6b 61 a3 a5 e3 3c 40 aa 73 b5 b2 a1 7b 97 c2 d9 85 20 4f 31 cc 9f a3 72 03 00 b7 63 79 42 7e c9 fa 67 3b 93 0b ae 0d 6c f3 c3 d0 32 0b e5 fe 00 10 3f f5 0d 73 b5 c3 f0 6a 3a ad 31 a8 97 42 9c 50 b0 66 27 a0 e3 0f 5c df 12 01 c1 5a b9 ab f2 8e
1451963729.338579: EAPOL: SUPP_BE entering state RECEIVE
1451963729.349263: l2_packet_receive: src=3c:0e:23:8e:48:3f len=95
1451963729.349315: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.349328: RX EAPOL - hexdump(len=95): 02 00 00 5b 01 08 00 5b 19 00 17 03 01 00 50 9c 3c 73 86 ec 4c a6 c7 42 13 24 7d 35 7f dd 15 83 ae 4f 88 c0 ae e6 d5 d9 67 8a b0 d6 6b 50 94 f2 33 d7 21 e0 b5 95 e7 93 b4 bf ef 6a 78 56 b6 c9 63 d1 49 2c a7 a1 83 29 51 f1 b7 46 ba 1d e7 1e 8f 46 11 35 d2 97 25 19 81 08 4d 77 4d dc 3e
1451963729.349367: EAPOL: Received EAP-Packet frame
1451963729.349378: EAPOL: SUPP_BE entering state REQUEST
1451963729.349387: EAPOL: getSuppRsp
1451963729.349397: EAP: EAP entering state RECEIVED
1451963729.349414: EAP: Received EAP-Request id=8 method=25 vendor=0 vendorMethod=0
1451963729.349425: EAP: EAP entering state METHOD
1451963729.349438: SSL: Received packet(len=91) - Flags 0x00
1451963729.349449: EAP-PEAP: received 85 bytes encrypted data for Phase 2
1451963729.349471: OpenSSL: RX ver=0x0 content_type=256
1451963729.349482: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.349502: EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=47): 1a 03 07 00 2e 53 3d 41 34 46 43 43 42 45 36 38 36 31 32 45 34 46 46 34 46 38 39 34 41 33 39 35 38 38 33 34 32 36 45 31 33 41 39 45 31 45 39
1451963729.349526: EAP-PEAP: received Phase 2: code=1 identifier=8 length=51
1451963729.349536: EAP-PEAP: Phase 2 Request: type=26
1451963729.349546: EAP-MSCHAPV2: RX identifier 8 mschapv2_id 7
1451963729.349556: EAP-MSCHAPV2: Received success
1451963729.349566: EAP-MSCHAPV2: Success message - hexdump_ascii(len=0):
1451963729.349576: EAP-MSCHAPV2: Authentication succeeded
1451963729.349586: EAP-PEAP: Encrypting Phase 2 data - hexdump(len=6): [REMOVED]
1451963729.349600: OpenSSL: TX ver=0x0 content_type=256
1451963729.349609: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.349620: OpenSSL: TX ver=0x0 content_type=256
1451963729.349629: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.349640: SSL: 74 bytes left to be sent out (of total 74 bytes)
1451963729.349650: EAP: method process -> ignore=FALSE methodState=MAY_CONT decision=FAIL eapRespData=0x555b677acd90
1451963729.349663: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.349690: EAP: EAP entering state SEND_RESPONSE
1451963729.349700: EAP: EAP entering state IDLE
1451963729.349710: EAPOL: SUPP_BE entering state RESPONSE
1451963729.349719: EAPOL: txSuppRsp
1451963729.349728: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.349738: TX EAPOL - hexdump(len=84): 01 00 00 50 02 08 00 50 19 00 17 03 01 00 20 26 48 e1 ed dd 9d cd fd 25 5f 9a 14 32 bd b2 f7 95 e7 d5 94 e0 cb 16 c6 ca 11 d0 a9 94 41 ad 80 17 03 01 00 20 18 09 f9 67 97 ff d7 de 3a 98 2b bf 54 e4 dd fb 94 a1 5f bd f4 c9 6d f5 44 cc ae 15 f7 76 58 18
1451963729.349806: EAPOL: SUPP_BE entering state RECEIVE
1451963729.357577: l2_packet_receive: src=3c:0e:23:8e:48:3f len=111
1451963729.357677: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.357700: RX EAPOL - hexdump(len=111): 02 00 00 6b 01 0a 00 6b 19 00 17 03 01 00 60 b3 f5 a1 6d 73 91 4f f7 46 85 59 71 fd e9 5a f4 dd 00 02 4c 71 da 8d 18 2b 0a ec 18 7e 99 09 2f 1e 36 b3 56 17 b9 f2 da 8a a2 ac 72 f1 aa 40 de 89 18 1e e0 68 42 c3 ee d0 21 c1 ef 1e 13 47 45 e7 43 80 61 e2 4b ff b5 55 81 ba 58 15 a9 25 10 e4 d3 b7 4e 39 0f 2e 53 a9 63 b6 d9 02 a0 5b a7
1451963729.357790: EAPOL: Received EAP-Packet frame
1451963729.357809: EAPOL: SUPP_BE entering state REQUEST
1451963729.357825: EAPOL: getSuppRsp
1451963729.357843: EAP: EAP entering state RECEIVED
1451963729.357876: EAP: Received EAP-Request id=10 method=25 vendor=0 vendorMethod=0
1451963729.357916: EAP: EAP entering state METHOD
1451963729.357942: SSL: Received packet(len=107) - Flags 0x00
1451963729.357968: EAP-PEAP: received 101 bytes encrypted data for Phase 2
1451963729.358006: OpenSSL: RX ver=0x0 content_type=256
1451963729.358028: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.358071: EAP-PEAP: Decrypted Phase 2 EAP - hexdump(len=71): 01 0a 00 47 21 80 03 00 02 00 01 00 0c 00 38 00 00 00 00 a8 c8 90 39 15 20 a4 c6 90 9d 62 2c 02 e6 84 85 d9 04 4c 44 76 40 f5 00 03 0c 4f de cd aa 5a 36 c2 57 d5 64 8d d3 a6 08 bc de 5e ab bc e4 20 22 55 57 76 6f
1451963729.358139: EAP-PEAP: received Phase 2: code=1 identifier=10 length=71
1451963729.358158: EAP-PEAP: Phase 2 Request: type=33
1451963729.358173: EAP-TLV: Received TLVs - hexdump(len=66): 80 03 00 02 00 01 00 0c 00 38 00 00 00 00 a8 c8 90 39 15 20 a4 c6 90 9d 62 2c 02 e6 84 85 d9 04 4c 44 76 40 f5 00 03 0c 4f de cd aa 5a 36 c2 57 d5 64 8d d3 a6 08 bc de 5e ab bc e4 20 22 55 57 76 6f
1451963729.358222: EAP-PEAP: Cryptobinding TLV - hexdump(len=56): 00 00 00 00 a8 c8 90 39 15 20 a4 c6 90 9d 62 2c 02 e6 84 85 d9 04 4c 44 76 40 f5 00 03 0c 4f de cd aa 5a 36 c2 57 d5 64 8d d3 a6 08 bc de 5e ab bc e4 20 22 55 57 76 6f
1451963729.358281: EAP-PEAP: TK - hexdump(len=60): [REMOVED]
1451963729.358296: EAP-PEAP: IPMK from TK - hexdump(len=40): [REMOVED]
1451963729.358313: EAP-PEAP: CMK from TK - hexdump(len=20): [REMOVED]
1451963729.358345: EAP-PEAP: Compound_MAC data - hexdump(len=61): 00 0c 00 38 00 00 00 00 a8 c8 90 39 15 20 a4 c6 90 9d 62 2c 02 e6 84 85 d9 04 4c 44 76 40 f5 00 03 0c 4f de cd aa 5a 36 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 19
1451963729.358417: EAP-PEAP: Invalid Compound_MAC in cryptobinding TLV
1451963729.358431: EAP-PEAP: Received MAC - hexdump(len=20): c2 57 d5 64 8d d3 a6 08 bc de 5e ab bc e4 20 22 55 57 76 6f
1451963729.358448: EAP-PEAP: Expected MAC - hexdump(len=20): c9 26 98 4a 2b 87 4c 54 b0 f8 28 81 75 cc 3d 3c 46 2d 61 e9
1451963729.358464: EAP-TLV: Result TLV - hexdump(len=2): 00 01
1451963729.358475: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed
1451963729.358488: EAP-TLV: Earlier failure - force failed Phase 2
1451963729.358504: EAP-PEAP: Encrypting Phase 2 data - hexdump(len=11): [REMOVED]
1451963729.358533: OpenSSL: TX ver=0x0 content_type=256
1451963729.358547: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.358562: OpenSSL: TX ver=0x0 content_type=256
1451963729.358572: OpenSSL: Message - hexdump(len=5): [REMOVED]
1451963729.358587: SSL: 74 bytes left to be sent out (of total 74 bytes)
1451963729.358602: EAP: method process -> ignore=FALSE methodState=DONE decision=FAIL eapRespData=0x555b677acd90
1451963729.358622: EAP: Session-Id - hexdump(len=65): 19 db 8e 3c 7b a9 bd ca 13 d4 da a3 fe 43 c2 2d cf a1 77 d1 cd 10 5f 69 9e 2a ba 00 ba 55 c8 65 d5 56 8b 35 51 79 fb 1d 00 17 77 6b de f6 0a c0 1f 47 1c 66 81 8b 93 ce e6 a9 d3 be 76 fb f6 c5 bd
1451963729.358659: EAP: EAP entering state SEND_RESPONSE
1451963729.358672: EAP: EAP entering state IDLE
1451963729.358685: EAPOL: SUPP_BE entering state RESPONSE
1451963729.358696: EAPOL: txSuppRsp
1451963729.358710: TX EAPOL: dst=3c:0e:23:8e:48:3f
1451963729.358721: TX EAPOL - hexdump(len=84): 01 00 00 50 02 0a 00 50 19 00 17 03 01 00 20 b9 80 43 b3 2e 10 f0 6e cc 1b e0 22 01 d1 01 19 ce 73 e4 40 0b f5 ce cb b5 92 ae be 2c c4 02 91 17 03 01 00 20 76 5a a4 de 29 20 e9 df ad 47 a3 30 4a 20 24 f7 2e 2c 74 bf 3f cc 56 17 ba 20 45 f2 30 a4 55 c3
1451963729.358832: EAPOL: SUPP_BE entering state RECEIVE
1451963729.366083: l2_packet_receive: src=3c:0e:23:8e:48:3f len=8
1451963729.366123: wlan0: RX EAPOL from 3c:0e:23:8e:48:3f
1451963729.366134: RX EAPOL - hexdump(len=8): 02 00 00 04 04 0a 00 04
1451963729.366149: EAPOL: Received EAP-Packet frame
1451963729.366159: EAPOL: SUPP_BE entering state REQUEST
1451963729.366167: EAPOL: getSuppRsp
1451963729.366176: EAP: EAP entering state RECEIVED
1451963729.366190: EAP: Received EAP-Failure
1451963729.366199: EAP: Status notification: completion (param=failure)
1451963729.366270: EAP: EAP entering state FAILURE
1451963729.366291: wlan0: CTRL-EVENT-EAP-FAILURE EAP authentication failed
1451963729.366304: EAPOL: SUPP_PAE entering state HELD
1451963729.366319: EAPOL: Supplicant port status: Unauthorized
1451963729.366334: nl80211: Set supplicant port unauthorized for 3c:0e:23:8e:48:3f
1451963729.366546: EAPOL: SUPP_BE entering state RECEIVE
1451963729.366573: EAPOL: SUPP_BE entering state FAIL
1451963729.366586: EAPOL: SUPP_BE entering state IDLE
1451963729.366600: EAPOL authentication completed - result=FAILURE
1451963729.366621: wlan0: Setting authentication timeout: 2 sec 0 usec
1451963731.366835: wlan0: Authentication with 3c:0e:23:8e:48:3f timed out.
1451963731.366868: Added BSSID 3c:0e:23:8e:48:3f into blacklist
1451963731.366878: TDLS: Remove peers on disassociation
1451963731.366885: wlan0: WPA: Clear old PMK and PTK
1451963731.366895: wlan0: Request to deauthenticate - bssid=3c:0e:23:8e:48:3f pending_bssid=00:00:00:00:00:00 reason=3 state=COMPLETED
1451963731.366901: TDLS: Tear down peers
1451963731.366906: wpa_driver_nl80211_deauthenticate(addr=3c:0e:23:8e:48:3f reason_code=3)
1451963731.386988: wlan0: Event DEAUTH (12) received
1451963731.387015: wlan0: Deauthentication notification
1451963731.387024: wlan0: * reason 3 (locally generated)
1451963731.387032: Deauthentication frame IE(s) - hexdump(len=0): [NULL]
1451963731.387047: wlan0: CTRL-EVENT-DISCONNECTED bssid=3c:0e:23:8e:48:3f reason=3 locally_generated=1
1451963731.387063: wlan0: CTRL-EVENT-SSID-TEMP-DISABLED id=0 ssid="Mocana-SECURE" auth_failures=1 duration=10 reason=AUTH_FAILED
1451963731.387075: wlan0: Auto connect enabled: try to reconnect (wps=0/0 wpa_state=9)
1451963731.387087: wlan0: Setting scan request: 0.100000 sec
1451963731.387096: BSSID 3c:0e:23:8e:48:3f blacklist count incremented to 2
1451963731.387216: wlan0: Blacklist count 2 --> request scan in 500 ms
1451963731.387233: wlan0: Ignore new scan request for 0.500000 sec since an earlier request is scheduled to trigger sooner
1451963731.387242: TDLS: Remove peers on disassociation
1451963731.387251: wlan0: WPA: Clear old PMK and PTK
1451963731.387354: wlan0: Disconnect event - remove keys
1451963731.387381: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
1451963731.387422: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
1451963731.387451: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
1451963731.387482: wpa_driver_nl80211_set_key: ifindex=3 (wlan0) alg=0 addr=0x555b677a6550 key_idx=0 set_tx=0 seq_len=0 key_len=0
1451963731.387496: addr=3c:0e:23:8e:48:3f
1451963731.387518: wlan0: State: COMPLETED -> DISCONNECTED
1451963731.387529: nl80211: Set wlan0 operstate 1->0 (DORMANT)
1451963731.387539: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
1451963731.387555: bgscan: Deinitializing module 'simple'
1451963731.387566: nl80211: Signal monitor threshold=0 hysteresis=0
1451963731.387587: WMM AC: WMM AC is disabled
1451963731.387630: EAPOL: External notification - portEnabled=0
1451963731.387642: EAPOL: SUPP_PAE entering state DISCONNECTED
1451963731.387650: EAPOL: Supplicant port status: Unauthorized
1451963731.387659: nl80211: Skip set_supp_port(unauthorized) while not associated
1451963731.387667: EAPOL: SUPP_BE entering state INITIALIZE
1451963731.387676: EAP: EAP entering state DISABLED
1451963731.387686: EAPOL: External notification - portValid=0
1451963731.387706: wlan0: State: DISCONNECTED -> DISCONNECTED
1451963731.387713: nl80211: Set wlan0 operstate 0->0 (DORMANT)
1451963731.387719: netlink: Operstate: ifindex=3 linkmode=-1 (no change), operstate=5 (IF_OPER_DORMANT)
1451963731.387729: EAPOL: External notification - portEnabled=0
1451963731.387737: EAPOL: External notification - portValid=0
1451963731.387745: wlan0: Ignore new scan request for 1.000000 sec since an earlier request is scheduled to trigger sooner
1451963731.387766: RTM_NEWLINK: ifi_index=3 ifname=wlan0 wext ifi_family=0 ifi_flags=0x1043 ([UP][RUNNING])
1451963731.387782: RTM_NEWLINK: ifi_index=3 ifname=wlan0 operstate=2 linkmode=1 ifi_family=0 ifi_flags=0x1003 ([UP])
1451963731.387796: nl80211: Event message available
1451963731.387808: nl80211: Ignored event (cmd=20) for foreign interface (ifindex 3 wdev 0x0)
1451963731.387816: nl80211: Drv Event 20 (NL80211_CMD_DEL_STATION) received for wlan0
1451963731.387823: nl80211: Delete station 3c:0e:23:8e:48:3f
1451963731.387834: nl80211: Event message available
1451963731.387842: nl80211: Ignored event (cmd=39) for foreign interface (ifindex 3 wdev 0x0)
1451963731.387849: nl80211: Drv Event 39 (NL80211_CMD_DEAUTHENTICATE) received for wlan0
1451963731.387855: nl80211: MLME event 39 (NL80211_CMD_DEAUTHENTICATE) on wlan0(7c:7a:91:86:c9:3c) A1=3c:0e:23:8e:48:3f A2=7c:7a:91:86:c9:3c
1451963731.387865: nl80211: MLME event frame - hexdump(len=26): c0 00 00 00 3c 0e 23 8e 48 3f 7c 7a 91 86 c9 3c 3c 0e 23 8e 48 3f 00 00 03 00
1451963731.387877: nl80211: Deauthenticate event
1451963731.387883: nl80211: Ignore deauth event triggered due to own deauth request
1451963731.387892: nl80211: Event message available
1451963731.387900: nl80211: Ignored event (cmd=48) for foreign interface (ifindex 3 wdev 0x0)
1451963731.387907: nl80211: Drv Event 48 (NL80211_CMD_DISCONNECT) received for wlan0
1451963731.387913: nl80211: Ignore disconnect event when using userspace SME
1451963731.389558: nl80211: Event message available
1451963731.389584: nl80211: Drv Event 36 (NL80211_CMD_REG_CHANGE) received for p2p-dev-wlan0
1451963731.389591: nl80211: Regulatory domain change
1451963731.389596: * initiator=0
1451963731.389601: * type=1
1451963731.389610: p2p-dev-wlan0: Event CHANNEL_LIST_CHANGED (28) received
1451963731.389619: p2p-dev-wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
1451963731.389747: nl80211: Regulatory information - country=00
1451963731.389757: nl80211: 2402-2472 @ 40 MHz 20 mBm
1451963731.389764: nl80211: 2457-2482 @ 40 MHz 20 mBm (no IR)
1451963731.389772: nl80211: 2474-2494 @ 20 MHz 20 mBm (no OFDM) (no IR)
1451963731.389779: nl80211: 5170-5250 @ 80 MHz 20 mBm (no IR)
1451963731.389787: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) (no IR)
1451963731.389794: nl80211: 5490-5730 @ 160 MHz 20 mBm (DFS) (no IR)
1451963731.389802: nl80211: 5735-5835 @ 80 MHz 20 mBm (no IR)
1451963731.389809: nl80211: 57240-63720 @ 2160 MHz 0 mBm
1451963731.389826: nl80211: Added 802.11b mode based on 802.11g information
1451963731.389835: P2P: Add operating class 81
1451963731.389842: P2P: Channels - hexdump(len=11): 01 02 03 04 05 06 07 08 09 0a 0b
1451963731.389858: P2P: Update channel list
1451963731.389869: P2P: channels: 81:1,2,3,4,5,6,7,8,9,10,11
1451963731.389876: P2P: cli_channels:
1451963731.389882: wlan0: Updating hw mode
1451963731.389981: nl80211: Regulatory information - country=00
1451963731.389989: nl80211: 2402-2472 @ 40 MHz 20 mBm
1451963731.389996: nl80211: 2457-2482 @ 40 MHz 20 mBm (no IR)
1451963731.390003: nl80211: 2474-2494 @ 20 MHz 20 mBm (no OFDM) (no IR)
1451963731.390011: nl80211: 5170-5250 @ 80 MHz 20 mBm (no IR)
1451963731.390018: nl80211: 5250-5330 @ 80 MHz 20 mBm (DFS) (no IR)
1451963731.390025: nl80211: 5490-5730 @ 160 MHz 20 mBm (DFS) (no IR)
1451963731.390032: nl80211: 5735-5835 @ 80 MHz 20 mBm (no IR)
1451963731.390039: nl80211: 57240-63720 @ 2160 MHz 0 mBm
1451963731.390055: nl80211: Added 802.11b mode based on 802.11g information
1451963731.392696: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
1451963731.487289: wlan0: State: DISCONNECTED -> SCANNING
1451963731.487386: Scan SSID - hexdump_ascii(len=13):
4d 6f 63 61 6e 61 2d 53 45 43 55 52 45 Mocana-SECURE
1451963731.487397: wlan0: Starting AP scan for wildcard SSID
________________________________________
From: Jouni Malinen [j at w1.fi]
Sent: Monday, January 04, 2016 15:29
To: Adam Jacobs
Cc: hostap at lists.infradead.org
Subject: Re: EAP-TLV: Earlier failure - force failed Phase 2
On Mon, Jan 04, 2016 at 02:46:43PM -0800, Adam Jacobs wrote:
> My laptop runs Ubuntu, and when I reproduced the error, it was invoking wpa_supplicant via NetworkManager. Of course, to test disabling TLS1.2, I had to shut off NetworkManager and invoke wpa_supplicant manually.
>
> What I've now discovered is that if I invoke wpa_supplicant manually, everything works fine even if I DON'T disable TLS1.2.
You might want to try to test this with NetworkManager and just
increasing debug verbosity for wpa_supplicant, e.g., by killing the
existing wpa_supplicant process and starting another one with something
like "-dddtu -f /tmp/wpas.log" on the command line.
> My config looks like this:
>
> network={
> ssid="Mocana-SECURE"
> key_mgmt=WPA-EAP
> eap=PEAP
> identity="ajacobs"
> password="**********"
> phase2="auth=MSCHAPV2"
> ca_cert="/usr/local/etc/MocanaRoot.pem"
> }
Based on couple of logs that Dan pointed me to, the only real
differences to that with NM would be addition of fragment_size=1300 (or
something around that value) and proactive_key_caching=1. I don't know
how either of these would cause the issue, but well, I guess it is worth
trying these (or that debugging mechanism with NM mentioned above). In
any case, I don't think I can do much more without the issue being
reproduced with verbose debugging enabled in wpa_supplicant.
> So it must be something about the way NetworkManager is calling/managing NetworkSupplicant that causes this failure. Unfortunately I don't know of any way to debug that further, and as I've shown wpa_supplicant to be working properly it is probably no longer the domain of this group, Still, I'm happy to take suggestions if anyone has any ideas for debugging further.
NM should not be able to configure wpa_supplicant in a way that causes
this type of interop issues, so I'd interpret that a bit differently: at
least one configuration of wpa_supplicant works, but something else in
the configuration or timing or whatever makes this fail in some other
cases.
--
Jouni Malinen PGP id EFC895FA
More information about the Hostap
mailing list