Red Hat Bugzilla – Bug 441819
iwl3945: long delay locating networks after suspend
Last modified: 2008-08-19 14:44:58 EDT
Description of problem:
When I boot my system, NetworkManager finds my local network and connects very
quickly, no problems. Then, if I suspend my laptop and wake it up, it'll find
the network again, but there is a generally a 30 delay before it locates any
networks, including my own.
I guess I'm impatient, but this is a long time.... Is this normal? Can it be
%> uname -r
%> grep iw /var/log/dmesg
iwl3945: Intel(R) PRO/Wireless 3945ABG/BG Network Connection driver for Linux,
iwl3945: Copyright(c) 2003-2008 Intel Corporation
iwl3945: Detected Intel Wireless WiFi Link 3945ABG
iwl3945: Tunable channels: 13 802.11bg, 23 802.11a channels
phy0: Selected rate control algorithm 'iwl-3945-rs'
%>grep -H NetworkManager rpmpkgs
It takes some time to accumulate scan info. I'm not sure what NM uses to
determine that it has "enough" info. 30 seconds doesn't sound completely
unreasonable to me, but perhaps there is some explanation...I'll CC the NM
Thanks for that. Hello again dcbw ;-) we're back were we started. See the last
comment in BZ 441050 for a final thought on the previous bug report.
John, I wonder why though it only takes a few seconds to find it when first
booting up, verses 30 seconds to find it after resuming from suspend?
Can you run 'iwevent' in a terminal over a suspend/resume and post the output
here, also indicating at what time you suspended?
Won't wpa_supplicant have to trigger the scan? How does he know to do that?
I suppose it may take mac80211 a little while to figure-out that the
connection has dropped -- it is completely unaware of suspend/resume. Of
course, the driver should be unregistering the device before suspend and
reregistering upon resume. I'm not sure why that would take any longer than
the original boot.
Hmm; could be. NM would be throwing away the device, and re-initializing it,
and then would be requesting scans from wpa_supplicant immediately after it
finds the device again. Would need to see the output from iwevent first to
determine whether this is a kernel bug or an NM bug I guess.
I see this on a 4965 too:
I close the lid at 12:01:45 and unsuspend at 12:02:11
12:01:48.044860 wlan0 Set ESSID:off/any
12:01:48.044934 wlan0 Set Encryption key:off
12:01:48.049753 wlan0 New Access Point/Cell address:Not-Associated
12:01:48.088841 wlan0 Scan request completed
12:02:12.439582 wlan0 Set Mode:Managed
12:02:12.449201 wlan0 Set ESSID:off/any
12:02:12.449224 wlan0 Set Encryption key:off
12:02:34.156096 wlan0 Scan request completed
12:02:39.888907 wlan0 Scan request completed
12:02:39.889152 wlan0 Set Mode:Managed
12:02:39.892184 wlan0 Set Frequency:2.462 GHz (Channel 11)
12:02:39.894508 wlan0 Set ESSID:"AGSM2"
12:02:40.109692 wlan0 Custom driver
12:02:40.109743 wlan0 New Access Point/Cell address:00:19:07:8E:1A:55
Suspended at 09:34:53, resumed at 09:35:04, network found at 09:35:33. 30 second
Unfortunately, it took an additional minute or so after that to actually
connect, since after resuming, gnome-keyring-manager seems to always have a bout
of amnesia, cause i often times need to reenter my web keys to connect...PITA...
but that's a different issue all together. :-)
Waiting for Wireless Events from interfaces...
09:34:53.406893 wlan0 New Access Point/Cell address:Not-Associated
09:35:04.568241 wlan0 Set Mode:Managed
09:35:04.580492 wlan0 Set ESSID:off/any
09:35:27.154755 wlan0 Scan request completed
09:35:33.755066 wlan0 Scan request completed
09:35:33.756027 wlan0 Set Mode:Managed
09:35:33.756061 wlan0 Set ESSID:"rh-wireless"
So, back at home, I'm again able to reproduce the 'more than 30 seconds to
connect' issue I was having originally. I'm not sure what's causing the problem,
but I'd surely like to solve it. :-)
In this case, I've been on my computer, surfing surfing surfing. I was connected
using VPN (just in case it might be a clue. :-). Then i suspended my laptop.
After an hour or so, i resumed it, and waited a few minutes. My network was
never found. So i switched on iwevent, suspended again, resumed, and here's the
result. You'll notice that eventually it did find the network, but that's only
because I did a `rmmod iwl3945; modprobe iwl3945;`. After which, the network was
found and connected to in just a few seconds, as expected. I've added comments,
where I think the actions occurred more or less.
Waiting for Wireless Events from interfaces...
18:54:46.534597 wlan0 Set Mode:Managed
18:54:46.539154 wlan0 Set ESSID:off/any
# RESUME - notice i wait ~5 minutes
18:54:50.766608 wlan0 Scan request completed
18:55:10.805003 wlan0 Scan request completed
18:56:10.805829 wlan0 Scan request completed
18:57:50.806802 wlan0 Scan request completed
18:59:50.807562 wlan0 Scan request completed
# RMMOD IWL3945
19:00:22.429736 wlan0 Set ESSID:off/any
19:00:22.515609 wlan0 Set Mode:Managed
# MODPROBE IWL3945
19:00:22.527608 wlan0 Set ESSID:off/any
19:00:26.742100 wlan0 Scan request completed
19:00:29.768341 wlan0 Set Mode:Managed
19:00:29.769658 wlan0 Set Frequency:2.462 GHz (Channel 11)
19:00:29.769755 wlan0 Set ESSID:"wayuptop"
19:00:29.775788 wlan0 Custom driver
19:00:29.775822 wlan0 New Access Point/Cell address:00:1D:7E:BD:4C:AA
Dan it looks like it is getting the scan completed events. Any way to tell
what the contents of those scans are?
I think this is working better now.