NetworkManager not listing access points

NetworkManager not listing access points

[Detlev Casanova]

Hello,

After a bisection on the kernel, it seems that a patch is causing a 
problem with NetworkManager: 

commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 ("cfg80211: 
use DS or HT operation IEs to determine BSS channel")

The Wifi access points are not listed in the KDE plasma widget and it 
won't even connect to the saved ones even if they are in range.

There is a fix though: running "iwlist wlan0 scan" twice as root (which 
properly lists APs in reach) and the second time must be run about two 
seconds after the first time.

Then NetworkManager lists the access points and connects to the 
prefered one if possible (normal behavior).

This also happens with nm-applet in Gnome.

The hardware is: 14e4:4315 (Network controller: Broadcom Corporation 
BCM4312 802.11b/g LP-PHY (rev 01)) on an Intel Core i3 M370 CPU (64 
bits) computer.

The abnormal behaviour is not random, it happens every time.

Detlev Casanova

Re: NetworkManager not listing access points

[Dan Williams]

On Wed, 2013-09-18 at 22:47 +0200, Detlev Casanova wrote:
> Hello,
> 
> After a bisection on the kernel, it seems that a patch is causing a 
> problem with NetworkManager: 
> 
> commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 ("cfg80211: 
> use DS or HT operation IEs to determine BSS channel")
> 
> The Wifi access points are not listed in the KDE plasma widget and it 
> won't even connect to the saved ones even if they are in range.
> 
> There is a fix though: running "iwlist wlan0 scan" twice as root (which 
> properly lists APs in reach) and the second time must be run about two 
> seconds after the first time.
> 
> Then NetworkManager lists the access points and connects to the 
> prefered one if possible (normal behavior).
> 
> This also happens with nm-applet in Gnome.
> 
> The hardware is: 14e4:4315 (Network controller: Broadcom Corporation 
> BCM4312 802.11b/g LP-PHY (rev 01)) on an Intel Core i3 M370 CPU (64 
> bits) computer.
> 
> The abnormal behaviour is not random, it happens every time.

Can you run wpa_supplicant with debugging output?  The quick and dirty
way is to:

mv /usr/sbin/wpa_supplicant /
killall -TERM wpa_supplicant
/wpa_supplicant -dddtu

and then wait for the problem to happen, and grab the log output for us
to analyze.

Dan

Re: NetworkManager not listing access points

[Detlev Casanova]

[-- Attachment #1: Type: text/plain, Size: 1512 bytes --]

Le mercredi 18 septembre 2013 23:16:08 Dan Williams a écrit :
> On Wed, 2013-09-18 at 22:47 +0200, Detlev Casanova wrote:
> > Hello,
> > 
> > After a bisection on the kernel, it seems that a patch is causing 
a
> > problem with NetworkManager:
> > 
> > commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 
("cfg80211:
> > use DS or HT operation IEs to determine BSS channel")
> > 
> > The Wifi access points are not listed in the KDE plasma widget 
and it
> > won't even connect to the saved ones even if they are in range.
> > 
> > There is a fix though: running "iwlist wlan0 scan" twice as root 
(which
> > properly lists APs in reach) and the second time must be run 
about two
> > seconds after the first time.
> > 
> > Then NetworkManager lists the access points and connects to 
the
> > prefered one if possible (normal behavior).
> > 
> > This also happens with nm-applet in Gnome.
> > 
> > The hardware is: 14e4:4315 (Network controller: Broadcom 
Corporation
> > BCM4312 802.11b/g LP-PHY (rev 01)) on an Intel Core i3 M370 
CPU (64
> > bits) computer.
> > 
> > The abnormal behaviour is not random, it happens every time.
> 
> Can you run wpa_supplicant with debugging output?  The quick 
and dirty
> way is to:
> 
> mv /usr/sbin/wpa_supplicant /
> killall -TERM wpa_supplicant
> /wpa_supplicant -dddtu
> 
> and then wait for the problem to happen, and grab the log output 
for us
> to analyze.
> 
> Dan

Here is the output (attached file for formatting)

[-- Attachment #2: output --]
[-- Type: text/plain, Size: 25412 bytes --]

1379569812.462808: dbus: Register D-Bus object '/fi/w1/wpa_supplicant1'
1379569812.463387: Providing DBus service 'fi.w1.wpa_supplicant1'.
1379569812.463961: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.
1379569812.464204: dbus: fi.w1.wpa_supplicant1.CreateInterface (/fi/w1/wpa_supplicant1)
1379569812.464274: Initializing interface 'wlan0' conf 'N/A' driver 'nl80211,wext' ctrl_interface 'N/A' bridge 'N/A'
1379569812.465509: netlink: Operstate: linkmode=1, operstate=5
1379569812.473709: Own MAC address: 00:16:44:f1:d3:07
1379569812.473746: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=0 set_tx=0 seq_len=0 key_len=0
1379569812.473803: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=1 set_tx=0 seq_len=0 key_len=0
1379569812.473840: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=2 set_tx=0 seq_len=0 key_len=0
1379569812.473872: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=3 set_tx=0 seq_len=0 key_len=0
1379569812.473889: RSN: flushing PMKID list in the driver
1379569812.473894: State: DISCONNECTED -> INACTIVE
1379569812.477830: EAPOL: SUPP_PAE entering state DISCONNECTED
1379569812.477840: EAPOL: Supplicant port status: Unauthorized
1379569812.477876: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1379569812.477881: EAPOL: SUPP_BE entering state INITIALIZE
1379569812.477884: EAP: EAP entering state DISABLED
1379569812.477887: EAPOL: Supplicant port status: Unauthorized
1379569812.477903: EAPOL: Supplicant port status: Unauthorized
1379569812.477929: dbus: Register interface object '/fi/w1/wpa_supplicant1/Interfaces/1'
1379569812.478202: Added interface wlan0
1379569812.478284: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1)
1379569812.479406: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.479828: dbus: fi.w1.wpa_supplicant1.Interface.NetworkReply (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.479848: no method handler for fi.w1.wpa_supplicant1.Interface.NetworkReply on /fi/w1/wpa_supplicant1/Interfaces/1
1379569812.479985: dbus: org.freedesktop.DBus.Introspectable.Introspect (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.480838: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.482196: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.482692: Scan requested (ret=0) - scan timeout 10 seconds
1379569812.482872: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569812.482915: nl80211: Scan trigger failed: ret=-16 (Device or resource busy)
1379569812.483555: nl80211: Event message available
1379569812.483581: nl80211: Scan trigger
1379569813.478983: EAPOL: disable timer tick
1379569813.479019: EAPOL: Supplicant port status: Unauthorized
1379569814.163044: nl80211: Event message available
1379569814.163106: nl80211: New scan results available
1379569814.163159: Received scan results (0 BSSes)
1379569814.163173: BSS: Start scan result update 1
1379569814.163178: New scan results available
1379569814.163450: No suitable network found
1379569814.163457: State: INACTIVE -> INACTIVE
1379569814.163471: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569814.163480: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569835.357239: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569835.357744: Scan requested (ret=0) - scan timeout 30 seconds
1379569835.357880: nl80211: Event message available
1379569835.357914: nl80211: Scan trigger
1379569837.039966: nl80211: Event message available
1379569837.040031: nl80211: New scan results available
1379569837.040140: Received scan results (0 BSSes)
1379569837.040149: BSS: Start scan result update 2
1379569837.040154: New scan results available
1379569837.040186: No suitable network found
1379569837.040193: State: INACTIVE -> INACTIVE
1379569837.040409: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569837.040426: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569837.045232: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569868.358662: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569868.359106: Scan requested (ret=0) - scan timeout 30 seconds
1379569868.359206: nl80211: Event message available
1379569868.359224: nl80211: Scan trigger
1379569870.038738: nl80211: Event message available
1379569870.038808: nl80211: New scan results available
1379569870.038915: Received scan results (0 BSSes)
1379569870.038925: BSS: Start scan result update 3
1379569870.038928: New scan results available
1379569870.038947: No suitable network found
1379569870.038953: State: INACTIVE -> INACTIVE
1379569870.038964: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569870.038969: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569870.044029: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569883.691230: nl80211: Event message available
1379569883.691292: nl80211: Scan trigger
1379569884.810881: nl80211: Event message available
1379569884.810949: nl80211: New scan results available
1379569884.810989: Received scan results (0 BSSes)
1379569884.810996: BSS: Start scan result update 4
1379569884.811000: New scan results available
1379569884.811064: No suitable network found
1379569884.811070: State: INACTIVE -> INACTIVE
1379569884.811381: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569884.811393: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569889.035023: nl80211: Event message available
1379569889.035086: nl80211: Scan trigger
1379569890.153956: nl80211: Event message available
1379569890.154007: nl80211: New scan results available
1379569890.154073: Received scan results (2 BSSes)
1379569890.154082: BSS: Start scan result update 5
1379569890.154087: BSS: Add new id 0 BSSID 78:54:2e:a6:e3:80 SSID 'Maison'
1379569890.154096: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0'
1379569890.154310: BSS: Add new id 1 BSSID 9c:d3:6d:98:2a:7c SSID 'VOO-264889'
1379569890.154317: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1'
1379569890.154450: New scan results available
1379569890.154477: No suitable network found
1379569890.154483: State: INACTIVE -> INACTIVE
1379569890.154498: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569890.154505: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569890.159375: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569890.358936: dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569890.360391: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569890.360437: dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1379569890.360557: scan_ssid=1 (0x1)
1379569890.360569: ssid - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379569890.360584: key_mgmt: 0x2
1379569890.360594: PSK (ASCII passphrase) - hexdump_ascii(len=10): [REMOVED]
1379569890.372592: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1379569890.373053: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
1379569890.373104: Setting scan request: 0 sec 0 usec
1379569890.373198: State: INACTIVE -> SCANNING
1379569890.373240: Scan SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379569890.373264: Starting AP scan for wildcard SSID
1379569890.373306: nl80211: Scan SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379569890.373340: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1379569890.374211: Scan requested (ret=0) - scan timeout 30 seconds
1379569890.374231: nl80211: Event message available
1379569890.374252: nl80211: Scan trigger
1379569890.378304: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569891.493950: nl80211: Event message available
1379569891.494003: nl80211: New scan results available
1379569891.494124: Received scan results (2 BSSes)
1379569891.494133: BSS: Start scan result update 6
1379569891.494150: New scan results available
1379569891.494170: Selecting BSS from priority group 0
1379569891.494173: Try to find WPA-enabled AP
1379569891.494176: 0: 78:54:2e:a6:e3:80 ssid='Maison' wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1379569891.494182:    selected based on RSN IE
1379569891.494184:    selected WPA AP 78:54:2e:a6:e3:80 ssid='Maison'
1379569891.494190: Automatic auth_alg selection: 0x1
1379569891.494195: RSN: using IEEE 802.11i/D9.0
1379569891.494198: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
1379569891.494201: WPA: set AP WPA IE - hexdump(len=28): dd 1a 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 02 00 50 f2 04 01 00 00 50 f2 02
1379569891.494209: WPA: set AP RSN IE - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.494216: WPA: using GTK TKIP
1379569891.494218: WPA: using PTK CCMP
1379569891.494220: WPA: using KEY_MGMT WPA-PSK
1379569891.494223: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.494230: Cancelling scan request
1379569891.494233: Trying to authenticate with 78:54:2e:a6:e3:80 (SSID='Maison' freq=2447 MHz)
1379569891.494236: No keys have been configured - skip key clearing
1379569891.494239: State: SCANNING -> AUTHENTICATING
1379569891.494259: EAPOL: External notification - EAP success=0
1379569891.494264: EAPOL: Supplicant port status: Unauthorized
1379569891.494309: EAPOL: External notification - EAP fail=0
1379569891.494312: EAPOL: Supplicant port status: Unauthorized
1379569891.494327: EAPOL: External notification - portControl=Auto
1379569891.494330: EAPOL: Supplicant port status: Unauthorized
1379569891.494353: nl80211: Authenticate (ifindex=6)
1379569891.494357:   * bssid=78:54:2e:a6:e3:80
1379569891.494360:   * freq=2447
1379569891.494362:   * SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379569891.494368:   * IEs - hexdump(len=0): [NULL]
1379569891.494370:   * Auth Type 0
1379569891.503619: nl80211: Authentication request send successfully
1379569891.503677: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569891.503763: nl80211: Event message available
1379569891.503778: nl80211: Ignored unknown event (cmd=19)
1379569891.503786: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379569891.503792: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569891.503800: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
1379569891.503829: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
1379569891.505465: nl80211: Event message available
1379569891.505482: nl80211: MLME event 37
1379569891.505485: nl80211: MLME event frame - hexdump(len=30): b0 00 3a 01 00 16 44 f1 d3 07 78 54 2e a6 e3 80 78 54 2e a6 e3 80 50 a1 00 00 02 00 00 00
1379569891.505494: SME: Authentication response: peer=78:54:2e:a6:e3:80 auth_type=0 status_code=0
1379569891.505497: SME: Authentication response IEs - hexdump(len=0): [NULL]
1379569891.505502: Trying to associate with 78:54:2e:a6:e3:80 (SSID='Maison' freq=2447 MHz)
1379569891.505505: State: AUTHENTICATING -> ASSOCIATING
1379569891.505507: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1379569891.505511: netlink: Operstate: linkmode=-1, operstate=5
1379569891.505548: WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.505561: nl80211: Associate (ifindex=6)
1379569891.505567:   * bssid=78:54:2e:a6:e3:80
1379569891.505571:   * freq=2447
1379569891.505574:   * SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379569891.505583:   * IEs - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.505611: nl80211: Association request send successfully
1379569891.510618: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569891.512395: RX EAPOL from 78:54:2e:a6:e3:80
1379569891.512418: RX EAPOL - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.512515: Not associated - Delay processing of received EAPOL frame
1379569891.512541: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379569891.512546: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569891.512684: nl80211: Event message available
1379569891.512913: nl80211: MLME event 38
1379569891.512918: nl80211: MLME event frame - hexdump(len=106): 10 00 3a 01 00 16 44 f1 d3 07 78 54 2e a6 e3 80 78 54 2e a6 e3 80 60 a1 31 04 00 00 03 c0 01 08 82 84 8b 96 0c 12 18 24 32 04 30 48 60 6c dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 01 20 dd 06 00 e0 4c 02 01 60
1379569891.512949: Association info event
1379569891.512952: resp_ies - hexdump(len=76): 01 08 82 84 8b 96 0c 12 18 24 32 04 30 48 60 6c dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 01 20 dd 06 00 e0 4c 02 01 60
1379569891.512986: freq=2447 MHz
1379569891.512998: State: ASSOCIATING -> ASSOCIATED
1379569891.513008: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1379569891.513018: netlink: Operstate: linkmode=-1, operstate=5
1379569891.513137: Associated to a new BSS: BSSID=78:54:2e:a6:e3:80
1379569891.513159: No keys have been configured - skip key clearing
1379569891.513173: Associated with 78:54:2e:a6:e3:80
1379569891.513181: WPA: Association event - clear replay counter
1379569891.513198: WPA: Clear old PTK
1379569891.513207: EAPOL: External notification - portEnabled=0
1379569891.513215: EAPOL: Supplicant port status: Unauthorized
1379569891.513309: EAPOL: External notification - portValid=0
1379569891.513323: EAPOL: Supplicant port status: Unauthorized
1379569891.513381: EAPOL: External notification - EAP success=0
1379569891.513394: EAPOL: Supplicant port status: Unauthorized
1379569891.513437: EAPOL: External notification - portEnabled=1
1379569891.513445: EAPOL: SUPP_PAE entering state CONNECTING
1379569891.513450: EAPOL: enable timer tick
1379569891.513456: EAPOL: SUPP_BE entering state IDLE
1379569891.513464: Setting authentication timeout: 10 sec 0 usec
1379569891.513471: Cancelling scan request
1379569891.513477: Process pending EAPOL frame that was received just before association notification
1379569891.513482: RX EAPOL from 78:54:2e:a6:e3:80
1379569891.513488: RX EAPOL - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513543: Setting authentication timeout: 10 sec 0 usec
1379569891.513551: IEEE 802.1X RX: version=1 type=3 length=117
1379569891.513557:   EAPOL-Key type=2
1379569891.513562:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1379569891.513569:   key_length=16 key_data_length=22
1379569891.513575:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1379569891.513583:   key_nonce - hexdump(len=32): 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0
1379569891.513600:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513611:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1379569891.513620:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1379569891.513628:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513687: WPA: RX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513763: State: ASSOCIATED -> 4WAY_HANDSHAKE
1379569891.513818: WPA: RX message 1 of 4-Way Handshake from 78:54:2e:a6:e3:80 (ver=2)
1379569891.513824: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513834: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513844: RSN: PMKID from Authenticator - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379569891.513852: RSN: no matching PMKID found
1379569891.514277: WPA: Renewed SNonce - hexdump(len=32): 9b 1d 73 09 5a c7 3a 2c b3 91 4d 52 d1 02 08 4b d0 ad da 74 b0 0c 76 f6 3c 1f dc b2 7b 50 29 c1
1379569891.514303: WPA: PTK derivation - A1=00:16:44:f1:d3:07 A2=78:54:2e:a6:e3:80
1379569891.514307: WPA: PMK - hexdump(len=32): [REMOVED]
1379569891.514309: WPA: PTK - hexdump(len=48): [REMOVED]
1379569891.514313: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.514321: WPA: Sending EAPOL-Key 2/4
1379569891.514326: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 9b 1d 73 09 5a c7 3a 2c b3 91 4d 52 d1 02 08 4b d0 ad da 74 b0 0c 76 f6 3c 1f dc b2 7b 50 29 c1 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 b2 27 2b b9 d1 57 b8 ca 94 d0 00 47 ad b5 3d 08 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.514373: nl80211: Event message available
1379569891.514577: nl80211: Ignore connect event (cmd=46) when using userspace SME
1379569891.514583: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379569891.514587: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569891.514591: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379569891.514593: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569891.518190: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569891.518547: RX EAPOL from 78:54:2e:a6:e3:80
1379569891.518568: RX EAPOL - hexdump(len=179): 01 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 13 62 07 00 00 00 00 00 00 00 00 00 00 00 00 00 b8 d4 c6 fa 60 3e c7 57 bb 19 33 00 4e 6b 1a 9d 00 50 9d 0f 44 b0 9e 21 3b f3 3f 17 32 3d 92 45 cd 84 b3 56 07 af d1 81 44 22 8e d4 1d fc 16 cb a3 a3 0b 24 7c 04 95 f7 b7 c4 54 0e 56 6a 31 d6 61 c3 2d 56 84 04 a8 99 78 07 22 0e 4a 61 7f a1 6b 3d 19 c8 7d 22 de 5d 96 e9 93 be 90 ce 66 9c d6 02
1379569891.518677: IEEE 802.1X RX: version=1 type=3 length=175
1379569891.518682:   EAPOL-Key type=2
1379569891.518685:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1379569891.518690:   key_length=16 key_data_length=80
1379569891.518693:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
1379569891.518698:   key_nonce - hexdump(len=32): 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0
1379569891.518705:   key_iv - hexdump(len=16): 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e
1379569891.518709:   key_rsc - hexdump(len=8): 13 62 07 00 00 00 00 00
1379569891.518712:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1379569891.518715:   key_mic - hexdump(len=16): b8 d4 c6 fa 60 3e c7 57 bb 19 33 00 4e 6b 1a 9d
1379569891.518721: WPA: RX EAPOL-Key - hexdump(len=179): 01 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 0e c5 26 3f 76 43 50 d8 90 d4 06 b4 df fa d1 a0 38 95 71 ca a5 53 62 64 60 94 a9 0a 02 fe 5b 0e 13 62 07 00 00 00 00 00 00 00 00 00 00 00 00 00 b8 d4 c6 fa 60 3e c7 57 bb 19 33 00 4e 6b 1a 9d 00 50 9d 0f 44 b0 9e 21 3b f3 3f 17 32 3d 92 45 cd 84 b3 56 07 af d1 81 44 22 8e d4 1d fc 16 cb a3 a3 0b 24 7c 04 95 f7 b7 c4 54 0e 56 6a 31 d6 61 c3 2d 56 84 04 a8 99 78 07 22 0e 4a 61 7f a1 6b 3d 19 c8 7d 22 de 5d 96 e9 93 be 90 ce 66 9c d6 02
1379569891.518768: RSN: encrypted key data - hexdump(len=80): 9d 0f 44 b0 9e 21 3b f3 3f 17 32 3d 92 45 cd 84 b3 56 07 af d1 81 44 22 8e d4 1d fc 16 cb a3 a3 0b 24 7c 04 95 f7 b7 c4 54 0e 56 6a 31 d6 61 c3 2d 56 84 04 a8 99 78 07 22 0e 4a 61 7f a1 6b 3d 19 c8 7d 22 de 5d 96 e9 93 be 90 ce 66 9c d6 02
1379569891.518825: WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
1379569891.518830: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1379569891.518832: WPA: RX message 3 of 4-Way Handshake from 78:54:2e:a6:e3:80 (ver=2)
1379569891.518835: WPA: IE KeyData - hexdump(len=72): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 26 00 0f ac 01 01 00 e7 67 6b e9 f6 cd 28 01 26 73 14 61 45 d8 db 44 90 79 47 6b 3c df f4 85 55 4a 5e 5b 87 37 69 8b dd 00 00 00 00 00
1379569891.518848: WPA: RSN IE in EAPOL-Key - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00
1379569891.518855: WPA: GTK in EAPOL-Key - hexdump(len=40): [REMOVED]
1379569891.518858: WPA: Sending EAPOL-Key 4/4
1379569891.518863: 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 da 41 37 9d fa e7 2a 6c 88 9d 37 e1 e5 fd b2 d3 00 00
1379569891.518890: WPA: Installing PTK to the driver.
1379569891.518916: wpa_driver_nl80211_set_key: ifindex=6 alg=3 addr=0xbcec60 key_idx=0 set_tx=1 seq_len=6 key_len=16
1379569891.518924:    addr=78:54:2e:a6:e3:80
1379569891.519171: EAPOL: External notification - portValid=1
1379569891.519180: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1379569891.519219: RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
1379569891.519226: WPA: Group Key - hexdump(len=32): [REMOVED]
1379569891.519229: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32).
1379569891.519233: WPA: RSC - hexdump(len=6): 13 62 07 00 00 00
1379569891.519247: wpa_driver_nl80211_set_key: ifindex=6 alg=2 addr=0x45ca89 key_idx=1 set_tx=0 seq_len=6 key_len=32
1379569891.519272: WPA: Key negotiation completed with 78:54:2e:a6:e3:80 [PTK=CCMP GTK=TKIP]
1379569891.519278: Cancelling authentication timeout
1379569891.519282: State: GROUP_HANDSHAKE -> COMPLETED
1379569891.519287: CTRL-EVENT-CONNECTED - Connection to 78:54:2e:a6:e3:80 completed (auth) [id=0 id_str=]
1379569891.519291: wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)
1379569891.519295: netlink: Operstate: linkmode=-1, operstate=6
1379569891.519355: EAPOL: External notification - portValid=1
1379569891.519361: EAPOL: External notification - EAP success=1
1379569891.519365: EAPOL: SUPP_PAE entering state AUTHENTICATING
1379569891.519368: EAPOL: SUPP_BE entering state SUCCESS
1379569891.519371: EAP: EAP entering state DISABLED
1379569891.519374: EAPOL: SUPP_PAE entering state AUTHENTICATED
1379569891.519377: EAPOL: Supplicant port status: Authorized
1379569891.519406: EAPOL: SUPP_BE entering state IDLE
1379569891.519411: EAPOL authentication completed successfully
1379569891.519421: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1379569891.519427: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379569891.524282: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379569893.049791: nl80211: Event message available
1379569894.059793: nl80211: Event message available
1379569894.515643: EAPOL: startWhen --> 0
1379569894.515671: EAPOL: disable timer tick
1379569895.059803: nl80211: Event message available
1379569896.049785: nl80211: Event message available
1379569897.059991: nl80211: Event message available
1379569898.059787: nl80211: Event message available
1379569899.059786: nl80211: Event message available
1379569900.049789: nl80211: Event message available
1379569901.059764: nl80211: Event message available
1379569902.053868: nl80211: Event message available

Re: NetworkManager not listing access points

[Johannes Berg]

On Thu, 2013-09-19 at 07:58 +0200, Detlev Casanova wrote:

> Here is the output (attached file for formatting)

Was that from the good case? The bad case would have been more
interesting.

johannes

Re: NetworkManager not listing access points

[Detlev Casanova]

[-- Attachment #1: Type: text/plain, Size: 998 bytes --]

Le samedi 21 septembre 2013 22:51:59 Johannes Berg a écrit :
> On Thu, 2013-09-19 at 07:58 +0200, Detlev Casanova wrote:
> > Here is the output (attached file for formatting)
> 
> Was that from the good case? The bad case would have been 
more
> interesting.

This is both cases. I made another one and here, I can give more 
details:

Network manager is trying to list APs and fails until time 
1379858724.386569
The The first "iwlist wlan0 scan" is done juste after the log line 
(1379858738.682054). It lists the APs in range in the console but 
not in the Network Manager ui.

The second "iwlist wlan0 scan" is done at time 1379858739.802067 
and APs are being listed in the console and in the Network Manager 
UI.

After that, NM will connect to the acces point with SSID "Maison".

It also looks like the listing in Network Manager comes between the 
moment "iwlist wlan0 scan" is run for the second time and the 
moment is shows its output on the console.

Detlev.

[-- Attachment #2: output --]
[-- Type: text/plain, Size: 29537 bytes --]

1379858664.668605: dbus: Register D-Bus object '/fi/w1/wpa_supplicant1'                                                                                                                                              
1379858664.668901: Providing DBus service 'fi.w1.wpa_supplicant1'.                                                                                                                                                   
1379858664.669460: Providing DBus service 'fi.epitest.hostap.WPASupplicant'.                                                                                                                                         
1379858664.669902: dbus: fi.w1.wpa_supplicant1.CreateInterface (/fi/w1/wpa_supplicant1)                                                                                                                              
1379858664.669941: Initializing interface 'wlan0' conf 'N/A' driver 'nl80211,wext' ctrl_interface 'N/A' bridge 'N/A'
1379858666.245151: netlink: Operstate: linkmode=1, operstate=5
1379858666.250112: Own MAC address: 00:16:44:f1:d3:07
1379858666.250272: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=0 set_tx=0 seq_len=0 key_len=0
1379858666.250395: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=1 set_tx=0 seq_len=0 key_len=0
1379858666.250480: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=2 set_tx=0 seq_len=0 key_len=0
1379858666.250566: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=3 set_tx=0 seq_len=0 key_len=0
1379858666.250654: RSN: flushing PMKID list in the driver
1379858666.250683: State: DISCONNECTED -> INACTIVE
1379858666.255458: EAPOL: SUPP_PAE entering state DISCONNECTED
1379858666.255500: EAPOL: Supplicant port status: Unauthorized
1379858666.255607: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
1379858666.255641: EAPOL: SUPP_BE entering state INITIALIZE
1379858666.255685: EAP: EAP entering state DISABLED
1379858666.255712: EAPOL: Supplicant port status: Unauthorized
1379858666.255792: EAPOL: Supplicant port status: Unauthorized
1379858666.255901: dbus: Register interface object '/fi/w1/wpa_supplicant1/Interfaces/1'
1379858666.256308: Added interface wlan0
1379858666.256421: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1)
1379858666.256562: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858666.256583: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858666.257323: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.257579: dbus: fi.w1.wpa_supplicant1.Interface.NetworkReply (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.257600: no method handler for fi.w1.wpa_supplicant1.Interface.NetworkReply on /fi/w1/wpa_supplicant1/Interfaces/1
1379858666.257640: dbus: org.freedesktop.DBus.Introspectable.Introspect (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.258307: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.262958: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.263399: Scan requested (ret=0) - scan timeout 10 seconds
1379858666.263464: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858666.263501: nl80211: Scan trigger failed: ret=-16 (Device or resource busy)
1379858666.263562: nl80211: Event message available
1379858666.263574: nl80211: Scan trigger
1379858667.256109: EAPOL: disable timer tick
1379858667.256144: EAPOL: Supplicant port status: Unauthorized
1379858667.945211: nl80211: Event message available
1379858667.945255: nl80211: New scan results available
1379858667.945300: Received scan results (0 BSSes)
1379858667.945313: BSS: Start scan result update 1
1379858667.945320: New scan results available
1379858667.945386: No suitable network found
1379858667.945393: State: INACTIVE -> INACTIVE
1379858667.945404: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858667.945410: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858689.697832: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858689.698343: Scan requested (ret=0) - scan timeout 30 seconds
1379858689.698479: nl80211: Event message available
1379858689.698514: nl80211: Scan trigger
1379858691.380452: nl80211: Event message available
1379858691.380499: nl80211: New scan results available
1379858691.380809: Received scan results (0 BSSes)
1379858691.380817: BSS: Start scan result update 2
1379858691.380821: New scan results available
1379858691.380844: No suitable network found
1379858691.380849: State: INACTIVE -> INACTIVE
1379858691.380878: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858691.380891: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858691.385848: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858722.696534: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858722.697210: Scan requested (ret=0) - scan timeout 30 seconds
1379858722.697277: nl80211: Event message available
1379858722.697293: nl80211: Scan trigger
1379858724.381370: nl80211: Event message available
1379858724.381434: nl80211: New scan results available
1379858724.381522: Received scan results (0 BSSes)
1379858724.381528: BSS: Start scan result update 3
1379858724.381532: New scan results available
1379858724.381553: No suitable network found
1379858724.381558: State: INACTIVE -> INACTIVE
1379858724.381566: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858724.381571: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858724.386569: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858738.682054: nl80211: Event message available
1379858738.682102: nl80211: Scan trigger
1379858739.801286: nl80211: Event message available
1379858739.801350: nl80211: New scan results available
1379858739.801388: Received scan results (0 BSSes)
1379858739.801393: BSS: Start scan result update 4
1379858739.801397: New scan results available
1379858739.801452: No suitable network found
1379858739.801457: State: INACTIVE -> INACTIVE
1379858739.802055: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858739.802067: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858745.833897: nl80211: Event message available
1379858745.833942: nl80211: Scan trigger
1379858746.953796: nl80211: Event message available
1379858746.953847: nl80211: New scan results available
1379858746.953924: Received scan results (3 BSSes)
1379858746.953934: BSS: Start scan result update 5
1379858746.953940: BSS: Add new id 0 BSSID 78:54:2e:a6:e3:80 SSID 'Maison'
1379858746.953949: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0'
1379858746.954277: BSS: Add new id 1 BSSID 00:19:70:ad:71:6e SSID 'bbox2-ec38'
1379858746.954288: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1'
1379858746.954466: BSS: Add new id 2 BSSID 06:19:70:ad:71:6e SSID 'FON_BELGACOM'
1379858746.954475: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2'
1379858746.954633: New scan results available
1379858746.954661: No suitable network found
1379858746.954667: State: INACTIVE -> INACTIVE
1379858746.955083: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858746.955096: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858746.959338: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858765.699913: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858765.700345: Scan requested (ret=0) - scan timeout 30 seconds
1379858765.700429: nl80211: Event message available
1379858765.700447: nl80211: Scan trigger
1379858767.383335: nl80211: Event message available
1379858767.383419: nl80211: New scan results available
1379858767.383576: Received scan results (4 BSSes)
1379858767.383586: BSS: Start scan result update 6
1379858767.383607: BSS: Add new id 3 BSSID 9c:d3:6d:98:2a:7c SSID 'VOO-264889'
1379858767.383613: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3'
1379858767.383807: New scan results available
1379858767.383829: No suitable network found
1379858767.383833: State: INACTIVE -> INACTIVE
1379858767.383842: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858767.383846: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858767.388587: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858767.388662: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
1379858767.388681: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
1379858768.422358: dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858768.424213: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858768.424256: dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1379858768.424381: scan_ssid=1 (0x1)
1379858768.424394: ssid - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379858768.424410: key_mgmt: 0x2
1379858768.424418: PSK (ASCII passphrase) - hexdump_ascii(len=10): [REMOVED]
1379858768.444880: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1379858768.445480: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
1379858768.445529: Setting scan request: 0 sec 0 usec
1379858768.445910: State: INACTIVE -> SCANNING
1379858768.445986: Scan SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379858768.446012: Starting AP scan for wildcard SSID
1379858768.446086: nl80211: Scan SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379858768.446113: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1379858768.446457: Scan requested (ret=0) - scan timeout 30 seconds
1379858768.446474: nl80211: Event message available
1379858768.446491: nl80211: Scan trigger
1379858768.451057: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858769.565110: nl80211: Event message available
1379858769.565180: nl80211: New scan results available
1379858769.565298: Received scan results (4 BSSes)
1379858769.565308: BSS: Start scan result update 7
1379858769.565315: New scan results available
1379858769.565335: Selecting BSS from priority group 0
1379858769.565338: Try to find WPA-enabled AP
1379858769.565340: 0: 78:54:2e:a6:e3:80 ssid='Maison' wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1379858769.565346:    selected based on RSN IE
1379858769.565349:    selected WPA AP 78:54:2e:a6:e3:80 ssid='Maison'
1379858769.565354: Automatic auth_alg selection: 0x1
1379858769.565360: RSN: using IEEE 802.11i/D9.0
1379858769.565362: WPA: Selected cipher suites: group 8 pairwise 24 key_mgmt 2 proto 2
1379858769.565365: WPA: set AP WPA IE - hexdump(len=28): dd 1a 00 50 f2 01 01 00 00 50 f2 02 02 00 00 50 f2 02 00 50 f2 04 01 00 00 50 f2 02
1379858769.565373: WPA: set AP RSN IE - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.565380: WPA: using GTK TKIP
1379858769.565382: WPA: using PTK CCMP
1379858769.565384: WPA: using KEY_MGMT WPA-PSK
1379858769.565387: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.565393: Cancelling scan request
1379858769.565396: Trying to authenticate with 78:54:2e:a6:e3:80 (SSID='Maison' freq=2457 MHz)
1379858769.565399: No keys have been configured - skip key clearing
1379858769.565401: State: SCANNING -> AUTHENTICATING
1379858769.565421: EAPOL: External notification - EAP success=0
1379858769.565426: EAPOL: Supplicant port status: Unauthorized
1379858769.565464: EAPOL: External notification - EAP fail=0
1379858769.565467: EAPOL: Supplicant port status: Unauthorized
1379858769.565482: EAPOL: External notification - portControl=Auto
1379858769.565485: EAPOL: Supplicant port status: Unauthorized
1379858769.565508: nl80211: Authenticate (ifindex=6)
1379858769.565512:   * bssid=78:54:2e:a6:e3:80
1379858769.565515:   * freq=2457
1379858769.565517:   * SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379858769.565523:   * IEs - hexdump(len=0): [NULL]
1379858769.565525:   * Auth Type 0
1379858769.574701: nl80211: Authentication request send successfully
1379858769.574736: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858769.574825: nl80211: Event message available
1379858769.574845: nl80211: Ignored unknown event (cmd=19)
1379858769.574855: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1379858769.574861: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858769.576530: nl80211: Event message available
1379858769.576580: nl80211: MLME event 37
1379858769.576593: nl80211: MLME event frame - hexdump(len=30): b0 00 3a 01 00 16 44 f1 d3 07 78 54 2e a6 e3 80 78 54 2e a6 e3 80 30 77 00 00 02 00 00 00
1379858769.576631: SME: Authentication response: peer=78:54:2e:a6:e3:80 auth_type=0 status_code=0
1379858769.576636: SME: Authentication response IEs - hexdump(len=0): [NULL]
1379858769.576644: Trying to associate with 78:54:2e:a6:e3:80 (SSID='Maison' freq=2457 MHz)
1379858769.576648: State: AUTHENTICATING -> ASSOCIATING
1379858769.576652: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1379858769.576657: netlink: Operstate: linkmode=-1, operstate=5
1379858769.576723: WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.576738: nl80211: Associate (ifindex=6)
1379858769.576746:   * bssid=78:54:2e:a6:e3:80
1379858769.576750:   * freq=2457
1379858769.576753:   * SSID - hexdump_ascii(len=6):
     4d 61 69 73 6f 6e                                 Maison          
1379858769.576761:   * IEs - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.576801: nl80211: Association request send successfully
1379858769.581815: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858769.583316: RX EAPOL from 78:54:2e:a6:e3:80
1379858769.583340: RX EAPOL - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.583434: Not associated - Delay processing of received EAPOL frame
1379858769.584422: nl80211: Event message available
1379858769.584455: nl80211: MLME event 38
1379858769.584460: nl80211: MLME event frame - hexdump(len=106): 10 00 3a 01 00 16 44 f1 d3 07 78 54 2e a6 e3 80 78 54 2e a6 e3 80 40 77 31 04 00 00 04 c0 01 08 82 84 8b 96 0c 12 18 24 32 04 30 48 60 6c dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 01 20 dd 06 00 e0 4c 02 01 60
1379858769.584495: Association info event
1379858769.584498: resp_ies - hexdump(len=76): 01 08 82 84 8b 96 0c 12 18 24 32 04 30 48 60 6c dd 18 00 50 f2 02 01 01 80 00 03 a4 00 00 27 a4 00 00 42 43 5e 00 62 32 2f 00 dd 18 00 50 f2 04 10 4a 00 01 10 10 3b 00 01 03 10 49 00 06 00 37 2a 00 01 20 dd 06 00 e0 4c 02 01 60
1379858769.584522: freq=2457 MHz
1379858769.584526: State: ASSOCIATING -> ASSOCIATED
1379858769.584530: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1379858769.584535: netlink: Operstate: linkmode=-1, operstate=5
1379858769.584597: Associated to a new BSS: BSSID=78:54:2e:a6:e3:80
1379858769.584606: No keys have been configured - skip key clearing
1379858769.584613: Associated with 78:54:2e:a6:e3:80
1379858769.584617: WPA: Association event - clear replay counter
1379858769.584625: WPA: Clear old PTK
1379858769.584628: EAPOL: External notification - portEnabled=0
1379858769.584633: EAPOL: Supplicant port status: Unauthorized
1379858769.584689: EAPOL: External notification - portValid=0
1379858769.584695: EAPOL: Supplicant port status: Unauthorized
1379858769.584721: EAPOL: External notification - EAP success=0
1379858769.584726: EAPOL: Supplicant port status: Unauthorized
1379858769.584749: EAPOL: External notification - portEnabled=1
1379858769.584755: EAPOL: SUPP_PAE entering state CONNECTING
1379858769.584758: EAPOL: enable timer tick
1379858769.584762: EAPOL: SUPP_BE entering state IDLE
1379858769.584767: Setting authentication timeout: 10 sec 0 usec
1379858769.584772: Cancelling scan request
1379858769.584775: Process pending EAPOL frame that was received just before association notification
1379858769.584778: RX EAPOL from 78:54:2e:a6:e3:80
1379858769.584782: RX EAPOL - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584821: Setting authentication timeout: 10 sec 0 usec
1379858769.584826: IEEE 802.1X RX: version=1 type=3 length=117
1379858769.584830:   EAPOL-Key type=2
1379858769.584833:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1379858769.584838:   key_length=16 key_data_length=22
1379858769.584841:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1379858769.584847:   key_nonce - hexdump(len=32): 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8
1379858769.584858:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584866:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1379858769.584872:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1379858769.584877:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584886: WPA: RX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584926: State: ASSOCIATED -> 4WAY_HANDSHAKE
1379858769.584963: WPA: RX message 1 of 4-Way Handshake from 78:54:2e:a6:e3:80 (ver=2)
1379858769.584970: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584982: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.584991: RSN: PMKID from Authenticator - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1379858769.585000: RSN: no matching PMKID found
1379858769.585688: WPA: Renewed SNonce - hexdump(len=32): 22 d5 20 3f 56 53 24 77 de ba 71 d1 d0 51 ff c3 31 d7 f4 b0 dd 95 ef fb c4 25 32 88 00 34 3f b6
1379858769.585725: WPA: PTK derivation - A1=00:16:44:f1:d3:07 A2=78:54:2e:a6:e3:80
1379858769.585732: WPA: PMK - hexdump(len=32): [REMOVED]
1379858769.585735: WPA: PTK - hexdump(len=48): [REMOVED]
1379858769.585741: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.585756: WPA: Sending EAPOL-Key 2/4
1379858769.585764: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 01 22 d5 20 3f 56 53 24 77 de ba 71 d1 d0 51 ff c3 31 d7 f4 b0 dd 95 ef fb c4 25 32 88 00 34 3f b6 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 6b 51 84 fb c9 a7 ee 04 c3 fc 8b 7f 87 14 3c 7d 00 16 30 14 01 00 00 0f ac 02 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.585836: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379858769.585844: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858769.585851: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379858769.585856: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858769.585861: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1379858769.585866: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858769.585875: nl80211: Event message available
1379858769.585889: nl80211: Ignore connect event (cmd=46) when using userspace SME
1379858769.589663: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858769.609580: RX EAPOL from 78:54:2e:a6:e3:80
1379858769.609611: RX EAPOL - hexdump(len=179): 01 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 53 c2 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0e eb bd 70 ba 12 f5 37 82 fa 0b 71 66 f2 45 24 00 50 27 48 00 14 dd 93 c4 b7 5c c0 f7 26 c2 3a b4 68 8b 69 83 4f 88 bc 32 c2 1f 7c 8c c8 f1 3f a9 42 33 ad cc e7 54 32 23 e1 ed be 62 7a ed 58 78 a4 93 c5 fb c8 68 c0 3e de c2 51 73 64 34 14 4c 05 aa 01 4f 43 c9 8b b3 12 39 78 80 1a 28 94 8b d5
1379858769.609646: IEEE 802.1X RX: version=1 type=3 length=175
1379858769.609649:   EAPOL-Key type=2
1379858769.609652:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1379858769.609656:   key_length=16 key_data_length=80
1379858769.609658:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
1379858769.609661:   key_nonce - hexdump(len=32): 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8
1379858769.609668:   key_iv - hexdump(len=16): 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40
1379858769.609672:   key_rsc - hexdump(len=8): 53 c2 00 00 00 00 00 00
1379858769.609675:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1379858769.609679:   key_mic - hexdump(len=16): 0e eb bd 70 ba 12 f5 37 82 fa 0b 71 66 f2 45 24
1379858769.609686: WPA: RX EAPOL-Key - hexdump(len=179): 01 03 00 af 02 13 ca 00 10 00 00 00 00 00 00 00 02 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 5e 1f 09 19 dc 69 c3 53 e8 48 c1 49 09 26 e8 a8 53 ea 56 86 27 43 6a 33 f0 46 24 cd b8 95 e7 40 53 c2 00 00 00 00 00 00 00 00 00 00 00 00 00 00 0e eb bd 70 ba 12 f5 37 82 fa 0b 71 66 f2 45 24 00 50 27 48 00 14 dd 93 c4 b7 5c c0 f7 26 c2 3a b4 68 8b 69 83 4f 88 bc 32 c2 1f 7c 8c c8 f1 3f a9 42 33 ad cc e7 54 32 23 e1 ed be 62 7a ed 58 78 a4 93 c5 fb c8 68 c0 3e de c2 51 73 64 34 14 4c 05 aa 01 4f 43 c9 8b b3 12 39 78 80 1a 28 94 8b d5
1379858769.609730: RSN: encrypted key data - hexdump(len=80): 27 48 00 14 dd 93 c4 b7 5c c0 f7 26 c2 3a b4 68 8b 69 83 4f 88 bc 32 c2 1f 7c 8c c8 f1 3f a9 42 33 ad cc e7 54 32 23 e1 ed be 62 7a ed 58 78 a4 93 c5 fb c8 68 c0 3e de c2 51 73 64 34 14 4c 05 aa 01 4f 43 c9 8b b3 12 39 78 80 1a 28 94 8b d5
1379858769.609784: WPA: decrypted EAPOL-Key key data - hexdump(len=72): [REMOVED]
1379858769.609788: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1379858769.609791: WPA: RX message 3 of 4-Way Handshake from 78:54:2e:a6:e3:80 (ver=2)
1379858769.609794: WPA: IE KeyData - hexdump(len=72): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00 dd 26 00 0f ac 01 01 00 fe 6d db d5 84 95 d2 a7 56 0a 53 ac 6a 89 1f 81 7c 5b 8f 57 9d ba fa 0d 78 af eb 50 13 4b 34 26 dd 00 00 00 00 00
1379858769.609808: WPA: RSN IE in EAPOL-Key - hexdump(len=26): 30 18 01 00 00 0f ac 02 02 00 00 0f ac 02 00 0f ac 04 01 00 00 0f ac 02 00 00
1379858769.609814: WPA: GTK in EAPOL-Key - hexdump(len=40): [REMOVED]
1379858769.609819: WPA: Sending EAPOL-Key 4/4
1379858769.609824: 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 50 90 7b d3 93 f4 92 c9 de d8 de 36 41 03 e3 65 00 00
1379858769.609868: WPA: Installing PTK to the driver.
1379858769.610100: wpa_driver_nl80211_set_key: ifindex=6 alg=3 addr=0x26468e0 key_idx=0 set_tx=1 seq_len=6 key_len=16
1379858769.610119:    addr=78:54:2e:a6:e3:80
1379858769.610425: EAPOL: External notification - portValid=1
1379858769.610432: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1379858769.610499: RSN: received GTK in pairwise handshake - hexdump(len=34): [REMOVED]
1379858769.610503: WPA: Group Key - hexdump(len=32): [REMOVED]
1379858769.610506: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32).
1379858769.610508: WPA: RSC - hexdump(len=6): 53 c2 00 00 00 00
1379858769.610519: wpa_driver_nl80211_set_key: ifindex=6 alg=2 addr=0x45ca89 key_idx=1 set_tx=0 seq_len=6 key_len=32
1379858769.610541: WPA: Key negotiation completed with 78:54:2e:a6:e3:80 [PTK=CCMP GTK=TKIP]
1379858769.610546: Cancelling authentication timeout
1379858769.610549: State: GROUP_HANDSHAKE -> COMPLETED
1379858769.610554: CTRL-EVENT-CONNECTED - Connection to 78:54:2e:a6:e3:80 completed (auth) [id=0 id_str=]
1379858769.610558: wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)
1379858769.610610: netlink: Operstate: linkmode=-1, operstate=6
1379858769.610678: EAPOL: External notification - portValid=1
1379858769.610685: EAPOL: External notification - EAP success=1
1379858769.610688: EAPOL: SUPP_PAE entering state AUTHENTICATING
1379858769.610691: EAPOL: SUPP_BE entering state SUCCESS
1379858769.610694: EAP: EAP entering state DISABLED
1379858769.610697: EAPOL: SUPP_PAE entering state AUTHENTICATED
1379858769.610699: EAPOL: Supplicant port status: Authorized
1379858769.610725: EAPOL: SUPP_BE entering state IDLE
1379858769.610730: EAPOL authentication completed successfully
1379858769.610738: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
1379858769.610742: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
1379858769.615560: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
1379858770.390146: nl80211: Event message available
1379858771.400206: nl80211: Event message available
^C1379858772.112717: CTRL-EVENT-TERMINATING - signal 2 received
1379858772.112739: Removing interface wlan0
1379858772.112745: wpa_driver_nl80211_deauthenticate
1379858772.115743: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=0 set_tx=0 seq_len=0 key_len=0
1379858772.115817: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=1 set_tx=0 seq_len=0 key_len=0
1379858772.115879: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=2 set_tx=0 seq_len=0 key_len=0
1379858772.115937: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x45ca89 key_idx=3 set_tx=0 seq_len=0 key_len=0
1379858772.115995: wpa_driver_nl80211_set_key: ifindex=6 alg=0 addr=0x2646120 key_idx=0 set_tx=0 seq_len=0 key_len=0
1379858772.116076:    addr=78:54:2e:a6:e3:80
1379858772.116116: State: COMPLETED -> DISCONNECTED
1379858772.116129: wpa_driver_nl80211_set_operstate: operstate 1->0 (DORMANT)
1379858772.116139: netlink: Operstate: linkmode=-1, operstate=5
1379858772.116372: EAPOL: External notification - portEnabled=0
1379858772.116387: EAPOL: SUPP_PAE entering state DISCONNECTED
1379858772.116401: EAPOL: Supplicant port status: Unauthorized
1379858772.116432: EAPOL: SUPP_BE entering state INITIALIZE
1379858772.116440: EAPOL: Supplicant port status: Unauthorized
1379858772.116464: EAPOL: External notification - portValid=0
1379858772.116469: EAPOL: Supplicant port status: Unauthorized
1379858772.116528: EAPOL: External notification - EAP success=0
1379858772.116540: EAPOL: Supplicant port status: Unauthorized
1379858772.116603: No keys have been configured - skip key clearing
1379858772.131079: dbus: Unregister network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1379858772.131517: BSS: Remove id 0 BSSID 78:54:2e:a6:e3:80 SSID 'Maison'
1379858772.131527: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0'
1379858772.131593: BSS: Remove id 1 BSSID 00:19:70:ad:71:6e SSID 'bbox2-ec38'
1379858772.131614: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1'
1379858772.131669: BSS: Remove id 3 BSSID 9c:d3:6d:98:2a:7c SSID 'VOO-264889'
1379858772.131687: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3'
1379858772.131734: BSS: Remove id 2 BSSID 06:19:70:ad:71:6e SSID 'FON_BELGACOM'
1379858772.131741: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2'
1379858772.131833: Cancelling scan request
1379858772.131841: Cancelling authentication timeout
1379858772.131849: dbus: Unregister interface object '/fi/w1/wpa_supplicant1/Interfaces/1'
1379858772.131875: netlink: Operstate: linkmode=0, operstate=6
1379858772.163542: dbus: Unregister D-Bus object '/fi/w1/wpa_supplicant1'

Re: NetworkManager not listing access points

[Dan Williams]

On Sun, 2013-09-22 at 16:20 +0200, Detlev Casanova wrote:
> Le samedi 21 septembre 2013 22:51:59 Johannes Berg a écrit :
> > On Thu, 2013-09-19 at 07:58 +0200, Detlev Casanova wrote:
> > > Here is the output (attached file for formatting)
> > 
> > Was that from the good case? The bad case would have been 
> more
> > interesting.
> 
> This is both cases. I made another one and here, I can give more 
> details:
> 
> Network manager is trying to list APs and fails until time 
> 1379858724.386569

Ok, the logs indicate that the driver simply doesn't see any scan
results:

1379858724.381522: Received scan results (0 BSSes)

Then 20 seconds later (after the explicit iwlist), it finds some scan
results:

1379858746.953924: Received scan results (3 BSSes)

So I'm not sure what's going on here, but I don't think NetworkManager
is the issue; it's likely in the supplicant's scanning code or in the
driver itself.  NetworkManager asks the supplicant to scan with both the
wildcard SSID and any hidden-tagged SSID, and the wildcard SSID should
ensure that all available APs are found.

Johannes, does anything else jump out at you in the logs?

Dan

> The The first "iwlist wlan0 scan" is done juste after the log line 
> (1379858738.682054). It lists the APs in range in the console but 
> not in the Network Manager ui.
> 
> The second "iwlist wlan0 scan" is done at time 1379858739.802067 
> and APs are being listed in the console and in the Network Manager 
> UI.
> 
> After that, NM will connect to the acces point with SSID "Maison".
> 
> It also looks like the listing in Network Manager comes between the 
> moment "iwlist wlan0 scan" is run for the second time and the 
> moment is shows its output on the console.
> 
> Detlev.

Re: NetworkManager not listing access points

[Detlev Casanova]

Le lundi 23 septembre 2013 11:13:49 Dan Williams a écrit :
> On Sun, 2013-09-22 at 16:20 +0200, Detlev Casanova wrote:
> > Le samedi 21 septembre 2013 22:51:59 Johannes Berg a écrit :
> > > On Thu, 2013-09-19 at 07:58 +0200, Detlev Casanova wrote:
> > > > Here is the output (attached file for formatting)
> > > 
> > > Was that from the good case? The bad case would have been
> > 
> > more
> > 
> > > interesting.
> > 
> > This is both cases. I made another one and here, I can give more
> > details:
> > 
> > Network manager is trying to list APs and fails until time
> > 1379858724.386569
> 
> Ok, the logs indicate that the driver simply doesn't see any scan
> results:
> 
> 1379858724.381522: Received scan results (0 BSSes)
> 
> Then 20 seconds later (after the explicit iwlist), it finds some scan
> results:
> 
> 1379858746.953924: Received scan results (3 BSSes)
> 
> So I'm not sure what's going on here, but I don't think NetworkManager
> is the issue; it's likely in the supplicant's scanning code or in the
> driver itself.  NetworkManager asks the supplicant to scan with both the
> wildcard SSID and any hidden-tagged SSID, and the wildcard SSID should
> ensure that all available APs are found.

Yes and the problem is most likely to be in the driver because it doesn't 
occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 ("cfg80211: use 
DS or HT operation IEs to determine BSS channel")

> Johannes, does anything else jump out at you in the logs?
> 
> Dan
> 
> > The The first "iwlist wlan0 scan" is done juste after the log line
> > (1379858738.682054). It lists the APs in range in the console but
> > not in the Network Manager ui.
> > 
> > The second "iwlist wlan0 scan" is done at time 1379858739.802067
> > and APs are being listed in the console and in the Network Manager
> > UI.
> > 
> > After that, NM will connect to the acces point with SSID "Maison".
> > 
> > It also looks like the listing in Network Manager comes between the
> > moment "iwlist wlan0 scan" is run for the second time and the
> > moment is shows its output on the console.
> > 
> > Detlev.

Re: NetworkManager not listing access points

[Rafał Miłecki]

2013/9/18 Detlev Casanova <detlev.casanova@gmail.com>:
> After a bisection on the kernel, it seems that a patch is causing a
> problem with NetworkManager:
>
> commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 ("cfg80211:
> use DS or HT operation IEs to determine BSS channel")
>
> (...)
>
> The hardware is: 14e4:4315 (Network controller: Broadcom Corporation
> BCM4312 802.11b/g LP-PHY (rev 01)) on an Intel Core i3 M370 CPU (64
> bits) computer.

See:
http://www.spinics.net/lists/linux-wireless/msg105359.html
("Scanning regression since "cfg80211: use DS or HT operation IEs to
determine BSS channel"")

It seems that starting with the mentioned commit, b43 doesn't report
any results on the 1st scanning. No idea how this patch affected b43.
Scanning on channel b43 is failing even worse starting with that
commit.

-- 
Rafał

Re: NetworkManager not listing access points

[Rafał Miłecki]

2013/9/29 Rafał Miłecki <zajec5@gmail.com>:
> Scanning on channel b43 is failing even worse starting with that
> commit.

s/b43/13/

-- 
Rafał

Re: NetworkManager not listing access points

[Johannes Berg]

On Sun, 2013-09-29 at 21:29 +0200, Detlev Casanova wrote:

> > So I'm not sure what's going on here, but I don't think NetworkManager
> > is the issue; it's likely in the supplicant's scanning code or in the
> > driver itself.  NetworkManager asks the supplicant to scan with both the
> > wildcard SSID and any hidden-tagged SSID, and the wildcard SSID should
> > ensure that all available APs are found.
> 
> Yes and the problem is most likely to be in the driver because it doesn't 
> occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8 ("cfg80211: use 
> DS or HT operation IEs to determine BSS channel")

Does it work on a newer kernel if you revert that commit? I really see
nothing wrong with that commit ...

Failing all else, since I can't reproduce the issue, can you please
compare the output of "iw list" before and after the failure (on the
failing kernel)? Maybe all channels are marked disabled or something?
But that really should've been the same behaviour before the patch too.

Also, tracing would be good (trace-cmd record -e cfg80211 -e mac80211,
compress trace.dat and send it to me)

johannes

Re: NetworkManager not listing access points

[Johannes Berg]

On Mon, 2013-10-07 at 08:48 +0200, Detlev Casanova wrote:

> > > Yes and the problem is most likely to be in the driver because it
> doesn't
> > > occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8
> ("cfg80211:
> > > use DS or HT operation IEs to determine BSS channel")

[...]

> I looked into wpa_supplicant and after an upgrade from 0.7.3 to 2.0,
> the problem seems to be fixed.

Huh, that's odd. Did 0.7.3 use wext driver?

johannes

Re: NetworkManager not listing access points

[Detlev Casanova]

Le lundi 7 octobre 2013 09:40:58 Johannes Berg a écrit :
> On Mon, 2013-10-07 at 08:48 +0200, Detlev Casanova wrote:
> > > > Yes and the problem is most likely to be in the driver because it
> > 
> > doesn't
> > 
> > > > occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8
> > 
> > ("cfg80211:
> > > > use DS or HT operation IEs to determine BSS channel")
> 
> [...]
> 
> > I looked into wpa_supplicant and after an upgrade from 0.7.3 to 2.0,
> > the problem seems to be fixed.
> 
> Huh, that's odd. Did 0.7.3 use wext driver?

Yes it did.

Re: NetworkManager not listing access points

[Johannes Berg]

On Fri, 2013-10-11 at 17:43 +0200, Detlev Casanova wrote:

> > > > > occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8
> > > 
> > > ("cfg80211:
> > > > > use DS or HT operation IEs to determine BSS channel")
> > 
> > [...]
> > 
> > > I looked into wpa_supplicant and after an upgrade from 0.7.3 to 2.0,
> > > the problem seems to be fixed.
> > 
> > Huh, that's odd. Did 0.7.3 use wext driver?
> 
> Yes it did.

Hmm. Even taking that into account though I don't really see any
difference.

Maybe you could check if there's any difference in iwlist scan output
before/after the patch (for the affected AP)?

johannes

Re: NetworkManager not listing access points

[Will Hawkins]

On 10/17/2013 10:38 AM, Johannes Berg wrote:
> On Fri, 2013-10-11 at 17:43 +0200, Detlev Casanova wrote:
> 
>>>>>> occur before commit 0172bb75073e11a5aa9d8a953bdaefb8709f00c8
>>>>
>>>> ("cfg80211:
>>>>>> use DS or HT operation IEs to determine BSS channel")
>>>
>>> [...]
>>>
>>>> I looked into wpa_supplicant and after an upgrade from 0.7.3 to 2.0,
>>>> the problem seems to be fixed.
>>>
>>> Huh, that's odd. Did 0.7.3 use wext driver?
>>
>> Yes it did.
> 
> Hmm. Even taking that into account though I don't really see any
> difference.
> 
> Maybe you could check if there's any difference in iwlist scan output
> before/after the patch (for the affected AP)?
> 
> johannes

Not to clog up the channel, but I was running into exactly the same
problem. I expected to see the problem somewhere in the kernel, etc. I
turned on debugging and kernel tracing and saw nothing. The fix for me
is almost identical to the fix that Detlev first described.

However, the problem for me was somewhere else entirely. The access
point was sending out malformed beacon messages that kept it from
showing up.

I *hope* that this helps. However, I hope, at least, this was not a
waste of bits. :-)

Will


> 
> 
> --
> To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

Re: NetworkManager not listing access points

[Johannes Berg]

On Thu, 2013-10-17 at 12:19 -0400, Will Hawkins wrote:

> Not to clog up the channel, but I was running into exactly the same
> problem. I expected to see the problem somewhere in the kernel, etc. I
> turned on debugging and kernel tracing and saw nothing. The fix for me
> is almost identical to the fix that Detlev first described.
> 
> However, the problem for me was somewhere else entirely. The access
> point was sending out malformed beacon messages that kept it from
> showing up.

Any idea how they were malformed? Was there a bad DS IE or so?

johannes

Re: NetworkManager not listing access points

[Will Hawkins]

[-- Attachment #1: Type: text/plain, Size: 979 bytes --]



On 10/21/2013 09:06 AM, Johannes Berg wrote:
> On Thu, 2013-10-17 at 12:19 -0400, Will Hawkins wrote:
> 
>> Not to clog up the channel, but I was running into exactly the same
>> problem. I expected to see the problem somewhere in the kernel, etc. I
>> turned on debugging and kernel tracing and saw nothing. The fix for me
>> is almost identical to the fix that Detlev first described.
>>
>> However, the problem for me was somewhere else entirely. The access
>> point was sending out malformed beacon messages that kept it from
>> showing up.
> 
> Any idea how they were malformed? Was there a bad DS IE or so?

I'm not enough of an expert to answer your question definitively.
However, I've included the malformed packet as an attachment. I've
stripped identifying information (hopefully), but think that this will
still give you information to answer the question.

If this is not sufficient, please let me know! I'm glad to help however
I can.

Will


> 
> johannes
> 
> 

[-- Attachment #2: malformed-beacon (filtered).txt --]
[-- Type: text/plain, Size: 26060 bytes --]

No.     Time        Source                Destination           Protocol Length Info
  22955 54.834442   xxxxxxxxxxxxxxxxx     Broadcast             802.11   295    Beacon frame, SN=382, FN=0, Flags=........, BI=100, SSID=xxxx[Malformed Packet]

Frame 22955: 295 bytes on wire (2360 bits), 295 bytes captured (2360 bits)
    Arrival Time: Oct  7, 2013 11:18:42.842426000 EDT
    Epoch Time: 1381159122.842426000 seconds
    [Time delta from previous captured frame: 0.009828000 seconds]
    [Time delta from previous displayed frame: 0.009828000 seconds]
    [Time since reference or first frame: 54.834442000 seconds]
    Frame Number: 22955
    Frame Length: 295 bytes (2360 bits)
    Capture Length: 295 bytes (2360 bits)
    [Frame is marked: False]
    [Frame is ignored: False]
    [Protocols in frame: radiotap:wlan]
Radiotap Header v0, Length 18
    Header revision: 0
    Header pad: 0
    Header length: 18
    Present flags
        .... .... .... .... .... .... .... ...0 = TSFT: False
        .... .... .... .... .... .... .... ..1. = Flags: True
        .... .... .... .... .... .... .... .1.. = Rate: True
        .... .... .... .... .... .... .... 1... = Channel: True
        .... .... .... .... .... .... ...0 .... = FHSS: False
        .... .... .... .... .... .... ..1. .... = dBm Antenna Signal: True
        .... .... .... .... .... .... .0.. .... = dBm Antenna Noise: False
        .... .... .... .... .... .... 0... .... = Lock Quality: False
        .... .... .... .... .... ...0 .... .... = TX Attenuation: False
        .... .... .... .... .... ..0. .... .... = dB TX Attenuation: False
        .... .... .... .... .... .0.. .... .... = dBm TX Power: False
        .... .... .... .... .... 1... .... .... = Antenna: True
        .... .... .... .... ...0 .... .... .... = dB Antenna Signal: False
        .... .... .... .... ..0. .... .... .... = dB Antenna Noise: False
        .... .... .... .... .1.. .... .... .... = RX flags: True
        .... .... .... .0.. .... .... .... .... = Channel+: False
        .... .... .... 0... .... .... .... .... = HT information: False
        ..0. .... .... .... .... .... .... .... = Radiotap NS next: False
        .0.. .... .... .... .... .... .... .... = Vendor NS next: False
        0... .... .... .... .... .... .... .... = Ext: False
    Flags: 0x00
        .... ...0 = CFP: False
        .... ..0. = Preamble: Long
        .... .0.. = WEP: False
        .... 0... = Fragmentation: False
        ...0 .... = FCS at end: False
        ..0. .... = Data Pad: False
        .0.. .... = Bad FCS: False
        0... .... = Short GI: False
    Data Rate: 1.0 Mb/s
    Channel frequency: 2437 [BG 6]
    Channel type: 802.11b (0x00a0)
        .... .... ...0 .... = Turbo: False
        .... .... ..1. .... = Complementary Code Keying (CCK): True
        .... .... .0.. .... = Orthogonal Frequency-Division Multiplexing (OFDM): False
        .... .... 1... .... = 2 GHz spectrum: True
        .... ...0 .... .... = 5 GHz spectrum: False
        .... ..0. .... .... = Passive: False
        .... .0.. .... .... = Dynamic CCK-OFDM: False
        .... 0... .... .... = Gaussian Frequency Shift Keying (GFSK): False
        ...0 .... .... .... = GSM (900MHz): False
        ..0. .... .... .... = Static Turbo: False
        .0.. .... .... .... = Half Rate Channel (10MHz Channel Width): False
        0... .... .... .... = Quarter Rate Channel (5MHz Channel Width): False
    SSI Signal: -48 dBm
    Antenna: 3
    RX flags: 0x0000
        .... .... .... .... .... ..0. = Bad PLCP: False
IEEE 802.11 Beacon frame, Flags: ........
    Type/Subtype: Beacon frame (0x08)
    Frame Control: 0x0080 (Normal)
        Version: 0
        Type: Management frame (0)
        Subtype: 8
        Flags: 0x0
            .... ..00 = DS status: Not leaving DS or network is operating in AD-HOC mode (To DS: 0 From DS: 0) (0x00)
            .... .0.. = More Fragments: This is the last fragment
            .... 0... = Retry: Frame is not being retransmitted
            ...0 .... = PWR MGT: STA will stay up
            ..0. .... = More Data: No data buffered
            .0.. .... = Protected flag: Data is not protected
            0... .... = Order flag: Not strictly ordered
    Duration: 0
    Destination address: Broadcast (ff:ff:ff:ff:ff:ff)
    Source address: xxxx
    BSS Id: xxxx
    Fragment number: 0
    Sequence number: 382
IEEE 802.11 wireless LAN management frame
    Fixed parameters (12 bytes)
        Timestamp: 0x00000314d3051180
        Beacon Interval: 0.102400 [Seconds]
        Capabilities Information: 0x0131
            .... .... .... ...1 = ESS capabilities: Transmitter is an AP
            .... .... .... ..0. = IBSS status: Transmitter belongs to a BSS
            .... ..0. .... 00.. = CFP participation capabilities: No point coordinator at AP (0x0000)
            .... .... ...1 .... = Privacy: AP/STA can support WEP
            .... .... ..1. .... = Short Preamble: Short preamble allowed
            .... .... .0.. .... = PBCC: PBCC modulation not allowed
            .... .... 0... .... = Channel Agility: Channel agility not in use
            .... ...1 .... .... = Spectrum Management: dot11SpectrumManagementRequired TRUE
            .... .0.. .... .... = Short Slot Time: Short slot time not in use
            .... 0... .... .... = Automatic Power Save Delivery: apsd not implemented
            ..0. .... .... .... = DSSS-OFDM: DSSS-OFDM modulation not allowed
            .0.. .... .... .... = Delayed Block Ack: delayed block ack not implemented
            0... .... .... .... = Immediate Block Ack: immediate block ack not implemented
    Tagged parameters (241 bytes)
        Tag: SSID parameter set: xxxx
            Tag Number: SSID parameter set (0)
            Tag length: 14
            SSID: xxxx
        Tag: Supported Rates 1(B), 2(B), 5.5(B), 11(B), 6, 9, 12, 18, [Mbit/sec]
            Tag Number: Supported Rates (1)
            Tag length: 8
            Supported Rates: 1(B)
            Supported Rates: 2(B)
            Supported Rates: 5.5(B)
            Supported Rates: 11(B)
            Supported Rates: 6
            Supported Rates: 9
            Supported Rates: 12
            Supported Rates: 18
        Tag: DS Parameter set : Current Channel: 6
            Tag Number: DS Parameter set (3)
            Tag length: 1
            Current Channel: 6
        Tag: Traffic Indication Map (TIM): DTIM 0 of 0 bitmap
            Tag Number: Traffic Indication Map (TIM) (5)
            Tag length: 4
            DTIM count: 0
            DTIM period: 1
            Bitmap control: 0x00
                .... ...0 = Multicast: False
                0000 000. = Bitmap Offset: 0x00
            Partial Virtual Bitmap: 00
        Tag: Country Information: Country Code AU, Environment Any
            Tag Number: Country Information (7)
            Tag length: 6
            Code: AU
            Environment: Any (0x20)
            Country Info: First Channel Number: 1, Number of Channels: 13, Maximum Transmit Power Level: 22 dBm
                First Channel Number: 1
                Number of Channels: 13
                Maximum Transmit Power Level (in dBm): 22
        Tag: Power Constraint :0
            Tag Number: Power Constraint (32)
            Tag length: 1
            Local Power Constraint: 0x00
        Tag: ERP Information
            Tag Number: ERP Information (42)
            Tag length: 1
            ERP Information: 0x02
                .... ...0 = Non ERP Present: Not set
                .... ..1. = Use Protection: Set
                .... .0.. = Barker Preamble Mode: Not set
                0000 0... = Reserved: 0x00
        Tag: RSN Information
            Tag Number: RSN Information (48)
            Tag length: 24
            RSN Version: 24
            Group Cipher Suite: 00-0f-ac (Ieee8021) TKIP
                Group Cipher Suite OUI: 00-0f-ac (Ieee8021)
                Group Cipher Suite type: TKIP (2)
            Pairwise Cipher Suite Count: 2
            Pairwise Cipher Suite List 00-0f-ac (Ieee8021) AES (CCM) 00-0f-ac (Ieee8021) TKIP
                Pairwise Cipher Suite: 00-0f-ac (Ieee8021) AES (CCM)
                    Pairwise Cipher Suite OUI: 00-0f-ac (Ieee8021)
                    Pairwise Cipher Suite type: AES (CCM) (4)
                Pairwise Cipher Suite: 00-0f-ac (Ieee8021) TKIP
                    Pairwise Cipher Suite OUI: 00-0f-ac (Ieee8021)
                    Pairwise Cipher Suite type: TKIP (2)
            Auth Key Management (AKM) Suite Count: 2
            Auth Key Management (AKM) List 00-0f-ac (Ieee8021) PSK
                Auth Key Management (AKM) Suite: 00-0f-ac (Ieee8021) PSK
                    Auth Key Management (AKM) OUI: 00-0f-ac (Ieee8021)
                    Auth Key Management (AKM) type: PSK (2)
                Auth Key Management (AKM) Suite: 00-00-32 (Marconi) FT using PSK
                    Auth Key Management (AKM) OUI: 00-00-32 (Marconi)
                    Auth Key Management (AKM) type: 4
            RSN Capabilities: 0x4830
                .... .... .... ...0 = RSN Pre-Auth capabilities: Transmitter does not support pre-authentication
                .... .... .... ..0. = RSN No Pairwise capabilities: Transmitter can support WEP default key 0 simultaneously with Pairwise key
                .... .... .... 00.. = RSN PTKSA Replay Counter capabilities: 1 replay counter per PTKSA/GTKSA/STAKeySA (0x0000)
                .... .... ..11 .... = RSN GTKSA Replay Counter capabilities: 16 replay counters per PTKSA/GTKSA/STAKeySA (0x0003)
                .... .... .0.. .... = Management Frame Protection Required: False
                .... .... 0... .... = Management Frame Protection Capable: False
                .... ..0. .... .... = PeerKey Enabled: False
        Tag: Extended Supported Rates 24, 36, 48, 54, [Mbit/sec]
            Tag Number: Extended Supported Rates (50)
            Tag length: 4
            Extented Supported Rates: 24
            Extented Supported Rates: 36
            Extented Supported Rates: 48
            Extented Supported Rates: 54
        Tag: HT Capabilities (802.11n D1.10)
            Tag Number: HT Capabilities (802.11n D1.10) (45)
            Tag length: 26
            HT Capabilities Info: 0x018c
                .... .... .... ...0 = HT LDPC coding capability: Transmitter does not support receiving LDPC coded packets
                .... .... .... ..0. = HT Support channel width: Transmitter only supports 20MHz operation
                .... .... .... 11.. = HT SM Power Save: SM Power Save disabled (0x0003)
                .... .... ...0 .... = HT Green Field: Transmitter is not able to receive PPDUs with Green Field (GF) preamble
                .... .... ..0. .... = HT Short GI for 20MHz: Not supported
                .... .... .0.. .... = HT Short GI for 40MHz: Not supported
                .... .... 1... .... = HT Tx STBC: Supported
                .... ..01 .... .... = HT Rx STBC: Rx support of one spatial stream (0x0001)
                .... .0.. .... .... = HT Delayed Block ACK: Transmitter does not support HT-Delayed BlockAck
                .... 0... .... .... = HT Max A-MSDU length: 3839 bytes
                ...0 .... .... .... = HT DSSS/CCK mode in 40MHz: Won't/Can't use of DSSS/CCK in 40 MHz
                ..0. .... .... .... = HT PSMP Support: Won't/Can't support PSMP operation
                .0.. .... .... .... = HT Forty MHz Intolerant: Use of 40 MHz transmissions unrestricted/allowed
                0... .... .... .... = HT L-SIG TXOP Protection support: Not supported
            A-MPDU Parameters: 0x001b
                .... ..11 = Maximum Rx A-MPDU Length: 65535 [Bytes]
                ...1 10.. = MPDU Density: 8 [usec] (0x06)
                000. .... = Reserved: 0x00
            Rx Supported Modulation and Coding Scheme Set: MCS Set
                Tag interpretation: Rx Modulation and Coding Scheme (One bit per modulation)
                    .... .... .... .... .... .... 1111 1111 = Rx Bitmask Bits 0-7: 0x000000ff
                    .... .... .... .... 0111 1111 .... .... = Rx Bitmask Bits 8-15: 0x0000007f
                    .... .... 0000 0000 .... .... .... .... = Rx Bitmask Bits 16-23: 0x00000000
                    0000 0000 .... .... .... .... .... .... = Rx Bitmask Bits 24-31: 0x00000000
                    .... .... .... .... .... .... .... ...0 = Rx Bitmask Bit 32: 0x00000000
                    .... .... .... .... .... .... .000 000. = Rx Bitmask Bits 33-38: 0x00000000
                    .... .... ...0 0000 0000 0000 0... .... = Rx Bitmask Bits 39-52: 0x00000000
                    ...0 0000 0000 0000 0000 0000 000. .... = Rx Bitmask Bits 53-76: 0x00000000
                Highest Supported Data Rate: 0x0000
                .... .... .... ...0 = Tx Supported MCS Set: Not Defined
                .... .... .... ..0. = Tx and Rx MCS Set: Equal
                .... .... .... 00.. = Tx Maximum Number of Spatial Streams Supported: 1 spatial stream (0x0000)
                .... .... ...0 .... = Unequal Modulation: Not supported
            HT Extended Capabilities: 0x0000
                .... .... .... ...0 = Transmitter supports PCO: Not supported
                .... .... .... .00. = Time needed to transition between 20MHz and 40MHz: No Transition (0x0000)
                .... ..00 .... .... = MCS Feedback capability: STA does not provide MCS feedback (0x0000)
                .... .0.. .... .... = High Throughput: Not supported
                .... 0... .... .... = Reverse Direction Responder: Not supported
            Transmit Beam Forming (TxBF) Capabilities: 0x0000
                .... .... .... .... .... .... .... ...0 = Transmit Beamforming: Not supported
                .... .... .... .... .... .... .... ..0. = Receive Staggered Sounding: Not supported
                .... .... .... .... .... .... .... .0.. = Transmit Staggered Sounding: Not supported
                .... .... .... .... .... .... .... 0... = Receive Null Data packet (NDP): Not supported
                .... .... .... .... .... .... ...0 .... = Transmit Null Data packet (NDP): Not supported
                .... .... .... .... .... .... ..0. .... = Implicit TxBF capable: Not supported
                .... .... .... .... .... .... 00.. .... = Calibration: incapable (0x00000000)
                .... .... .... .... .... ...0 .... .... = STA can apply TxBF using CSI explicit feedback: Not supported
                .... .... .... .... .... ..0. .... .... = STA can apply TxBF using uncompressed beamforming feedback matrix: Not supported
                .... .... .... .... .... .0.. .... .... = STA can apply TxBF using compressed beamforming feedback matrix: Not supported
                .... .... .... .... ...0 0... .... .... = Receiver can return explicit CSI feedback: not supported (0x00000000)
                .... .... .... .... .00. .... .... .... = Receiver can return explicit uncompressed Beamforming Feedback Matrix: not supported (0x00000000)
                .... .... .... ...0 0... .... .... .... = STA can compress and use compressed Beamforming Feedback Matrix: not supported (0x00000000)
                .... .... .... .00. .... .... .... .... = Minimal grouping used for explicit feedback reports: No grouping supported (0x00000000)
                .... .... ...0 0... .... .... .... .... = Max antennae STA can support when CSI feedback required: 1 TX antenna sounding (0x00000000)
                .... .... .00. .... .... .... .... .... = Max antennae STA can support when uncompressed Beamforming feedback required: 1 TX antenna sounding (0x00000000)
                .... ...0 0... .... .... .... .... .... = Max antennae STA can support when compressed Beamforming feedback required: 1 TX antenna sounding (0x00000000)
                .... .00. .... .... .... .... .... .... = Maximum number of rows of CSI explicit feedback: 1 row of CSI (0x00000000)
                ...0 0... .... .... .... .... .... .... = Maximum number of space time streams for which channel dimensions can be simultaneously estimated: 1 space time stream (0x00000000)
                000. .... .... .... .... .... .... .... = Reserved: 0x00000000
            Antenna Selection (ASEL) Capabilities: 0x00
                .... ...0 = Antenna Selection Capable: Not supported
                .... ..0. = Explicit CSI Feedback Based Tx ASEL: Not supported
                .... .0.. = Antenna Indices Feedback Based Tx ASEL: Not supported
                .... 0... = Explicit CSI Feedback: Not supported
                ...0 .... = Antenna Indices Feedback: Not supported
                ..0. .... = Rx ASEL: Not supported
                .0.. .... = Tx Sounding PPDUs: Not supported
                0... .... = Reserved: 0x00
        Tag: AP Channel Report: Tag 51 Len 26
            Tag Number: AP Channel Report (51)
            Tag length: 26
            Tag interpretation: Not interpreted
        Tag: HT Information (802.11n D1.10)
            Tag Number: HT Information (802.11n D1.10) (61)
            Tag length: 22
            Primary Channel: 6
            HT Information Subset (1 of 3): 0x00
                .... ..00 = Secondary channel offset: No secondary channel (0x00)
                .... .0.. = Supported channel width: 20 MHz channel width only
                .... 0... = Reduced Interframe Spacing (RIFS): Prohibited
                ...0 .... = Power Save Multi-Poll (PSMP) stations only: Association requests are accepted regardless of PSMP capability
                000. .... = Shortest service interval: 5 ms (0x00)
            HT Information Subset (2 of 3): 0x0013
                .... .... .... ..11 = Operating mode of BSS: HT mixed mode (0x0003)
                .... .... .... .0.. = Non-greenfield STAs present: All associated STAs are greenfield capable
                .... .... .... 0... = Transmit burst limit: No limit
                .... .... ...1 .... = OBSS non-HT STAs present: Use of protection for non-HT STAs by overlapping BSSs is needed
                0000 0000 000. .... = Reserved: 0x0000
            HT Information Subset (3 of 3): 0x0000
                .... .... ..00 0000 = Reserved: 0x0000
                .... .... .0.. .... = Dual beacon: No second beacon is transmitted
                .... .... 0... .... = Dual Clear To Send (CTS) protection: Not required
                .... ...0 .... .... = Beacon ID: Primary beacon
                .... ..0. .... .... = L-SIG TXOP Protection Full Support: One or more HT STAs in the BSS do not support L-SIG TXOP protection
                .... .0.. .... .... = Phased Coexistence Operation (PCO): Inactive
                .... 0... .... .... = Phased Coexistence Operation (PCO) Phase: Switch to or continue 20 MHz phase
                0000 .... .... .... = Reserved: 0x0000
            Rx Supported Modulation and Coding Scheme Set: Basic MCS Set
                Tag interpretation: Rx Modulation and Coding Scheme (One bit per modulation)
                    .... .... .... .... .... .... 0000 0000 = Rx Bitmask Bits 0-7: 0x00000000
                    .... .... .... .... 0000 0000 .... .... = Rx Bitmask Bits 8-15: 0x00000000
                    .... .... 0000 0000 .... .... .... .... = Rx Bitmask Bits 16-23: 0x00000000
                    0000 0000 .... .... .... .... .... .... = Rx Bitmask Bits 24-31: 0x00000000
                    .... .... .... .... .... .... .... ...0 = Rx Bitmask Bit 32: 0x00000000
                    .... .... .... .... .... .... .000 000. = Rx Bitmask Bits 33-38: 0x00000000
                    .... .... ...0 0000 0000 0000 0... .... = Rx Bitmask Bits 39-52: 0x00000000
                    ...0 0000 0000 0000 0000 0000 000. .... = Rx Bitmask Bits 53-76: 0x00000000
                Highest Supported Data Rate: 0x0000
                .... .... .... ...0 = Tx Supported MCS Set: Not Defined
                .... .... .... ..0. = Tx and Rx MCS Set: Equal
                .... .... .... 00.. = Tx Maximum Number of Spatial Streams Supported: 1 spatial stream (0x0000)
                .... .... ...0 .... = Unequal Modulation: Not supported
        Tag: Neighbor Report
            Tag Number: Neighbor Report (52)
            Tag length: 22
            BSSID: 16:00:13:00:00:00 (16:00:13:00:00:00)
            BSSID Information: 0x00000000
                .... .... .... ..00 = AP Reachability: 0x0000
                .... .... .... .0.. = Security: 0x0000
                .... .... .... 0... = Key Scope: 0x0000
                .... .... ...0 .... = Capability: Spectrum Management: 0x0000
                .... .... ..0. .... = Capability: QoS: 0x0000
                .... .... .0.. .... = Capability: APSD: 0x0000
                .... .... 0... .... = Capability: Radio Measurement: 0x0000
                .... ...0 .... .... = Capability: Delayed Block Ack: 0x0000
                .... ..0. .... .... = Capability: Immediate Block Ack: 0x0000
                .... .0.. .... .... = Mobility Domain: 0x0000
                .... 0... .... .... = High Throughput: 0x0000
                Reserved: 0x00000000
            Regulatory Class: 0x00
            Channel Number: 0x00
            PHY Type: 0x00
            Unknown Data
        Tag: Overlapping BSS Scan Parameters: Tag 74 Len 14
            Tag Number: Overlapping BSS Scan Parameters (74)
            Tag length: 14
            Tag interpretation: Not interpreted
        Tag: Extended Capabilities
            Tag Number: Extended Capabilities (127)
            Tag length: 1
            Extended Capabilities: 0x01 (octet 0)
                .... ...1 = 20/40 BSS Coexistence Management Support: Supported
                .... ..0. = On-demand beacon: Not supported
                .... .0.. = Extended Channel Switching: Not supported
                .... 0... = WAVE indication: Not supported
                ...0 .... = PSMP Capability: Not supported
                .0.. .... = S-PSMP Support: Not supported
        Tag: Vendor Specific: Microsof: WMM/WME: Parameter Element
            Tag Number: Vendor Specific (221)
            Tag length: 24
            OUI: 00-50-f2 (Microsof)
            Vendor Specific OUI Type: 2
            Type: WMM/WME (0x02)
            WME Subtype: Parameter Element (1)
            WME Version: 1
            WME QoS Info: 0x81
                1... .... = U-APSD: Enabled
                .... 0001 = Parameter Set Count: 0x01
                .000 .... = Reserved: 0x00
            Reserved: 00
            Ac Parameters ACI 0 (Best Effort), ACM no , AIFSN 3, ECWmin 4 ,ECWmax 10, TXOP 0
                ACI / AIFSN Field: 0x03
                    .00. .... = ACI: Best Effort (0)
                    ...0 .... = Admission Control Mandatory: No
                    .... 0011 = AIFSN: 3
                    0... .... = Reserved: 0
                ECW: 0xa4
                    1010 .... = ECW Max: 10
                    .... 0100 = ECW Min: 4
                TXOP Limit: 0
            Ac Parameters ACI 1 (Background), ACM no , AIFSN 7, ECWmin 4 ,ECWmax 10, TXOP 0
                ACI / AIFSN Field: 0x27
                    .01. .... = ACI: Background (1)
                    ...0 .... = Admission Control Mandatory: No
                    .... 0111 = AIFSN: 7
                    0... .... = Reserved: 0
                ECW: 0xa4
                    1010 .... = ECW Max: 10
                    .... 0100 = ECW Min: 4
                TXOP Limit: 0
            Ac Parameters ACI 2 (Video), ACM no , AIFSN 2, ECWmin 3 ,ECWmax 4, TXOP 94
                ACI / AIFSN Field: 0x42
                    .10. .... = ACI: Video (2)
                    ...0 .... = Admission Control Mandatory: No
                    .... 0010 = AIFSN: 2
                    0... .... = Reserved: 0
                ECW: 0x43
                    0100 .... = ECW Max: 4
                    .... 0011 = ECW Min: 3
                TXOP Limit: 94
            Ac Parameters ACI 3 (Voice), ACM no , AIFSN 2, ECWmin 2 ,ECWmax 6, TXOP 47
                ACI / AIFSN Field: 0x62
                    .11. .... = ACI: Voice (3)
                    ...0 .... = Admission Control Mandatory: No
                    .... 0010 = AIFSN: 2
                    0... .... = Reserved: 0
                ECW: 0x62
                    0110 .... = ECW Max: 6
                    .... 0010 = ECW Min: 2
                TXOP Limit: 47
        Tag: Vendor Specific
            Tag Number: Vendor Specific (221)
            Tag length: 221
[Malformed Packet: IEEE 802.11]
    [Expert Info (Error/Malformed): Malformed Packet (Exception occurred)]
        [Message: Malformed Packet (Exception occurred)]
        [Severity level: Error]
        [Group: Malformed]

0000  00 00 12 00 2e 48 00 00 00 02 85 09 a0 00 d0 03   .....H..........
0010  00 00 80 00 00 00 ff ff ff ff ff ff xx xx xx xx   ................
0020  xx xx xx xx xx xx xx xx e0 17 80 11 05 d3 14 03   ................
0030  00 00 64 00 31 01 00 0e xx xx xx xx xx xx xx xx   ..d.1...........
0040  xx xx xx xx xx xx 01 08 82 84 8b 96 0c 12 18 24   ...............$
0050  03 01 06 05 04 00 01 00 00 07 06 41 55 20 01 0d   ...........AU ..
0060  16 20 01 00 2a 01 02 30 18 18 00 00 0f ac 02 02   . ..*..0........
0070  00 00 0f ac 04 00 0f ac 02 02 00 00 0f ac 02 00   ................
0080  00 32 04 30 48 60 6c 2d 1a 8c 01 1b ff 7f 00 00   .2.0H`l-........
0090  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00   ................
00a0  00 00 00 33 1a 8c 01 1b ff ff 00 00 00 00 00 00   ...3............
00b0  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 3d   ...............=
00c0  16 06 00 13 00 00 00 00 00 00 00 00 00 00 00 00   ................
00d0  00 00 00 00 00 00 00 34 16 16 00 13 00 00 00 00   .......4........
00e0  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 4a   ...............J
00f0  0e 14 00 0a 00 2c 01 c8 00 00 00 05 00 19 00 7f   .....,..........
0100  01 01 dd 18 00 50 f2 02 01 01 81 00 03 a4 00 00   .....P..........
0110  27 a4 00 00 42 43 5e 00 62 62 2f 00 dd dd 00 03   '...BC^.bb/.....
0120  7f 7f 01 00 00 00 00                              .......