Bug 441819 - iwl3945: long delay locating networks after suspend
Summary: iwl3945: long delay locating networks after suspend
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 8
Hardware: All
OS: Linux
Target Milestone: ---
Assignee: John W. Linville
QA Contact: Fedora Extras Quality Assurance
Depends On:
TreeView+ depends on / blocked
Reported: 2008-04-10 11:49 UTC by Chris Ward
Modified: 2008-08-19 18:44 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Last Closed: 2008-08-19 18:44:58 UTC
Type: ---

Attachments (Terms of Use)

Description Chris Ward 2008-04-10 11:49:01 UTC
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

Comment 1 John W. Linville 2008-04-10 13:39:16 UTC
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 

Comment 2 Chris Ward 2008-04-10 13:57:59 UTC
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?

Comment 3 Dan Williams 2008-04-10 15:22:18 UTC
Can you run 'iwevent' in a terminal over a suspend/resume and post the output
here, also indicating at what time you suspended?

Comment 4 John W. Linville 2008-04-10 15:27:29 UTC
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.

Comment 5 Dan Williams 2008-04-10 16:47:39 UTC
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.

Comment 6 Bradley 2008-04-11 02:06:52 UTC
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

Comment 7 Chris Ward 2008-04-11 07:47:27 UTC
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. :-)

%> iwevent 
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"

Comment 8 Chris Ward 2008-04-12 17:13:25 UTC
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. 

%> iwevent 
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

19:00:22.429736   wlan0    Set ESSID:off/any
19:00:22.515609   wlan0    Set Mode:Managed

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

Comment 9 John W. Linville 2008-04-17 18:54:14 UTC
Dan it looks like it is getting the scan completed events.  Any way to tell 
what the contents of those scans are?

Comment 10 John W. Linville 2008-04-21 17:44:49 UTC

Comment 11 John W. Linville 2008-08-19 18:44:58 UTC
I think this is working better now.

Note You need to log in before you can comment on or make changes to this bug.