[Bug 566483] [NEW] wireless is slow to reconnect after suspend
Launchpad Bug Tracker
566483 at bugs.launchpad.net
Mon Apr 19 13:27:36 UTC 2010
You have been subscribed to a public bug:
Lucid Beta 2 Netbook Remix, with all updates
Description: Ubuntu lucid (development branch)
Release: 10.04
PC is an HP5101 netbook. It has a Broadcom BCM4353 802.11 with the
Broadcom Linux STA wireless driver activated
After resuming wireless reconnection can take 45 sec or more. This
appears to be a regression from Karmic where reconnection on the same
netbook took less than 10 seconds.
Once reconnection is complete, "periodic_update(): Roamed from
BSSID...." messages appear in the log every few seconds.
daemon.log follows (note IP addresses replaced with xxx.xxx.xxx.xxx):
Apr 19 20:18:29 rio NetworkManager: <info> Waking up...
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): now managed
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): device state change: 1 -> 2 (reason 2)
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): bringing up device.
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): preparing device.
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): deactivating device (reason: 2).
Apr 19 20:18:29 rio NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Apr 19 20:18:29 rio NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889)
Apr 19 20:18:29 rio NetworkManager: <info> (eth0): now managed
Apr 19 20:18:29 rio NetworkManager: <info> (eth0): device state change: 1 -> 2 (reason 2)
Apr 19 20:18:29 rio NetworkManager: <info> (eth0): bringing up device.
Apr 19 20:18:29 rio NetworkManager: <info> (eth0): preparing device.
Apr 19 20:18:29 rio NetworkManager: <info> (eth0): deactivating device (reason: 2).
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): supplicant interface state: starting -> ready
Apr 19 20:18:29 rio NetworkManager: <info> (eth1): device state change: 2 -> 3 (reason 42)
Apr 19 20:18:31 rio avahi-daemon[789]: Registering new address record for fe80::226:82ff:fe25:324b on eth1.*.
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) starting connection 'Auto synet'
Apr 19 20:18:55 rio NetworkManager: <info> (eth1): device state change: 3 -> 4 (reason 0)
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) scheduled...
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) started...
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) scheduled...
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 1 of 5 (Device Prepare) complete.
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) starting...
Apr 19 20:18:55 rio NetworkManager: <info> (eth1): device state change: 4 -> 5 (reason 0)
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1/wireless): connection 'Auto synet' has security, and secrets exist. No new secrets needed.
Apr 19 20:18:55 rio NetworkManager: <info> Config: added 'ssid' value 'synet'
Apr 19 20:18:55 rio NetworkManager: <info> Config: added 'scan_ssid' value '1'
Apr 19 20:18:55 rio NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK'
Apr 19 20:18:55 rio NetworkManager: <info> Config: added 'psk' value '<omitted>'
Apr 19 20:18:55 rio NetworkManager: nm_setting_802_1x_get_pkcs11_engine_path: assertion `NM_IS_SETTING_802_1X (setting)' failed
Apr 19 20:18:55 rio NetworkManager: nm_setting_802_1x_get_pkcs11_module_path: assertion `NM_IS_SETTING_802_1X (setting)' failed
Apr 19 20:18:55 rio NetworkManager: <info> Activation (eth1) Stage 2 of 5 (Device Configure) complete.
Apr 19 20:18:55 rio NetworkManager: <info> Config: set interface ap_scan to 1
Apr 19 20:18:55 rio NetworkManager: <info> (eth1): supplicant connection state: scanning -> disconnected
Apr 19 20:19:00 rio NetworkManager: <info> (eth1): supplicant connection state: disconnected -> scanning
Apr 19 20:19:05 rio wpa_supplicant[824]: Trying to associate with 00:23:69:99:91:8e (SSID='synet' freq=2447 MHz)
Apr 19 20:19:05 rio wpa_supplicant[824]: Association request to the driver failed
Apr 19 20:19:05 rio NetworkManager: <info> (eth1): supplicant connection state: scanning -> associating
Apr 19 20:19:09 rio wpa_supplicant[824]: Associated with 00:23:69:99:91:8e
Apr 19 20:19:09 rio NetworkManager: <info> (eth1): supplicant connection state: associating -> associated
Apr 19 20:19:09 rio NetworkManager: <info> (eth1): supplicant connection state: associated -> 4-way handshake
Apr 19 20:19:09 rio NetworkManager: <info> (eth1): supplicant connection state: 4-way handshake -> group handshake
Apr 19 20:19:09 rio wpa_supplicant[824]: WPA: Key negotiation completed with 00:23:69:99:91:8e [PTK=CCMP GTK=CCMP]
Apr 19 20:19:09 rio wpa_supplicant[824]: CTRL-EVENT-CONNECTED - Connection to 00:23:69:99:91:8e completed (auth) [id=0 id_str=]
Apr 19 20:19:09 rio NetworkManager: <info> (eth1): supplicant connection state: group handshake -> completed
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'synet'.
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) scheduled.
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) started...
Apr 19 20:19:09 rio NetworkManager: <info> (eth1): device state change: 5 -> 7 (reason 0)
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Beginning DHCP transaction (timeout in 45 seconds)
Apr 19 20:19:09 rio NetworkManager: <info> dhclient started with pid 3691
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP6 Configure Get) scheduled...
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 3 of 5 (IP Configure Start) complete.
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP6 Configure Get) started...
Apr 19 20:19:09 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP6 Configure Get) complete.
Apr 19 20:19:09 rio dhclient: Internet Systems Consortium DHCP Client V3.1.3
Apr 19 20:19:09 rio dhclient: Copyright 2004-2009 Internet Systems Consortium.
Apr 19 20:19:09 rio dhclient: All rights reserved.
Apr 19 20:19:09 rio dhclient: For info, please visit https://www.isc.org/software/dhcp/
Apr 19 20:19:09 rio dhclient:
Apr 19 20:19:09 rio NetworkManager: <info> DHCP: device eth1 state changed normal exit -> preinit
Apr 19 20:19:10 rio dhclient: Listening on LPF/eth1/00:26:82:25:32:4b
Apr 19 20:19:10 rio dhclient: Sending on LPF/eth1/00:26:82:25:32:4b
Apr 19 20:19:10 rio dhclient: Sending on Socket/fallback
Apr 19 20:19:10 rio dhclient: DHCPREQUEST of xxx.xxx.xxx.xxx on eth1 to 255.255.255.255 port 67
Apr 19 20:19:10 rio dhclient: DHCPACK of xxx.xxx.xxx.xxx from 202.97.110.59
Apr 19 20:19:10 rio dhclient: bound to xxx.xxx.xxx.xxx -- renewal in 43024 seconds.
Apr 19 20:19:10 rio NetworkManager: <info> DHCP: device eth1 state changed preinit -> reboot
Apr 19 20:19:10 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) scheduled...
Apr 19 20:19:10 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) started...
Apr 19 20:19:10 rio NetworkManager: <info> address xxx.xxx.xxx.xxx
Apr 19 20:19:10 rio NetworkManager: <info> prefix 27 (255.255.255.224)
Apr 19 20:19:10 rio NetworkManager: <info> gateway 202.97.110.59
Apr 19 20:19:10 rio NetworkManager: <info> hostname 'rio'
Apr 19 20:19:10 rio NetworkManager: <info> nameserver '202.97.110.59'
Apr 19 20:19:10 rio NetworkManager: <info> domain name 'inmap.net'
Apr 19 20:19:10 rio NetworkManager: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) scheduled...
Apr 19 20:19:10 rio NetworkManager: <info> Activation (eth1) Stage 4 of 5 (IP4 Configure Get) complete.
Apr 19 20:19:10 rio NetworkManager: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) started...
Apr 19 20:19:10 rio avahi-daemon[789]: Joining mDNS multicast group on interface eth1.IPv4 with address xxx.xxx.xxx.xxx.
Apr 19 20:19:10 rio avahi-daemon[789]: New relevant interface eth1.IPv4 for mDNS.
Apr 19 20:19:10 rio avahi-daemon[789]: Registering new address record for xxx.xxx.xxx.xxx on eth1.IPv4.
Apr 19 20:19:11 rio NetworkManager: <info> (eth1): device state change: 7 -> 8 (reason 0)
Apr 19 20:19:11 rio NetworkManager: <info> Policy set 'Auto synet' (eth1) as default for routing and DNS.
Apr 19 20:19:11 rio NetworkManager: <info> Activation (eth1) successful, device activated.
Apr 19 20:19:11 rio NetworkManager: <info> Activation (eth1) Stage 5 of 5 (IP Configure Commit) complete.
Apr 19 20:19:13 rio ntpdate[3731]: adjust time server 91.189.94.4 offset 0.207425 sec
Apr 19 20:19:24 rio NetworkManager: <debug> [1271665164.004192] periodic_update(): Roamed from BSSID 00:23:69:99:91:8E (synet) to (none) ((none))
Apr 19 20:19:30 rio NetworkManager: <debug> [1271665170.006969] periodic_update(): Roamed from BSSID (none) ((none)) to 00:23:69:99:91:8E (synet)
Apr 19 20:19:36 rio NetworkManager: <debug> [1271665176.003683] periodic_update(): Roamed from BSSID 00:23:69:99:91:8E (synet) to (none) ((none))
Apr 19 20:19:42 rio NetworkManager: <debug> [1271665182.006729] periodic_update(): Roamed from BSSID (none) ((none)) to 00:23:69:99:91:8E (synet)
Apr 19 20:19:48 rio NetworkManager: <debug> [1271665188.006743] periodic_update(): Roamed from BSSID 00:23:69:99:91:8E (synet) to (none) ((none))
Apr 19 20:19:54 rio NetworkManager: <debug> [1271665194.006772] periodic_update(): Roamed from BSSID (none) ((none)) to 00:23:69:99:91:8E (synet)
Apr 19 20:20:00 rio NetworkManager: <debug> [1271665200.006925] periodic_update(): Roamed from BSSID 00:23:69:99:91:8E (synet) to (none) ((none))
Apr 19 20:20:06 rio NetworkManager: <debug> [1271665206.006470] periodic_update(): Roamed from BSSID (none) ((none)) to 00:23:69:99:91:8E (synet)
Apr 19 20:20:12 rio NetworkManager: <debug> [1271665212.006649] periodic_update(): Roamed from BSSID 00:23:69:99:91:8E (synet) to (none) ((none))
** Affects: linux (Ubuntu)
Importance: Undecided
Status: New
--
wireless is slow to reconnect after suspend
https://bugs.launchpad.net/bugs/566483
You received this bug notification because you are a member of Kernel Bugs, which is subscribed to linux in ubuntu.
More information about the kernel-bugs
mailing list