Activation (wlan1/wireless): association took too long



I've ran into a recurring issue with a recently acquired AT&T U-verse
connection.

If the wireless modem is reset (the modem's power turned off and back
on in quick succession), NetworkManager consistently fails to
automatically reconnect. Instead, it prompts me to re-insert the
password. After several prompts, the connection is successful. If
NetworkManager is itself restarted (by toggling 'Wireless' in the
applet menu), no prompting is required and the connection is
reestablished successfully. This leads me to believe NetworkManager is
too impatient with a recently restarted modem.

This issue affects me because I often SSH into my computer remotely.
If my wireless connection drops, NetworkManager will not reestablish a
connection; it will presumably remain disconnected until I return to
re-enter my credentials.

The following thread -
http://mail.gnome.org/archives/networkmanager-list/2011-April/msg00193.html
- discussed a very similar issue to my own. In that thread, the
timeout was lengthened in order to alleviate the issue. I imagine a
similar patch would work around my case as well. However, in my
admittedly amateurish view, it seems that NetworkManager is too eager
to begin this timeout. This is because the default value is sufficient
if the connection is attempted once the modem is fully operational.

Of course, what use is a bug report without copious logs! Here's my
version info (note that I'm using the rawhide version of
NetworkManager; the current Fedora 15 version in @updates exhibits the
same behavior):

$ uname -a
Linux fritocomp 2.6.40.6-0.fc15.x86_64 #1 SMP Tue Oct 4 00:39:50 UTC
2011 x86_64 x86_64 x86_64 GNU/Linux
$ rpm -q NetworkManager
NetworkManager-0.9.1.90-3.git20110927.fc17.x86_64

I've collected output from /var/log/messages and
/var/log/wpa_supplicant.log. I followed the directions on
http://live.gnome.org/NetworkManager/Debugging to ensure I get a
detailed wpa_supplicant debug spew.

There are three notable events that I've noted in the following logfiles:

######## 1. Nov  4 21:29:06 (1320460146): Wireless modem is unplugged, plugged

######## 2. Nov  4 21:29:21 (1320460161): Pause begins

######## 3. Nov  4 21:29:45 (1320460185): Connection takes too long

I've marked these events in both logfiles for easier comparison.
They're easily findable by searching for the hashes.

First, /var/log/messages:

Nov  4 21:29:03 fritocomp kernel: [ 1435.182952] cfg80211: Calling
CRDA to update world regulatory domain
Nov  4 21:29:03 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: completed -> disconnected
Nov  4 21:29:03 fritocomp kernel: [ 1435.227725] cfg80211: World
regulatory domain updated:
Nov  4 21:29:03 fritocomp kernel: [ 1435.227730] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227734] cfg80211:
(2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227738] cfg80211:
(2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227741] cfg80211:
(2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227745] cfg80211:
(5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227748] cfg80211:
(5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.227763] cfg80211: Calling
CRDA for country: US
Nov  4 21:29:03 fritocomp kernel: [ 1435.236920] cfg80211: Regulatory
domain changed to country: US
Nov  4 21:29:03 fritocomp kernel: [ 1435.236924] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236929] cfg80211:
(2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236933] cfg80211:
(5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236936] cfg80211:
(5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236939] cfg80211:
(5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236943] cfg80211:
(5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:29:03 fritocomp kernel: [ 1435.236946] cfg80211:
(5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
Nov  4 21:29:03 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: disconnected -> scanning
Nov  4 21:29:04 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: scanning -> authenticating
Nov  4 21:29:06 fritocomp NetworkManager[1201]: <info> (wlan1): roamed
from BSSID 34:EF:44:1F:5B:59 (Robertson) to (none) ((none))

######## 1. Nov  4 21:29:06 (1320460146): Wireless modem is unplugged, plugged

Nov  4 21:29:19 fritocomp NetworkManager[1201]: <warn> (wlan1): link timed out.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: activated -> disconnected (reason 'supplicant-timeout')
[100 30 11]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1):
deactivating device (reason 'supplicant-timeout') [11]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1):
canceled DHCP transaction, DHCP client pid 3475
Nov  4 21:29:19 fritocomp avahi-daemon[1189]: Withdrawing address
record for 192.168.1.66 on wlan1.
Nov  4 21:29:19 fritocomp dnsmasq[1704]: reading /etc/resolv.conf
Nov  4 21:29:19 fritocomp avahi-daemon[1189]: Leaving mDNS multicast
group on interface wlan1.IPv4 with address 192.168.1.66.
Nov  4 21:29:19 fritocomp dnsmasq[1704]: using nameserver 192.168.1.254#53
Nov  4 21:29:19 fritocomp avahi-daemon[1189]: Interface wlan1.IPv4 no
longer relevant for mDNS.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: authenticating -> disconnected
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Auto-activating
connection 'Auto Robertson'.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) starting connection 'Auto Robertson'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: disconnected -> prepare (reason 'none') [30 40 0]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) started...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) scheduled...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) complete.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) starting...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: prepare -> config (reason 'none') [40 50 0]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1/wireless): access point 'Auto Robertson' has security, but
secrets are required.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: config -> need-auth (reason 'none') [50 60 0]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) complete.
Nov  4 21:29:19 fritocomp dbus: [system] Activating service
name='org.freedesktop.nm_dispatcher' (using servicehelper)
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) started...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: need-auth -> prepare (reason 'none') [60 40 0]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) scheduled...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) complete.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) starting...
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: prepare -> config (reason 'none') [40 50 0]
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1/wireless): connection 'Auto Robertson' has security, and
secrets exist.  No new secrets needed.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: added
'ssid' value 'Robertson'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: added
'scan_ssid' value '1'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: added
'key_mgmt' value 'WPA-PSK'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: added
'psk' value '<omitted>'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: added
'proto' value 'WPA RSN'
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) complete.
Nov  4 21:29:19 fritocomp NetworkManager[1201]: <info> Config: set
interface ap_scan to 1
Nov  4 21:29:19 fritocomp dbus: [system] Successfully activated
service 'org.freedesktop.nm_dispatcher'
Nov  4 21:29:21 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: disconnected -> scanning

######## 2. Nov  4 21:29:21 (1320460161): Pause begins

######## 3. Nov  4 21:29:45 (1320460185): Connection takes too long

Nov  4 21:29:45 fritocomp NetworkManager[1201]: <warn> Activation
(wlan1/wireless): association took too long.
Nov  4 21:29:45 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: config -> need-auth (reason 'none') [50 60 0]
Nov  4 21:29:45 fritocomp NetworkManager[1201]: <warn> Activation
(wlan1/wireless): asking for new secrets
Nov  4 21:29:45 fritocomp NetworkManager[1201]: <warn> Couldn't
disconnect supplicant interface: This interface is not connected.
Nov  4 21:29:45 fritocomp NetworkManager[1201]: <warn> Couldn't
disconnect supplicant interface: This interface is not connected.
Nov  4 21:29:45 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: scanning -> inactive
Nov  4 21:29:57 fritocomp NetworkManager[1201]: get_secret_flags:
assertion `is_secret_prop (setting, secret_name, error)' failed
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) started...
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: need-auth -> prepare (reason 'none') [60 40 0]
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) scheduled...
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) complete.
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) starting...
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: prepare -> config (reason 'none') [40 50 0]
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1/wireless): connection 'Auto Robertson' has security, and
secrets exist.  No new secrets needed.
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: added
'ssid' value 'Robertson'
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: added
'scan_ssid' value '1'
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: added
'key_mgmt' value 'WPA-PSK'
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: added
'psk' value '<omitted>'
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: added
'proto' value 'WPA RSN'
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) complete.
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> Config: set
interface ap_scan to 1
Nov  4 21:29:57 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: inactive -> scanning
Nov  4 21:30:23 fritocomp NetworkManager[1201]: <warn> Activation
(wlan1/wireless): association took too long.
Nov  4 21:30:23 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: config -> need-auth (reason 'none') [50 60 0]
Nov  4 21:30:23 fritocomp NetworkManager[1201]: <warn> Activation
(wlan1/wireless): asking for new secrets
Nov  4 21:30:23 fritocomp NetworkManager[1201]: <warn> Couldn't
disconnect supplicant interface: This interface is not connected.
Nov  4 21:30:23 fritocomp NetworkManager[1201]: <warn> Couldn't
disconnect supplicant interface: This interface is not connected.
Nov  4 21:30:26 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: scanning -> inactive
Nov  4 21:30:28 fritocomp NetworkManager[1201]: get_secret_flags:
assertion `is_secret_prop (setting, secret_name, error)' failed
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) scheduled...
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) started...
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: need-auth -> prepare (reason 'none') [60 40 0]
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) scheduled...
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 1 of 5 (Device Prepare) complete.
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) starting...
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: prepare -> config (reason 'none') [40 50 0]
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1/wireless): connection 'Auto Robertson' has security, and
secrets exist.  No new secrets needed.
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: added
'ssid' value 'Robertson'
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: added
'scan_ssid' value '1'
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: added
'key_mgmt' value 'WPA-PSK'
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: added
'psk' value '<omitted>'
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: added
'proto' value 'WPA RSN'
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 2 of 5 (Device Configure) complete.
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> Config: set
interface ap_scan to 1
Nov  4 21:30:28 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: inactive -> scanning
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: scanning -> authenticating
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: authenticating -> associating
Nov  4 21:30:29 fritocomp kernel: [ 1520.331596] cfg80211: Calling
CRDA for country: US
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: associating -> associated
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: associated -> 4-way handshake
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1):
supplicant interface state: 4-way handshake -> completed
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1/wireless) Stage 2 of 5 (Device Configure) successful.
Connected to wireless network 'Robertson'.
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 3 of 5 (IP Configure Start) scheduled.
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 3 of 5 (IP Configure Start) started...
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: config -> ip-config (reason 'none') [50 70 0]
Nov  4 21:30:29 fritocomp kernel: [ 1520.373924] cfg80211: Regulatory
domain changed to country: US
Nov  4 21:30:29 fritocomp kernel: [ 1520.373927] cfg80211:
(start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373929] cfg80211:
(2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2700 mBm)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373932] cfg80211:
(5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 1700 mBm)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373934] cfg80211:
(5250000 KHz - 5330000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373936] cfg80211:
(5490000 KHz - 5600000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373938] cfg80211:
(5650000 KHz - 5710000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Nov  4 21:30:29 fritocomp kernel: [ 1520.373940] cfg80211:
(5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 3000 mBm)
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Beginning DHCPv4 transaction (timeout in 45 seconds)
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> dhclient
started with pid 3855
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Beginning IP6 addrconf.
Nov  4 21:30:29 fritocomp avahi-daemon[1189]: Withdrawing address
record for fe80::f6ec:38ff:fee5:1c4a on wlan1.
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 3 of 5 (IP Configure Start) complete.
Nov  4 21:30:29 fritocomp dnsmasq[1704]: no servers found in
/etc/resolv.conf, will retry
Nov  4 21:30:29 fritocomp dhclient[3855]: Internet Systems Consortium
DHCP Client 4.2.1-P1
Nov  4 21:30:29 fritocomp dhclient[3855]: Copyright 2004-2011 Internet
Systems Consortium.
Nov  4 21:30:29 fritocomp dhclient[3855]: All rights reserved.
Nov  4 21:30:29 fritocomp dhclient[3855]: For info, please visit
https://www.isc.org/software/dhcp/
Nov  4 21:30:29 fritocomp dhclient[3855]:
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1): DHCPv4
state changed nbi -> preinit
Nov  4 21:30:29 fritocomp dhclient[3855]: Listening on
LPF/wlan1/f4:ec:38:e5:1c:4a
Nov  4 21:30:29 fritocomp dhclient[3855]: Sending on
LPF/wlan1/f4:ec:38:e5:1c:4a
Nov  4 21:30:29 fritocomp dhclient[3855]: Sending on   Socket/fallback
Nov  4 21:30:29 fritocomp dhclient[3855]: DHCPREQUEST on wlan1 to
255.255.255.255 port 67
Nov  4 21:30:29 fritocomp dhclient[3855]: DHCPACK from 192.168.1.254
Nov  4 21:30:29 fritocomp dhclient[3855]: bound to 192.168.1.66 --
renewal in 41091 seconds.
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> (wlan1): DHCPv4
state changed preinit -> reboot
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP4 Configure Get) scheduled...
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP4 Configure Get) started...
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info>   address 192.168.1.66
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info>   prefix 24
(255.255.255.0)
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info>   gateway 192.168.1.254
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info>   nameserver
'192.168.1.254'
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info>   domain name
'gateway.2wire.net'
Nov  4 21:30:29 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP4 Configure Get) complete.
Nov  4 21:30:31 fritocomp avahi-daemon[1189]: Registering new address
record for fe80::f6ec:38ff:fee5:1c4a on wlan1.*.
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> (wlan1): IP6
addrconf timed out or failed.
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP6 Configure Timeout) scheduled...
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP6 Configure Timeout) started...
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 5 of 5 (IP Configure Commit) scheduled...
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 4 of 5 (IP6 Configure Timeout) complete.
Nov  4 21:30:49 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 5 of 5 (IP Configure Commit) started...
Nov  4 21:30:49 fritocomp avahi-daemon[1189]: Joining mDNS multicast
group on interface wlan1.IPv4 with address 192.168.1.66.
Nov  4 21:30:49 fritocomp avahi-daemon[1189]: New relevant interface
wlan1.IPv4 for mDNS.
Nov  4 21:30:49 fritocomp avahi-daemon[1189]: Registering new address
record for 192.168.1.66 on wlan1.IPv4.
Nov  4 21:30:50 fritocomp NetworkManager[1201]: <info> (wlan1): device
state change: ip-config -> activated (reason 'none') [70 100 0]
Nov  4 21:30:50 fritocomp NetworkManager[1201]: <info> (wlan1): roamed
from BSSID 34:EF:44:1F:5B:59 (Robertson) to 34:EF:44:1F:5B:59
(Robertson)
Nov  4 21:30:50 fritocomp NetworkManager[1201]: <info> Policy set
'Auto Robertson' (wlan1) as default for IPv4 routing and DNS.
Nov  4 21:30:50 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) successful, device activated.
Nov  4 21:30:50 fritocomp NetworkManager[1201]: <info> Activation
(wlan1) Stage 5 of 5 (IP Configure Commit) complete.
Nov  4 21:30:50 fritocomp dbus: [system] Activating service
name='org.freedesktop.nm_dispatcher' (using servicehelper)
Nov  4 21:30:50 fritocomp dbus: [system] Successfully activated
service 'org.freedesktop.nm_dispatcher'

######## And now, /var/log/wpa_supplicant.log

1320460129.712610: Current BSS: 34:ef:44:1f:5b:59 level=-50
1320460129.712617: Selected BSS: 34:ef:44:1f:5b:59 level=-50
1320460129.712623: Skip roam - too small difference in signal level
1320460129.713001: RTM_NEWLINK: operstate=1 ifi_flags=0x11043
([UP][RUNNING][LOWER_UP])
1320460129.713019: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460129.717654: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460129.717720: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29
1320460129.717759: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460129.717793: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/28
1320460129.717825: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460143.811020: RTM_NEWLINK: operstate=1 ifi_flags=0x1003 ([UP])
1320460143.811059: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460143.821342: nl80211: Event message available
1320460143.821392: nl80211: Ignored unknown event (cmd=20)
1320460143.823907: nl80211: Event message available
1320460143.823953: nl80211: MLME event 39
1320460143.823974: nl80211: MLME event frame - hexdump(len=26): c0 00
00 00 34 ef 44 1f 5b 59 f4 ec 38 e5 1c 4a 34 ef 44 1f 5b 59 00 00 04
00
1320460143.823996: Deauthentication notification
1320460143.824010: Setting scan request: 0 sec 100000 usec
1320460143.824024: Added BSSID 34:ef:44:1f:5b:59 into blacklist
1320460143.824039: CTRL-EVENT-DISCONNECTED bssid=34:ef:44:1f:5b:59 reason=4
1320460143.824051: Disconnect event - remove keys
1320460143.824466: wpa_driver_nl80211_set_key: ifindex=4 alg=0
addr=0x47a641 key_idx=0 set_tx=0 seq_len=0 key_len=0
1320460143.837590: wpa_driver_nl80211_set_key: ifindex=4 alg=0
addr=0x47a641 key_idx=1 set_tx=0 seq_len=0 key_len=0
1320460143.837690: wpa_driver_nl80211_set_key: ifindex=4 alg=0
addr=0x47a641 key_idx=2 set_tx=0 seq_len=0 key_len=0
1320460143.837791: wpa_driver_nl80211_set_key: ifindex=4 alg=0
addr=0x47a641 key_idx=3 set_tx=0 seq_len=0 key_len=0
1320460143.837895: wpa_driver_nl80211_set_key: ifindex=4 alg=0
addr=0x1bd0930 key_idx=0 set_tx=0 seq_len=0 key_len=0
1320460143.837911:    addr=34:ef:44:1f:5b:59
1320460143.837928: State: COMPLETED -> DISCONNECTED
1320460143.837937: wpa_driver_nl80211_set_operstate: operstate 1->0 (DORMANT)
1320460143.837944: netlink: Operstate: linkmode=-1, operstate=5
1320460143.838006: EAPOL: External notification - portEnabled=0
1320460143.838020: EAPOL: SUPP_PAE entering state DISCONNECTED
1320460143.838027: EAPOL: Supplicant port status: Unauthorized
1320460143.838130: EAPOL: SUPP_BE entering state INITIALIZE
1320460143.838145: EAPOL: Supplicant port status: Unauthorized
1320460143.838252: EAPOL: External notification - portValid=0
1320460143.838267: EAPOL: Supplicant port status: Unauthorized
1320460143.838352: EAPOL: External notification - EAP success=0
1320460143.838370: EAPOL: Supplicant port status: Unauthorized
1320460143.838477: nl80211: Event message available
1320460143.838495: nl80211: Ignore disconnect event when using userspace SME
1320460143.838505: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460143.838521: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460143.843117: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460143.924178: State: DISCONNECTED -> SCANNING
1320460143.924379: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460143.924408: Starting AP scan for wildcard SSID
1320460143.924439: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460143.924476: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460143.926974: Scan requested (ret=0) - scan timeout 30 seconds
1320460143.927005: nl80211: Event message available
1320460143.927024: nl80211: Scan trigger
1320460143.929477: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460144.628490: nl80211: Event message available
1320460144.628588: nl80211: New scan results available
1320460144.628681: Received scan results (7 BSSes)
1320460144.628696: BSS: Start scan result update 28
1320460144.628716: BSS: Expire BSS 30 due to no match in scan
1320460144.628742: BSS: Remove id 30 BSSID 1c:af:f7:ca:16:d3 SSID '477302'
1320460144.628761: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/30'
1320460144.628820: New scan results available
1320460144.628840: WPS: attr type=0x104a len=1
1320460144.628849: WPS: attr type=0x1044 len=1
1320460144.628855: WPS: attr type=0x103b len=1
1320460144.628862: WPS: attr type=0x1047 len=16
1320460144.628868: WPS: attr type=0x1021 len=7
1320460144.628875: WPS: attr type=0x1023 len=7
1320460144.628882: WPS: attr type=0x1024 len=6
1320460144.628888: WPS: attr type=0x1042 len=7
1320460144.628895: WPS: attr type=0x1054 len=8
1320460144.628901: WPS: attr type=0x1011 len=9
1320460144.628909: WPS: attr type=0x1008 len=2
1320460144.628916: WPS: attr type=0x104a len=1
1320460144.628923: WPS: attr type=0x1044 len=1
1320460144.628931: WPS: attr type=0x103b len=1
1320460144.628949: WPS: attr type=0x1047 len=16
1320460144.628960: WPS: attr type=0x1021 len=7
1320460144.628970: WPS: attr type=0x1023 len=7
1320460144.629009: WPS: attr type=0x1024 len=6
1320460144.629021: WPS: attr type=0x1042 len=7
1320460144.629028: WPS: attr type=0x1054 len=8
1320460144.629035: WPS: attr type=0x1011 len=9
1320460144.629041: WPS: attr type=0x1008 len=2
1320460144.629065: Selecting BSS from priority group 0
1320460144.629103: Try to find WPA-enabled AP
1320460144.629110: 0: 34:ef:44:1f:5b:59 ssid='Robertson' wpa_ie_len=0
rsn_ie_len=20 caps=0x431
1320460144.629120:    selected based on RSN IE
1320460144.629127:    selected WPA AP 34:ef:44:1f:5b:59 ssid='Robertson'
1320460144.629136: Automatic auth_alg selection: 0x1
1320460144.629146: RSN: using IEEE 802.11i/D9.0
1320460144.629154: WPA: Selected cipher suites: group 16 pairwise 16
key_mgmt 2 proto 2
1320460144.629161: WPA: clearing AP WPA IE
1320460144.629168: 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 00 00
1320460144.629208: WPA: using GTK CCMP
1320460144.629220: WPA: using PTK CCMP
1320460144.629231: WPA: using KEY_MGMT WPA-PSK
1320460144.629245: 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
1320460144.629261: Cancelling scan request
1320460144.629273: Trying to authenticate with 34:ef:44:1f:5b:59
(SSID='Robertson' freq=2462 MHz)
1320460144.629314: No keys have been configured - skip key clearing
1320460144.629321: State: SCANNING -> AUTHENTICATING
1320460144.629353: EAPOL: External notification - EAP success=0
1320460144.629401: EAPOL: Supplicant port status: Unauthorized
1320460144.629521: EAPOL: External notification - EAP fail=0
1320460144.629533: EAPOL: Supplicant port status: Unauthorized
1320460144.629613: EAPOL: External notification - portControl=Auto
1320460144.629625: EAPOL: Supplicant port status: Unauthorized
1320460144.629710: nl80211: Authenticate (ifindex=4)
1320460144.629731:   * bssid=34:ef:44:1f:5b:59
1320460144.629738:   * freq=2462
1320460144.629745:   * SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460144.629757:   * IEs - hexdump(len=0): [NULL]
1320460144.629764:   * Auth Type 0
1320460144.630804: nl80211: Authentication request send successfully
1320460144.630819: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460144.630827: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460144.633747: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460144.633830: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460144.633859: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460144.633910: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460144.633945: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460144.634709: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460144.634856: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460144.635008: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460144.635128: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460144.635247: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460144.635341: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/28)
1320460144.635448: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29)
1320460145.236684: nl80211: Event message available
1320460145.236802: nl80211: MLME event 37; timeout with 34:ef:44:1f:5b:59
1320460145.236849: SME: Authentication timed out
1320460145.236870: Setting scan request: 5 sec 0 usec

######## 1. Nov  4 21:29:06 (1320460146): Wireless modem is unplugged, plugged

1320460150.238366: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460150.238470: Starting AP scan for wildcard SSID
1320460150.238580: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460150.238618: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460150.241236: Scan requested (ret=0) - scan timeout 30 seconds
1320460150.241276: nl80211: Event message available
1320460150.241307: nl80211: Scan trigger
1320460150.243690: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460150.943602: nl80211: Event message available
1320460150.943635: nl80211: New scan results available
1320460150.943696: Received scan results (6 BSSes)
1320460150.943711: BSS: Start scan result update 29
1320460150.943727: BSS: Add new id 31 BSSID 1c:af:f7:ca:16:d3 SSID '477302'
1320460150.943736: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31'
1320460150.943803: New scan results available
1320460150.943824: WPS: attr type=0x104a len=1
1320460150.943833: WPS: attr type=0x1044 len=1
1320460150.943840: WPS: attr type=0x103b len=1
1320460150.943847: WPS: attr type=0x1047 len=16
1320460150.943854: WPS: attr type=0x1021 len=7
1320460150.943861: WPS: attr type=0x1023 len=7
1320460150.943868: WPS: attr type=0x1024 len=6
1320460150.943875: WPS: attr type=0x1042 len=7
1320460150.943881: WPS: attr type=0x1054 len=8
1320460150.943888: WPS: attr type=0x1011 len=9
1320460150.943895: WPS: attr type=0x1008 len=2
1320460150.943917: WPS: attr type=0x104a len=1
1320460150.943923: WPS: attr type=0x1044 len=1
1320460150.943932: WPS: attr type=0x103b len=1
1320460150.943942: WPS: attr type=0x1047 len=16
1320460150.943952: WPS: attr type=0x1021 len=7
1320460150.943985: WPS: attr type=0x1023 len=7
1320460150.943996: WPS: attr type=0x1024 len=6
1320460150.944006: WPS: attr type=0x1042 len=7
1320460150.944017: WPS: attr type=0x1054 len=8
1320460150.944028: WPS: attr type=0x1011 len=9
1320460150.944060: WPS: attr type=0x1008 len=2
1320460150.944089: Selecting BSS from priority group 0
1320460150.944101: Try to find WPA-enabled AP
1320460150.944107: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460150.944116:    skip - SSID mismatch
1320460150.944123: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460150.944131:    skip - SSID mismatch
1320460150.944137: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460150.944146:    skip - SSID mismatch
1320460150.944152: 3: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460150.944165:    skip - SSID mismatch
1320460150.944176: 4: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460150.944205:    skip - no WPA/RSN IE
1320460150.944216: 5: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460150.944228:    skip - no WPA/RSN IE
1320460150.944239: Try to find non-WPA AP
1320460150.944253: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460150.944268:    skip - SSID mismatch
1320460150.944283: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460150.944292:    skip - SSID mismatch
1320460150.944301: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460150.944316:    skip - SSID mismatch
1320460150.944327: 3: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460150.944337:    skip - SSID mismatch
1320460150.944346: 4: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460150.944356:    skip - SSID mismatch
1320460150.944365: 5: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460150.944377:    skip - SSID mismatch
1320460150.944388: No APs found - clear blacklist and try again
1320460150.944396: Removed BSSID 34:ef:44:1f:5b:59 from blacklist (clear)
1320460150.944403: Selecting BSS from priority group 0
1320460150.944410: Try to find WPA-enabled AP
1320460150.944416: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460150.944424:    skip - SSID mismatch
1320460150.944430: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460150.944442:    skip - SSID mismatch
1320460150.944457: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460150.944470:    skip - SSID mismatch
1320460150.944482: 3: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460150.944495:    skip - SSID mismatch
1320460150.944506: 4: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460150.944520:    skip - no WPA/RSN IE
1320460150.944529: 5: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460150.944540:    skip - no WPA/RSN IE
1320460150.944550: Try to find non-WPA AP
1320460150.944560: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460150.944572:    skip - SSID mismatch
1320460150.944584: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460150.944596:    skip - SSID mismatch
1320460150.944605: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460150.944620:    skip - SSID mismatch
1320460150.944631: 3: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460150.944642:    skip - SSID mismatch
1320460150.944651: 4: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460150.944663:    skip - SSID mismatch
1320460150.944672: 5: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460150.944680:    skip - SSID mismatch
1320460150.944695: No suitable network found
1320460150.944705: Setting scan request: 5 sec 0 usec
1320460150.944719: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460150.944727: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460150.948803: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460150.948881: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460150.948944: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460150.949580: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460150.949705: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460150.949793: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460150.949881: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460150.949972: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460150.950066: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/28)
1320460150.950160: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29)
1320460150.950259: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460155.949921: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460155.950016: Starting AP scan for wildcard SSID
1320460155.950083: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460155.950108: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460155.952573: Scan requested (ret=0) - scan timeout 30 seconds
1320460155.952603: nl80211: Event message available
1320460155.952623: nl80211: Scan trigger
1320460155.955195: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460156.654534: nl80211: Event message available
1320460156.654616: nl80211: New scan results available
1320460156.654717: Received scan results (7 BSSes)
1320460156.654741: BSS: Start scan result update 30
1320460156.654767: BSS: Add new id 32 BSSID ac:81:12:82:d4:5b SSID
'Overdosed_on_Hip_Hop'
1320460156.654782: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32'
1320460156.654888: BSS: Expire BSS 28 due to no match in scan
1320460156.654906: BSS: Remove id 28 BSSID 64:0f:28:f5:35:11 SSID '2WIRE674'
1320460156.654920: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/28'
1320460156.654953: New scan results available
1320460156.654979: WPS: attr type=0x104a len=1
1320460156.654991: WPS: attr type=0x1044 len=1
1320460156.655001: WPS: attr type=0x103b len=1
1320460156.655011: WPS: attr type=0x1047 len=16
1320460156.655021: WPS: attr type=0x1021 len=7
1320460156.655032: WPS: attr type=0x1023 len=7
1320460156.655043: WPS: attr type=0x1024 len=6
1320460156.655053: WPS: attr type=0x1042 len=7
1320460156.655063: WPS: attr type=0x1054 len=8
1320460156.655073: WPS: attr type=0x1011 len=9
1320460156.655082: WPS: attr type=0x1008 len=2
1320460156.655093: WPS: attr type=0x104a len=1
1320460156.655103: WPS: attr type=0x1044 len=1
1320460156.655113: WPS: attr type=0x103b len=1
1320460156.655122: WPS: attr type=0x1047 len=16
1320460156.655132: WPS: attr type=0x1021 len=7
1320460156.655142: WPS: attr type=0x1023 len=7
1320460156.655152: WPS: attr type=0x1024 len=6
1320460156.655162: WPS: attr type=0x1042 len=7
1320460156.655172: WPS: attr type=0x1054 len=8
1320460156.655182: WPS: attr type=0x1011 len=9
1320460156.655203: WPS: attr type=0x1008 len=2
1320460156.655233: Selecting BSS from priority group 0
1320460156.655247: Try to find WPA-enabled AP
1320460156.655257: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460156.655280:    skip - SSID mismatch
1320460156.655293: 1: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460156.655305:    skip - SSID mismatch
1320460156.655315: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460156.655327:    skip - SSID mismatch
1320460156.655337: 3: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460156.655348:    skip - SSID mismatch
1320460156.655358: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460156.655370:    skip - SSID mismatch
1320460156.655380: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460156.655392:    skip - no WPA/RSN IE
1320460156.655402: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460156.655414:    skip - no WPA/RSN IE
1320460156.655423: Try to find non-WPA AP
1320460156.655433: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460156.655446:    skip - SSID mismatch
1320460156.655456: 1: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460156.655468:    skip - SSID mismatch
1320460156.655477: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460156.655488:    skip - SSID mismatch
1320460156.655499: 3: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460156.655510:    skip - SSID mismatch
1320460156.655519: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460156.655530:    skip - SSID mismatch
1320460156.655540: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460156.655553:    skip - SSID mismatch
1320460156.655563: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460156.655574:    skip - SSID mismatch
1320460156.655585: No suitable network found
1320460156.655598: Setting scan request: 5 sec 0 usec
1320460156.655615: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460156.655628: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460156.659799: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460156.659905: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460156.659948: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460156.659986: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460156.660021: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460156.661496: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460156.661721: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460156.661963: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460156.662267: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460156.662479: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460156.662701: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29)
1320460156.662947: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460156.663247: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32)
1320460159.293701: dbus: fi.w1.wpa_supplicant1.Interface.Disconnect
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460159.293751: No keys have been configured - skip key clearing
1320460159.293772: State: AUTHENTICATING -> DISCONNECTED
1320460159.293794: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1320460159.293833: netlink: Operstate: linkmode=-1, operstate=5
1320460159.294065: EAPOL: External notification - portEnabled=0
1320460159.294094: EAPOL: Supplicant port status: Unauthorized
1320460159.297037: EAPOL: External notification - portValid=0
1320460159.297076: EAPOL: Supplicant port status: Unauthorized
1320460159.297311: EAPOL: External notification - EAP success=0
1320460159.297341: EAPOL: Supplicant port status: Unauthorized
1320460159.297764: dbus: fi.w1.wpa_supplicant1.Interface.RemoveNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460159.297805: dbus: Unregister network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460159.356821: dbus: org.freedesktop.DBus.Properties.Set
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460159.357837: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460159.357872: dbus: Register network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460159.357963: scan_ssid=1 (0x1)
1320460159.357986: proto: 0x3
1320460159.358006: ssid - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460159.358040: key_mgmt: 0x2
1320460159.358057: PSK (ASCII passphrase) - hexdump_ascii(len=33): [REMOVED]
1320460159.370554: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1320460159.371014: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460159.371052: Not rescheduling scan to ensure that specific SSID
scans occur

######## 2. Nov  4 21:29:21 (1320460161): Pause begins

1320460161.658080: State: DISCONNECTED -> SCANNING
1320460161.658373: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460161.658408: Starting AP scan for wildcard SSID
1320460161.658468: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460161.658493: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460161.661033: Scan requested (ret=0) - scan timeout 30 seconds
1320460161.661071: nl80211: Event message available
1320460161.661101: nl80211: Scan trigger
1320460161.663527: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460162.362502: nl80211: Event message available
1320460162.362547: nl80211: New scan results available
1320460162.362692: Received scan results (7 BSSes)
1320460162.362715: BSS: Start scan result update 31
1320460162.362759: New scan results available
1320460162.362791: WPS: attr type=0x104a len=1
1320460162.362805: WPS: attr type=0x1044 len=1
1320460162.362817: WPS: attr type=0x103b len=1
1320460162.362828: WPS: attr type=0x1047 len=16
1320460162.362864: WPS: attr type=0x1021 len=7
1320460162.362876: WPS: attr type=0x1023 len=7
1320460162.362886: WPS: attr type=0x1024 len=6
1320460162.362897: WPS: attr type=0x1042 len=7
1320460162.362908: WPS: attr type=0x1054 len=8
1320460162.362919: WPS: attr type=0x1011 len=9
1320460162.362930: WPS: attr type=0x1008 len=2
1320460162.362941: WPS: attr type=0x104a len=1
1320460162.362964: WPS: attr type=0x1044 len=1
1320460162.362976: WPS: attr type=0x103b len=1
1320460162.362987: WPS: attr type=0x1047 len=16
1320460162.362998: WPS: attr type=0x1021 len=7
1320460162.363009: WPS: attr type=0x1023 len=7
1320460162.363019: WPS: attr type=0x1024 len=6
1320460162.363030: WPS: attr type=0x1042 len=7
1320460162.363041: WPS: attr type=0x1054 len=8
1320460162.363051: WPS: attr type=0x1011 len=9
1320460162.363062: WPS: attr type=0x1008 len=2
1320460162.363091: Selecting BSS from priority group 0
1320460162.363105: Try to find WPA-enabled AP
1320460162.363115: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460162.363129:    skip - SSID mismatch
1320460162.363141: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460162.363155:    skip - SSID mismatch
1320460162.363166: 2: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460162.363180:    skip - SSID mismatch
1320460162.363200: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460162.363227:    skip - SSID mismatch
1320460162.363238: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460162.363252:    skip - SSID mismatch
1320460162.363264: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460162.363276:    skip - no WPA/RSN IE
1320460162.363287: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460162.363299:    skip - no WPA/RSN IE
1320460162.363309: Try to find non-WPA AP
1320460162.363319: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460162.363335:    skip - SSID mismatch
1320460162.363345: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460162.363358:    skip - SSID mismatch
1320460162.363368: 2: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460162.363381:    skip - SSID mismatch
1320460162.363392: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460162.363406:    skip - SSID mismatch
1320460162.363416: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460162.363430:    skip - SSID mismatch
1320460162.363440: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460162.363453:    skip - SSID mismatch
1320460162.363464: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460162.363497:    skip - SSID mismatch
1320460162.363509: No suitable network found
1320460162.363523: Setting scan request: 5 sec 0 usec
1320460162.364001: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460162.364018: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460162.367803: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460162.367921: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460162.368078: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460162.368137: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460162.368208: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460162.368254: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460162.368331: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31
1320460167.368680: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460167.368749: Starting AP scan for wildcard SSID
1320460167.368825: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460167.368888: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460167.371328: Scan requested (ret=0) - scan timeout 30 seconds
1320460167.371364: nl80211: Event message available
1320460167.371395: nl80211: Scan trigger
1320460167.373932: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460168.073472: nl80211: Event message available
1320460168.073695: nl80211: New scan results available
1320460168.073824: Received scan results (9 BSSes)
1320460168.073857: BSS: Start scan result update 32
1320460168.073892: BSS: Add new id 33 BSSID 64:0f:28:f5:35:11 SSID '2WIRE674'
1320460168.073912: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33'
1320460168.074033: BSS: Add new id 34 BSSID 00:17:9a:35:13:82 SSID
'Timmy 'n' Veronique'
1320460168.074055: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34'
1320460168.074152: BSS: Expire BSS 29 due to no match in scan
1320460168.074211: BSS: Remove id 29 BSSID 34:ef:44:1f:5b:59 SSID 'Robertson'
1320460168.074271: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/29'
1320460168.074305: New scan results available
1320460168.074328: WPS: attr type=0x104a len=1
1320460168.074341: WPS: attr type=0x1044 len=1
1320460168.074350: WPS: attr type=0x103b len=1
1320460168.074362: WPS: attr type=0x1047 len=16
1320460168.074371: WPS: attr type=0x1021 len=7
1320460168.074411: WPS: attr type=0x1023 len=7
1320460168.074478: WPS: attr type=0x1024 len=6
1320460168.074541: WPS: attr type=0x1042 len=7
1320460168.074595: WPS: attr type=0x1054 len=8
1320460168.074610: WPS: attr type=0x1011 len=9
1320460168.074624: WPS: attr type=0x1008 len=2
1320460168.074639: WPS: attr type=0x104a len=1
1320460168.074681: WPS: attr type=0x1044 len=1
1320460168.074731: WPS: attr type=0x103b len=1
1320460168.074768: WPS: attr type=0x1047 len=16
1320460168.074781: WPS: attr type=0x1021 len=7
1320460168.074795: WPS: attr type=0x1023 len=7
1320460168.074808: WPS: attr type=0x1024 len=6
1320460168.074822: WPS: attr type=0x1042 len=7
1320460168.074835: WPS: attr type=0x1054 len=8
1320460168.074849: WPS: attr type=0x1011 len=9
1320460168.074863: WPS: attr type=0x1008 len=2
1320460168.074898: Selecting BSS from priority group 0
1320460168.074916: Try to find WPA-enabled AP
1320460168.074930: 0: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460168.074947:    skip - SSID mismatch
1320460168.074960: 1: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460168.074976:    skip - SSID mismatch
1320460168.074990: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460168.075006:    skip - SSID mismatch
1320460168.075019: 3: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460168.075035:    skip - SSID mismatch
1320460168.075049: 4: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460168.075065:    skip - SSID mismatch
1320460168.075078: 5: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460168.075096:    skip - SSID mismatch
1320460168.075109: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460168.075119:    skip - no WPA/RSN IE
1320460168.075131: 7: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460168.075144:    skip - no WPA/RSN IE
1320460168.075157: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460168.075171:    skip - no WPA/RSN IE
1320460168.075178: Try to find non-WPA AP
1320460168.075203: 0: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460168.075218:    skip - SSID mismatch
1320460168.075229: 1: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460168.075244:    skip - SSID mismatch
1320460168.075252: 2: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460168.075267:    skip - SSID mismatch
1320460168.075280: 3: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460168.075292:    skip - SSID mismatch
1320460168.075304: 4: ac:81:12:82:d4:5b ssid='Overdosed_on_Hip_Hop'
wpa_ie_len=0 rsn_ie_len=24 caps=0x431
1320460168.075314:    skip - SSID mismatch
1320460168.075326: 5: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460168.075339:    skip - SSID mismatch
1320460168.075351: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460168.075365:    skip - SSID mismatch
1320460168.075373: 7: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460168.075402:    skip - SSID mismatch
1320460168.075419: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460168.075439:    skip - SSID mismatch
1320460168.075462: No suitable network found
1320460168.075488: Setting scan request: 5 sec 0 usec
1320460168.075650: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460168.075681: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460168.078911: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460168.079043: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460168.079108: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460168.079167: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460168.079325: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460168.079892: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460168.080079: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460168.080229: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460168.080417: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460168.080540: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460168.080663: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460168.080842: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32)
1320460168.081046: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33)
1320460168.081255: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34)
1320460173.079822: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460173.079884: Starting AP scan for wildcard SSID
1320460173.079990: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460173.080029: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460173.082463: Scan requested (ret=0) - scan timeout 30 seconds
1320460173.082499: nl80211: Event message available
1320460173.082529: nl80211: Scan trigger
1320460173.085131: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460173.784451: nl80211: Event message available
1320460173.784499: nl80211: New scan results available
1320460173.784623: Received scan results (9 BSSes)
1320460173.784664: BSS: Start scan result update 33
1320460173.784710: BSS: Add new id 35 BSSID 00:24:b2:91:b0:f8 SSID 'APT256'
1320460173.784739: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35'
1320460173.784849: New scan results available
1320460173.784881: WPS: attr type=0x104a len=1
1320460173.784897: WPS: attr type=0x1044 len=1
1320460173.784908: WPS: attr type=0x103b len=1
1320460173.784919: WPS: attr type=0x1047 len=16
1320460173.784929: WPS: attr type=0x1021 len=7
1320460173.784939: WPS: attr type=0x1023 len=7
1320460173.784948: WPS: attr type=0x1024 len=6
1320460173.784958: WPS: attr type=0x1042 len=7
1320460173.784976: WPS: attr type=0x1054 len=8
1320460173.784986: WPS: attr type=0x1011 len=9
1320460173.784995: WPS: attr type=0x1008 len=2
1320460173.785005: WPS: attr type=0x104a len=1
1320460173.785015: WPS: attr type=0x1044 len=1
1320460173.785026: WPS: attr type=0x103b len=1
1320460173.785049: WPS: attr type=0x1047 len=16
1320460173.785060: WPS: attr type=0x1021 len=7
1320460173.785079: WPS: attr type=0x1023 len=7
1320460173.785090: WPS: attr type=0x1024 len=6
1320460173.785106: WPS: attr type=0x1042 len=7
1320460173.785124: WPS: attr type=0x1054 len=8
1320460173.785136: WPS: attr type=0x1011 len=9
1320460173.785150: WPS: attr type=0x1008 len=2
1320460173.785183: Selecting BSS from priority group 0
1320460173.785353: Try to find WPA-enabled AP
1320460173.785364: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460173.785385:    skip - SSID mismatch
1320460173.785395: 1: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460173.785408:    skip - SSID mismatch
1320460173.785418: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460173.785430:    skip - SSID mismatch
1320460173.785440: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460173.785453:    skip - SSID mismatch
1320460173.785464: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460173.785478:    skip - SSID mismatch
1320460173.785490: 5: 00:24:b2:91:b0:f8 ssid='APT256' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460173.785503:    skip - SSID mismatch
1320460173.785514: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460173.785526:    skip - no WPA/RSN IE
1320460173.785536: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460173.785551:    skip - no WPA/RSN IE
1320460173.785561: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460173.785573:    skip - no WPA/RSN IE
1320460173.785594: Try to find non-WPA AP
1320460173.785613: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460173.785636:    skip - SSID mismatch
1320460173.785653: 1: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460173.785673:    skip - SSID mismatch
1320460173.785693: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460173.785716:    skip - SSID mismatch
1320460173.785734: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460173.785756:    skip - SSID mismatch
1320460173.785773: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460173.785793:    skip - SSID mismatch
1320460173.785813: 5: 00:24:b2:91:b0:f8 ssid='APT256' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460173.785836:    skip - SSID mismatch
1320460173.785855: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460173.785867:    skip - SSID mismatch
1320460173.785876: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460173.785892:    skip - SSID mismatch
1320460173.785903: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460173.785916:    skip - SSID mismatch
1320460173.785926: No suitable network found
1320460173.785939: Setting scan request: 5 sec 0 usec
1320460173.785958: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460173.785983: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460173.789686: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460173.789794: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460173.789857: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460173.789921: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460173.789978: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460173.790049: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460173.790111: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31
1320460173.790434: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460173.790776: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460173.791072: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460173.791375: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460173.791734: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460173.792009: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460173.792299: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32)
1320460173.792606: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33)
1320460173.792837: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34)
1320460173.793173: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35)
1320460178.791087: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460178.791145: Starting AP scan for wildcard SSID
1320460178.791231: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460178.791385: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460178.793795: Scan requested (ret=0) - scan timeout 30 seconds
1320460178.793827: nl80211: Event message available
1320460178.793846: nl80211: Scan trigger
1320460178.796372: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460179.495510: nl80211: Event message available
1320460179.495576: nl80211: New scan results available
1320460179.495683: Received scan results (9 BSSes)
1320460179.495730: BSS: Start scan result update 34
1320460179.495758: BSS: Expire BSS 32 due to no match in scan
1320460179.495767: BSS: Remove id 32 BSSID ac:81:12:82:d4:5b SSID
'Overdosed_on_Hip_Hop'
1320460179.495775: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/32'
1320460179.495803: New scan results available
1320460179.495832: WPS: attr type=0x104a len=1
1320460179.495849: WPS: attr type=0x1044 len=1
1320460179.495860: WPS: attr type=0x103b len=1
1320460179.495876: WPS: attr type=0x1047 len=16
1320460179.495888: WPS: attr type=0x1021 len=7
1320460179.495898: WPS: attr type=0x1023 len=7
1320460179.495910: WPS: attr type=0x1024 len=6
1320460179.495923: WPS: attr type=0x1042 len=7
1320460179.495933: WPS: attr type=0x1054 len=8
1320460179.495943: WPS: attr type=0x1011 len=9
1320460179.495954: WPS: attr type=0x1008 len=2
1320460179.495968: WPS: attr type=0x104a len=1
1320460179.495979: WPS: attr type=0x1044 len=1
1320460179.495990: WPS: attr type=0x103b len=1
1320460179.496003: WPS: attr type=0x1047 len=16
1320460179.496014: WPS: attr type=0x1021 len=7
1320460179.496024: WPS: attr type=0x1023 len=7
1320460179.496033: WPS: attr type=0x1024 len=6
1320460179.496039: WPS: attr type=0x1042 len=7
1320460179.496047: WPS: attr type=0x1054 len=8
1320460179.496053: WPS: attr type=0x1011 len=9
1320460179.496060: WPS: attr type=0x1008 len=2
1320460179.496083: Selecting BSS from priority group 0
1320460179.496097: Try to find WPA-enabled AP
1320460179.496109: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460179.496124:    skip - SSID mismatch
1320460179.496136: 1: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460179.496150:    skip - SSID mismatch
1320460179.496160: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460179.496173:    skip - SSID mismatch
1320460179.496185: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460179.496255:    skip - SSID mismatch
1320460179.496266: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460179.496279:    skip - SSID mismatch
1320460179.496291: 5: 00:24:b2:91:b0:f8 ssid='APT256' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460179.496306:    skip - SSID mismatch
1320460179.496317: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460179.496333:    skip - no WPA/RSN IE
1320460179.496341: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460179.496359:    skip - no WPA/RSN IE
1320460179.496367: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460179.496375:    skip - no WPA/RSN IE
1320460179.496382: Try to find non-WPA AP
1320460179.496388: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460179.496398:    skip - SSID mismatch
1320460179.496404: 1: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460179.496413:    skip - SSID mismatch
1320460179.496419: 2: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460179.496427:    skip - SSID mismatch
1320460179.496433: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460179.496441:    skip - SSID mismatch
1320460179.496448: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460179.496456:    skip - SSID mismatch
1320460179.496462: 5: 00:24:b2:91:b0:f8 ssid='APT256' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460179.496470:    skip - SSID mismatch
1320460179.496477: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460179.496485:    skip - SSID mismatch
1320460179.496492: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460179.496500:    skip - SSID mismatch
1320460179.496507: 8: 00:17:9a:35:13:82 ssid='Timmy 'n' Veronique'
wpa_ie_len=0 rsn_ie_len=0 caps=0x431
1320460179.496515:    skip - SSID mismatch
1320460179.496522: No suitable network found
1320460179.496531: Setting scan request: 5 sec 0 usec
1320460179.496544: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460179.496553: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460179.500823: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460179.500943: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460179.500984: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460179.502764: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460179.502998: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460179.503269: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460179.503485: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460179.503796: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460179.504020: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460179.504406: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33)
1320460179.504618: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34)
1320460179.504857: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35)
1320460184.501729: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460184.501815: Starting AP scan for wildcard SSID
1320460184.501881: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460184.501949: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460184.504395: Scan requested (ret=0) - scan timeout 30 seconds
1320460184.504428: nl80211: Event message available
1320460184.504447: nl80211: Scan trigger
1320460184.507020: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460185.090978: dbus: fi.w1.wpa_supplicant1.Interface.Disconnect
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460185.091166: dbus: fi.w1.wpa_supplicant1.Interface.RemoveNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460185.091219: dbus: Unregister network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460185.091315: dbus: fi.w1.wpa_supplicant1.Interface.Disconnect
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460185.206452: nl80211: Event message available
1320460185.206914: nl80211: New scan results available
1320460185.207008: Received scan results (7 BSSes)
1320460185.207030: BSS: Start scan result update 35
1320460185.207060: New scan results available
1320460185.207093: WPS: attr type=0x104a len=1
1320460185.207110: WPS: attr type=0x1044 len=1
1320460185.207122: WPS: attr type=0x103b len=1
1320460185.207144: WPS: attr type=0x1047 len=16
1320460185.207157: WPS: attr type=0x1021 len=7
1320460185.207168: WPS: attr type=0x1023 len=7
1320460185.207179: WPS: attr type=0x1024 len=6
1320460185.207238: WPS: attr type=0x1042 len=7
1320460185.207250: WPS: attr type=0x1054 len=8
1320460185.207260: WPS: attr type=0x1011 len=9
1320460185.207271: WPS: attr type=0x1008 len=2
1320460185.207282: WPS: attr type=0x104a len=1
1320460185.207306: WPS: attr type=0x1044 len=1
1320460185.207317: WPS: attr type=0x103b len=1
1320460185.207328: WPS: attr type=0x1047 len=16
1320460185.207339: WPS: attr type=0x1021 len=7
1320460185.207351: WPS: attr type=0x1023 len=7
1320460185.207361: WPS: attr type=0x1024 len=6
1320460185.207372: WPS: attr type=0x1042 len=7
1320460185.207383: WPS: attr type=0x1054 len=8
1320460185.207393: WPS: attr type=0x1011 len=9
1320460185.207404: WPS: attr type=0x1008 len=2
1320460185.207436: No suitable network found
1320460185.207452: State: SCANNING -> INACTIVE
1320460185.207502: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460185.207517: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460185.212141: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460185.212306: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460185.212375: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460185.212433: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7

######## 3. Nov  4 21:29:45 (1320460185): Connection takes too long

1320460197.900774: dbus: org.freedesktop.DBus.Properties.Set
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460197.901252: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460197.901291: dbus: Register network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460197.901427: scan_ssid=1 (0x1)
1320460197.901463: proto: 0x3
1320460197.901494: ssid - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460197.901541: key_mgmt: 0x2
1320460197.901572: PSK (ASCII passphrase) - hexdump_ascii(len=33): [REMOVED]
1320460197.914005: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1320460197.914496: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460197.914538: Setting scan request: 0 sec 0 usec
1320460197.914668: State: INACTIVE -> SCANNING
1320460197.914716: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460197.914745: Starting AP scan for wildcard SSID
1320460197.914781: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460197.914810: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460197.917212: Scan requested (ret=0) - scan timeout 30 seconds
1320460197.917235: nl80211: Event message available
1320460197.917248: nl80211: Scan trigger
1320460197.919852: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460198.619481: nl80211: Event message available
1320460198.622163: nl80211: New scan results available
1320460198.622337: Received scan results (7 BSSes)
1320460198.622366: BSS: Start scan result update 36
1320460198.622409: BSS: Add new id 36 BSSID 00:24:b2:91:e1:6a SSID
'Rhymeslykedymes13'
1320460198.622425: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36'
1320460198.622535: BSS: Expire BSS 34 due to no match in scan
1320460198.622551: BSS: Remove id 34 BSSID 00:17:9a:35:13:82 SSID
'Timmy 'n' Veronique'
1320460198.622564: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/34'
1320460198.622596: New scan results available
1320460198.622621: WPS: attr type=0x104a len=1
1320460198.622635: WPS: attr type=0x1044 len=1
1320460198.622645: WPS: attr type=0x103b len=1
1320460198.622656: WPS: attr type=0x1047 len=16
1320460198.622666: WPS: attr type=0x1021 len=6
1320460198.622676: WPS: attr type=0x1023 len=13
1320460198.622687: WPS: attr type=0x1024 len=7
1320460198.622697: WPS: attr type=0x1042 len=4
1320460198.622708: WPS: attr type=0x1054 len=8
1320460198.622718: WPS: attr type=0x1011 len=22
1320460198.622729: WPS: attr type=0x1008 len=2
1320460198.622739: WPS: attr type=0x103c len=1
1320460198.622749: WPS: attr type=0x1049 len=20
1320460198.622760: WPS: Unsupported attribute type 0x1049 len=20
1320460198.622771: WPS: attr type=0x104a len=1
1320460198.622781: WPS: attr type=0x1044 len=1
1320460198.622792: WPS: attr type=0x103b len=1
1320460198.622802: WPS: attr type=0x1047 len=16
1320460198.622812: WPS: attr type=0x1021 len=6
1320460198.622823: WPS: attr type=0x1023 len=13
1320460198.622833: WPS: attr type=0x1024 len=7
1320460198.622844: WPS: attr type=0x1042 len=4
1320460198.622854: WPS: attr type=0x1054 len=8
1320460198.622864: WPS: attr type=0x1011 len=22
1320460198.622875: WPS: attr type=0x1008 len=2
1320460198.622885: WPS: attr type=0x103c len=1
1320460198.622895: WPS: attr type=0x1049 len=20
1320460198.622906: WPS: Unsupported attribute type 0x1049 len=20
1320460198.622931: Selecting BSS from priority group 0
1320460198.622945: Try to find WPA-enabled AP
1320460198.622955: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460198.622968:    skip - SSID mismatch
1320460198.622979: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460198.622991:    skip - SSID mismatch
1320460198.623002: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460198.623014:    skip - SSID mismatch
1320460198.623024: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460198.623036:    skip - SSID mismatch
1320460198.623047: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460198.623059:    skip - SSID mismatch
1320460198.623069: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460198.623082:    skip - SSID mismatch
1320460198.623092: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460198.623104:    skip - no WPA/RSN IE
1320460198.623114: Try to find non-WPA AP
1320460198.623125: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460198.623137:    skip - SSID mismatch
1320460198.623147: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460198.623160:    skip - SSID mismatch
1320460198.623170: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460198.623182:    skip - SSID mismatch
1320460198.623314: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460198.623326:    skip - SSID mismatch
1320460198.623337: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460198.623349:    skip - SSID mismatch
1320460198.623359: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460198.623372:    skip - SSID mismatch
1320460198.623382: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460198.623396:    skip - SSID mismatch
1320460198.623408: No suitable network found
1320460198.623423: Setting scan request: 5 sec 0 usec
1320460198.623454: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460198.623494: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460198.627367: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460198.627440: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33
1320460198.627527: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460198.627563: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460198.627598: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460198.628419: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460198.628592: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460198.629099: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460198.629335: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460198.629499: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460198.629666: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460198.630206: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33)
1320460198.630408: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35)
1320460198.630653: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36)
1320460203.628289: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460203.628367: Starting AP scan for wildcard SSID
1320460203.628716: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460203.628736: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460203.631159: Scan requested (ret=0) - scan timeout 30 seconds
1320460203.631335: nl80211: Event message available
1320460203.631359: nl80211: Scan trigger
1320460203.633797: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460204.332538: nl80211: Event message available
1320460204.332643: nl80211: New scan results available
1320460204.332749: Received scan results (8 BSSes)
1320460204.332772: BSS: Start scan result update 37
1320460204.332844: BSS: Expire BSS 35 due to no match in scan
1320460204.332860: BSS: Remove id 35 BSSID 00:24:b2:91:b0:f8 SSID 'APT256'
1320460204.332874: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/35'
1320460204.332926: New scan results available
1320460204.332957: WPS: attr type=0x104a len=1
1320460204.332975: WPS: attr type=0x1044 len=1
1320460204.332986: WPS: attr type=0x103b len=1
1320460204.332997: WPS: attr type=0x1047 len=16
1320460204.333009: WPS: attr type=0x1021 len=7
1320460204.333021: WPS: attr type=0x1023 len=7
1320460204.333032: WPS: attr type=0x1024 len=6
1320460204.333043: WPS: attr type=0x1042 len=7
1320460204.333054: WPS: attr type=0x1054 len=8
1320460204.333065: WPS: attr type=0x1011 len=9
1320460204.333076: WPS: attr type=0x1008 len=2
1320460204.333087: WPS: attr type=0x104a len=1
1320460204.333099: WPS: attr type=0x1044 len=1
1320460204.333110: WPS: attr type=0x103b len=1
1320460204.333123: WPS: attr type=0x1047 len=16
1320460204.333135: WPS: attr type=0x1021 len=7
1320460204.333145: WPS: attr type=0x1023 len=7
1320460204.333156: WPS: attr type=0x1024 len=6
1320460204.333167: WPS: attr type=0x1042 len=7
1320460204.333177: WPS: attr type=0x1054 len=8
1320460204.333229: WPS: attr type=0x1011 len=9
1320460204.333282: WPS: attr type=0x1008 len=2
1320460204.333312: Selecting BSS from priority group 0
1320460204.333325: Try to find WPA-enabled AP
1320460204.333350: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460204.333364:    skip - SSID mismatch
1320460204.333375: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460204.333387:    skip - SSID mismatch
1320460204.333398: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460204.333412:    skip - SSID mismatch
1320460204.333423: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460204.333436:    skip - SSID mismatch
1320460204.333447: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460204.333461:    skip - SSID mismatch
1320460204.333472: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460204.333486:    skip - SSID mismatch
1320460204.333497: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460204.333509:    skip - no WPA/RSN IE
1320460204.333520: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460204.333533:    skip - no WPA/RSN IE
1320460204.333543: Try to find non-WPA AP
1320460204.333555: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460204.333568:    skip - SSID mismatch
1320460204.333578: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460204.333593:    skip - SSID mismatch
1320460204.333617: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460204.333631:    skip - SSID mismatch
1320460204.333642: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460204.333655:    skip - SSID mismatch
1320460204.333666: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460204.333679:    skip - SSID mismatch
1320460204.333690: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460204.333704:    skip - SSID mismatch
1320460204.333715: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460204.333728:    skip - SSID mismatch
1320460204.333739: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460204.333753:    skip - SSID mismatch
1320460204.333764: No suitable network found
1320460204.333780: Setting scan request: 5 sec 0 usec
1320460204.333797: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460204.333810: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460204.337844: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460204.337980: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460204.338054: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460204.338112: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460204.338165: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31
1320460204.338570: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460204.338709: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460204.338846: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460204.338943: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460204.339063: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460204.339162: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460204.339319: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33)
1320460204.339422: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36)
1320460209.334337: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460209.334446: Starting AP scan for wildcard SSID
1320460209.334528: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460209.334570: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460209.337121: Scan requested (ret=0) - scan timeout 30 seconds
1320460209.337151: nl80211: Event message available
1320460209.337170: nl80211: Scan trigger
1320460209.339661: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460210.040718: nl80211: Event message available
1320460210.040779: nl80211: New scan results available
1320460210.040890: Received scan results (8 BSSes)
1320460210.040917: BSS: Start scan result update 38
1320460210.040953: New scan results available
1320460210.040988: WPS: attr type=0x104a len=1
1320460210.041003: WPS: attr type=0x1044 len=1
1320460210.041009: WPS: attr type=0x103b len=1
1320460210.041016: WPS: attr type=0x1047 len=16
1320460210.041022: WPS: attr type=0x1021 len=7
1320460210.041029: WPS: attr type=0x1023 len=7
1320460210.041036: WPS: attr type=0x1024 len=6
1320460210.041042: WPS: attr type=0x1042 len=7
1320460210.041049: WPS: attr type=0x1054 len=8
1320460210.041072: WPS: attr type=0x1011 len=9
1320460210.041079: WPS: attr type=0x1008 len=2
1320460210.041086: WPS: attr type=0x104a len=1
1320460210.041092: WPS: attr type=0x1044 len=1
1320460210.041098: WPS: attr type=0x103b len=1
1320460210.041104: WPS: attr type=0x1047 len=16
1320460210.041111: WPS: attr type=0x1021 len=7
1320460210.041117: WPS: attr type=0x1023 len=7
1320460210.041123: WPS: attr type=0x1024 len=6
1320460210.041129: WPS: attr type=0x1042 len=7
1320460210.041136: WPS: attr type=0x1054 len=8
1320460210.041142: WPS: attr type=0x1011 len=9
1320460210.041148: WPS: attr type=0x1008 len=2
1320460210.041168: Selecting BSS from priority group 0
1320460210.041177: Try to find WPA-enabled AP
1320460210.041193: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460210.041204:    skip - SSID mismatch
1320460210.041211: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460210.041218:    skip - SSID mismatch
1320460210.041224: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460210.041231:    skip - SSID mismatch
1320460210.041243: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460210.041251:    skip - SSID mismatch
1320460210.041258: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460210.041265:    skip - SSID mismatch
1320460210.041271: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460210.041279:    skip - SSID mismatch
1320460210.041285: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460210.041293:    skip - no WPA/RSN IE
1320460210.041299: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460210.041306:    skip - no WPA/RSN IE
1320460210.041312: Try to find non-WPA AP
1320460210.041318: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460210.041326:    skip - SSID mismatch
1320460210.041332: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460210.041339:    skip - SSID mismatch
1320460210.041345: 2: 64:0f:28:f5:35:11 ssid='2WIRE674' wpa_ie_len=26
rsn_ie_len=24 caps=0x431
1320460210.041353:    skip - SSID mismatch
1320460210.041359: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460210.041366:    skip - SSID mismatch
1320460210.041372: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460210.041380:    skip - SSID mismatch
1320460210.041386: 5: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460210.041404:    skip - SSID mismatch
1320460210.041411: 6: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460210.041418:    skip - SSID mismatch
1320460210.041424: 7: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460210.041431:    skip - SSID mismatch
1320460210.041438: No suitable network found
1320460210.041447: Setting scan request: 5 sec 0 usec
1320460210.041459: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460210.041467: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460210.045912: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460210.045988: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460210.046080: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460210.046211: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460210.046255: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460215.046595: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460215.046714: Starting AP scan for wildcard SSID
1320460215.046781: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460215.046805: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460215.049343: Scan requested (ret=0) - scan timeout 30 seconds
1320460215.049375: nl80211: Event message available
1320460215.049394: nl80211: Scan trigger
1320460215.051929: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460215.751549: nl80211: Event message available
1320460215.751700: nl80211: New scan results available
1320460215.751796: Received scan results (7 BSSes)
1320460215.751821: BSS: Start scan result update 39
1320460215.751846: New scan results available
1320460215.751869: WPS: attr type=0x104a len=1
1320460215.751885: WPS: attr type=0x1044 len=1
1320460215.751897: WPS: attr type=0x103b len=1
1320460215.751907: WPS: attr type=0x1047 len=16
1320460215.751916: WPS: attr type=0x1021 len=7
1320460215.751926: WPS: attr type=0x1023 len=7
1320460215.751935: WPS: attr type=0x1024 len=6
1320460215.751945: WPS: attr type=0x1042 len=7
1320460215.751955: WPS: attr type=0x1054 len=8
1320460215.751968: WPS: attr type=0x1011 len=9
1320460215.751976: WPS: attr type=0x1008 len=2
1320460215.751986: WPS: attr type=0x104a len=1
1320460215.751994: WPS: attr type=0x1044 len=1
1320460215.752005: WPS: attr type=0x103b len=1
1320460215.752015: WPS: attr type=0x1047 len=16
1320460215.752024: WPS: attr type=0x1021 len=7
1320460215.752034: WPS: attr type=0x1023 len=7
1320460215.752059: WPS: attr type=0x1024 len=6
1320460215.752069: WPS: attr type=0x1042 len=7
1320460215.752081: WPS: attr type=0x1054 len=8
1320460215.752091: WPS: attr type=0x1011 len=9
1320460215.752125: WPS: attr type=0x1008 len=2
1320460215.752210: Selecting BSS from priority group 0
1320460215.752227: Try to find WPA-enabled AP
1320460215.752238: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460215.752249:    skip - SSID mismatch
1320460215.752259: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460215.752270:    skip - SSID mismatch
1320460215.752282: 2: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460215.752293:    skip - SSID mismatch
1320460215.752302: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460215.752376:    skip - SSID mismatch
1320460215.752452: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460215.752512:    skip - SSID mismatch
1320460215.752534: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460215.752601:    skip - no WPA/RSN IE
1320460215.752651: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460215.752736:    skip - no WPA/RSN IE
1320460215.752746: Try to find non-WPA AP
1320460215.752756: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460215.752767:    skip - SSID mismatch
1320460215.752776: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460215.752787:    skip - SSID mismatch
1320460215.752796: 2: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460215.752807:    skip - SSID mismatch
1320460215.752816: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460215.752827:    skip - SSID mismatch
1320460215.752837: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460215.752848:    skip - SSID mismatch
1320460215.752857: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460215.752868:    skip - SSID mismatch
1320460215.752878: 6: 1c:af:f7:ca:16:d3 ssid='477302' wpa_ie_len=0
rsn_ie_len=0 caps=0x431
1320460215.752889:    skip - SSID mismatch
1320460215.752898: No suitable network found
1320460215.752911: Setting scan request: 5 sec 0 usec
1320460215.752925: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460215.752937: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460215.756847: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460215.756920: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460215.756963: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36
1320460215.757008: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460220.754821: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460220.755209: Starting AP scan for wildcard SSID
1320460220.755275: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460220.755342: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460220.757819: Scan requested (ret=0) - scan timeout 30 seconds
1320460220.757856: nl80211: Event message available
1320460220.757887: nl80211: Scan trigger
1320460220.760367: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460221.459338: nl80211: Event message available
1320460221.459530: nl80211: New scan results available
1320460221.459670: Received scan results (6 BSSes)
1320460221.459692: BSS: Start scan result update 40
1320460221.459719: BSS: Expire BSS 33 due to no match in scan
1320460221.459728: BSS: Remove id 33 BSSID 64:0f:28:f5:35:11 SSID '2WIRE674'
1320460221.459738: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/33'
1320460221.459767: New scan results available
1320460221.459789: WPS: attr type=0x104a len=1
1320460221.459802: WPS: attr type=0x1044 len=1
1320460221.459812: WPS: attr type=0x103b len=1
1320460221.459819: WPS: attr type=0x1047 len=16
1320460221.459828: WPS: attr type=0x1021 len=6
1320460221.459837: WPS: attr type=0x1023 len=13
1320460221.459845: WPS: attr type=0x1024 len=7
1320460221.459854: WPS: attr type=0x1042 len=4
1320460221.459863: WPS: attr type=0x1054 len=8
1320460221.459873: WPS: attr type=0x1011 len=22
1320460221.459882: WPS: attr type=0x1008 len=2
1320460221.459891: WPS: attr type=0x103c len=1
1320460221.459900: WPS: attr type=0x1049 len=20
1320460221.459910: WPS: Unsupported attribute type 0x1049 len=20
1320460221.459919: WPS: attr type=0x104a len=1
1320460221.459928: WPS: attr type=0x1044 len=1
1320460221.459937: WPS: attr type=0x103b len=1
1320460221.459946: WPS: attr type=0x1047 len=16
1320460221.459966: WPS: attr type=0x1021 len=6
1320460221.459974: WPS: attr type=0x1023 len=13
1320460221.459984: WPS: attr type=0x1024 len=7
1320460221.459992: WPS: attr type=0x1042 len=4
1320460221.460000: WPS: attr type=0x1054 len=8
1320460221.460009: WPS: attr type=0x1011 len=22
1320460221.460017: WPS: attr type=0x1008 len=2
1320460221.460026: WPS: attr type=0x103c len=1
1320460221.460035: WPS: attr type=0x1049 len=20
1320460221.460044: WPS: Unsupported attribute type 0x1049 len=20
1320460221.460065: Selecting BSS from priority group 0
1320460221.460078: Try to find WPA-enabled AP
1320460221.460088: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460221.460100:    skip - SSID mismatch
1320460221.460109: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460221.460120:    skip - SSID mismatch
1320460221.460130: 2: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460221.460162:    skip - SSID mismatch
1320460221.460238: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460221.460253:    skip - SSID mismatch
1320460221.460262: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460221.460273:    skip - SSID mismatch
1320460221.460282: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460221.460292:    skip - no WPA/RSN IE
1320460221.460303: Try to find non-WPA AP
1320460221.460366: 0: 00:24:a0:ab:4a:0a ssid='cupcake' wpa_ie_len=24
rsn_ie_len=0 caps=0x411
1320460221.460376:    skip - SSID mismatch
1320460221.460385: 1: 00:22:a4:84:82:21 ssid='You are loved'
wpa_ie_len=26 rsn_ie_len=24 caps=0x431
1320460221.460395:    skip - SSID mismatch
1320460221.460454: 2: 00:24:b2:91:e1:6a ssid='Rhymeslykedymes13'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460221.460519:    skip - SSID mismatch
1320460221.460575: 3: 00:24:b2:0b:50:02 ssid='N@@dLeS' wpa_ie_len=28
rsn_ie_len=24 caps=0x411
1320460221.460616:    skip - SSID mismatch
1320460221.460626: 4: 00:24:b2:b5:eb:e6 ssid='FBI Security Van'
wpa_ie_len=28 rsn_ie_len=24 caps=0x411
1320460221.460637:    skip - SSID mismatch
1320460221.460647: 5: cc:af:78:4c:71:98 ssid='cerberus_last_haven'
wpa_ie_len=0 rsn_ie_len=0 caps=0x411
1320460221.460658:    skip - SSID mismatch
1320460221.460682: No suitable network found
1320460221.460730: Setting scan request: 5 sec 0 usec
1320460221.460895: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460221.460908: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460221.464727: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460221.464805: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460221.464868: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460221.464957: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460221.465017: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4
1320460221.465077: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460221.465395: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460221.465643: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460221.465813: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460221.465960: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460221.466108: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460221.466274: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31)
1320460221.466508: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36)
1320460223.092060: dbus: fi.w1.wpa_supplicant1.Interface.Disconnect
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460223.092272: dbus: fi.w1.wpa_supplicant1.Interface.RemoveNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460223.092301: dbus: Unregister network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460223.092415: dbus: fi.w1.wpa_supplicant1.Interface.Disconnect
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460226.464226: No enabled networks - do not scan
1320460226.464274: State: SCANNING -> INACTIVE
1320460226.469450: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460228.404518: dbus: org.freedesktop.DBus.Properties.Set
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460228.404838: dbus: fi.w1.wpa_supplicant1.Interface.AddNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460228.404864: dbus: Register network object
'/fi/w1/wpa_supplicant1/Interfaces/1/Networks/0'
1320460228.404941: scan_ssid=1 (0x1)
1320460228.404961: proto: 0x3
1320460228.404982: ssid - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460228.405010: key_mgmt: 0x2
1320460228.405021: PSK (ASCII passphrase) - hexdump_ascii(len=33): [REMOVED]
1320460228.414709: PSK (from passphrase) - hexdump(len=32): [REMOVED]
1320460228.415176: dbus: fi.w1.wpa_supplicant1.Interface.SelectNetwork
(/fi/w1/wpa_supplicant1/Interfaces/1)
1320460228.415219: Setting scan request: 0 sec 0 usec
1320460228.415399: State: INACTIVE -> SCANNING
1320460228.415445: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460228.415474: Starting AP scan for wildcard SSID
1320460228.415513: nl80211: Scan SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460228.415598: nl80211: Scan SSID - hexdump_ascii(len=0): [NULL]
1320460228.417981: Scan requested (ret=0) - scan timeout 30 seconds
1320460228.418006: nl80211: Event message available
1320460228.418027: nl80211: Scan trigger
1320460228.420561: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460229.119384: nl80211: Event message available
1320460229.119434: nl80211: New scan results available
1320460229.119522: Received scan results (7 BSSes)
1320460229.119548: BSS: Start scan result update 41
1320460229.119563: BSS: Add new id 37 BSSID 34:ef:44:1f:5b:59 SSID 'Robertson'
1320460229.119578: dbus: Register BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/37'
1320460229.119669: BSS: Expire BSS 31 due to no match in scan
1320460229.119717: BSS: Remove id 31 BSSID 1c:af:f7:ca:16:d3 SSID '477302'
1320460229.119740: dbus: Unregister BSS object
'/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/31'
1320460229.119800: New scan results available
1320460229.119835: WPS: attr type=0x104a len=1
1320460229.119854: WPS: attr type=0x1044 len=1
1320460229.119865: WPS: attr type=0x103b len=1
1320460229.119876: WPS: attr type=0x1047 len=16
1320460229.119888: WPS: attr type=0x1021 len=7
1320460229.119899: WPS: attr type=0x1023 len=7
1320460229.119922: WPS: attr type=0x1024 len=6
1320460229.119937: WPS: attr type=0x1042 len=7
1320460229.119970: WPS: attr type=0x1054 len=8
1320460229.119992: WPS: attr type=0x1011 len=9
1320460229.119999: WPS: attr type=0x1008 len=2
1320460229.120008: WPS: attr type=0x104a len=1
1320460229.120021: WPS: attr type=0x1044 len=1
1320460229.120034: WPS: attr type=0x103b len=1
1320460229.120048: WPS: attr type=0x1047 len=16
1320460229.120063: WPS: attr type=0x1021 len=7
1320460229.120076: WPS: attr type=0x1023 len=7
1320460229.120090: WPS: attr type=0x1024 len=6
1320460229.120104: WPS: attr type=0x1042 len=7
1320460229.120117: WPS: attr type=0x1054 len=8
1320460229.120130: WPS: attr type=0x1011 len=9
1320460229.120145: WPS: attr type=0x1008 len=2
1320460229.120176: Selecting BSS from priority group 0
1320460229.120254: Try to find WPA-enabled AP
1320460229.120266: 0: 34:ef:44:1f:5b:59 ssid='Robertson' wpa_ie_len=0
rsn_ie_len=20 caps=0x431
1320460229.120281:    selected based on RSN IE
1320460229.120294:    selected WPA AP 34:ef:44:1f:5b:59 ssid='Robertson'
1320460229.120312: Automatic auth_alg selection: 0x1
1320460229.120327: RSN: using IEEE 802.11i/D9.0
1320460229.120341: WPA: Selected cipher suites: group 16 pairwise 16
key_mgmt 2 proto 2
1320460229.120352: WPA: clearing AP WPA IE
1320460229.120362: 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 00 00
1320460229.120382: WPA: using GTK CCMP
1320460229.120393: WPA: using PTK CCMP
1320460229.120403: WPA: using KEY_MGMT WPA-PSK
1320460229.120415: 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
1320460229.120434: Cancelling scan request
1320460229.120448: Trying to authenticate with 34:ef:44:1f:5b:59
(SSID='Robertson' freq=2447 MHz)
1320460229.120461: No keys have been configured - skip key clearing
1320460229.120472: State: SCANNING -> AUTHENTICATING
1320460229.120513: EAPOL: External notification - EAP success=0
1320460229.120532: EAPOL: Supplicant port status: Unauthorized
1320460229.120948: EAPOL: External notification - EAP fail=0
1320460229.120968: EAPOL: Supplicant port status: Unauthorized
1320460229.121101: EAPOL: External notification - portControl=Auto
1320460229.121120: EAPOL: Supplicant port status: Unauthorized
1320460229.121279: nl80211: Authenticate (ifindex=4)
1320460229.121299:   * bssid=34:ef:44:1f:5b:59
1320460229.121311:   * freq=2447
1320460229.121321:   * SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460229.121341:   * IEs - hexdump(len=0): [NULL]
1320460229.121352:   * Auth Type 0
1320460229.121619: nl80211: Authentication request send successfully
1320460229.121643: RTM_NEWLINK: operstate=0 ifi_flags=0x1003 ([UP])
1320460229.121659: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460229.124591: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460229.124689: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36
1320460229.124751: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16
1320460229.124813: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3
1320460229.124871: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20
1320460229.124933: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7
1320460229.125571: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/3)
1320460229.125848: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/4)
1320460229.126129: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/7)
1320460229.126382: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/16)
1320460229.126625: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/20)
1320460229.126946: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/36)
1320460229.127263: dbus: org.freedesktop.DBus.Properties.GetAll
(/fi/w1/wpa_supplicant1/Interfaces/1/BSSs/37)
1320460229.147664: nl80211: Event message available
1320460229.147717: nl80211: MLME event 37
1320460229.147728: nl80211: MLME event frame - hexdump(len=30): b0 00
02 01 f4 ec 38 e5 1c 4a 34 ef 44 1f 5b 59 34 ef 44 1f 5b 59 00 03 00
00 02 00 00 00
1320460229.147740: SME: Authentication response:
peer=34:ef:44:1f:5b:59 auth_type=0 status_code=0
1320460229.147749: SME: Authentication response IEs - hexdump(len=0): [NULL]
1320460229.147773: Trying to associate with 34:ef:44:1f:5b:59
(SSID='Robertson' freq=2447 MHz)
1320460229.147782: State: AUTHENTICATING -> ASSOCIATING
1320460229.147790: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1320460229.147797: netlink: Operstate: linkmode=-1, operstate=5
1320460229.147847: 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
1320460229.147871: nl80211: Associate (ifindex=4)
1320460229.147889:   * bssid=34:ef:44:1f:5b:59
1320460229.147899:   * freq=2447
1320460229.147909:   * SSID - hexdump_ascii(len=9):
     52 6f 62 65 72 74 73 6f 6e                        Robertson
1320460229.147942:   * 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
1320460229.147960:   * prev_bssid=34:ef:44:1f:5b:59
1320460229.152542: nl80211: Association request send successfully
1320460229.152959: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460229.190114: nl80211: Event message available
1320460229.190166: nl80211: Ignored unknown event (cmd=19)
1320460229.191329: nl80211: Event message available
1320460229.191370: nl80211: MLME event 38
1320460229.191382: nl80211: MLME event frame - hexdump(len=57): 30 00
a2 00 f4 ec 38 e5 1c 4a 34 ef 44 1f 5b 59 34 ef 44 1f 5b 59 20 03 31
04 00 00 01 c0 01 08 82 84 8b 0c 12 96 18 24 32 04 30 48 60 6c dd 09
00 03 7f 01 01 00 00 ff 7f
1320460229.191408: Association info event
1320460229.191418: resp_ies - hexdump(len=27): 01 08 82 84 8b 0c 12 96
18 24 32 04 30 48 60 6c dd 09 00 03 7f 01 01 00 00 ff 7f
1320460229.191468: freq=2447 MHz
1320460229.191482: State: ASSOCIATING -> ASSOCIATED
1320460229.191493: wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT)
1320460229.191504: netlink: Operstate: linkmode=-1, operstate=5
1320460229.191607: Associated to a new BSS: BSSID=34:ef:44:1f:5b:59
1320460229.191629: No keys have been configured - skip key clearing
1320460229.191642: Associated with 34:ef:44:1f:5b:59
1320460229.191654: WPA: Association event - clear replay counter
1320460229.191680: WPA: Clear old PTK
1320460229.191690: EAPOL: External notification - portEnabled=0
1320460229.191702: EAPOL: Supplicant port status: Unauthorized
1320460229.191917: EAPOL: External notification - portValid=0
1320460229.191935: EAPOL: Supplicant port status: Unauthorized
1320460229.192066: EAPOL: External notification - EAP success=0
1320460229.192083: EAPOL: Supplicant port status: Unauthorized
1320460229.192237: EAPOL: External notification - portEnabled=1
1320460229.192255: EAPOL: SUPP_PAE entering state CONNECTING
1320460229.192265: EAPOL: enable timer tick
1320460229.192277: EAPOL: SUPP_BE entering state IDLE
1320460229.192290: Setting authentication timeout: 10 sec 0 usec
1320460229.192347: Cancelling scan request
1320460229.192367: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1320460229.192383: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460229.192396: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1320460229.192408: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460229.192422: RTM_NEWLINK: operstate=0 ifi_flags=0x11003 ([UP][LOWER_UP])
1320460229.192433: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460229.192448: nl80211: Event message available
1320460229.192470: nl80211: Ignore connect event (cmd=46) when using
userspace SME
1320460229.196682: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460229.199170: RX EAPOL from 34:ef:44:1f:5b:59
1320460229.199277: RX EAPOL - hexdump(len=99): 01 03 00 5f 02 00 8a 00
10 00 00 00 00 00 00 00 01 53 ac 29 f9 f4 0f 27 a9 54 e4 9e 46 ba e1
ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 58 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
1320460229.199317: Setting authentication timeout: 10 sec 0 usec
1320460229.199347: IEEE 802.1X RX: version=1 type=3 length=95
1320460229.199361:   EAPOL-Key type=2
1320460229.199371:   key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1320460229.199382:   key_length=16 key_data_length=0
1320460229.199393:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
1320460229.199407:   key_nonce - hexdump(len=32): 53 ac 29 f9 f4 0f 27
a9 54 e4 9e 46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38
0a 58
1320460229.199455:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00
1320460229.199470:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.199512:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.199527:   key_mic - hexdump(len=16): 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00
1320460229.199552: WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02
00 8a 00 10 00 00 00 00 00 00 00 01 53 ac 29 f9 f4 0f 27 a9 54 e4 9e
46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 58 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00
1320460229.199587: State: ASSOCIATED -> 4WAY_HANDSHAKE
1320460229.199641: WPA: RX message 1 of 4-Way Handshake from
34:ef:44:1f:5b:59 (ver=2)
1320460229.199662: RSN: msg 1/4 key data - hexdump(len=0):
1320460229.201526: WPA: Renewed SNonce - hexdump(len=32): 3a dd be 40
d1 04 e1 ed 9c ef 1f 4b aa af de f6 8e cc 23 70 d8 bd 81 a2 0d d0 4e
e5 f8 92 2e 37
1320460229.201568: WPA: PTK derivation - A1=f4:ec:38:e5:1c:4a
A2=34:ef:44:1f:5b:59
1320460229.201580: WPA: PMK - hexdump(len=32): [REMOVED]
1320460229.201590: WPA: PTK - hexdump(len=48): [REMOVED]
1320460229.201599: 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
1320460229.201615: WPA: Sending EAPOL-Key 2/4
1320460229.201628: WPA: TX EAPOL-Key - hexdump(len=121): 01 03 00 75
02 01 0a 00 00 00 00 00 00 00 00 00 01 3a dd be 40 d1 04 e1 ed 9c ef
1f 4b aa af de f6 8e cc 23 70 d8 bd 81 a2 0d d0 4e e5 f8 92 2e 37 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 10 b1 51 b1 af ae 4f a8 67 3a 2b 75 56 30 06
aa 00 16 30 14 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 00 0f ac 02
00 00
1320460229.204796: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460229.216016: RX EAPOL from 34:ef:44:1f:5b:59
1320460229.216131: RX EAPOL - hexdump(len=155): 01 03 00 97 02 13 ca
00 10 00 00 00 00 00 00 00 02 53 ac 29 f9 f4 0f 27 a9 54 e4 9e 46 ba
e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 58 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 b7 c2 66 b2 f4 7f 0e 83 59 b1 71 0f 82 2d 14 e4 00 38
57 24 a7 fa 78 93 6c 69 3c 01 26 45 3f a8 e7 47 89 41 9e 85 03 f4 3a
52 7d 5d fc fa 05 bc 75 c8 79 6b 35 ca 7f 26 e3 ab 5d ce d4 a1 f1 67
d2 d2 97 88 95 bc b0 be 60 6e
1320460229.216177: IEEE 802.1X RX: version=1 type=3 length=151
1320460229.216212:   EAPOL-Key type=2
1320460229.216226:   key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise
Install Ack MIC Secure Encr)
1320460229.216242:   key_length=16 key_data_length=56
1320460229.216254:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 02
1320460229.216268:   key_nonce - hexdump(len=32): 53 ac 29 f9 f4 0f 27
a9 54 e4 9e 46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38
0a 58
1320460229.216289:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00
1320460229.216305:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.216351:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.216364:   key_mic - hexdump(len=16): b7 c2 66 b2 f4 7f 0e
83 59 b1 71 0f 82 2d 14 e4
1320460229.216384: WPA: RX EAPOL-Key - hexdump(len=155): 01 03 00 97
02 13 ca 00 10 00 00 00 00 00 00 00 02 53 ac 29 f9 f4 0f 27 a9 54 e4
9e 46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 58 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 b7 c2 66 b2 f4 7f 0e 83 59 b1 71 0f 82 2d 14
e4 00 38 57 24 a7 fa 78 93 6c 69 3c 01 26 45 3f a8 e7 47 89 41 9e 85
03 f4 3a 52 7d 5d fc fa 05 bc 75 c8 79 6b 35 ca 7f 26 e3 ab 5d ce d4
a1 f1 67 d2 d2 97 88 95 bc b0 be 60 6e
1320460229.216449: RSN: encrypted key data - hexdump(len=56): 57 24 a7
fa 78 93 6c 69 3c 01 26 45 3f a8 e7 47 89 41 9e 85 03 f4 3a 52 7d 5d
fc fa 05 bc 75 c8 79 6b 35 ca 7f 26 e3 ab 5d ce d4 a1 f1 67 d2 d2 97
88 95 bc b0 be 60 6e
1320460229.216503: WPA: decrypted EAPOL-Key key data -
hexdump(len=48): [REMOVED]
1320460229.216517: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1320460229.216528: WPA: RX message 3 of 4-Way Handshake from
34:ef:44:1f:5b:59 (ver=2)
1320460229.216541: 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 00 00 dd 16 00 0f ac 01
01 00 48 e2 0d bb 7c 9f e2 59 1b 72 df 60 b1 57 03 3c dd 00
1320460229.216567: 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 00 00
1320460229.216587: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
1320460229.216601: WPA: Sending EAPOL-Key 4/4
1320460229.216615: 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 25 b2 e3 b2 9d 45 9c 57 a5 5b 61 9f d3 25 aa 5e
00 00
1320460229.216671: WPA: Installing PTK to the driver.
1320460229.217093: wpa_driver_nl80211_set_key: ifindex=4 alg=3
addr=0x1bd3ab0 key_idx=0 set_tx=1 seq_len=6 key_len=16
1320460229.217121:    addr=34:ef:44:1f:5b:59
1320460229.217541: EAPOL: External notification - portValid=1
1320460229.217566: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1320460229.217626: RSN: received GTK in pairwise handshake -
hexdump(len=18): [REMOVED]
1320460229.217647: WPA: Group Key - hexdump(len=16): [REMOVED]
1320460229.217657: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16).
1320460229.217668: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
1320460229.217810: wpa_driver_nl80211_set_key: ifindex=4 alg=3
addr=0x47a641 key_idx=1 set_tx=0 seq_len=6 key_len=16
1320460229.217902: WPA: Key negotiation completed with
34:ef:44:1f:5b:59 [PTK=CCMP GTK=CCMP]
1320460229.217920: Cancelling authentication timeout
1320460229.217931: State: GROUP_HANDSHAKE -> COMPLETED
1320460229.217943: CTRL-EVENT-CONNECTED - Connection to
34:ef:44:1f:5b:59 completed (reauth) [id=0 id_str=]
1320460229.217953: wpa_driver_nl80211_set_operstate: operstate 0->1 (UP)
1320460229.217978: netlink: Operstate: linkmode=-1, operstate=6
1320460229.218954: EAPOL: External notification - portValid=1
1320460229.218993: EAPOL: External notification - EAP success=1
1320460229.219003: EAPOL: SUPP_PAE entering state AUTHENTICATING
1320460229.219014: EAPOL: SUPP_BE entering state SUCCESS
1320460229.219023: EAP: EAP entering state DISABLED
1320460229.219069: EAPOL: SUPP_PAE entering state AUTHENTICATED
1320460229.219079: EAPOL: Supplicant port status: Authorized
1320460229.219249: EAPOL: SUPP_BE entering state IDLE
1320460229.219268: EAPOL authentication completed successfully
1320460229.219288: RTM_NEWLINK: operstate=1 ifi_flags=0x11043
([UP][RUNNING][LOWER_UP])
1320460229.219315: RTM_NEWLINK, IFLA_IFNAME: Interface 'wlan1' added
1320460229.221448: RX EAPOL from 34:ef:44:1f:5b:59
1320460229.221482: RX EAPOL - hexdump(len=131): 01 03 00 7f 02 13 82
00 10 00 00 00 00 00 00 00 03 53 ac 29 f9 f4 0f 27 a9 54 e4 9e 46 ba
e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 57 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 17 2b 4c 7c 7c 47 62 0c 8d 07 37 c7 db b2 2e b9 00 20
79 14 fd 11 ac bc 39 45 21 fb 3a b3 c2 7a d1 31 c6 7a 71 89 f2 4d 1a
ef 9e 9e 82 6f 9a 0b e8 ac
1320460229.221553: IEEE 802.1X RX: version=1 type=3 length=127
1320460229.221565:   EAPOL-Key type=2
1320460229.221575:   key_info 0x1382 (ver=2 keyidx=0 rsvd=0 Group Ack
MIC Secure Encr)
1320460229.221588:   key_length=16 key_data_length=32
1320460229.221641:   replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 03
1320460229.221655:   key_nonce - hexdump(len=32): 53 ac 29 f9 f4 0f 27
a9 54 e4 9e 46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38
0a 57
1320460229.221673:   key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00
1320460229.221689:   key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.221702:   key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
1320460229.221717:   key_mic - hexdump(len=16): 17 2b 4c 7c 7c 47 62
0c 8d 07 37 c7 db b2 2e b9
1320460229.221733: WPA: RX EAPOL-Key - hexdump(len=131): 01 03 00 7f
02 13 82 00 10 00 00 00 00 00 00 00 03 53 ac 29 f9 f4 0f 27 a9 54 e4
9e 46 ba e1 ef 77 1c 27 f7 d8 f8 b8 a2 9e 20 83 cb e2 38 38 0a 57 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 17 2b 4c 7c 7c 47 62 0c 8d 07 37 c7 db b2 2e
b9 00 20 79 14 fd 11 ac bc 39 45 21 fb 3a b3 c2 7a d1 31 c6 7a 71 89
f2 4d 1a ef 9e 9e 82 6f 9a 0b e8 ac
1320460229.221784: RSN: encrypted key data - hexdump(len=32): 79 14 fd
11 ac bc 39 45 21 fb 3a b3 c2 7a d1 31 c6 7a 71 89 f2 4d 1a ef 9e 9e
82 6f 9a 0b e8 ac
1320460229.221819: WPA: decrypted EAPOL-Key key data -
hexdump(len=24): [REMOVED]
1320460229.221832: WPA: RX message 1 of Group Key Handshake from
34:ef:44:1f:5b:59 (ver=2)
1320460229.221845: RSN: msg 1/2 key data - hexdump(len=24): dd 16 00
0f ac 01 01 00 48 e2 0d bb 7c 9f e2 59 1b 72 df 60 b1 57 03 3c
1320460229.221862: WPA: GTK in EAPOL-Key - hexdump(len=24): [REMOVED]
1320460229.221873: RSN: received GTK in group key handshake -
hexdump(len=18): 01 00 48 e2 0d bb 7c 9f e2 59 1b 72 df 60 b1 57 03 3c
1320460229.221888: State: COMPLETED -> GROUP_HANDSHAKE
1320460229.221938: WPA: Group Key - hexdump(len=16): [REMOVED]
1320460229.221954: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=16).
1320460229.221964: WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
1320460229.222085: wpa_driver_nl80211_set_key: ifindex=4 alg=3
addr=0x47a641 key_idx=1 set_tx=0 seq_len=6 key_len=16
1320460229.233439: WPA: Sending EAPOL-Key 2/2
1320460229.233493: WPA: TX EAPOL-Key - hexdump(len=99): 01 03 00 5f 02
03 02 00 00 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
00 00 00 00 00 00 00 81 f2 62 00 e7 5a 8f eb 2b ec ff 63 32 ba 16 d8
00 00
1320460229.233558: WPA: Group rekeying completed with
34:ef:44:1f:5b:59 [GTK=CCMP]
1320460229.233576: Cancelling authentication timeout
1320460229.233589: State: GROUP_HANDSHAKE -> COMPLETED
1320460229.233643: dbus: flush_object_timeout_handler: Timeout -
sending changed properties of object
/fi/w1/wpa_supplicant1/Interfaces/1
1320460230.193321: EAPOL: startWhen --> 0
1320460230.193435: EAPOL: disable timer tick

Thanks in advance!

-- 
Aaron Faanes <dafrito gmail com>


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