[pkg-wpa-devel] Bug#498600: After resume, wpasupplicant sits idle

[Antony Gelberg]

Kel Modderman wrote:
> Hi Antony,
> 
> On Thursday 11 September 2008 22:03:11 Antony Gelberg wrote:
>> Package: wpasupplicant
>> Version: 0.6.4~git20080716.93ef879-1
>> Severity: normal
>>
>> Hi,
>>
>> I have to say that this is a difficult problem to replicate, or should I say
>> the workaround is not always the same.  I find that after suspending or
>> hibernating my laptop, the wlan0 interface doesn't come back up properly.  It
>> doesn't seem to matter whether or not I resume in the same SSID that I
>> suspended in.
> 
> My hunch is it is very likely to be a problem related to the kernel
> wifi driver/networking stack. Also check your dmesg buffer for interesting
> messages from the kernel.

Thanks for responding.

Here's this morning's messages (please excuse my mailer's wrapping).

# grep wlan0 /var/log/syslog |grep -v avahi |grep -v ntp |grep "Sep 15"
Sep 15 10:13:33 labrie kernel: [365672.296512] wlan0: Initial auth_alg=0
Sep 15 10:13:33 labrie kernel: [365672.296518] wlan0: authenticate with 
AP 00:14:bf:3d:a7:8e
Sep 15 10:13:33 labrie kernel: [365672.301184] wlan0: RX authentication 
from 00:14:bf:3d:a7:8e (alg=0 transaction=2 status=0)
Sep 15 10:13:33 labrie kernel: [365672.301184] wlan0: authenticated
Sep 15 10:13:33 labrie kernel: [365672.301184] wlan0: associate with AP 
00:14:bf:3d:a7:8e
Sep 15 10:13:33 labrie kernel: [365672.303877] wlan0: RX ReassocResp 
from 00:14:bf:3d:a7:8e (capab=0x471 status=0 aid=1)
Sep 15 10:13:33 labrie kernel: [365672.303877] wlan0: associated
Sep 15 10:13:35 labrie kernel: [365680.310981] wlan0: RX 
deauthentication from 00:14:bf:3d:a7:8e (reason=1)
Sep 15 10:13:35 labrie kernel: [365680.310981] wlan0: deauthenticated
Sep 15 10:13:36 labrie kernel: [365681.309938] wlan0: authenticate with 
AP 00:14:bf:3d:a7:8e
Sep 15 10:13:36 labrie kernel: [365681.312178] wlan0: RX authentication 
from 00:14:bf:3d:a7:8e (alg=0 transaction=2 status=0)
Sep 15 10:13:36 labrie kernel: [365681.312178] wlan0: authenticated
Sep 15 10:13:36 labrie kernel: [365681.312178] wlan0: associate with AP 
00:14:bf:3d:a7:8e
Sep 15 10:13:36 labrie kernel: [365681.314684] wlan0: RX ReassocResp 
from 00:14:bf:3d:a7:8e (capab=0x471 status=0 aid=1)
Sep 15 10:13:36 labrie kernel: [365681.314684] wlan0: associated
Sep 15 10:13:36 labrie kernel: [365681.314684] wlan0: CTS protection 
enabled (BSSID=00:14:bf:3d:a7:8e)
Sep 15 10:13:36 labrie kernel: [365681.314684] wlan0: switched to short 
barker preamble (BSSID=00:14:bf:3d:a7:8e)
Sep 15 10:13:46 labrie dhclient: There is already a pid file 
/var/run/dhclient.wlan0.pid with pid 20970
Sep 15 10:13:46 labrie dhclient: Listening on LPF/wlan0/00:1f:3c:4b:70:1f
Sep 15 10:13:46 labrie dhclient: Sending on   LPF/wlan0/00:1f:3c:4b:70:1f
Sep 15 10:14:10 labrie dhclient: DHCPRELEASE on wlan0 to 192.168.1.1 port 67
Sep 15 10:14:15 labrie kernel: [365720.820450] ADDRCONF(NETDEV_UP): 
wlan0: link is not ready
Sep 15 10:14:17 labrie dhclient: Listening on LPF/wlan0/00:1f:3c:4b:70:1f
Sep 15 10:14:17 labrie dhclient: Sending on   LPF/wlan0/00:1f:3c:4b:70:1f
Sep 15 10:14:19 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 7
Sep 15 10:14:26 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 7
Sep 15 10:14:33 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 7
Sep 15 10:14:40 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 9
Sep 15 10:14:49 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 16
Sep 15 10:15:05 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 8
Sep 15 10:15:13 labrie dhclient: DHCPDISCOVER on wlan0 to 
255.255.255.255 port 67 interval 7

The only thing that strikes me as strange is the "kernel: 
[365720.820450] ADDRCONF(NETDEV_UP): wlan0: link is not ready".  I do 
not see why this should be so if wlan0 is associated with the AP.  Are 
you saying that this is definitely a kernel issue, because if so I will 
move the bug.

> 
> Workarounds:
> 
> I have found it very reliable to have the network disconnected entering
> suspend, and reconnected upon resuming. Otherwise, for me, the iwl* driver
> seemed to resume still associated network but without meaningful network
> connectivity.
> 

Hmm, iwl*?  Me too.  *ding*

The one thing I need to confirm is that for me, the driver resumes /not/ 
associated to the AP.  I will reply to this message in a day or two with 
confirmation.  At the moment, my recollection is that after a short 
sleep, it remains associated, and after a long sleep, it doesn't.

I am also trying the latest firmware (not yet in Debian), which I 
suppose might resolve the issue.

> The execution of such a hook depends on what power management software you are
> using. On Debian the popular ones seem to be acpi-support or pm-utils. I
> understand pm-utils pretty well, and have integrated a suspend/resume hook in a
> package in personal archive:
> http://sidux.net/kelmo/debian/pool/main/w/wpasupplicant/
> (Disclaimer: be careful with packages not coming directly from Debian archive)
> 
> It installs a script to:
> /etc/wpa_supplicant/action_wpa.sh
> 
> With symlink to script in pm-utils hook area:
> /etc/pm/sleep.d/action_wpa
> 
> As long as you keep the default wpa_supplicant configuration option for
> ctrl_interface (/var/run/wpa_supplicant/) this hook should be able to
> disconnect all wpa-roam'ing interfaces as machine goes into sleep, and
> reconnect on resume.
> 

I'm using pm-utils.  I have found that a simple, clunky script run on 
resume does the job:
#!/bin/sh
/etc/init.d/networking stop
modprobe -r iwl3945
modprobe iwl3945
/etc/init.d/networking start

Antony