Issue with Linux connectivity in a High Density WLAN

  • 2
  • Question
  • Updated 3 years ago
  • Answered
Maybe I'm too deep in the weeds here and am missing something obvious, but here goes...

A high-density WLAN that I manage serves a handful of Linux users, most of which are fine, but about 4-5 of them are having intermittent disconnects in Ubuntu 13.10 and Debian. It occurs during (re)associations, and definitely has to do with the authentication process. The problem is exacerbated by the high-density nature of the WLAN due to redundant coverage causing more roaming than usual.

Today I visited on-site, sat down with a fresh Ubuntu 13.10 image with Network Manager on a cell boundary overlap, connected with no problems, and stayed that way for about 1.5 hours.

One of the users having issues came over and worked with me, and I was able to capture logs from Client Monitor and wpa_supplicant, as well as a packet capture from the station's position (20 feet visual LOS from the desired AP). The results are mystifying me though. I can't seem to make heads or tails as to whether I've got an RF issue or a supplicant issue on my hands.

So far I've been able to conclude that the supplicant fails to transmit 2/4 of the 4-way handshake. The supplicant logs show it transmits, but the packet capture and client monitor do not show the transmitted frame.

The really weird thing to me is that if the user inputs a specific BSSID of which AP he wants to connect, there is one out of the 6 APs total that works consistently. This is shown in the last part of the supplicant log, after the line breaks. This particular AP, however, is physically one of the farthest away from the station's position.

Can anyone help make any sense out of this?

(On a side note, I'm not a CWAP quite yet, but the QoS Null Frame with the power management bit set to 0 during the failed authentication seems odd to me. Is this part of the issue or can it be ignored?)

Logs to follow....
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes

Posted 4 years ago

  • 2
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
iwconfig (while connected to ap01)

$ sudo iwconfig
wlan1 IEEE 802.11abgn ESSID:"CoCo"
Mode:Managed Frequency:5.2 GHz Access Point: E0:1C:41:1E:8B:A8
Bit Rate=117 Mb/s Tx-Power=15 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Encryption key:off
Power Management:off
Link Quality=37/70 Signal level=-73 dBm
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:27209 Invalid misc:971 Missed beacon:0

eth0 no wireless extensions.

lo no wireless extensions.

_____________________________________________

Client Monitor:

(All de-authentications from ap01 are intentional)

01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1084)Rx auth (frame 1, rssi 44dB)
01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1085)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1086)Rx assoc req (rssi 44dB)
01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1087)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1088)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 12:58:06 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1089)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:58:10 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1090)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:58:14 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1091)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:58:18 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1092)Sta(at if=wifi1.1) is de-authenticated because of 4way handshake failure
01/07/2014 12:58:18 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1094)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1105)Rx auth (frame 1, rssi 44dB)
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1106)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1107)Rx assoc req (rssi 46dB)
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1108)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1109)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 12:59:08 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1110)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:59:12 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1111)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:59:16 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1112)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 12:59:20 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1113)Sta(at if=wifi1.1) is de-authenticated because of 4way handshake failure
01/07/2014 12:59:20 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1115)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1138)Rx auth (frame 1, rssi 45dB)
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1139)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1140)Rx assoc req (rssi 44dB)
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1141)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1142)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 01:00:29 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1143)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:00:33 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1144)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:00:37 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1145)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:00:41 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1146)Sta(at if=wifi1.1) is de-authenticated because of 4way handshake failure
01/07/2014 01:00:41 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1148)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1175)Rx auth (frame 1, rssi 45dB)
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1176)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1177)Rx assoc req (rssi 45dB)
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1178)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1179)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 01:02:26 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1180)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:30 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1181)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:34 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 INFO (1182)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:38 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1183)Sta(at if=wifi1.1) is de-authenticated because of 4way handshake failure
01/07/2014 01:02:38 PM B4B676BF4A73 E01C411E8BE8 coco400-ap03 BASIC (1185)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (988)Rx auth (frame 1, rssi 36dB)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (989)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (990)Rx assoc req (rssi 33dB)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (991)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (992)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (993)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (994)Received 2/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (995)Sending 3/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (996)Received 4/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (997)PTK is set (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (998)Authentication is successfully finished (at if=wifi1.1)
01/07/2014 01:02:45 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (999)station sent out DHCP DISCOVER message
01/07/2014 01:02:47 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1000)station sent out DHCP DISCOVER message
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1001)DHCP server sent out DHCP OFFER message to station
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1002)station sent out DHCP REQUEST message
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1003)DHCP server sent out DHCP OFFER message to station
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1004)DHCP server sent out DHCP ACKNOWLEDGE message to station
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1005)DHCP session completed for station
01/07/2014 01:02:52 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1006)IP 10.105.7.157 assigned for station
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1007)Rx auth (frame 1, rssi 34dB)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1008)Tx auth (frame 2, status 0, pwr 11dBm)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1009)Sta(at if=wifi1.1) is de-authenticated because of notification of driver
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1010)Rx assoc req (rssi 31dB)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1011)Tx assoc resp (status 0, pwr 11dBm)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1012)WPA-PSK auth is starting (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1013)Sending 1/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1014)Received 2/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1015)Sending 3/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1016)Received 4/4 msg of 4-Way Handshake (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1017)PTK is set (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1018)Authentication is successfully finished (at if=wifi1.1)
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1019)station sent out DHCP REQUEST message
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 INFO (1020)DHCP server sent out DHCP ACKNOWLEDGE message to station
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1021)DHCP session completed for station
01/07/2014 01:07:28 PM B4B676BF4A73 E01C411E8BA8 coco400-ap01 BASIC (1022)IP 10.105.7.157 assigned for station

________________________________________________

wpa_supplicant -dd

EAPOL: Supplicant port status: Unauthorized
dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1)
dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
scan_ssid=1 (0x1)
auth_alg: 0x1
ssid - hexdump_ascii(len=4):
43 6f 43 6f CoCo
key_mgmt: 0x2
PSK (ASCII passphrase) - hexdump_ascii(len=8): [REMOVED]
PSK (from passphrase) - hexdump(len=32): [REMOVED]
dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
wlan1: Setting scan request: 0 sec 0 usec
wlan1: State: INACTIVE -> SCANNING
Scan SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
wlan1: Starting AP scan for wildcard SSID
nl80211: Scan SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
Scan requested (ret=0) - scan timeout 30 seconds
nl80211: Event message available
nl80211: Scan trigger
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: New scan results available
wlan1: Event SCAN_RESULTS (3) received
nl80211: Received scan results (32 BSSes)
wlan1: BSS: Start scan result update 3
wlan1: BSS: Add new id 26 BSSID 00:27:0d:60:5f:df SSID 'HCWDN'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/26'
wlan1: BSS: Add new id 27 BSSID 00:27:0d:60:5f:de SSID 'HC_VOIP'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/27'
wlan1: BSS: Add new id 28 BSSID 00:0d:67:0b:2e:1c SSID 'usiw_secure_S03N114T1'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/28'
wlan1: BSS: Add new id 29 BSSID 00:24:37:0b:9a:20 SSID 'spirit river'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29'
wlan1: BSS: Add new id 30 BSSID 00:27:0d:eb:93:ed SSID 'HC_GUEST'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/30'
wlan1: BSS: Add new id 31 BSSID 00:27:0d:60:5f:d2 SSID 'HC_GUEST'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31'
Add randomness: count=22 entropy=0
Add randomness: count=23 entropy=1
Add randomness: count=24 entropy=2
Add randomness: count=25 entropy=3
Add randomness: count=26 entropy=4
Add randomness: count=27 entropy=5
Add randomness: count=28 entropy=6
Add randomness: count=29 entropy=7
Add randomness: count=30 entropy=8
Add randomness: count=31 entropy=9
wlan1: New scan results available
wlan1: Selecting BSS from priority group 0
wlan1: 0: 74:d0:2b:89:02:38 ssid='FBI Surveillance Van-GMC541' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-36 wps
wlan1: skip - SSID mismatch
wlan1: 1: 74:d0:2b:89:02:3c ssid='FBI Surveillance Van-GMC541_Fast' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-53 wps
wlan1: skip - SSID mismatch
wlan1: 2: e0:1c:41:1e:8b:e8 ssid='CoCo' wpa_ie_len=0 rsn_ie_len=22 caps=0x511 level=-54
wlan1: selected based on RSN IE
wlan1: selected BSS e0:1c:41:1e:8b:e8 ssid='CoCo'
wlan1: Request association: reassociate: 1 selected: e0:1c:41:1e:8b:e8 bssid: 00:00:00:00:00:00 pending: 00:00:00:00:00:00 wpa_state: SCANNING
wlan1: Automatic auth_alg selection: 0x1
wlan1: Overriding auth_alg selection: 0x1
wlan1: RSN: using IEEE 802.11i/D9.0
wlan1: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
wlan1: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=24): 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 00 00
wlan1: WPA: using GTK CCMP
wlan1: WPA: using PTK CCMP
wlan1: WPA: using KEY_MGMT WPA-PSK
wlan1: WPA: not using MGMT group cipher
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0):
wlan1: Cancelling scan request
wlan1: SME: Trying to authenticate with e0:1c:41:1e:8b:e8 (SSID='CoCo' freq=5220 MHz)
wlan1: No keys have been configured - skip key clearing
wlan1: State: SCANNING -> AUTHENTICATING
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP fail=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portControl=Auto
EAPOL: Supplicant port status: Unauthorized
nl80211: Authenticate (ifindex=3)
* bssid=e0:1c:41:1e:8b:e8
* freq=5220
* SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
* IEs - hexdump(len=0): [NULL]
* Auth Type 0
nl80211: Authentication request send successfully
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
wlan1: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
nl80211: Event message available
nl80211: New station e0:1c:41:1e:8b:e8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/6
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/9
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/10
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/17
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/11
nl80211: Event message available
nl80211: MLME event 37
nl80211: MLME event frame - hexdump(len=30): b0 00 2c 00 b4 b6 76 bf 4a 73 e0 1c 41 1e 8b e8 e0 1c 41 1e 8b e8 00 10 00 00 02 00 00 00
wlan1: Event AUTH (11) received
wlan1: SME: Authentication response: peer=e0:1c:41:1e:8b:e8 auth_type=0 status_code=0
SME: Authentication response IEs - hexdump(len=0): [NULL]
wlan1: Trying to associate with e0:1c:41:1e:8b:e8 (SSID='CoCo' freq=5220 MHz)
wlan1: State: AUTHENTICATING -> ASSOCIATING
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
nl80211: Associate (ifindex=3)
* bssid=e0:1c:41:1e:8b:e8
* freq=5220
* SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
* IEs - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
* pairwise=0xfac04
* group=0xfac04
* prev_bssid=e0:1c:41:1e:8c:54
nl80211: Association request send successfully
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/14
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/23
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/21
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/22
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
nl80211: Event message available
nl80211: MLME event 38
nl80211: MLME event frame - hexdump(len=189): 30 00 2c 00 b4 b6 76 bf 4a 73 e0 1c 41 1e 8b e8 e0 1c 41 1e 8b e8 10 10 11 04 00 00 0c c0 01 04 b0 48 60 6c 2d 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 33 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 2c 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 16 2c 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 05 01 00 00 00 00 dd 18 00 50 f2 02 01 01 04 00 00 00 00 00 20 00 00 00 40 00 00 00 60 00 00 00
wlan1: Event ASSOC (0) received
wlan1: Association info event
resp_ies - hexdump(len=159): 01 04 b0 48 60 6c 2d 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 33 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 2c 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 16 2c 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 05 01 00 00 00 00 dd 18 00 50 f2 02 01 01 04 00 00 00 00 00 20 00 00 00 40 00 00 00 60 00 00 00
wlan1: freq=5220 MHz
FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0):
wlan1: State: ASSOCIATING -> ASSOCIATED
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
wlan1: Associated to a new BSS: BSSID=e0:1c:41:1e:8b:e8
Add randomness: count=32 entropy=10
wlan1: No keys have been configured - skip key clearing
wlan1: Associated with e0:1c:41:1e:8b:e8
wlan1: WPA: Association event - clear replay counter
wlan1: WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
wlan1: Setting authentication timeout: 10 sec 0 usec
wlan1: Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: Ignore connect event (cmd=46) when using userspace SME
nl80211: l2_packet read 99
wlan1: RX EAPOL from e0:1c:41:1e:8b:e8
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: Setting authentication timeout: 10 sec 0 usec
wlan1: IEEE 802.1X RX: version=1 type=3 length=95
wlan1: EAPOL-Key type=2
wlan1: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan1: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
key_nonce - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlan1: WPA: RX message 1 of 4-Way Handshake from e0:1c:41:1e:8b:e8 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
Get randomness: len=32 entropy=11
WPA: Renewed SNonce - hexdump(len=32): 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7
WPA: PTK derivation - A1=b4:b6:76:bf:4a:73 A2=e0:1c:41:1e:8b:e8
WPA: Nonce1 - hexdump(len=32): 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7
WPA: Nonce2 - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01
wlan1: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 8c b8 ff 9a e3 cf d0 7c 4a 2a b9 ce a5 b7 9b a1
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8c b8 ff 9a e3 cf d0 7c 4a 2a b9 ce a5 b7 9b a1 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
nl80211: Event message available
nl80211: Regulatory domain change
wlan1: Event CHANNEL_LIST_CHANGED (31) received
nl80211: Regulatory information - country=US
nl80211: 2402-2472 @ 40 MHz
nl80211: 5170-5250 @ 40 MHz
nl80211: 5250-5330 @ 40 MHz
nl80211: 5490-5600 @ 40 MHz
nl80211: 5650-5710 @ 40 MHz
nl80211: 5735-5835 @ 40 MHz
nl80211: 57240-63720 @ 2160 MHz
nl80211: Added 802.11b mode based on 802.11g information
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
EAPOL: startWhen --> 0
EAPOL: disable timer tick
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: enable timer tick
EAPOL: txStart
WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
nl80211: l2_packet read 99
wlan1: RX EAPOL from e0:1c:41:1e:8b:e8
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 02 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: IEEE 802.1X RX: version=1 type=3 length=95
wlan1: EAPOL-Key type=2
wlan1: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan1: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
key_nonce - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 02 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan1: WPA: RX message 1 of 4-Way Handshake from e0:1c:41:1e:8b:e8 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=b4:b6:76:bf:4a:73 A2=e0:1c:41:1e:8b:e8
WPA: Nonce1 - hexdump(len=32): 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7
WPA: Nonce2 - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 02
wlan1: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 11 28 e9 4f fd 94 57 0f 46 02 6a ed 93 83 0b 3b
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 02 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 11 28 e9 4f fd 94 57 0f 46 02 6a ed 93 83 0b 3b 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
nl80211: l2_packet read 99
wlan1: RX EAPOL from e0:1c:41:1e:8b:e8
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 03 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: IEEE 802.1X RX: version=1 type=3 length=95
wlan1: EAPOL-Key type=2
wlan1: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan1: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
key_nonce - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 03 b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan1: WPA: RX message 1 of 4-Way Handshake from e0:1c:41:1e:8b:e8 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
WPA: PTK derivation - A1=b4:b6:76:bf:4a:73 A2=e0:1c:41:1e:8b:e8
WPA: Nonce1 - hexdump(len=32): 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7
WPA: Nonce2 - hexdump(len=32): b3 fc 1f 0a e9 1c c9 14 05 d0 cd ef 66 85 85 f0 d9 83 86 ae 8a 0f f9 d4 bb a3 8a 29 9b a1 be d6
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 03
wlan1: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 22 b5 63 f1 33 31 b7 d0 b4 b7 31 6f 2b 65 08 d8
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 03 6e c6 82 8d 22 97 16 7d fd 71 83 f4 66 60 19 f2 a9 86 00 51 5a 3b 21 ca 90 21 71 23 b8 e0 fe b7 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 22 b5 63 f1 33 31 b7 d0 b4 b7 31 6f 2b 65 08 d8 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
wlan1: Authentication with e0:1c:41:1e:8b:e8 timed out.
Added BSSID e0:1c:41:1e:8b:e8 into blacklist
wpa_driver_nl80211_disassociate
wlan1: No keys have been configured - skip key clearing
wlan1: State: 4WAY_HANDSHAKE -> DISCONNECTED
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: SUPP_PAE entering state DISCONNECTED
EAPOL: Supplicant port status: Unauthorized
EAPOL: SUPP_BE entering state INITIALIZE
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
wlan1: Setting scan request: 1 sec 0 usec
EAPOL: Supplicant port status: Unauthorized
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: Delete station e0:1c:41:1e:8b:e8
nl80211: Event message available
nl80211: MLME event 40
nl80211: MLME event frame - hexdump(len=26): a0 00 00 00 e0 1c 41 1e 8b e8 b4 b6 76 bf 4a 73 e0 1c 41 1e 8b e8 00 00 03 00
wlan1: Event DISASSOC (1) received
wlan1: Disassociation notification
wlan1: * reason 3
wlan1: * address e0:1c:41:1e:8b:e8
Disassociation frame IE(s) - hexdump(len=0): [NULL]
wlan1: SME: Disassociation event received
wlan1: SME: Deauthenticate to clear driver state
wpa_driver_nl80211_deauthenticate(addr=e0:1c:41:1e:8b:e8 reason_code=3)
wlan1: WPA: Auto connect enabled: try to reconnect (wps=0)
BSSID 00:00:00:00:00:00 blacklist count incremented to 2
wlan1: Not rescheduling scan to ensure that specific SSID scans occur
wlan1: CTRL-EVENT-DISCONNECTED bssid=00:00:00:00:00:00 reason=3
wlan1: Disconnect event - remove keys
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=4 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=5 set_tx=0 seq_len=0 key_len=0
wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=0xee0d30 key_idx=0 set_tx=0 seq_len=0 key_len=0
addr=00:00:00:00:00:00
wlan1: State: DISCONNECTED -> DISCONNECTED
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
nl80211: Event message available
nl80211: Ignore disconnect event when using userspace SME
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: Regulatory domain change
wlan1: Event CHANNEL_LIST_CHANGED (31) received
nl80211: Regulatory information - country=00
nl80211: 2402-2472 @ 40 MHz
nl80211: 2457-2482 @ 40 MHz
nl80211: 2474-2494 @ 20 MHz
nl80211: 5170-5250 @ 40 MHz
nl80211: 5735-5835 @ 40 MHz
nl80211: Added 802.11b mode based on 802.11g information
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
dbus: fi.w1.wpa_supplicant1.Interface.RemoveNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
dbus: Unregister network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
wlan1: No enabled networks - do not scan
wlan1: State: DISCONNECTED -> INACTIVE
EAPOL: Supplicant port status: Unauthorized
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized

(Successful auth below to apo1)

dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
Scan requested (ret=0) - scan timeout 30 seconds
nl80211: Event message available
nl80211: Scan trigger
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: New scan results available
wlan1: Event SCAN_RESULTS (3) received
nl80211: Received scan results (29 BSSes)
wlan1: BSS: Start scan result update 4
wlan1: BSS: Add new id 32 BSSID 00:0d:67:09:b5:36 SSID 'usiw_secure'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32'
wlan1: BSS: Add new id 33 BSSID 58:8d:09:e3:60:5c SSID 'UDTLAW'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33'
wlan1: BSS: Add new id 34 BSSID 00:27:0d:60:5f:d1 SSID 'HC_VOIP'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34'
Add randomness: count=33 entropy=0
Add randomness: count=34 entropy=1
Add randomness: count=35 entropy=2
Add randomness: count=36 entropy=3
Add randomness: count=37 entropy=4
Add randomness: count=38 entropy=5
Add randomness: count=39 entropy=6
Add randomness: count=40 entropy=7
Add randomness: count=41 entropy=8
Add randomness: count=42 entropy=9
wlan1: New scan results available
wlan1: No APs found - clear blacklist and try again
Removed BSSID e0:1c:41:1e:8b:e8 from blacklist (clear)
Removed BSSID 00:00:00:00:00:00 from blacklist (clear)
Removed BSSID e0:1c:41:1e:8c:54 from blacklist (clear)
wlan1: No suitable network found
wlan1: State: INACTIVE -> INACTIVE
wlan1: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/6
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/9
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/10
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/11
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/17
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/15
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/23
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/21
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/22
EAPOL: Supplicant port status: Unauthorized
dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1)
dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
scan_ssid=1 (0x1)
ssid - hexdump_ascii(len=4):
43 6f 43 6f CoCo
BSSID - hexdump(len=6): e0 1c 41 1e 8b a8
key_mgmt: 0x2
PSK (ASCII passphrase) - hexdump_ascii(len=8): [REMOVED]
PSK (from passphrase) - hexdump(len=32): [REMOVED]
dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
wlan1: Setting scan request: 0 sec 0 usec
wlan1: State: INACTIVE -> SCANNING
Scan SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
wlan1: Starting AP scan for wildcard SSID
nl80211: Scan SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
Scan requested (ret=0) - scan timeout 30 seconds
nl80211: Event message available
nl80211: Scan trigger
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
EAPOL: Supplicant port status: Unauthorized
RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: New scan results available
wlan1: Event SCAN_RESULTS (3) received
nl80211: Received scan results (30 BSSes)
wlan1: BSS: Start scan result update 5
wlan1: BSS: Add new id 35 BSSID 00:0d:67:09:b5:35 SSID 'USI Wireless'
dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35'
wlan1: BSS: Expire BSS 18 due to no match in scan
wlan1: BSS: Remove id 18 BSSID 00:19:77:4e:ec:d4 SSID 'jamfsoftware'
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/18'
wlan1: BSS: Expire BSS 24 due to no match in scan
wlan1: BSS: Remove id 24 BSSID 00:27:0d:60:5f:d0 SSID 'HCWDN'
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/24'
wlan1: BSS: Expire BSS 19 due to no match in scan
wlan1: BSS: Remove id 19 BSSID 20:aa:4b:79:ed:1a SSID 'WHDavisLaw Wireless'
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/19'
wlan1: BSS: Expire BSS 25 due to no match in scan
wlan1: BSS: Remove id 25 BSSID 00:0d:67:09:b5:38 SSID 'City of Minneapolis Public WiFi'
dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/25'
Add randomness: count=43 entropy=10
Add randomness: count=44 entropy=11
Add randomness: count=45 entropy=12
Add randomness: count=46 entropy=13
Add randomness: count=47 entropy=14
Add randomness: count=48 entropy=15
Add randomness: count=49 entropy=16
Add randomness: count=50 entropy=17
Add randomness: count=51 entropy=18
Add randomness: count=52 entropy=19
wlan1: New scan results available
wlan1: Selecting BSS from priority group 0
wlan1: 0: 74:d0:2b:89:02:38 ssid='FBI Surveillance Van-GMC541' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-41 wps
wlan1: skip - SSID mismatch
wlan1: 1: 74:d0:2b:89:02:3c ssid='FBI Surveillance Van-GMC541_Fast' wpa_ie_len=0 rsn_ie_len=20 caps=0x11 level=-55 wps
wlan1: skip - SSID mismatch
wlan1: 2: e0:1c:41:1e:8b:e8 ssid='CoCo' wpa_ie_len=0 rsn_ie_len=22 caps=0x511 level=-56
wlan1: skip - BSSID mismatch
wlan1: 3: 28:c6:8e:ae:83:f3 ssid='NastyVirus' wpa_ie_len=0 rsn_ie_len=20 caps=0x31 level=-52 wps
wlan1: skip - SSID mismatch
wlan1: 4: e0:1c:41:1e:8b:68 ssid='CoCo' wpa_ie_len=0 rsn_ie_len=22 caps=0x511 level=-59
wlan1: skip - BSSID mismatch
wlan1: 5: e0:1c:41:1e:8c:54 ssid='CoCo' wpa_ie_len=0 rsn_ie_len=22 caps=0x31 level=-55
wlan1: skip - BSSID mismatch
wlan1: 6: e0:1c:41:1e:8b:a8 ssid='CoCo' wpa_ie_len=0 rsn_ie_len=22 caps=0x511 level=-66
wlan1: selected based on RSN IE
wlan1: selected BSS e0:1c:41:1e:8b:a8 ssid='CoCo'
wlan1: Request association: reassociate: 1 selected: e0:1c:41:1e:8b:a8 bssid: 00:00:00:00:00:00 pending: 00:00:00:00:00:00 wpa_state: SCANNING
wlan1: Automatic auth_alg selection: 0x1
wlan1: RSN: using IEEE 802.11i/D9.0
wlan1: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
wlan1: WPA: clearing AP WPA IE
WPA: set AP RSN IE - hexdump(len=24): 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 00 00
wlan1: WPA: using GTK CCMP
wlan1: WPA: using PTK CCMP
wlan1: WPA: using KEY_MGMT WPA-PSK
wlan1: WPA: not using MGMT group cipher
WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0):
wlan1: Cancelling scan request
wlan1: SME: Trying to authenticate with e0:1c:41:1e:8b:a8 (SSID='CoCo' freq=5200 MHz)
wlan1: No keys have been configured - skip key clearing
wlan1: State: SCANNING -> AUTHENTICATING
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP fail=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portControl=Auto
EAPOL: Supplicant port status: Unauthorized
nl80211: Authenticate (ifindex=3)
* bssid=e0:1c:41:1e:8b:a8
* freq=5200
* SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
* IEs - hexdump(len=0): [NULL]
* Auth Type 0
nl80211: Authentication request send successfully
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
RSN: Ignored PMKID candidate without preauth flag
wlan1: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
nl80211: Event message available
nl80211: New station e0:1c:41:1e:8b:a8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/6
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/8
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/9
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/10
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/13
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/27
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/26
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/23
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/15
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/12
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/21
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/22
nl80211: Event message available
nl80211: MLME event 37
nl80211: MLME event frame - hexdump(len=30): b0 00 2c 00 b4 b6 76 bf 4a 73 e0 1c 41 1e 8b a8 e0 1c 41 1e 8b a8 00 10 00 00 02 00 00 00
wlan1: Event AUTH (11) received
wlan1: SME: Authentication response: peer=e0:1c:41:1e:8b:a8 auth_type=0 status_code=0
SME: Authentication response IEs - hexdump(len=0): [NULL]
wlan1: Trying to associate with e0:1c:41:1e:8b:a8 (SSID='CoCo' freq=5200 MHz)
wlan1: State: AUTHENTICATING -> ASSOCIATING
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
nl80211: Associate (ifindex=3)
* bssid=e0:1c:41:1e:8b:a8
* freq=5200
* SSID - hexdump_ascii(len=4):
43 6f 43 6f CoCo
* IEs - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
* pairwise=0xfac04
* group=0xfac04
* prev_bssid=e0:1c:41:1e:8b:e8
nl80211: Association request send successfully
nl80211: Event message available
nl80211: MLME event 38
nl80211: MLME event frame - hexdump(len=189): 30 00 2c 00 b4 b6 76 bf 4a 73 e0 1c 41 1e 8b a8 e0 1c 41 1e 8b a8 10 10 11 04 00 00 0e c0 01 04 b0 48 60 6c 2d 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 33 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 28 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 16 28 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 05 01 00 00 00 00 dd 18 00 50 f2 02 01 01 06 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
wlan1: Event ASSOC (0) received
wlan1: Association info event
resp_ies - hexdump(len=159): 01 04 b0 48 60 6c 2d 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 33 1a ad 01 03 ff ff ff 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d 16 28 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 34 16 28 08 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a 0e 14 00 0a 00 2c 01 c8 00 14 00 05 00 19 00 7f 05 01 00 00 00 00 dd 18 00 50 f2 02 01 01 06 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00
wlan1: freq=5200 MHz
FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0):
wlan1: State: ASSOCIATING -> ASSOCIATED
wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
netlink: Operstate: linkmode=-1, operstate=5
wlan1: Associated to a new BSS: BSSID=e0:1c:41:1e:8b:a8
Add randomness: count=53 entropy=20
wlan1: No keys have been configured - skip key clearing
wlan1: Associated with e0:1c:41:1e:8b:a8
wlan1: WPA: Association event - clear replay counter
wlan1: WPA: Clear old PTK
EAPOL: External notification - portEnabled=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portValid=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - EAP success=0
EAPOL: Supplicant port status: Unauthorized
EAPOL: External notification - portEnabled=1
EAPOL: SUPP_PAE entering state CONNECTING
EAPOL: SUPP_BE entering state IDLE
wlan1: Setting authentication timeout: 10 sec 0 usec
wlan1: Cancelling scan request
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
nl80211: if_removed already cleared - ignore event
nl80211: Event message available
nl80211: Ignore connect event (cmd=46) when using userspace SME
nl80211: l2_packet read 99
wlan1: RX EAPOL from e0:1c:41:1e:8b:a8
RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: Setting authentication timeout: 10 sec 0 usec
wlan1: IEEE 802.1X RX: version=1 type=3 length=95
wlan1: EAPOL-Key type=2
wlan1: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan1: key_length=16 key_data_length=0
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
key_nonce - hexdump(len=32): 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 00 8a 00 10 00 00 00 00 00 00 00 01 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
wlan1: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlan1: WPA: RX message 1 of 4-Way Handshake from e0:1c:41:1e:8b:a8 (ver=2)
RSN: msg 1/4 key data - hexdump(len=0):
Get randomness: len=32 entropy=21
WPA: Renewed SNonce - hexdump(len=32): ac ab 42 3c de 3e f7 89 14 b0 da 01 35 79 f1 4c 19 2a 95 c3 ce a5 45 f5 37 28 f2 7d af 28 de d9
WPA: PTK derivation - A1=b4:b6:76:bf:4a:73 A2=e0:1c:41:1e:8b:a8
WPA: Nonce1 - hexdump(len=32): ac ab 42 3c de 3e f7 89 14 b0 da 01 35 79 f1 4c 19 2a 95 c3 ce a5 45 f5 37 28 f2 7d af 28 de d9
WPA: Nonce2 - hexdump(len=32): 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9
WPA: PMK - hexdump(len=32): [REMOVED]
WPA: PTK - hexdump(len=48): [REMOVED]
WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01
wlan1: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): e6 aa 31 f3 5a 32 b8 a4 04 a1 6a 42 a0 b3 e9 77
WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 ac ab 42 3c de 3e f7 89 14 b0 da 01 35 79 f1 4c 19 2a 95 c3 ce a5 45 f5 37 28 f2 7d af 28 de d9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 e6 aa 31 f3 5a 32 b8 a4 04 a1 6a 42 a0 b3 e9 77 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
nl80211: Event message available
nl80211: Regulatory domain change
wlan1: Event CHANNEL_LIST_CHANGED (31) received
nl80211: Regulatory information - country=US
nl80211: 2402-2472 @ 40 MHz
nl80211: 5170-5250 @ 40 MHz
nl80211: 5250-5330 @ 40 MHz
nl80211: 5490-5600 @ 40 MHz
nl80211: 5650-5710 @ 40 MHz
nl80211: 5735-5835 @ 40 MHz
nl80211: 57240-63720 @ 2160 MHz
nl80211: Added 802.11b mode based on 802.11g information
nl80211: l2_packet read 155
wlan1: RX EAPOL from e0:1c:41:1e:8b:a8
RX EAPOL - hexdump(len=155): 01 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 02 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8d c1 42 07 00 00 00 00 00 00 00 00 00 00 00 00 28 2e 10 50 b1 6c bc 6a 8c d7 74 17 dd 48 8a 6d 00 38 28 bf 15 52 03 4f bc ec 19 b8 41 56 cb 5f 9d 53 15 99 b6 c5 b8 96 0d fa 88 58 e6 a6 28 1c 40 80 0b a3 e8 23 7e a0 cb 9c d2 28 34 17 bb 00 ee 9a f6 39 da ff 74 18 da 63
wlan1: IEEE 802.1X RX: version=1 type=3 length=151
wlan1: EAPOL-Key type=2
wlan1: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
wlan1: key_length=16 key_data_length=56
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
key_nonce - hexdump(len=32): 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 8d c1 42 07 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 28 2e 10 50 b1 6c bc 6a 8c d7 74 17 dd 48 8a 6d
WPA: RX EAPOL-Key - hexdump(len=155): 01 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 02 4f 7f c4 c3 dd 57 ad d2 95 00 93 3c a1 6d 9f a8 44 68 13 e5 c4 ea b0 21 4b c7 50 52 2b 22 39 e9 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 8d c1 42 07 00 00 00 00 00 00 00 00 00 00 00 00 28 2e 10 50 b1 6c bc 6a 8c d7 74 17 dd 48 8a 6d 00 38 28 bf 15 52 03 4f bc ec 19 b8 41 56 cb 5f 9d 53 15 99 b6 c5 b8 96 0d fa 88 58 e6 a6 28 1c 40 80 0b a3 e8 23 7e a0 cb 9c d2 28 34 17 bb 00 ee 9a f6 39 da ff 74 18 da 63
RSN: encrypted key data - hexdump(len=56): 28 bf 15 52 03 4f bc ec 19 b8 41 56 cb 5f 9d 53 15 99 b6 c5 b8 96 0d fa 88 58 e6 a6 28 1c 40 80 0b a3 e8 23 7e a0 cb 9c d2 28 34 17 bb 00 ee 9a f6 39 da ff 74 18 da 63
WPA: decrypted EAPOL-Key key data - hexdump(len=48): [REMOVED]
wlan1: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
wlan1: WPA: RX message 3 of 4-Way Handshake from e0:1c:41:1e:8b:a8 (ver=2)
WPA: IE KeyData - hexdump(len=48): 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 00 00 dd 16 00 0f ac 01 01 00 c9 69 fd ef bb a7 17 ae c9 6f 8e 26 6e bb 2b e3
WPA: RSN IE in EAPOL-Key - hexdump(len=24): 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 00 00
WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
wlan1: WPA: Sending EAPOL-Key 4/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): 0e 63 25 44 f7 02 0f 8c 82 5e 47 59 c6 cf 76 f1
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 0e 63 25 44 f7 02 0f 8c 82 5e 47 59 c6 cf 76 f1 00 00
wlan1: WPA: Installing PTK to the driver
wpa_driver_nl80211_set_key: ifindex=3 alg=3 addr=0xee45f8 key_idx=0 set_tx=1 seq_len=6 key_len=16
addr=e0:1c:41:1e:8b:a8
EAPOL: External notification - portValid=1
wlan1: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
RSN: received GTK in pairwise handshake - hexdump(len=18): [REMOVED]
WPA: Group Key - hexdump(len=16): [REMOVED]
wlan1: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16)
WPA: RSC - hexdump(len=6): 8d c1 42 07 00 00
wpa_driver_nl80211_set_key: ifindex=3 alg=3 addr=0x4eb5dc key_idx=1 set_tx=0 seq_len=6 key_len=16
broadcast key
wlan1: WPA: Key negotiation completed with e0:1c:41:1e:8b:a8 [PTK=CCMP GTK=CCMP]
wlan1: Cancelling authentication timeout
wlan1: State: GROUP_HANDSHAKE -> COMPLETED
wlan1: CTRL-EVENT-CONNECTED - Connection to e0:1c:41:1e:8b:a8 completed (
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
And finally Wireshark. I'll do a screenshot here of two failed authentications to ap03. Keep in mind that the PWR MGT bit is set to 0 in both of the null data frames.

Photo of Chaitanya Krushna T

Chaitanya Krushna T

  • 1 Post
  • 0 Reply Likes
Well the Qos Null frame is a keep alive, which starts right after the successful re- association response (doesnt wait for 4-way/DHCP to complete) that's mac80211.

Interesting thing is that the M1 from AP got the ACK but the M2 (which is prepared correctly, the dump from wpa_supplicant) is not seen in the sniffer.

Where was the location of the sniffer? Near to AP/STA/Somewhere else?
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
The location was about 1 foot from station, and about 25 feet visual LOS to the AP. Presumably I would have picked up the 2/4 frame if it was transmitted.
Photo of Andrew MacTaggart

Andrew MacTaggart, Champ

  • 483 Posts
  • 86 Reply Likes
I would lean towards supplicant issue

country=00 doesn't seem right to me - not sure what country you are in, but maybe make sure the client driver loads the correct country code

not sure if you are using DFS channels and the client doesn't support it and maybe that is why it connects to the AP that is the farthest away.

nl80211: Regulatory information - country=00
nl80211: 2402-2472 @ 40 MHz
nl80211: 2457-2482 @ 40 MHz
nl80211: 2474-2494 @ 20 MHz
nl80211: 5170-5250 @ 40 MHz
nl80211: 5735-5835 @ 40 MHz

and for dense deployment you could always tweak the power settings down to get a balance of coverage but not so much coverage that it would cause issues. Also you can disable lower data rates to shrink the coverage as well, although if you have dot ac the standard does not allow disabling of data rates.
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
Thanks for the reply Andrew. I'm leaning towards supplicant as well.

A little bit about the network policy:

-US regulations
-No DFS channels enabled
-Power settings are tweaked down about as much as they can go. It's a very unique space and somewhat challenging to keep cell size down while keeping power levels in range with station tx power. I'd have to go with semi-directional antennas to achieve smaller cell sizes.
-Supported rates on the SSID start at 12 Mbps basic for b/g, 12 Mbps basic for a, and all n rates are optional. I'm hesitant to go any higher due to compatibility issues.

Considering another Linux client was connecting perfectly to the proper AP that was sitting right next to the computer with issues, I feel like it has to be a supplicant issue. But frankly this is my first foray into serious troubleshooting with Linux clients, and it's the wild west out there.
Photo of Stefan van der Wal

Stefan van der Wal, Champ

  • 70 Posts
  • 24 Reply Likes
Hi Steve,

Looks like a fun implementation! What radioprofiles are currently in effect? I am pretty much in agreement with Andrew that it's a supplicant issue, but I've run into some crazy behavior with Linux and some radio settings. I'd like to exclude it as an issue.

Stefan
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
Stefan,

Here are the radio profiles. I tend to be more conservative about band steering and load balancing generally, but here both are off completely in this implementation for compatibility.

Power and channel settings are set manually for all radios.

b/g/n



a/n


Photo of Stefan van der Wal

Stefan van der Wal, Champ

  • 70 Posts
  • 24 Reply Likes
Steve,

Looks perfectly fine, it's definitely the way to go in these deployments. I am sitting down with some other people that've been in touch with this stuff tomorrow. I'm going to go ahead and throw this in and see what they think about it.

I'll let you know.
Photo of Roberto Casula

Roberto Casula, Champ

  • 231 Posts
  • 111 Reply Likes
It's a bit difficult to just go on the screenshots, but it looks as if we have the following (just to confirm what you have already concluded):

1. The supplicant is receiving the first packet of the 4-way handshake from the AP. There's no indication that there is anything "wrong" with the data received from the AP in packet 1 as the supplicant goes on to...
2. ...derive the PTK and generate its MIC data for packet 2. As you note, according to the supplicant log is "transmitting" this packet (WPA: TX EAPOL-Key).
3. The Wireshark capture (which you state is taken by a third device located close to the client) does not show this packet and the client monitor trace shows the AP never processes the packet.

From this I guess we have to conclude, as you did, that the packet never actually got transmitted. In the absence of any debug data, this could be the result of a supplicant bug or a driver bug.

The fact that one BSSID out of six reliably "works" is certainly interesting and could suggests some kind of hash collision bug or similar in the driver where whether the reauthentication succeeds or not is dependent on the BSSID of the AP you're associating to and maybe even what other BSSIDs there are in the vicinity.

[For example, there was a bug in InSSIDer at one point where it used a "stupid" hash-algorithm that resulted in an extremely high probability of a hash-table collision between BSSIDs of APs from the same vendor. The result of this was that InSSIDer often seemed not to "see" a number of APs; in fact what was happening was it was treating multiple APs as the same AP as they all hashed to the same 32-bit supposedly-unique hash value. Once I rewrote the hash function to properly mix the bits in the BSSID when calculating the 32-bit hash value the problem was fixed (this change is now in the InSSIDer code - the wonders of OSS).]

Possibly something like that could be happening here inside the driver during a reauthentication or roam...

What wireless NIC and driver version are you using? Are you using kernel drivers or have you compiled the driver from the NIC vendor? Have you tried a newer/older kernel or a newer/older driver?

Depending on the driver, you may be able to enable debug logging for the driver to get a bit more detail about what is going on.

I have to say I've had similar sorts of behaviour in the past, and it was invariably a driver problem. Almost always it was resolvable by grabbing and compiling the latest (or sometimes an older!) driver from the vendor.
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
Thanks for the followup Roberto, this makes sense to me, especially your guess as to why one particular BSSID seems to function.

There are two users that I'm working with the most that have the issue. I'll have to follow up with them regarding the drivers because frankly I don't remember but I did jot down their chipset models.

The logs above are an Intel Centrino Mobile Advanced-N 6235
The other user is an Intel Centrino Mobile Advanced 6200

I have put out a request for more wpa supplicant logs, driver and hw models from other users in the hope that the Intel chipset remains a common factor. I wanted to make sure I was going down the right path first (regarding supplicant vs RF) before I dug deep into driver troubleshooting.
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
To follow up, the user that has the 6235 chipset is using iwlwifi kernel drivers. I've requested for him to upgrade or downgrade firmware first and report back to me.

Kernel is 3.11

For now, the driver and firmware info:

Information from lspci about network controller
# lspci -vv
01:00.0 Network controller: Intel Corporation Centrino Advanced-N 6235 (rev 24)
Subsystem: Intel Corporation Centrino Advanced-N 6235 AGN
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- SERR-
version: in-tree:
description: Intel(R) Wireless WiFi driver for Linux
firmware: iwlwifi-100-5.ucode
firmware: iwlwifi-1000-5.ucode
firmware: iwlwifi-135-6.ucode
firmware: iwlwifi-105-6.ucode
firmware: iwlwifi-2030-6.ucode
firmware: iwlwifi-2000-6.ucode
firmware: iwlwifi-5150-2.ucode
firmware: iwlwifi-5000-5.ucode
firmware: iwlwifi-6000g2b-6.ucode
firmware: iwlwifi-6000g2a-5.ucode
firmware: iwlwifi-6050-5.ucode
firmware: iwlwifi-6000-4.ucode
firmware: iwlwifi-3160-7.ucode
firmware: iwlwifi-7260-7.ucode
srcversion: B3EF32124305F5D1F6E94A5
alias: pci:v00008086d000008B3sv*sd00008470bc*sc*i*
alias: pci:v00008086d000008B4sv*sd00008270bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00008062bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00008060bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00008170bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00008070bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00000470bc*sc*i*
alias: pci:v00008086d000008B4sv*sd00000270bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00000062bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00000060bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00000170bc*sc*i*
alias: pci:v00008086d000008B3sv*sd00000070bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C420bc*sc*i*
alias: pci:v00008086d000008B2sv*sd0000C220bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C020bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C462bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C460bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C470bc*sc*i*
alias: pci:v00008086d000008B2sv*sd0000C262bc*sc*i*
alias: pci:v00008086d000008B2sv*sd0000C260bc*sc*i*
alias: pci:v00008086d000008B2sv*sd0000C270bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C162bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C062bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C160bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C060bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C170bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000C070bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004420bc*sc*i*
alias: pci:v00008086d000008B2sv*sd00004220bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004020bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004A6Cbc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004A6Ebc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004A70bc*sc*i*
alias: pci:v00008086d000008B1sv*sd0000486Ebc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004870bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004462bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004460bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004470bc*sc*i*
alias: pci:v00008086d000008B2sv*sd00004262bc*sc*i*
alias: pci:v00008086d000008B2sv*sd00004260bc*sc*i*
alias: pci:v00008086d000008B2sv*sd00004270bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004162bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004062bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004160bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004060bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004170bc*sc*i*
alias: pci:v00008086d000008B1sv*sd00004070bc*sc*i*
alias: pci:v00008086d00000892sv*sd00000462bc*sc*i*
alias: pci:v00008086d00000893sv*sd00000262bc*sc*i*
alias: pci:v00008086d00000892sv*sd00000062bc*sc*i*
alias: pci:v00008086d00000894sv*sd00000822bc*sc*i*
alias: pci:v00008086d00000894sv*sd00000422bc*sc*i*
alias: pci:v00008086d00000895sv*sd00000222bc*sc*i*
alias: pci:v00008086d00000894sv*sd00000022bc*sc*i*
alias: pci:v00008086d0000088Fsv*sd00005260bc*sc*i*
alias: pci:v00008086d0000088Esv*sd00004860bc*sc*i*
alias: pci:v00008086d0000088Esv*sd00004460bc*sc*i*
alias: pci:v00008086d0000088Fsv*sd00004260bc*sc*i*
alias: pci:v00008086d0000088Esv*sd00004060bc*sc*i*
alias: pci:v00008086d00000887sv*sd00004462bc*sc*i*
alias: pci:v00008086d00000888sv*sd00004262bc*sc*i*
alias: pci:v00008086d00000887sv*sd00004062bc*sc*i*
alias: pci:v00008086d00000890sv*sd00004822bc*sc*i*
alias: pci:v00008086d00000890sv*sd00004422bc*sc*i*
alias: pci:v00008086d00000891sv*sd00004222bc*sc*i*
alias: pci:v00008086d00000890sv*sd00004022bc*sc*i*
alias: pci:v00008086d00000896sv*sd00005027bc*sc*i*
alias: pci:v00008086d00000896sv*sd00005025bc*sc*i*
alias: pci:v00008086d00000897sv*sd00005017bc*sc*i*
alias: pci:v00008086d00000897sv*sd00005015bc*sc*i*
alias: pci:v00008086d00000896sv*sd00005007bc*sc*i*
alias: pci:v00008086d00000896sv*sd00005005bc*sc*i*
alias: pci:v00008086d000008AEsv*sd00001027bc*sc*i*
alias: pci:v00008086d000008AEsv*sd00001025bc*sc*i*
alias: pci:v00008086d000008AFsv*sd00001017bc*sc*i*
alias: pci:v00008086d000008AFsv*sd00001015bc*sc*i*
alias: pci:v00008086d000008AEsv*sd00001007bc*sc*i*
alias: pci:v00008086d000008AEsv*sd00001005bc*sc*i*
alias: pci:v00008086d00000084sv*sd00001316bc*sc*i*
alias: pci:v00008086d00000084sv*sd00001216bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001326bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001226bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001306bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001206bc*sc*i*
alias: pci:v00008086d00000084sv*sd00001315bc*sc*i*
alias: pci:v00008086d00000084sv*sd00001215bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001325bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001225bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001305bc*sc*i*
alias: pci:v00008086d00000083sv*sd00001205bc*sc*i*
alias: pci:v00008086d00000886sv*sd00001317bc*sc*i*
alias: pci:v00008086d00000886sv*sd00001315bc*sc*i*
alias: pci:v00008086d00000885sv*sd00001327bc*sc*i*
alias: pci:v00008086d00000885sv*sd00001325bc*sc*i*
alias: pci:v00008086d00000885sv*sd00001307bc*sc*i*
alias: pci:v00008086d00000885sv*sd00001305bc*sc*i*
alias: pci:v00008086d00000089sv*sd00001316bc*sc*i*
alias: pci:v00008086d00000089sv*sd00001311bc*sc*i*
alias: pci:v00008086d00000087sv*sd00001326bc*sc*i*
alias: pci:v00008086d00000087sv*sd00001321bc*sc*i*
alias: pci:v00008086d00000087sv*sd00001306bc*sc*i*
alias: pci:v00008086d00000087sv*sd00001301bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005226bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005225bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005221bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005207bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005206bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005205bc*sc*i*
alias: pci:v00008086d00000091sv*sd00005201bc*sc*i*
alias: pci:v00008086d00000090sv*sd00005216bc*sc*i*
alias: pci:v00008086d00000090sv*sd00005215bc*sc*i*
alias: pci:v00008086d00000090sv*sd00005211bc*sc*i*
alias: pci:v00008086d0000008Bsv*sd00005317bc*sc*i*
alias: pci:v00008086d0000008Bsv*sd00005315bc*sc*i*
alias: pci:v00008086d0000008Asv*sd00005327bc*sc*i*
alias: pci:v00008086d0000008Asv*sd00005325bc*sc*i*
alias: pci:v00008086d0000008Asv*sd00005307bc*sc*i*
alias: pci:v00008086d0000008Asv*sd00005305bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001305bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001304bc*sc*i*
alias: pci:v00008086d00000082sv*sd00004820bc*sc*i*
alias: pci:v00008086d00000085sv*sd0000C220bc*sc*i*
alias: pci:v00008086d00000082sv*sd0000C020bc*sc*i*
alias: pci:v00008086d00000085sv*sd00001316bc*sc*i*
alias: pci:v00008086d00000085sv*sd00001311bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001326bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001321bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001307bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001306bc*sc*i*
alias: pci:v00008086d00000082sv*sd00001301bc*sc*i*
alias: pci:v00008086d00004239sv*sd00001316bc*sc*i*
alias: pci:v00008086d00004239sv*sd00001311bc*sc*i*
alias: pci:v00008086d00004238sv*sd00001111bc*sc*i*
alias: pci:v00008086d0000422Csv*sd00001326bc*sc*i*
alias: pci:v00008086d0000422Csv*sd00001321bc*sc*i*
alias: pci:v00008086d0000422Csv*sd00001307bc*sc*i*
alias: pci:v00008086d0000422Csv*sd00001306bc*sc*i*
alias: pci:v00008086d0000422Csv*sd00001301bc*sc*i*
alias: pci:v00008086d0000422Bsv*sd00001121bc*sc*i*
alias: pci:v00008086d0000422Bsv*sd00001101bc*sc*i*
alias: pci:v00008086d0000423Dsv*sd00001316bc*sc*i*
alias: pci:v00008086d0000423Dsv*sd00001216bc*sc*i*
alias: pci:v00008086d0000423Dsv*sd00001311bc*sc*i*
alias: pci:v00008086d0000423Dsv*sd00001211bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001326bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001321bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001221bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001306bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001206bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001301bc*sc*i*
alias: pci:v00008086d0000423Csv*sd00001201bc*sc*i*
alias: pci:v00008086d0000423Bsv*sd00001011bc*sc*i*
alias: pci:v00008086d0000423Asv*sd00001021bc*sc*i*
alias: pci:v00008086d0000423Asv*sd00001001bc*sc*i*
alias: pci:v00008086d00004236sv*sd00001114bc*sc*i*
alias: pci:v00008086d00004236sv*sd00001014bc*sc*i*
alias: pci:v00008086d00004236sv*sd00001111bc*sc*i*
alias: pci:v00008086d00004236sv*sd00001011bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001104bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001004bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001101bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001001bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001124bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001024bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001121bc*sc*i*
alias: pci:v00008086d00004235sv*sd00001021bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001316bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001216bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001315bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001215bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001314bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001214bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001311bc*sc*i*
alias: pci:v00008086d00004237sv*sd00001211bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001326bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001226bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001325bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001225bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001324bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001224bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001321bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001221bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001306bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001206bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001305bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001205bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001304bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001204bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001301bc*sc*i*
alias: pci:v00008086d00004232sv*sd00001201bc*sc*i*
depends: cfg80211
intree: Y
vermagic: 3.11.0-14-generic SMP mod_unload modversions
parm: swcrypto:using crypto in software (default 0 [hardware]) (int)
parm: 11n_disable:disable 11n functionality, bitmap: 1: full, 2: agg TX, 4: agg RX (uint)
parm: amsdu_size_8K:enable 8K amsdu size (default 0) (int)
parm: fw_restart:restart firmware in case of error (default true) (bool)
parm: antenna_coupling:specify antenna coupling in dB (defualt: 0 dB) (int)
parm: wd_disable:Disable stuck queue watchdog timer 0=system default, 1=disable, 2=enable (default: 0) (int)
parm: nvm_file:NVM file name (charp)
parm: bt_coex_active:enable wifi/bt co-exist (default: enable) (bool)
parm: led_mode:0=system default, 1=On(RF On)/Off(RF Off), 2=blinking, 3=Off (default: 0) (int)
parm: power_save:enable WiFi power management (default: disable) (bool)
parm: power_level:default power save level (range from 1 - 5, default: 1) (int)
Photo of Nick Lowe

Nick Lowe, Official Rep

  • 2491 Posts
  • 451 Reply Likes
Have you read:

https://community.aerohive.com/aerohi...

Specifically, Matthew Gast's comment:

"According to the client monitor log, the AP is sending the first frame in the 4WHS but is not getting a response.

The AP RSN IE has the following data: 30 16 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00 00 00. (For those of you following along at home, search on the text "WPA: set AP RSN IE" to located it in the wpa_supplicant trace) That looks like it's set to use WEP40 as the group cipher with PSK authentication, which is an odd combo to say the least.

It looks like wpa_supplicant might be ignoring the AP RSN IE and choosing its own security. With a mismatch like that, it wouldn't respond to the first frame in the 4WHS and that would explain the behavior we're seeing."
Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
I have read that, in fact it was one of the first threads I read when I found out about the issue. Here's what's confusing about that in this instance:

The reassociation frame has the following RSN info:



The client shows the following:

WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 01
wlan1: WPA: Sending EAPOL-Key 2/4
WPA: KCK - hexdump(len=16): [REMOVED]
WPA: Derived Key MIC - hexdump(len=16): e6 aa 31 f3 5a 32 b8 a4 04 a1 6a 42 a0 b3 e9 77
WPA: TX EAPOL-Key - hexdump(len=121): (omitted)

If I'm reading it correctly, it's showing that the RSN IE info that's created for 4WHS 2/4 matches and that the frame is actually sent from wpa_supplicant's perspective. Let me know if this is an incorrect interpretation of the logs.

In other news, I'm in conversations with the Linux wireless dev group for the iwlwifi driver in order to get their input on this, per Roberto's suggestion. They seem to agree it's a driver bug, but are looking for a driver trace to comb through. I have yet to receive that from the user. But I'll update this thread when i found out more.
Photo of plengnom

plengnom

  • 1 Post
  • 0 Reply Likes
Any update here? I'm having similar issues with two linux clients (Lenovo T431s w/Arch and HP 2540p w/Ubuntu) - and a Ricoh printer (!). This is with AP330s. The clients has no problems with other non-aerohive APs (that I've tried atleast).

Often these clients don't connect at all, just keep asking for the key. The weird thing is that what always works is to change the radio profile. Then it works, but some time later it fails again. Change back to the profile that didnt work before - and it works again..


Photo of Steven Bateman

Steven Bateman

  • 65 Posts
  • 12 Reply Likes
I was referencing this thread for a colleague and saw that I never updated it! Sorry...

The issue was a supplicant issue, and was resolved by updating Ubuntu from 13.10 to 14.04.