GNOME Bugzilla – Bug 582842
Delayed connection after standby
Last modified: 2010-01-04 21:40:58 UTC
Please describe the problem: I am running a Thinkpad z61m laptop and the wireless functions well. The only problem is when going from standby mode. Sometimes it takes almost a minute for the NetworkManager to start trying to connect to the wireless network. When it finally starts connecting, the connection is established in seconds. Steps to reproduce: 1. Put laptop into standby mode 2. Bring laptop out of standby mode 3. Observer NetworkManager icon on top panel Actual results: I will eventually connect to my wireless network, but it takes almost a minute before it tries. Expected results: Immediately after step 2 - start connecting Does this happen every time? 80% of times Other information: From daemon.log: May 16 07:03:53 ziggy-laptop NetworkManager: <info> Waking up... May 16 07:03:53 ziggy-laptop NetworkManager: <info> (eth0): now managed May 16 07:03:53 ziggy-laptop NetworkManager: <info> (eth0): device state change: 1 -> 2 May 16 07:03:53 ziggy-laptop NetworkManager: <info> (eth0): bringing up device. May 16 07:03:53 ziggy-laptop NetworkManager: <info> (eth0): preparing device. May 16 07:03:53 ziggy-laptop NetworkManager: <info> (eth0): deactivating device (reason: 2). May 16 07:03:53 ziggy-laptop NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889) May 16 07:03:53 ziggy-laptop NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889) May 16 07:03:53 ziggy-laptop NetworkManager: <info> (wlan0): now managed May 16 07:03:53 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 1 -> 2 May 16 07:03:53 ziggy-laptop NetworkManager: <info> (wlan0): bringing up device. May 16 07:03:54 ziggy-laptop NetworkManager: <info> (wlan0): preparing device. May 16 07:03:54 ziggy-laptop NetworkManager: <info> (wlan0): deactivating device (reason: 2). May 16 07:03:54 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 2 -> 3 May 16 07:03:54 ziggy-laptop NetworkManager: <info> (wlan0): supplicant interface state: starting -> ready May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) starting connection 'Auto stardust' May 16 07:04:45 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 3 -> 4 May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... May 16 07:04:45 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 4 -> 5 May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto stardust' has security, and secrets exist. No new secrets needed. May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'ssid' value 'stardust' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'scan_ssid' value '1' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'psk' value '<omitted>' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'proto' value 'WPA RSN' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'pairwise' value 'TKIP CCMP' May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: added 'group' value 'WEP40 WEP104 TKIP CCMP' May 16 07:04:45 ziggy-laptop NetworkManager: nm_setting_802_1x_get_pkcs11_engine_path: assertion `NM_IS_SETTING_802_1X (setting)' failed May 16 07:04:45 ziggy-laptop NetworkManager: nm_setting_802_1x_get_pkcs11_module_path: assertion `NM_IS_SETTING_802_1X (setting)' failed May 16 07:04:45 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. May 16 07:04:45 ziggy-laptop NetworkManager: <info> Config: set interface ap_scan to 1 May 16 07:04:45 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected May 16 07:04:50 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning May 16 07:04:51 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating May 16 07:04:52 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake May 16 07:04:52 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated May 16 07:04:54 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associated -> 4-way handshake May 16 07:04:54 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated May 16 07:04:58 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associated -> disconnected May 16 07:04:58 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning May 16 07:04:59 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: scanning -> 4-way handshake May 16 07:04:59 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated May 16 07:05:00 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associated -> 4-way handshake May 16 07:05:00 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> group handshake May 16 07:05:00 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: group handshake -> completed May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'stardust'. May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... May 16 07:05:00 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 5 -> 7 May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Beginning DHCP transaction. May 16 07:05:00 ziggy-laptop NetworkManager: <info> dhclient started with pid 29219 May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete. May 16 07:05:00 ziggy-laptop NetworkManager: <info> DHCP: device wlan0 state changed normal exit -> preinit May 16 07:05:00 ziggy-laptop NetworkManager: <info> DHCP: device wlan0 state changed preinit -> bound May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled... May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) started... May 16 07:05:00 ziggy-laptop NetworkManager: <info> address 10.0.0.7 May 16 07:05:00 ziggy-laptop NetworkManager: <info> prefix 24 (255.255.255.0) May 16 07:05:00 ziggy-laptop NetworkManager: <info> gateway 10.0.0.138 May 16 07:05:00 ziggy-laptop NetworkManager: <info> nameserver '10.0.0.138' May 16 07:05:00 ziggy-laptop NetworkManager: <info> domain name 'lan' May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled... May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete. May 16 07:05:00 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started... May 16 07:05:01 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 7 -> 8 May 16 07:05:01 ziggy-laptop NetworkManager: <info> Policy set 'Auto stardust' (wlan0) as default for routing and DNS. May 16 07:05:01 ziggy-laptop NetworkManager: <info> Activation (wlan0) successful, device activated. May 16 07:05:01 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
Another log entry when the same happened: May 16 12:27:11 ziggy-laptop NetworkManager: <info> Waking up... May 16 12:27:11 ziggy-laptop NetworkManager: <info> (eth0): now managed May 16 12:27:11 ziggy-laptop NetworkManager: <info> (eth0): device state change: 1 -> 2 May 16 12:27:11 ziggy-laptop NetworkManager: <info> (eth0): bringing up device. May 16 12:27:11 ziggy-laptop NetworkManager: <info> (eth0): preparing device. May 16 12:27:11 ziggy-laptop NetworkManager: <info> (eth0): deactivating device (reason: 2). May 16 12:27:11 ziggy-laptop NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889) May 16 12:27:11 ziggy-laptop NetworkManager: <info> Unmanaged Device found; state CONNECTED forced. (see http://bugs.launchpad.net/bugs/191889) May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): now managed May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 1 -> 2 May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): bringing up device. May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): preparing device. May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): deactivating device (reason: 2). May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 2 -> 3 May 16 12:27:11 ziggy-laptop NetworkManager: <info> (wlan0): supplicant interface state: starting -> ready May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) starting connection 'Auto stardust' May 16 12:28:08 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 3 -> 4 May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... May 16 12:28:08 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 4 -> 5 May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0/wireless): connection 'Auto stardust' has security, and secrets exist. No new secrets needed. May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'ssid' value 'stardust' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'scan_ssid' value '1' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'key_mgmt' value 'WPA-PSK' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'psk' value '<omitted>' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'proto' value 'WPA RSN' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'pairwise' value 'TKIP CCMP' May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: added 'group' value 'WEP40 WEP104 TKIP CCMP' May 16 12:28:08 ziggy-laptop NetworkManager: nm_setting_802_1x_get_pkcs11_engine_path: assertion `NM_IS_SETTING_802_1X (setting)' failed May 16 12:28:08 ziggy-laptop NetworkManager: nm_setting_802_1x_get_pkcs11_module_path: assertion `NM_IS_SETTING_802_1X (setting)' failed May 16 12:28:08 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. May 16 12:28:08 ziggy-laptop NetworkManager: <info> Config: set interface ap_scan to 1 May 16 12:28:08 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: scanning -> disconnected May 16 12:28:08 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: disconnected -> scanning May 16 12:28:09 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: scanning -> associating May 16 12:28:09 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associating -> 4-way handshake May 16 12:28:09 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> associated May 16 12:28:10 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: associated -> 4-way handshake May 16 12:28:10 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: 4-way handshake -> group handshake May 16 12:28:10 ziggy-laptop NetworkManager: <info> (wlan0): supplicant connection state: group handshake -> completed May 16 12:28:10 ziggy-laptop NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to wireless network 'stardust'. May 16 12:28:10 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. May 16 12:28:10 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... May 16 12:28:10 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 5 -> 7 May 16 12:28:10 ziggy-laptop NetworkManager: <info> Activation (wlan0) Beginning DHCP transaction. May 16 12:28:10 ziggy-laptop NetworkManager: <info> dhclient started with pid 30812 May 16 12:28:10 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete. May 16 12:28:10 ziggy-laptop NetworkManager: <info> DHCP: device wlan0 state changed normal exit -> preinit May 16 12:28:11 ziggy-laptop NetworkManager: <info> DHCP: device wlan0 state changed preinit -> bound May 16 12:28:11 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled... May 16 12:28:11 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) started... May 16 12:28:11 ziggy-laptop NetworkManager: <info> address 10.0.0.7 May 16 12:28:11 ziggy-laptop NetworkManager: <info> prefix 24 (255.255.255.0) May 16 12:28:11 ziggy-laptop NetworkManager: <info> gateway 10.0.0.138 May 16 12:28:11 ziggy-laptop NetworkManager: <info> nameserver '10.0.0.138' May 16 12:28:11 ziggy-laptop NetworkManager: <info> domain name 'lan' May 16 12:28:11 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled... May 16 12:28:11 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete. May 16 12:28:11 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started... May 16 12:28:12 ziggy-laptop NetworkManager: <info> (wlan0): device state change: 7 -> 8 May 16 12:28:12 ziggy-laptop NetworkManager: <info> Policy set 'Auto stardust' (wlan0) as default for routing and DNS. May 16 12:28:12 ziggy-laptop NetworkManager: <info> Activation (wlan0) successful, device activated. May 16 12:28:12 ziggy-laptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.
You can see the one minute delay in the middle of the logs, just before activation of the wlan-device-
*** This bug has been marked as a duplicate of bug 596469 ***