Attachment 915778 Details for Bug 1014843 – Comment

Comment

comment_6396326.txt (text/plain), 87.22 KB, created by Dano on 2013-10-09 00:26:36 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Dano

Created: 2013-10-09 00:26:36 UTC

Size: 87.22 KB

patch

obsolete

>More debug info:
>1. Cleared wpa_supplicant.log
>2. Rebooted
>
>#dbus-send --system --print-reply --dest=fi.w1.wpa_supplicant1 /fi/w1/wpa_supplicant1 org.freedesktop.DBus.Properties.Set string:fi.w1.wpa_supplicant1 string:DebugTimestamp variant:boolean:true
>
>#dbus-send --system --print-reply --dest=fi.w1.wpa_supplicant1 /fi/w1/wpa_supplicant1 org.freedesktop.DBus.Properties.Set string:fi.w1.wpa_supplicant1 string:DebugLevel variant:string:"msgdump"
>
>#cat /var/log/wpa_supplicant.log
>1381276411.414390: wlan0: Removing interface wlan0
>1381276411.414442: wlan0: Request to deauthenticate - bssid=c0:c1:c0:dc:08:33 pending_bssid=00:00:00:00:00:00 reason=3 state=COMPLETED
>1381276411.414453: wpa_driver_nl80211_deauthenticate(addr=c0:c1:c0:dc:08:33 reason_code=3)
>1381276411.422492: wlan0: Event DEAUTH (12) received
>1381276411.422528: wlan0: Deauthentication notification
>1381276411.422539: wlan0:  * reason 3 (locally generated)
>1381276411.422548: Deauthentication frame IE(s) - hexdump(len=0): [NULL]
>1381276411.422560: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:c1:c0:dc:08:33 reason=3 locally_generated=1
>1381276411.422571: wlan0: Auto connect enabled: try to reconnect (wps=0 wpa_state=9)
>1381276411.422583: wlan0: Setting scan request: 0 sec 100000 usec
>1381276411.422594: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276411.422607: wlan0: Blacklist count 1 --> request scan in 100 ms
>1381276411.422618: wlan0: Not rescheduling scan to ensure that specific SSID scans occur
>1381276411.422726: wlan0: Disconnect event - remove keys
>1381276411.422758: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
>1381276411.422805: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
>1381276411.422837: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
>1381276411.422866: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
>1381276411.422895: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=0x2613828 key_idx=0 set_tx=0 seq_len=0 key_len=0
>1381276411.422908:    addr=c0:c1:c0:dc:08:33
>1381276411.422932: wlan0: State: COMPLETED -> DISCONNECTED
>1381276411.422943: wpa_driver_nl80211_set_operstate: operstate 1->0 (DORMANT)
>1381276411.422953: netlink: Operstate: linkmode=-1, operstate=5
>1381276411.423009: EAPOL: External notification - portEnabled=0
>1381276411.423021: EAPOL: SUPP_PAE entering state DISCONNECTED
>1381276411.423030: EAPOL: Supplicant port status: Unauthorized
>1381276411.423063: EAPOL: SUPP_BE entering state INITIALIZE
>1381276411.423077: EAPOL: Supplicant port status: Unauthorized
>1381276411.423105: EAPOL: External notification - portValid=0
>1381276411.423116: EAPOL: Supplicant port status: Unauthorized
>1381276411.423143: EAPOL: External notification - EAP success=0
>1381276411.423154: EAPOL: Supplicant port status: Unauthorized
>1381276411.432286: wlan0: No keys have been configured - skip key clearing
>1381276411.432326: wlan0: State: DISCONNECTED -> DISCONNECTED
>1381276411.432337: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276411.432347: netlink: Operstate: linkmode=-1, operstate=5
>1381276411.432364: EAPOL: External notification - portEnabled=0
>1381276411.432374: EAPOL: Supplicant port status: Unauthorized
>1381276411.432424: EAPOL: External notification - portValid=0
>1381276411.432434: EAPOL: Supplicant port status: Unauthorized
>1381276411.432465: wlan0: No keys have been configured - skip key clearing
>1381276411.441360: dbus: Unregister network object '/fi/w1/wpa_supplicant1/Interfaces/3/Networks/0'
>1381276411.441633: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276411.441725: wlan0: BSS: Remove id 0 BSSID c0:c1:c0:dc:08:33 SSID 'jagster' due to wpa_bss_flush
>1381276411.441736: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/0'
>1381276411.441775: wlan0: BSS: Remove id 1 BSSID 00:1e:e5:01:83:9c SSID '6000' due to wpa_bss_flush
>1381276411.441786: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/1'
>1381276411.441821: wlan0: BSS: Remove id 3 BSSID 68:7f:74:fc:08:4a SSID 'Schaefer Home' due to wpa_bss_flush
>1381276411.441832: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/3'
>1381276411.441864: wlan0: BSS: Remove id 2 BSSID 00:1d:d4:df:05:f0 SSID 'COGECO WIRELESS' due to wpa_bss_flush
>1381276411.441876: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/2'
>1381276411.441908: wlan0: BSS: Remove id 4 BSSID 34:ef:44:5d:d6:01 SSID 'BELL660' due to wpa_bss_flush
>1381276411.441941: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/4'
>1381276411.441975: wlan0: BSS: Remove id 5 BSSID 00:22:b0:ba:05:55 SSID 'dlink' due to wpa_bss_flush
>1381276411.441986: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/5'
>1381276411.442016: wlan0: Cancelling scan request
>1381276411.442028: wlan0: Cancelling authentication timeout
>1381276411.447323: netlink: Operstate: linkmode=0, operstate=6
>1381276411.504744: nl80211: Set mode ifindex 3 iftype 2 (STATION)
>1381276411.991494: nl80211: Unsubscribe mgmt frames handle 0x2612b40 (mode change)
>1381276411.991536: dbus: Unregister interface object '/fi/w1/wpa_supplicant1/Interfaces/3'
>1381276411.991605: wlan0: CTRL-EVENT-TERMINATING 
>1381276411.991620: dbus: Unregister D-Bus object '/fi/w1/wpa_supplicant1'
>Successfully initialized wpa_supplicant
>wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>wlan0: Trying to associate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>wlan0: Associated with c0:c1:c0:dc:08:33
>wlan0: WPA: Key negotiation completed with c0:c1:c0:dc:08:33 [PTK=CCMP GTK=CCMP]
>wlan0: CTRL-EVENT-CONNECTED - Connection to c0:c1:c0:dc:08:33 completed [id=0 id_str=]
>1381276565.702176: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276565.702581: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276565.703634: Scan requested (ret=0) - scan timeout 30 seconds
>1381276565.704346: nl80211: Event message available
>1381276565.706980: nl80211: Scan trigger
>1381276569.535878: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1381276569.536020: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276569.536102: nl80211: if_removed already cleared - ignore event
>1381276569.536149: nl80211: Event message available
>1381276569.536212: nl80211: New scan results available
>1381276569.536263: wlan0: Event SCAN_RESULTS (3) received
>1381276569.536490: nl80211: Associated on 2422 MHz
>1381276569.536588: nl80211: Associated with c0:c1:c0:dc:08:33
>1381276569.536656: nl80211: Received scan results (5 BSSes)
>1381276569.536728: nl80211: Scan results indicate BSS status with c0:c1:c0:dc:08:33 as associated
>1381276569.536790: wlan0: BSS: Start scan result update 4
>1381276569.536886: BSS: last_scan_res_used=5/32 last_scan_full=0
>1381276569.536933: wlan0: New scan results available
>1381276569.537042: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276569.537083: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276569.537114: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276569.537145: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276569.537183: wlan0: Selecting BSS from priority group 0
>1381276569.537223: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-55 wps
>1381276569.537260: wlan0:    selected based on RSN IE
>1381276569.537297: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276569.537333: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276569.541510: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276569.541933: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276569.542098: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276569.542367: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
>1381276569.542510: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276628.703628: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276628.704063: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276628.704245: Scan requested (ret=0) - scan timeout 30 seconds
>1381276628.704726: nl80211: Event message available
>1381276628.704888: nl80211: Scan trigger
>1381276632.837638: nl80211: Event message available
>1381276632.837746: nl80211: New scan results available
>1381276632.837782: wlan0: Event SCAN_RESULTS (3) received
>1381276632.837934: nl80211: Associated on 2422 MHz
>1381276632.837967: nl80211: Associated with c0:c1:c0:dc:08:33
>1381276632.838013: nl80211: Received scan results (4 BSSes)
>1381276632.838068: nl80211: Scan results indicate BSS status with c0:c1:c0:dc:08:33 as associated
>1381276632.838110: wlan0: BSS: Start scan result update 5
>1381276632.838181: wlan0: BSS: Remove id 5 BSSID 00:1d:d4:df:05:f0 SSID 'COGECO WIRELESS' due to no match in scan
>1381276632.838212: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/5'
>1381276632.838278: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276632.838320: wlan0: New scan results available
>1381276632.838395: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276632.838429: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276632.838457: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276632.838482: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276632.838533: wlan0: Selecting BSS from priority group 0
>1381276632.838568: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-61 wps
>1381276632.838600: wlan0:    selected based on RSN IE
>1381276632.838632: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276632.838663: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276632.840015: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1381276632.840297: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276632.840564: nl80211: if_removed already cleared - ignore event
>1381276632.842971: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276632.843258: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276632.844241: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276632.844923: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
>1381276632.845574: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>
>/***************************************************
>*  This is where I caused the fault.               *
>*  The stuff below showed up about a minute later. *
>***************************************************/
>
>1381276711.006170: RTM_NEWLINK: operstate=1 ifi_flags=0x1003 ([UP])
>1381276711.006302: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276711.006376: nl80211: if_removed already cleared - ignore event
>1381276711.009697: nl80211: Event message available
>1381276711.009782: nl80211: Delete station c0:c1:c0:dc:08:33
>1381276711.010047: nl80211: Event message available
>1381276711.010117: nl80211: MLME event 39
>1381276711.010155: nl80211: MLME event frame - hexdump(len=26): c0 00 00 00 c0 c1 c0 dc 08 33 00 1d 60 ad 03 79 c0 c1 c0 dc 08 33 00 00 04 00
>1381276711.010208: nl80211: Deauthenticate event
>1381276711.010252: wlan0: Event DEAUTH (12) received
>1381276711.010293: wlan0: Deauthentication notification
>1381276711.010331: wlan0:  * reason 4 (locally generated)
>1381276711.010375: wlan0:  * address c0:c1:c0:dc:08:33
>1381276711.010413: Deauthentication frame IE(s) - hexdump(len=0): [NULL]
>1381276711.010454: wlan0: CTRL-EVENT-DISCONNECTED bssid=c0:c1:c0:dc:08:33 reason=4 locally_generated=1
>1381276711.010497: wlan0: Auto connect enabled: try to reconnect (wps=0 wpa_state=9)
>1381276711.010570: wlan0: Setting scan request: 0 sec 100000 usec
>1381276711.010608: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276711.010655: wlan0: Blacklist count 1 --> request scan in 100 ms
>1381276711.010691: wlan0: Not rescheduling scan to ensure that specific SSID scans occur
>1381276711.010945: wlan0: Disconnect event - remove keys
>1381276711.011019: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
>1381276711.014718: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
>1381276711.014963: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
>1381276711.015148: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
>1381276711.016344: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=0x1d55868 key_idx=0 set_tx=0 seq_len=0 key_len=0
>1381276711.016520:    addr=c0:c1:c0:dc:08:33
>1381276711.016724: wlan0: State: COMPLETED -> DISCONNECTED
>1381276711.016882: wpa_driver_nl80211_set_operstate: operstate 1->0 (DORMANT)
>1381276711.017037: netlink: Operstate: linkmode=-1, operstate=5
>1381276711.017280: EAPOL: External notification - portEnabled=0
>1381276711.018068: EAPOL: SUPP_PAE entering state DISCONNECTED
>1381276711.018102: EAPOL: Supplicant port status: Unauthorized
>1381276711.018161: EAPOL: SUPP_BE entering state INITIALIZE
>1381276711.018178: EAPOL: Supplicant port status: Unauthorized
>1381276711.018211: EAPOL: External notification - portValid=0
>1381276711.018226: EAPOL: Supplicant port status: Unauthorized
>1381276711.018256: EAPOL: External notification - EAP success=0
>1381276711.018271: EAPOL: Supplicant port status: Unauthorized
>1381276711.018325: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276711.018341: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276711.018361: nl80211: if_removed already cleared - ignore event
>1381276711.018376: nl80211: Event message available
>1381276711.018395: nl80211: Ignore disconnect event when using userspace SME
>1381276711.018418: nl80211: Event message available
>1381276711.018434: nl80211: Regulatory domain change
>1381276711.018451: wlan0: Event CHANNEL_LIST_CHANGED (31) received
>1381276711.018574: nl80211: Regulatory information - country=00
>1381276711.018593: nl80211: 2402-2472 @ 40 MHz
>1381276711.018606: nl80211: 2457-2482 @ 40 MHz
>1381276711.018619: nl80211: 2474-2494 @ 20 MHz
>1381276711.018632: nl80211: 5170-5250 @ 40 MHz
>1381276711.018644: nl80211: 5735-5835 @ 40 MHz
>1381276711.018664: nl80211: Added 802.11b mode based on 802.11g information
>1381276711.022824: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276711.023024: nl80211: Event message available
>1381276711.023642: nl80211: Regulatory domain change
>1381276711.023694: wlan0: Event CHANNEL_LIST_CHANGED (31) received
>1381276711.023831: nl80211: Regulatory information - country=CA
>1381276711.023882: nl80211: 2402-2472 @ 40 MHz
>1381276711.023927: nl80211: 5170-5250 @ 40 MHz
>1381276711.023972: nl80211: 5250-5330 @ 40 MHz
>1381276711.024018: nl80211: 5490-5710 @ 40 MHz
>1381276711.024063: nl80211: 5735-5835 @ 40 MHz
>1381276711.024114: nl80211: Added 802.11b mode based on 802.11g information
>1381276711.110769: wlan0: State: DISCONNECTED -> SCANNING
>1381276711.111009: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276711.111043: wlan0: Starting AP scan for wildcard SSID
>1381276711.111085: nl80211: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276711.111220: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276711.111642: Scan requested (ret=0) - scan timeout 30 seconds
>1381276711.111675: nl80211: Event message available
>1381276711.111695: nl80211: Scan trigger
>1381276711.116112: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276711.870899: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276711.871364: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276711.871443: nl80211: if_removed already cleared - ignore event
>1381276711.871658: nl80211: Event message available
>1381276711.871715: nl80211: New scan results available
>1381276711.871922: wlan0: Event SCAN_RESULTS (3) received
>1381276711.872258: nl80211: Received scan results (4 BSSes)
>1381276711.872448: wlan0: BSS: Start scan result update 6
>1381276711.872639: dbus: wpas_dbus_bss_signal_prop_changed: Unknown Property value 7
>1381276711.872788: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276711.872917: wlan0: New scan results available
>1381276711.873115: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=1
>1381276711.873163: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276711.873198: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276711.873229: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276711.873582: wlan0: Selecting BSS from priority group 0
>1381276711.873723: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-57 wps
>1381276711.873834: wlan0:    skip - blacklisted (count=1 limit=0)
>1381276711.873942: wlan0: 1: 00:1e:e5:01:83:9c ssid='6000' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-65 wps
>1381276711.874047: wlan0:    skip - SSID mismatch
>1381276711.874161: wlan0: 2: 34:ef:44:5d:d6:01 ssid='BELL660' wpa_ie_len=0 rsn_ie_len=0 caps=0x431 level=-74
>1381276711.874269: wlan0:    skip - SSID mismatch
>1381276711.874383: wlan0: 3: 00:22:b0:ba:05:55 ssid='dlink' wpa_ie_len=0 rsn_ie_len=0 caps=0x521 level=-76 wps
>1381276711.874496: wlan0:    skip - SSID mismatch
>1381276711.874649: wlan0: No APs found - clear blacklist and try again
>1381276711.874754: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276711.874863: wlan0: Selecting BSS from priority group 0
>1381276711.874976: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-57 wps
>1381276711.875087: wlan0:    selected based on RSN IE
>1381276711.875203: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276711.875318: wlan0: Request association: reassociate: 0  selected: c0:c1:c0:dc:08:33  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1381276711.875424: wlan0: Automatic auth_alg selection: 0x1
>1381276711.875550: RSN: PMKSA cache search - network_ctx=(nil) try_opportunistic=0
>1381276711.875670: RSN: Search for BSSID c0:c1:c0:dc:08:33
>1381276711.875771: RSN: No PMKSA cache entry found
>1381276711.875876: wlan0: RSN: using IEEE 802.11i/D9.0
>1381276711.875985: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1381276711.876097: wlan0: WPA: clearing AP WPA IE
>1381276711.876201: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276711.876329: wlan0: WPA: using GTK CCMP
>1381276711.876438: wlan0: WPA: using PTK CCMP
>1381276711.876576: wlan0: WPA: using KEY_MGMT WPA-PSK
>1381276711.876685: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276711.876811: wlan0: Cancelling scan request
>1381276711.876926: wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276711.877033: wlan0: No keys have been configured - skip key clearing
>1381276711.877145: wlan0: State: SCANNING -> AUTHENTICATING
>1381276711.877334: EAPOL: External notification - EAP success=0
>1381276711.877454: EAPOL: Supplicant port status: Unauthorized
>1381276711.877658: EAPOL: External notification - EAP fail=0
>1381276711.877708: EAPOL: Supplicant port status: Unauthorized
>1381276711.877783: EAPOL: External notification - portControl=Auto
>1381276711.877823: EAPOL: Supplicant port status: Unauthorized
>1381276711.877904: nl80211: Authenticate (ifindex=3)
>1381276711.877946:   * bssid=c0:c1:c0:dc:08:33
>1381276711.877977:   * freq=2422
>1381276711.878004:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276711.878060:   * IEs - hexdump(len=0): [NULL]
>1381276711.878089:   * Auth Type 0
>1381276711.880125: nl80211: Authentication request send successfully
>1381276711.880204: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276711.880502: nl80211: Event message available
>1381276711.880650: nl80211: New station c0:c1:c0:dc:08:33
>1381276711.880695: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276711.880851: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276711.881078: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276711.881222: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276712.487829: nl80211: Event message available
>1381276712.487965: nl80211: Delete station c0:c1:c0:dc:08:33
>1381276712.488079: nl80211: Event message available
>1381276712.488325: nl80211: MLME event 37; timeout with c0:c1:c0:dc:08:33
>1381276712.488369: wlan0: Event AUTH_TIMED_OUT (14) received
>1381276712.488563: wlan0: SME: Authentication timed out
>1381276712.488719: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276712.488759: wlan0: Blacklist count 2 --> request scan in 500 ms
>1381276712.488907: wlan0: Setting scan request: 0 sec 500000 usec
>1381276712.488943: wlan0: State: AUTHENTICATING -> DISCONNECTED
>1381276712.489086: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276712.489116: netlink: Operstate: linkmode=-1, operstate=5
>1381276712.489380: EAPOL: External notification - portEnabled=0
>1381276712.489621: EAPOL: Supplicant port status: Unauthorized
>1381276712.489850: EAPOL: External notification - portValid=0
>1381276712.489892: EAPOL: Supplicant port status: Unauthorized
>1381276712.490081: EAPOL: External notification - EAP success=0
>1381276712.490122: EAPOL: Supplicant port status: Unauthorized
>1381276712.494691: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276712.989684: wlan0: State: DISCONNECTED -> SCANNING
>1381276712.989829: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276712.989857: wlan0: Starting AP scan for wildcard SSID
>1381276712.989898: nl80211: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276712.989921: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276712.990068: Scan requested (ret=0) - scan timeout 30 seconds
>1381276712.990099: nl80211: Event message available
>1381276712.990118: nl80211: Scan trigger
>1381276712.995108: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276713.750846: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276713.750978: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276713.751055: nl80211: if_removed already cleared - ignore event
>1381276713.751099: nl80211: Event message available
>1381276713.751163: nl80211: New scan results available
>1381276713.751217: wlan0: Event SCAN_RESULTS (3) received
>1381276713.751468: nl80211: Received scan results (4 BSSes)
>1381276713.751624: wlan0: BSS: Start scan result update 7
>1381276713.751691: dbus: wpas_dbus_bss_signal_prop_changed: Unknown Property value 7
>1381276713.751760: wlan0: BSS: Remove id 4 BSSID 68:7f:74:fc:08:4a SSID 'Schaefer Home' due to no match in scan
>1381276713.751801: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4'
>1381276713.751897: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276713.751946: wlan0: New scan results available
>1381276713.752047: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=1
>1381276713.752092: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276713.752123: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276713.752159: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276713.752233: wlan0: Selecting BSS from priority group 0
>1381276713.752272: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-58 wps
>1381276713.752305: wlan0:    skip - blacklisted (count=1 limit=0)
>1381276713.752348: wlan0: 1: 00:1e:e5:01:83:9c ssid='6000' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-61 wps
>1381276713.752379: wlan0:    skip - SSID mismatch
>1381276713.752414: wlan0: 2: 34:ef:44:5d:d6:01 ssid='BELL660' wpa_ie_len=0 rsn_ie_len=0 caps=0x431 level=-74
>1381276713.752444: wlan0:    skip - SSID mismatch
>1381276713.752479: wlan0: 3: 00:22:b0:ba:05:55 ssid='dlink' wpa_ie_len=0 rsn_ie_len=0 caps=0x521 level=-76 wps
>1381276713.752541: wlan0:    skip - SSID mismatch
>1381276713.752576: wlan0: No APs found - clear blacklist and try again
>1381276713.752603: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276713.752636: wlan0: Selecting BSS from priority group 0
>1381276713.752672: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-58 wps
>1381276713.752713: wlan0:    selected based on RSN IE
>1381276713.752756: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276713.752794: wlan0: Request association: reassociate: 0  selected: c0:c1:c0:dc:08:33  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1381276713.752828: wlan0: Automatic auth_alg selection: 0x1
>1381276713.752856: RSN: PMKSA cache search - network_ctx=(nil) try_opportunistic=0
>1381276713.752883: RSN: Search for BSSID c0:c1:c0:dc:08:33
>1381276713.752911: RSN: No PMKSA cache entry found
>1381276713.752940: wlan0: RSN: using IEEE 802.11i/D9.0
>1381276713.752971: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1381276713.753001: wlan0: WPA: clearing AP WPA IE
>1381276713.753028: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276713.753070: wlan0: WPA: using GTK CCMP
>1381276713.753098: wlan0: WPA: using PTK CCMP
>1381276713.753126: wlan0: WPA: using KEY_MGMT WPA-PSK
>1381276713.753155: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276713.753195: wlan0: Cancelling scan request
>1381276713.753228: wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276713.753258: wlan0: No keys have been configured - skip key clearing
>1381276713.753289: wlan0: State: SCANNING -> AUTHENTICATING
>1381276713.753798: EAPOL: External notification - EAP success=0
>1381276713.753846: EAPOL: Supplicant port status: Unauthorized
>1381276713.753959: EAPOL: External notification - EAP fail=0
>1381276713.753992: EAPOL: Supplicant port status: Unauthorized
>1381276713.754064: EAPOL: External notification - portControl=Auto
>1381276713.754104: EAPOL: Supplicant port status: Unauthorized
>1381276713.754183: nl80211: Authenticate (ifindex=3)
>1381276713.754218:   * bssid=c0:c1:c0:dc:08:33
>1381276713.754258:   * freq=2422
>1381276713.754286:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276713.754342:   * IEs - hexdump(len=0): [NULL]
>1381276713.754370:   * Auth Type 0
>1381276713.760161: nl80211: Authentication request send successfully
>1381276713.760281: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276713.760673: nl80211: Event message available
>1381276713.760738: nl80211: New station c0:c1:c0:dc:08:33
>1381276713.760782: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276713.760986: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276714.367826: nl80211: Event message available
>1381276714.368195: nl80211: Delete station c0:c1:c0:dc:08:33
>1381276714.368253: nl80211: Event message available
>1381276714.368415: nl80211: MLME event 37; timeout with c0:c1:c0:dc:08:33
>1381276714.368458: wlan0: Event AUTH_TIMED_OUT (14) received
>1381276714.368681: wlan0: SME: Authentication timed out
>1381276714.368713: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276714.368750: wlan0: Blacklist count 3 --> request scan in 1000 ms
>1381276714.368900: wlan0: Setting scan request: 1 sec 0 usec
>1381276714.368936: wlan0: State: AUTHENTICATING -> DISCONNECTED
>1381276714.369078: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276714.369109: netlink: Operstate: linkmode=-1, operstate=5
>1381276714.369374: EAPOL: External notification - portEnabled=0
>1381276714.369598: EAPOL: Supplicant port status: Unauthorized
>1381276714.369823: EAPOL: External notification - portValid=0
>1381276714.369864: EAPOL: Supplicant port status: Unauthorized
>1381276714.370050: EAPOL: External notification - EAP success=0
>1381276714.370091: EAPOL: Supplicant port status: Unauthorized
>1381276714.374498: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276715.370173: wlan0: State: DISCONNECTED -> SCANNING
>1381276715.370318: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276715.370346: wlan0: Starting AP scan for wildcard SSID
>1381276715.370387: nl80211: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276715.370410: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276715.370577: Scan requested (ret=0) - scan timeout 30 seconds
>1381276715.370608: nl80211: Event message available
>1381276715.370627: nl80211: Scan trigger
>1381276715.375593: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276716.129927: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276716.130045: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276716.130116: nl80211: if_removed already cleared - ignore event
>1381276716.130150: nl80211: Event message available
>1381276716.130206: nl80211: New scan results available
>1381276716.130248: wlan0: Event SCAN_RESULTS (3) received
>1381276716.130484: nl80211: Received scan results (6 BSSes)
>1381276716.130621: wlan0: BSS: Start scan result update 8
>1381276716.130703: wlan0: BSS: Add new id 6 BSSID 00:1d:d4:df:05:f0 SSID 'COGECO WIRELESS'
>1381276716.130736: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/6'
>1381276716.131000: wlan0: BSS: Add new id 7 BSSID 68:7f:74:fc:08:4a SSID 'Schaefer Home'
>1381276716.131039: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7'
>1381276716.131290: BSS: last_scan_res_used=6/32 last_scan_full=0
>1381276716.131343: wlan0: New scan results available
>1381276716.131449: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=1
>1381276716.131488: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276716.132571: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276716.132926: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276716.133490: wlan0: Selecting BSS from priority group 0
>1381276716.133873: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-55 wps
>1381276716.134928: wlan0:    skip - blacklisted (count=1 limit=0)
>1381276716.135264: wlan0: 1: 00:1e:e5:01:83:9c ssid='6000' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-61 wps
>1381276716.135611: wlan0:    skip - SSID mismatch
>1381276716.135949: wlan0: 2: 00:1d:d4:df:05:f0 ssid='COGECO WIRELESS' wpa_ie_len=0 rsn_ie_len=20 caps=0xc11 level=-81
>1381276716.136277: wlan0:    skip - SSID mismatch
>1381276716.136628: wlan0: 3: 68:7f:74:fc:08:4a ssid='Schaefer Home' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-81 wps
>1381276716.136961: wlan0:    skip - SSID mismatch
>1381276716.137291: wlan0: 4: 34:ef:44:5d:d6:01 ssid='BELL660' wpa_ie_len=0 rsn_ie_len=0 caps=0x431 level=-76
>1381276716.137631: wlan0:    skip - SSID mismatch
>1381276716.137964: wlan0: 5: 00:22:b0:ba:05:55 ssid='dlink' wpa_ie_len=0 rsn_ie_len=0 caps=0x521 level=-76 wps
>1381276716.138334: wlan0:    skip - SSID mismatch
>1381276716.138912: wlan0: No APs found - clear blacklist and try again
>1381276716.139236: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276716.139589: wlan0: Selecting BSS from priority group 0
>1381276716.139927: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-55 wps
>1381276716.140256: wlan0:    selected based on RSN IE
>1381276716.140595: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276716.140841: wlan0: Request association: reassociate: 0  selected: c0:c1:c0:dc:08:33  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1381276716.141058: wlan0: Automatic auth_alg selection: 0x1
>1381276716.141171: RSN: PMKSA cache search - network_ctx=(nil) try_opportunistic=0
>1381276716.141379: RSN: Search for BSSID c0:c1:c0:dc:08:33
>1381276716.141494: RSN: No PMKSA cache entry found
>1381276716.141774: wlan0: RSN: using IEEE 802.11i/D9.0
>1381276716.141840: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1381276716.143915: wlan0: WPA: clearing AP WPA IE
>1381276716.144054: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276716.144112: wlan0: WPA: using GTK CCMP
>1381276716.144159: wlan0: WPA: using PTK CCMP
>1381276716.144205: wlan0: WPA: using KEY_MGMT WPA-PSK
>1381276716.144251: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276716.144305: wlan0: Cancelling scan request
>1381276716.144355: wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276716.144402: wlan0: No keys have been configured - skip key clearing
>1381276716.144448: wlan0: State: SCANNING -> AUTHENTICATING
>1381276716.144654: EAPOL: External notification - EAP success=0
>1381276716.144723: EAPOL: Supplicant port status: Unauthorized
>1381276716.144844: EAPOL: External notification - EAP fail=0
>1381276716.144895: EAPOL: Supplicant port status: Unauthorized
>1381276716.144964: EAPOL: External notification - portControl=Auto
>1381276716.145012: EAPOL: Supplicant port status: Unauthorized
>1381276716.145087: nl80211: Authenticate (ifindex=3)
>1381276716.145140:   * bssid=c0:c1:c0:dc:08:33
>1381276716.145188:   * freq=2422
>1381276716.145234:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276716.145305:   * IEs - hexdump(len=0): [NULL]
>1381276716.145350:   * Auth Type 0
>1381276716.145841: nl80211: Authentication request send successfully
>1381276716.145931: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276716.147043: nl80211: Event message available
>1381276716.147308: nl80211: New station c0:c1:c0:dc:08:33
>1381276716.147371: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276716.148122: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276716.148863: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276716.753835: nl80211: Event message available
>1381276716.754068: nl80211: Delete station c0:c1:c0:dc:08:33
>1381276716.754259: nl80211: Event message available
>1381276716.754393: nl80211: MLME event 37; timeout with c0:c1:c0:dc:08:33
>1381276716.754569: wlan0: Event AUTH_TIMED_OUT (14) received
>1381276716.754708: wlan0: SME: Authentication timed out
>1381276716.754817: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276716.754933: wlan0: Blacklist count 4 --> request scan in 5000 ms
>1381276716.755042: wlan0: Setting scan request: 5 sec 0 usec
>1381276716.755155: wlan0: State: AUTHENTICATING -> DISCONNECTED
>1381276716.755260: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276716.755370: netlink: Operstate: linkmode=-1, operstate=5
>1381276716.755665: EAPOL: External notification - portEnabled=0
>1381276716.755717: EAPOL: Supplicant port status: Unauthorized
>1381276716.755836: EAPOL: External notification - portValid=0
>1381276716.755877: EAPOL: Supplicant port status: Unauthorized
>1381276716.755950: EAPOL: External notification - EAP success=0
>1381276716.755990: EAPOL: Supplicant port status: Unauthorized
>1381276716.760755: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276721.757933: wlan0: State: DISCONNECTED -> SCANNING
>1381276721.758193: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276721.758270: wlan0: Starting AP scan for wildcard SSID
>1381276721.758368: nl80211: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276721.758429: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276721.758707: Scan requested (ret=0) - scan timeout 30 seconds
>1381276721.758776: nl80211: Event message available
>1381276721.758816: nl80211: Scan trigger
>1381276721.763426: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276722.517795: nl80211: Event message available
>1381276722.517942: nl80211: New scan results available
>1381276722.517991: wlan0: Event SCAN_RESULTS (3) received
>1381276722.518264: nl80211: Received scan results (6 BSSes)
>1381276722.518428: wlan0: BSS: Start scan result update 9
>1381276722.518573: BSS: last_scan_res_used=6/32 last_scan_full=0
>1381276722.518635: wlan0: New scan results available
>1381276722.518765: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=1
>1381276722.518805: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276722.518834: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276722.518864: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276722.518902: wlan0: Selecting BSS from priority group 0
>1381276722.518940: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-55 wps
>1381276722.518973: wlan0:    skip - blacklisted (count=1 limit=0)
>1381276722.519008: wlan0: 1: 00:1e:e5:01:83:9c ssid='6000' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-63 wps
>1381276722.519038: wlan0:    skip - SSID mismatch
>1381276722.519072: wlan0: 2: 00:1d:d4:df:05:f0 ssid='COGECO WIRELESS' wpa_ie_len=0 rsn_ie_len=20 caps=0xc11 level=-81
>1381276722.519102: wlan0:    skip - SSID mismatch
>1381276722.519136: wlan0: 3: 68:7f:74:fc:08:4a ssid='Schaefer Home' wpa_ie_len=22 rsn_ie_len=20 caps=0x431 level=-81 wps
>1381276722.519165: wlan0:    skip - SSID mismatch
>1381276722.519200: wlan0: 4: 34:ef:44:5d:d6:01 ssid='BELL660' wpa_ie_len=0 rsn_ie_len=0 caps=0x431 level=-73
>1381276722.519230: wlan0:    skip - SSID mismatch
>1381276722.519265: wlan0: 5: 00:22:b0:ba:05:55 ssid='dlink' wpa_ie_len=0 rsn_ie_len=0 caps=0x521 level=-76 wps
>1381276722.519294: wlan0:    skip - SSID mismatch
>1381276722.519323: wlan0: No APs found - clear blacklist and try again
>1381276722.519350: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276722.519385: wlan0: Selecting BSS from priority group 0
>1381276722.519419: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-55 wps
>1381276722.519451: wlan0:    selected based on RSN IE
>1381276722.519484: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276722.519549: wlan0: Request association: reassociate: 0  selected: c0:c1:c0:dc:08:33  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1381276722.519593: wlan0: Automatic auth_alg selection: 0x1
>1381276722.519623: RSN: PMKSA cache search - network_ctx=(nil) try_opportunistic=0
>1381276722.519661: RSN: Search for BSSID c0:c1:c0:dc:08:33
>1381276722.519693: RSN: No PMKSA cache entry found
>1381276722.519721: wlan0: RSN: using IEEE 802.11i/D9.0
>1381276722.519752: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1381276722.519861: wlan0: WPA: clearing AP WPA IE
>1381276722.519890: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276722.519938: wlan0: WPA: using GTK CCMP
>1381276722.519968: wlan0: WPA: using PTK CCMP
>1381276722.519996: wlan0: WPA: using KEY_MGMT WPA-PSK
>1381276722.520025: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276722.520066: wlan0: Cancelling scan request
>1381276722.520109: wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276722.520139: wlan0: No keys have been configured - skip key clearing
>1381276722.520169: wlan0: State: SCANNING -> AUTHENTICATING
>1381276722.520279: EAPOL: External notification - EAP success=0
>1381276722.520321: EAPOL: Supplicant port status: Unauthorized
>1381276722.520439: EAPOL: External notification - EAP fail=0
>1381276722.520472: EAPOL: Supplicant port status: Unauthorized
>1381276722.520574: EAPOL: External notification - portControl=Auto
>1381276722.520611: EAPOL: Supplicant port status: Unauthorized
>1381276722.520690: nl80211: Authenticate (ifindex=3)
>1381276722.520724:   * bssid=c0:c1:c0:dc:08:33
>1381276722.520752:   * freq=2422
>1381276722.520779:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276722.520824:   * IEs - hexdump(len=0): [NULL]
>1381276722.520851:   * Auth Type 0
>1381276722.529191: nl80211: Authentication request send successfully
>1381276722.529321: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276722.529602: nl80211: Event message available
>1381276722.529668: nl80211: New station c0:c1:c0:dc:08:33
>1381276722.529714: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276722.529867: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276722.529904: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276722.529978: nl80211: if_removed already cleared - ignore event
>1381276722.530028: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276723.136711: nl80211: Event message available
>1381276723.136823: nl80211: Delete station c0:c1:c0:dc:08:33
>1381276723.136957: nl80211: Event message available
>1381276723.137019: nl80211: MLME event 37; timeout with c0:c1:c0:dc:08:33
>1381276723.137061: wlan0: Event AUTH_TIMED_OUT (14) received
>1381276723.137100: wlan0: SME: Authentication timed out
>1381276723.137130: Added BSSID c0:c1:c0:dc:08:33 into blacklist
>1381276723.137166: wlan0: Blacklist count 5 --> request scan in 10000 ms
>1381276723.137196: wlan0: Setting scan request: 10 sec 0 usec
>1381276723.137230: wlan0: State: AUTHENTICATING -> DISCONNECTED
>1381276723.137258: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276723.137286: netlink: Operstate: linkmode=-1, operstate=5
>1381276723.137446: EAPOL: External notification - portEnabled=0
>1381276723.137483: EAPOL: Supplicant port status: Unauthorized
>1381276723.137631: EAPOL: External notification - portValid=0
>1381276723.137669: EAPOL: Supplicant port status: Unauthorized
>1381276723.137742: EAPOL: External notification - EAP success=0
>1381276723.137774: EAPOL: Supplicant port status: Unauthorized
>1381276723.142736: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276726.996756: dbus: fi.w1.wpa_supplicant1.Interface.RemoveNetwork (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276726.996990: dbus: Unregister network object '/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
>1381276727.003550: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276727.003631: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276727.003774: Scan requested (ret=0) - scan timeout 30 seconds
>1381276727.003904: nl80211: Event message available
>1381276727.003942: nl80211: Scan trigger
>1381276727.763796: nl80211: Event message available
>1381276727.763951: nl80211: New scan results available
>1381276727.764008: wlan0: Event SCAN_RESULTS (3) received
>1381276727.764294: nl80211: Received scan results (6 BSSes)
>1381276727.764424: wlan0: BSS: Start scan result update 10
>1381276727.764562: BSS: last_scan_res_used=6/32 last_scan_full=0
>1381276727.764621: wlan0: New scan results available
>1381276727.764744: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=1
>1381276727.764782: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276727.764812: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276727.764841: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276727.764877: wlan0: No APs found - clear blacklist and try again
>1381276727.764905: Removed BSSID c0:c1:c0:dc:08:33 from blacklist (clear)
>1381276727.764936: wlan0: No suitable network found
>1381276727.764967: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276727.764998: wlan0: State: DISCONNECTED -> INACTIVE
>1381276727.765095: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276727.765162: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276727.765194: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276727.765260: nl80211: if_removed already cleared - ignore event
>1381276727.769235: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276727.769555: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276727.769758: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276727.769910: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276730.702681: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276730.702880: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276730.703102: Scan requested (ret=0) - scan timeout 30 seconds
>1381276730.703396: nl80211: Event message available
>1381276730.703454: nl80211: Scan trigger
>1381276731.464747: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276731.464864: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276731.464939: nl80211: if_removed already cleared - ignore event
>1381276731.464974: nl80211: Event message available
>1381276731.465025: nl80211: New scan results available
>1381276731.465067: wlan0: Event SCAN_RESULTS (3) received
>1381276731.465311: nl80211: Received scan results (6 BSSes)
>1381276731.465408: wlan0: BSS: Start scan result update 11
>1381276731.465488: BSS: last_scan_res_used=6/32 last_scan_full=0
>1381276731.465579: wlan0: New scan results available
>1381276731.465706: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276731.465755: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276731.465785: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276731.465815: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276731.465850: wlan0: No suitable network found
>1381276731.465883: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276731.465914: wlan0: State: INACTIVE -> INACTIVE
>1381276731.465946: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276731.470275: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276731.470480: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276731.470664: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276731.470847: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276733.139092: wlan0: No enabled networks - do not scan
>1381276733.139216: wlan0: State: INACTIVE -> INACTIVE
>1381276753.703398: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276753.703632: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276753.703861: Scan requested (ret=0) - scan timeout 30 seconds
>1381276753.704173: nl80211: Event message available
>1381276753.704236: nl80211: Scan trigger
>1381276754.464802: nl80211: Event message available
>1381276754.464945: nl80211: New scan results available
>1381276754.464999: wlan0: Event SCAN_RESULTS (3) received
>1381276754.465280: nl80211: Received scan results (4 BSSes)
>1381276754.465451: wlan0: BSS: Start scan result update 12
>1381276754.465612: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276754.465672: wlan0: New scan results available
>1381276754.465819: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276754.465870: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276754.465907: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276754.465947: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276754.465991: wlan0: No suitable network found
>1381276754.466028: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276754.466065: wlan0: State: INACTIVE -> INACTIVE
>1381276754.466101: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276754.466583: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276754.466649: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276754.466722: nl80211: if_removed already cleared - ignore event
>1381276754.470260: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276754.470692: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276754.470898: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1
>1381276754.471052: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276786.706092: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276786.706549: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276786.706780: Scan requested (ret=0) - scan timeout 30 seconds
>1381276786.707645: nl80211: Event message available
>1381276786.707719: nl80211: Scan trigger
>1381276787.465850: nl80211: Event message available
>1381276787.465986: nl80211: New scan results available
>1381276787.466034: wlan0: Event SCAN_RESULTS (3) received
>1381276787.466264: nl80211: Received scan results (4 BSSes)
>1381276787.466358: wlan0: BSS: Start scan result update 13
>1381276787.466437: wlan0: BSS: Remove id 6 BSSID 00:1d:d4:df:05:f0 SSID 'COGECO WIRELESS' due to no match in scan
>1381276787.466474: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/6'
>1381276787.466612: wlan0: BSS: Remove id 7 BSSID 68:7f:74:fc:08:4a SSID 'Schaefer Home' due to no match in scan
>1381276787.466658: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7'
>1381276787.466738: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276787.466800: wlan0: New scan results available
>1381276787.466905: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276787.466945: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276787.466980: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276787.467013: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276787.467053: wlan0: No suitable network found
>1381276787.467127: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276787.467158: wlan0: State: INACTIVE -> INACTIVE
>1381276787.467189: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276787.467245: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276787.467279: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276787.467344: nl80211: if_removed already cleared - ignore event
>1381276787.471454: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276787.471808: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0
>1381276787.471976: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276829.701351: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/1)
>1381276829.701590: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276829.701817: Scan requested (ret=0) - scan timeout 30 seconds
>1381276829.702110: nl80211: Event message available
>1381276829.702174: nl80211: Scan trigger
>1381276830.465024: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276830.465163: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276830.465253: nl80211: if_removed already cleared - ignore event
>1381276830.465301: nl80211: Event message available
>1381276830.465364: nl80211: New scan results available
>1381276830.465416: wlan0: Event SCAN_RESULTS (3) received
>1381276830.465707: nl80211: Received scan results (4 BSSes)
>1381276830.465814: wlan0: BSS: Start scan result update 14
>1381276830.465886: BSS: last_scan_res_used=4/32 last_scan_full=0
>1381276830.465933: wlan0: New scan results available
>1381276830.466042: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276830.466085: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276830.466119: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276830.466152: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276830.466191: wlan0: No suitable network found
>1381276830.466227: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276830.466262: wlan0: State: INACTIVE -> INACTIVE
>1381276830.466297: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276830.470695: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1
>1381276830.471097: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2
>1381276830.471270: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
>1381276840.343936: dbus: fi.w1.wpa_supplicant1.RemoveInterface (/fi/w1/wpa_supplicant1)
>1381276840.344486: wlan0: Removing interface wlan0
>1381276840.344682: wlan0: Request to deauthenticate - bssid=00:00:00:00:00:00 pending_bssid=00:00:00:00:00:00 reason=3 state=INACTIVE
>1381276840.344843: wlan0: No keys have been configured - skip key clearing
>1381276840.345005: wlan0: State: INACTIVE -> DISCONNECTED
>1381276840.345160: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276840.345318: netlink: Operstate: linkmode=-1, operstate=5
>1381276840.359889: EAPOL: External notification - portEnabled=0
>1381276840.362073: EAPOL: Supplicant port status: Unauthorized
>1381276840.362157: EAPOL: External notification - portValid=0
>1381276840.362179: EAPOL: Supplicant port status: Unauthorized
>1381276840.362221: wlan0: No keys have been configured - skip key clearing
>1381276840.365874: wlan0: BSS: Remove id 0 BSSID c0:c1:c0:dc:08:33 SSID 'jagster' due to wpa_bss_flush
>1381276840.365927: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/0'
>1381276840.365997: wlan0: BSS: Remove id 1 BSSID 00:1e:e5:01:83:9c SSID '6000' due to wpa_bss_flush
>1381276840.366040: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/1'
>1381276840.366081: wlan0: BSS: Remove id 2 BSSID 34:ef:44:5d:d6:01 SSID 'BELL660' due to wpa_bss_flush
>1381276840.366100: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/2'
>1381276840.366137: wlan0: BSS: Remove id 3 BSSID 00:22:b0:ba:05:55 SSID 'dlink' due to wpa_bss_flush
>1381276840.366153: dbus: Unregister BSS object '/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3'
>1381276840.366188: wlan0: Cancelling scan request
>1381276840.366208: wlan0: Cancelling authentication timeout
>1381276840.369579: netlink: Operstate: linkmode=0, operstate=6
>1381276840.369667: nl80211: Set mode ifindex 3 iftype 2 (STATION)
>1381276840.369731: nl80211: Unsubscribe mgmt frames handle 0x1d584b0 (mode change)
>1381276840.369787: dbus: Unregister interface object '/fi/w1/wpa_supplicant1/Interfaces/1'
>1381276840.369874: nl80211: Ignore event for foreign ifindex 3
>1381276846.329495: nl80211: Ignore event for foreign ifindex 3
>1381276846.330477: dbus: fi.w1.wpa_supplicant1.CreateInterface (/fi/w1/wpa_supplicant1)
>1381276846.330532: Initializing interface 'wlan0' conf 'N/A' driver 'nl80211,wext' ctrl_interface 'N/A' bridge 'N/A'
>1381276846.330609: nl80211: interface wlan0 in phy phy0
>1381276846.330636: rfkill: initial event: idx=0 type=1 op=0 soft=0 hard=0
>1381276846.330671: nl80211: Set mode ifindex 3 iftype 2 (STATION)
>1381276846.330725: nl80211: Subscribe to mgmt frames with non-AP handle 0x1d583e0
>1381276846.330743: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330756: nl80211: Register frame match - hexdump(len=2): 04 0a
>1381276846.330784: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330799: nl80211: Register frame match - hexdump(len=2): 04 0b
>1381276846.330822: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330837: nl80211: Register frame match - hexdump(len=2): 04 0c
>1381276846.330860: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330875: nl80211: Register frame match - hexdump(len=2): 04 0d
>1381276846.330897: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330912: nl80211: Register frame match - hexdump(len=6): 04 09 50 6f 9a 09
>1381276846.330936: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330951: nl80211: Register frame match - hexdump(len=5): 7f 50 6f 9a 09
>1381276846.330974: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.330989: nl80211: Register frame match - hexdump(len=1): 06
>1381276846.331011: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.331026: nl80211: Register frame match - hexdump(len=2): 0a 07
>1381276846.331049: nl80211: Register frame type=0xd0 nl_handle=0x1d583e0
>1381276846.331064: nl80211: Register frame match - hexdump(len=2): 0a 11
>1381276846.331091: netlink: Operstate: linkmode=1, operstate=5
>1381276846.331162: nl80211: Using driver-based off-channel TX
>1381276846.331192: nl80211: driver param='(null)'
>1381276846.331278: nl80211: Regulatory information - country=CA
>1381276846.331294: nl80211: 2402-2472 @ 40 MHz
>1381276846.331307: nl80211: 5170-5250 @ 40 MHz
>1381276846.331320: nl80211: 5250-5330 @ 40 MHz
>1381276846.331333: nl80211: 5490-5710 @ 40 MHz
>1381276846.331346: nl80211: 5735-5835 @ 40 MHz
>1381276846.331365: nl80211: Added 802.11b mode based on 802.11g information
>1381276846.336767: wlan0: Own MAC address: 00:1d:60:ad:03:79
>1381276846.336855: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=0 set_tx=0 seq_len=0 key_len=0
>1381276846.336942: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=1 set_tx=0 seq_len=0 key_len=0
>1381276846.337007: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=2 set_tx=0 seq_len=0 key_len=0
>1381276846.337059: wpa_driver_nl80211_set_key: ifindex=3 alg=0 addr=(nil) key_idx=3 set_tx=0 seq_len=0 key_len=0
>1381276846.337105: wlan0: RSN: flushing PMKID list in the driver
>1381276846.337134: nl80211: Flush PMKIDs
>1381276846.337186: wlan0: State: DISCONNECTED -> INACTIVE
>1381276846.337247: WPS: Set UUID for interface wlan0
>1381276846.337279: WPS: UUID based on MAC address - hexdump(len=16): c7 eb a0 08 aa a5 56 b3 91 5d 0c b6 b3 d1 c7 76
>1381276846.340672: EAPOL: SUPP_PAE entering state DISCONNECTED
>1381276846.340726: EAPOL: Supplicant port status: Unauthorized
>1381276846.340811: EAPOL: KEY_RX entering state NO_KEY_RECEIVE
>1381276846.340832: EAPOL: SUPP_BE entering state INITIALIZE
>1381276846.340851: EAP: EAP entering state DISABLED
>1381276846.340869: EAPOL: Supplicant port status: Unauthorized
>1381276846.340916: EAPOL: Supplicant port status: Unauthorized
>1381276846.340983: dbus: Register interface object '/fi/w1/wpa_supplicant1/Interfaces/3'
>1381276846.341409: wlan0: Added interface wlan0
>1381276846.341438: wlan0: State: INACTIVE -> DISCONNECTED
>1381276846.341457: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276846.341477: netlink: Operstate: linkmode=-1, operstate=5
>1381276846.343058: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276846.343753: dbus: fi.w1.wpa_supplicant1.Interface.NetworkReply (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276846.347178: dbus: org.freedesktop.DBus.Properties.GetAll (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276846.352846: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276846.352986: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276846.353168: Scan requested (ret=0) - scan timeout 10 seconds
>1381276846.353598: nl80211: Event message available
>1381276846.353641: nl80211: Scan trigger
>1381276846.353942: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276846.353983: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276846.354029: nl80211: Scan trigger failed: ret=-16 (Device or resource busy)
>1381276847.111862: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276847.111996: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276847.112082: nl80211: if_removed already cleared - ignore event
>1381276847.112127: nl80211: Event message available
>1381276847.112191: nl80211: New scan results available
>1381276847.112245: wlan0: Event SCAN_RESULTS (3) received
>1381276847.112423: nl80211: Received scan results (5 BSSes)
>1381276847.112626: wlan0: BSS: Start scan result update 1
>1381276847.112681: wlan0: BSS: Add new id 0 BSSID c0:c1:c0:dc:08:33 SSID 'jagster'
>1381276847.112715: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/0'
>1381276847.113034: wlan0: BSS: Add new id 1 BSSID 00:1e:e5:01:83:9c SSID '6000'
>1381276847.113083: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/1'
>1381276847.113360: wlan0: BSS: Add new id 2 BSSID 34:ef:44:5d:d6:01 SSID 'BELL660'
>1381276847.113397: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/2'
>1381276847.113628: wlan0: BSS: Add new id 3 BSSID 98:2c:be:49:21:f1 SSID 'BELL266'
>1381276847.113669: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/3'
>1381276847.113871: wlan0: BSS: Add new id 4 BSSID 00:22:b0:ba:05:55 SSID 'dlink'
>1381276847.113907: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/4'
>1381276847.114133: BSS: last_scan_res_used=5/32 last_scan_full=0
>1381276847.114184: wlan0: New scan results available
>1381276847.114282: WPS: AP c0:c1:c0:dc:08:33 type 0 added
>1381276847.114323: WPS: AP 00:1e:e5:01:83:9c type 0 added
>1381276847.114358: WPS: AP 00:22:b0:ba:05:55 type 0 added
>1381276847.114389: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276847.114419: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276847.114448: WPS: AP[2] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276847.114485: wlan0: No suitable network found
>1381276847.114538: wlan0: Short-circuit new scan request since there are no enabled networks
>1381276847.114576: wlan0: State: DISCONNECTED -> INACTIVE
>1381276847.114679: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276847.124914: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276847.223959: dbus: org.freedesktop.DBus.Properties.Set (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276847.235225: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276847.235283: dbus: Register network object '/fi/w1/wpa_supplicant1/Interfaces/3/Networks/0'
>1381276847.235392: scan_ssid=1 (0x1)
>1381276847.235412: proto: 0x3
>1381276847.235432: ssid - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276847.235456: key_mgmt: 0x2
>1381276847.235472: PSK (ASCII passphrase) - hexdump_ascii(len=8): [REMOVED]
>1381276847.254450: PSK (from passphrase) - hexdump(len=32): [REMOVED]
>1381276847.255136: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276847.255180: wlan0: Setting scan request: 0 sec 0 usec
>1381276847.255817: wlan0: State: INACTIVE -> SCANNING
>1381276847.255916: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276847.255949: wlan0: Starting AP scan for wildcard SSID
>1381276847.256030: nl80211: Scan SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276847.256059: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276847.256210: Scan requested (ret=0) - scan timeout 30 seconds
>1381276847.256242: nl80211: Event message available
>1381276847.256266: nl80211: Scan trigger
>1381276847.261013: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276847.341114: EAPOL: disable timer tick
>1381276847.341178: EAPOL: Supplicant port status: Unauthorized
>1381276848.014606: nl80211: Event message available
>1381276848.014672: nl80211: New scan results available
>1381276848.014694: wlan0: Event SCAN_RESULTS (3) received
>1381276848.014891: nl80211: Received scan results (5 BSSes)
>1381276848.014939: wlan0: BSS: Start scan result update 2
>1381276848.014990: BSS: last_scan_res_used=5/32 last_scan_full=0
>1381276848.015014: wlan0: New scan results available
>1381276848.015218: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276848.015241: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276848.015259: WPS: AP[2] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276848.015278: wlan0: Selecting BSS from priority group 0
>1381276848.015296: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-57 wps
>1381276848.015313: wlan0:    selected based on RSN IE
>1381276848.015330: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276848.015352: wlan0: Request association: reassociate: 1  selected: c0:c1:c0:dc:08:33  bssid: 00:00:00:00:00:00  pending: 00:00:00:00:00:00  wpa_state: SCANNING
>1381276848.015367: wlan0: Automatic auth_alg selection: 0x1
>1381276848.015380: RSN: PMKSA cache search - network_ctx=0x1d6f350 try_opportunistic=0
>1381276848.015394: RSN: Search for BSSID c0:c1:c0:dc:08:33
>1381276848.015407: RSN: No PMKSA cache entry found
>1381276848.015421: wlan0: RSN: using IEEE 802.11i/D9.0
>1381276848.015439: wlan0: WPA: Selected cipher suites: group 16 pairwise 16 key_mgmt 2 proto 2
>1381276848.015453: wlan0: WPA: clearing AP WPA IE
>1381276848.015465: WPA: set AP RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276848.015484: wlan0: WPA: using GTK CCMP
>1381276848.015498: wlan0: WPA: using PTK CCMP
>1381276848.015525: wlan0: WPA: using KEY_MGMT WPA-PSK
>1381276848.015546: WPA: Set own WPA IE default - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276848.015568: wlan0: Cancelling scan request
>1381276848.015584: wlan0: SME: Trying to authenticate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276848.015599: wlan0: No keys have been configured - skip key clearing
>1381276848.015632: wlan0: State: SCANNING -> AUTHENTICATING
>1381276848.015724: EAPOL: External notification - EAP success=0
>1381276848.015746: EAPOL: Supplicant port status: Unauthorized
>1381276848.015805: EAPOL: External notification - EAP fail=0
>1381276848.015824: EAPOL: Supplicant port status: Unauthorized
>1381276848.015856: EAPOL: External notification - portControl=Auto
>1381276848.015874: EAPOL: Supplicant port status: Unauthorized
>1381276848.015907: nl80211: Authenticate (ifindex=3)
>1381276848.015926:   * bssid=c0:c1:c0:dc:08:33
>1381276848.015939:   * freq=2422
>1381276848.015953:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276848.015974:   * IEs - hexdump(len=0): [NULL]
>1381276848.015990:   * Auth Type 0
>1381276848.024097: nl80211: Authentication request send successfully
>1381276848.024156: RSN: Ignored PMKID candidate without preauth flag
>1381276848.024209: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276848.024923: nl80211: Event message available
>1381276848.024958: nl80211: New station c0:c1:c0:dc:08:33
>1381276848.024981: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/0
>1381276848.025280: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
>1381276848.025302: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276848.025334: nl80211: if_removed already cleared - ignore event
>1381276848.025355: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/4
>1381276848.027619: nl80211: Event message available
>1381276848.027735: nl80211: MLME event 37
>1381276848.027783: nl80211: MLME event frame - hexdump(len=41): b0 00 3a 01 00 1d 60 ad 03 79 c0 c1 c0 dc 08 33 c0 c1 c0 dc 08 33 00 c7 00 00 02 00 00 00 dd 09 00 10 18 02 02 f0 04 00 00
>1381276848.027838: nl80211: Authenticate event
>1381276848.027888: wlan0: Event AUTH (11) received
>1381276848.027937: wlan0: SME: Authentication response: peer=c0:c1:c0:dc:08:33 auth_type=0 auth_transaction=2 status_code=0
>1381276848.027987: SME: Authentication response IEs - hexdump(len=11): dd 09 00 10 18 02 02 f0 04 00 00
>1381276848.028040: wlan0: Trying to associate with c0:c1:c0:dc:08:33 (SSID='jagster' freq=2422 MHz)
>1381276848.028088: wlan0: State: AUTHENTICATING -> ASSOCIATING
>1381276848.028133: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276848.028178: netlink: Operstate: linkmode=-1, operstate=5
>1381276848.028301: WPA: set own WPA/RSN IE - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276848.028446: nl80211: Associate (ifindex=3)
>1381276848.028502:   * bssid=c0:c1:c0:dc:08:33
>1381276848.028682:   * freq=2422
>1381276848.028730:   * SSID - hexdump_ascii(len=7):
>     6a 61 67 73 74 65 72                              jagster         
>1381276848.028809:   * IEs - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276848.028863:   * pairwise=0xfac04
>1381276848.028909:   * group=0xfac04
>1381276848.028996: nl80211: Association request send successfully
>1381276848.032111: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1381276848.032315: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276848.032486: nl80211: if_removed already cleared - ignore event
>1381276848.032735: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1381276848.032888: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276848.033046: nl80211: if_removed already cleared - ignore event
>1381276848.033196: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
>1381276848.033345: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276848.033504: nl80211: if_removed already cleared - ignore event
>1381276848.033672: nl80211: Event message available
>1381276848.033831: nl80211: MLME event 38
>1381276848.033981: nl80211: MLME event frame - hexdump(len=57): 10 00 3a 01 00 1d 60 ad 03 79 c0 c1 c0 dc 08 33 c0 c1 c0 dc 08 33 10 c7 11 04 00 00 03 c0 01 08 82 84 8b 96 24 b0 48 6c 32 04 8c 12 98 60 dd 09 00 10 18 02 02 f0 04 00 00
>1381276848.034159: nl80211: Associate event
>1381276848.034311: wlan0: Event ASSOC (0) received
>1381276848.034459: wlan0: Association info event
>1381276848.034630: resp_ies - hexdump(len=27): 01 08 82 84 8b 96 24 b0 48 6c 32 04 8c 12 98 60 dd 09 00 10 18 02 02 f0 04 00 00
>1381276848.034787: wlan0: freq=2422 MHz
>1381276848.034937: wlan0: State: ASSOCIATING -> ASSOCIATED
>1381276848.035238: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
>1381276848.035391: netlink: Operstate: linkmode=-1, operstate=5
>1381276848.035635: wlan0: Associated to a new BSS: BSSID=c0:c1:c0:dc:08:33
>1381276848.035839: wlan0: No keys have been configured - skip key clearing
>1381276848.035891: wlan0: Associated with c0:c1:c0:dc:08:33
>1381276848.035944: wlan0: WPA: Association event - clear replay counter
>1381276848.035996: wlan0: WPA: Clear old PTK
>1381276848.036046: EAPOL: External notification - portEnabled=0
>1381276848.036097: EAPOL: Supplicant port status: Unauthorized
>1381276848.036193: EAPOL: External notification - portValid=0
>1381276848.036243: EAPOL: Supplicant port status: Unauthorized
>1381276848.036311: EAPOL: External notification - EAP success=0
>1381276848.036385: EAPOL: Supplicant port status: Unauthorized
>1381276848.036451: EAPOL: External notification - portEnabled=1
>1381276848.036498: EAPOL: SUPP_PAE entering state CONNECTING
>1381276848.036566: EAPOL: enable timer tick
>1381276848.036611: EAPOL: SUPP_BE entering state IDLE
>1381276848.036659: wlan0: Setting authentication timeout: 10 sec 0 usec
>1381276848.036721: wlan0: Cancelling scan request
>1381276848.036778: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276848.036883: nl80211: Event message available
>1381276848.036916: nl80211: Ignore connect event (cmd=46) when using userspace SME
>1381276848.040907: wlan0: RX EAPOL from c0:c1:c0:dc:08:33
>1381276848.040935: RX EAPOL - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 b5 cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 43 9b 5a 58 bd cf c9 33 27 bb 3c 68 61 58 32 16
>1381276848.040978: wlan0: Setting authentication timeout: 10 sec 0 usec
>1381276848.040998: wlan0: IEEE 802.1X RX: version=2 type=3 length=117
>1381276848.041012: wlan0:   EAPOL-Key type=2
>1381276848.041039: wlan0:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
>1381276848.041057: wlan0:   key_length=16 key_data_length=22
>1381276848.041070:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 b5
>1381276848.041084:   key_nonce - hexdump(len=32): cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16
>1381276848.041102:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1381276848.041117:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
>1381276848.041131:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1381276848.041145:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
>1381276848.041163: WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 b5 cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 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 43 9b 5a 58 bd cf c9 33 27 bb 3c 68 61 58 32 16
>1381276848.041204: wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE
>1381276848.041281: wlan0: WPA: RX message 1 of 4-Way Handshake from c0:c1:c0:dc:08:33 (ver=2)
>1381276848.041297: RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 43 9b 5a 58 bd cf c9 33 27 bb 3c 68 61 58 32 16
>1381276848.041315: WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 43 9b 5a 58 bd cf c9 33 27 bb 3c 68 61 58 32 16
>1381276848.041346: RSN: PMKID from Authenticator - hexdump(len=16): 43 9b 5a 58 bd cf c9 33 27 bb 3c 68 61 58 32 16
>1381276848.041363: wlan0: RSN: no matching PMKID found
>1381276848.041377: Get randomness: len=32 entropy=70
>1381276848.041936: WPA: Renewed SNonce - hexdump(len=32): 72 08 02 26 d7 0c 4d 20 d5 bd 1c 71 d6 c4 5d 9d d0 99 9f 91 6a 3f 8a 21 9b 8d d1 99 f9 5e fd 79
>1381276848.041975: WPA: PTK derivation - A1=00:1d:60:ad:03:79 A2=c0:c1:c0:dc:08:33
>1381276848.041990: WPA: Nonce1 - hexdump(len=32): 72 08 02 26 d7 0c 4d 20 d5 bd 1c 71 d6 c4 5d 9d d0 99 9f 91 6a 3f 8a 21 9b 8d d1 99 f9 5e fd 79
>1381276848.042009: WPA: Nonce2 - hexdump(len=32): cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16
>1381276848.042027: WPA: PMK - hexdump(len=32): [REMOVED]
>1381276848.042039: WPA: PTK - hexdump(len=48): [REMOVED]
>1381276848.042051: WPA: WPA IE for msg 2/4 - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276848.042069: WPA: Replay Counter - hexdump(len=8): 00 00 00 00 00 00 00 b5
>1381276848.042084: wlan0: WPA: Sending EAPOL-Key 2/4
>1381276848.042102: WPA: KCK - hexdump(len=16): [REMOVED]
>1381276848.042115: WPA: Derived Key MIC - hexdump(len=16): 2e 94 8b 73 2f fe d5 ac 9d 8c 7a d5 66 8e 61 49
>1381276848.042130: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75 02 01 0a 00 00 00 00 00 00 00 00 00 b5 72 08 02 26 d7 0c 4d 20 d5 bd 1c 71 d6 c4 5d 9d d0 99 9f 91 6a 3f 8a 21 9b 8d d1 99 f9 5e fd 79 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 2e 94 8b 73 2f fe d5 ac 9d 8c 7a d5 66 8e 61 49 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 00 00
>1381276848.046548: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276848.057547: wlan0: RX EAPOL from c0:c1:c0:dc:08:33
>1381276848.057600: RX EAPOL - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 b6 cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 17 fa 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 57 2d 7d e9 86 39 61 25 84 7e e5 b5 73 bc 29 4f 00 38 e5 42 9a e4 b1 66 6a 08 5e c1 45 cc 8b 76 c8 c4 35 53 ab e6 ec d0 17 1b 8b 9c f3 eb ab 11 20 58 db 56 e7 eb da a7 09 32 24 18 69 d2 43 89 26 72 af a7 8c 51 43 46 23 4d
>1381276848.057653: wlan0: IEEE 802.1X RX: version=2 type=3 length=151
>1381276848.057668: wlan0:   EAPOL-Key type=2
>1381276848.057688: wlan0:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
>1381276848.057702: wlan0:   key_length=16 key_data_length=56
>1381276848.057716:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 b6
>1381276848.057731:   key_nonce - hexdump(len=32): cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16
>1381276848.057755:   key_iv - hexdump(len=16): 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 17
>1381276848.057772:   key_rsc - hexdump(len=8): fa 03 00 00 00 00 00 00
>1381276848.057788:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
>1381276848.057804:   key_mic - hexdump(len=16): 57 2d 7d e9 86 39 61 25 84 7e e5 b5 73 bc 29 4f
>1381276848.057822: WPA: RX EAPOL-Key - hexdump(len=155): 02 03 00 97 02 13 ca 00 10 00 00 00 00 00 00 00 b6 cc a0 47 60 fc 97 89 43 29 c0 d1 81 17 87 89 50 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 16 64 ad 98 0e f0 31 9a 16 68 85 92 77 96 90 c4 17 fa 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00 57 2d 7d e9 86 39 61 25 84 7e e5 b5 73 bc 29 4f 00 38 e5 42 9a e4 b1 66 6a 08 5e c1 45 cc 8b 76 c8 c4 35 53 ab e6 ec d0 17 1b 8b 9c f3 eb ab 11 20 58 db 56 e7 eb da a7 09 32 24 18 69 d2 43 89 26 72 af a7 8c 51 43 46 23 4d
>1381276848.057882: RSN: encrypted key data - hexdump(len=56): e5 42 9a e4 b1 66 6a 08 5e c1 45 cc 8b 76 c8 c4 35 53 ab e6 ec d0 17 1b 8b 9c f3 eb ab 11 20 58 db 56 e7 eb da a7 09 32 24 18 69 d2 43 89 26 72 af a7 8c 51 43 46 23 4d
>1381276848.057924: WPA: decrypted EAPOL-Key key data - hexdump(len=48): [REMOVED]
>1381276848.057959: wlan0: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
>1381276848.057975: wlan0: WPA: RX message 3 of 4-Way Handshake from c0:c1:c0:dc:08:33 (ver=2)
>1381276848.057988: WPA: IE KeyData - hexdump(len=48): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00 dd 16 00 0f ac 01 02 00 57 54 15 31 c5 5e 6f 82 37 83 9d 34 f3 b2 7e c1 dd 00
>1381276848.058013: WPA: RSN IE in EAPOL-Key - hexdump(len=22): 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02 0c 00
>1381276848.058032: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
>1381276848.058047: wlan0: WPA: Sending EAPOL-Key 4/4
>1381276848.058065: WPA: KCK - hexdump(len=16): [REMOVED]
>1381276848.058079: WPA: Derived Key MIC - hexdump(len=16): e6 9e c7 92 35 5c 29 f3 5b f9 aa 36 e4 15 fe 20
>1381276848.058098: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02 03 0a 00 00 00 00 00 00 00 00 00 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 e6 9e c7 92 35 5c 29 f3 5b f9 aa 36 e4 15 fe 20 00 00
>1381276848.058160: wlan0: WPA: Installing PTK to the driver
>1381276848.058196: wpa_driver_nl80211_set_key: ifindex=3 alg=3 addr=0x1d76d58 key_idx=0 set_tx=1 seq_len=6 key_len=16
>1381276848.058222:    addr=c0:c1:c0:dc:08:33
>1381276848.058334: EAPOL: External notification - portValid=1
>1381276848.058357: wlan0: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
>1381276848.058429: RSN: received GTK in pairwise handshake - hexdump(len=18): [REMOVED]
>1381276848.058488: WPA: Group Key - hexdump(len=16): [REMOVED]
>1381276848.058565: wlan0: WPA: Installing GTK to the driver (keyidx=2 tx=0 len=16)
>1381276848.058582: WPA: RSC - hexdump(len=6): fa 03 00 00 00 00
>1381276848.058607: wpa_driver_nl80211_set_key: ifindex=3 alg=3 addr=0x4e0cae key_idx=2 set_tx=0 seq_len=6 key_len=16
>1381276848.058628:    broadcast key
>1381276848.058689: wlan0: WPA: Key negotiation completed with c0:c1:c0:dc:08:33 [PTK=CCMP GTK=CCMP]
>1381276848.058709: wlan0: Cancelling authentication timeout
>1381276848.058724: wlan0: State: GROUP_HANDSHAKE -> COMPLETED
>1381276848.058740: wlan0: CTRL-EVENT-CONNECTED - Connection to c0:c1:c0:dc:08:33 completed [id=0 id_str=]
>1381276848.058755: wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)
>1381276848.058770: netlink: Operstate: linkmode=-1, operstate=6
>1381276848.058856: EAPOL: External notification - portValid=1
>1381276848.058977: EAPOL: External notification - EAP success=1
>1381276848.058992: EAPOL: SUPP_PAE entering state AUTHENTICATING
>1381276848.059004: EAPOL: SUPP_BE entering state SUCCESS
>1381276848.059016: EAP: EAP entering state DISABLED
>1381276848.059029: EAPOL: SUPP_PAE entering state AUTHENTICATED
>1381276848.059064: EAPOL: Supplicant port status: Authorized
>1381276848.059108: EAPOL: SUPP_BE entering state IDLE
>1381276848.059126: EAPOL authentication completed successfully
>1381276848.059170: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1381276848.059189: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276848.059210: nl80211: if_removed already cleared - ignore event
>1381276848.063543: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276849.037766: EAPOL: startWhen --> 0
>1381276849.037880: EAPOL: disable timer tick
>1381276869.701187: dbus: fi.w1.wpa_supplicant1.Interface.Scan (/fi/w1/wpa_supplicant1/Interfaces/3)
>1381276869.701786: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
>1381276869.702072: Scan requested (ret=0) - scan timeout 30 seconds
>1381276869.702755: nl80211: Event message available
>1381276869.702828: nl80211: Scan trigger
>1381276873.534831: RTM_NEWLINK: operstate=1 ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP])
>1381276873.534969: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan0' added
>1381276873.535056: nl80211: if_removed already cleared - ignore event
>1381276873.535103: nl80211: Event message available
>1381276873.535166: nl80211: New scan results available
>1381276873.535272: wlan0: Event SCAN_RESULTS (3) received
>1381276873.535582: nl80211: Associated on 2422 MHz
>1381276873.535636: nl80211: Associated with c0:c1:c0:dc:08:33
>1381276873.535691: nl80211: Received scan results (7 BSSes)
>1381276873.535764: nl80211: Scan results indicate BSS status with c0:c1:c0:dc:08:33 as associated
>1381276873.535822: wlan0: BSS: Start scan result update 3
>1381276873.535903: wlan0: BSS: Add new id 5 BSSID 68:7f:74:fc:08:4a SSID 'Schaefer Home'
>1381276873.535937: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/5'
>1381276873.536229: wlan0: BSS: Add new id 6 BSSID 00:1d:d4:df:05:f0 SSID 'COGECO WIRELESS'
>1381276873.536276: dbus: Register BSS object '/fi/w1/wpa_supplicant1/Interfaces/3/BSSs/6'
>1381276873.536544: dbus: wpas_dbus_bss_signal_prop_changed: Unknown Property value 7
>1381276873.536605: BSS: last_scan_res_used=7/32 last_scan_full=0
>1381276873.536655: wlan0: New scan results available
>1381276873.536750: WPS: AP c0:c1:c0:dc:08:33 type 0 added
>1381276873.536791: WPS: AP 00:1e:e5:01:83:9c type 0 added
>1381276873.536834: WPS: AP 68:7f:74:fc:08:4a type 0 added
>1381276873.536869: WPS: AP 00:22:b0:ba:05:55 type 0 added
>1381276873.536900: WPS: AP[0] c0:c1:c0:dc:08:33 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276873.536932: WPS: AP[1] 00:1e:e5:01:83:9c type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276873.536962: WPS: AP[2] 68:7f:74:fc:08:4a type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276873.536998: WPS: AP[3] 00:22:b0:ba:05:55 type=0 tries=0 last_attempt=-1 sec ago blacklist=0
>1381276873.537039: wlan0: Selecting BSS from priority group 0
>1381276873.537083: wlan0: 0: c0:c1:c0:dc:08:33 ssid='jagster' wpa_ie_len=0 rsn_ie_len=20 caps=0x411 level=-57 wps
>1381276873.537117: wlan0:    selected based on RSN IE
>1381276873.537152: wlan0:    selected BSS c0:c1:c0:dc:08:33 ssid='jagster'
>1381276873.537186: wlan0: Checking for other virtual interfaces sharing same radio (phy0) in event_scan_results
>1381276873.542637: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3
>1381276873.543069: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/0
>1381276873.543326: dbus: flush_object_timeout_handler: Timeout - sending changed properties of object /fi/w1/wpa_supplicant1/Interfaces/3/BSSs/4
>
>/***********************************************
>* Had to reboot here because everything froze. *
>***********************************************/

Actions: View

Attachments on bug 1014843: 915778