[Bug 566483] Re: wireless is slow to reconnect after suspend
John McCombs
jdm at inmap.co.nz
Thu Apr 29 02:47:19 UTC 2010
Hi Jeremy,
not entirely sure I know what you mean by "latest development release of
Ubuntu".
You mean this?
http://cdimage.ubuntu.com/releases/10.04/rc/ubuntu-10.04-rc-dvd-i386.iso
The above image, with and without all the subsequent updates applied
shows the problem described.
Also tested on an Acer Aspire One 150. The Acer does not exhibit this
problem.
As noted Karmic on the HP 5101 did not display this problem.
I've run apport-collect
** Tags added: apport-collected
** Description changed:
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))
+ ---
+ AlsaVersion: Advanced Linux Sound Architecture Driver Version 1.0.21.
+ AplayDevices:
+ **** List of PLAYBACK Hardware Devices ****
+ card 0: Intel [HDA Intel], device 0: AD198x Analog [AD198x Analog]
+ Subdevices: 1/1
+ Subdevice #0: subdevice #0
+ Architecture: i386
+ ArecordDevices:
+ **** List of CAPTURE Hardware Devices ****
+ card 0: Intel [HDA Intel], device 0: AD198x Analog [AD198x Analog]
+ Subdevices: 2/2
+ Subdevice #0: subdevice #0
+ Subdevice #1: subdevice #1
+ AudioDevicesInUse:
+ USER PID ACCESS COMMAND
+ /dev/snd/controlC0: ubuntu 2991 F.... pulseaudio
+ CRDA: Error: [Errno 2] No such file or directory
+ Card0.Amixer.info:
+ Card hw:0 'Intel'/'HDA Intel at 0xe8280000 irq 21'
+ Mixer name : 'Analog Devices AD1984A'
+ Components : 'HDA:11d4194a,103c3632,00100400'
+ Controls : 18
+ Simple ctrls : 11
+ DistroRelease: Ubuntu 10.04
+ LiveMediaBuild: Ubuntu 10.04 "Lucid Lynx" - Release Candidate i386 (20100419)
+ MachineType: Hewlett-Packard HP Mini 5101
+ NonfreeKernelModules: wl
+ Package: linux (not installed)
+ ProcCmdLine: BOOT_IMAGE=/casper/vmlinuz file=/cdrom/preseed/hostname.seed boot=casper initrd=/casper/initrd.lz quiet splash --
+ ProcEnviron:
+ LANG=en_US.UTF-8
+ SHELL=/bin/bash
+ ProcVersionSignature: Ubuntu 2.6.32-21.32-generic 2.6.32.11+drm33.2
+ Regression: Yes
+ RelatedPackageVersions: linux-firmware 1.34
+ Reproducible: Yes
+ RfKill:
+
+ Tags: lucid suspend resume regression-potential needs-upstream-testing
+ Uname: Linux 2.6.32-21-generic i686
+ UserGroups: adm admin cdrom dialout lpadmin plugdev sambashare
+ dmi.bios.date: 09/25/2009
+ dmi.bios.vendor: Hewlett-Packard
+ dmi.bios.version: 68DGI Ver. F.02
+ dmi.board.name: 3632
+ dmi.board.vendor: Hewlett-Packard
+ dmi.board.version: KBC Version 34.0F
+ dmi.chassis.asset.tag: CNU946CM96
+ dmi.chassis.type: 10
+ dmi.chassis.vendor: Hewlett-Packard
+ dmi.modalias: dmi:bvnHewlett-Packard:bvr68DGIVer.F.02:bd09/25/2009:svnHewlett-Packard:pnHPMini5101:pvrF.02:rvnHewlett-Packard:rn3632:rvrKBCVersion34.0F:cvnHewlett-Packard:ct10:cvr:
+ dmi.product.name: HP Mini 5101
+ dmi.product.version: F.02
+ dmi.sys.vendor: Hewlett-Packard
--
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