Re: Problem of associated pre-suspend AP showing up in NM's AP list after resume has returned in 2.6.30-rc4

[Peter Roediger <p roediger gmail com>]

I don't really know, how can I check this? When looking at /var/log/syslog I get the following output right before suspending to ram:

May  8 07:47:55 debian kernel: [63778.728835] CPU0 attaching NULL sched-domain.
May  8 07:47:55 debian kernel: [63778.728838] CPU1 attaching NULL sched-domain.
May  8 07:47:55 debian kernel: [63778.733189] CPU0 attaching sched-domain:
May  8 07:47:55 debian kernel: [63778.733192]  domain 0: span 0-1 level MC
May  8 07:47:55 debian kernel: [63778.733194]   groups: 0 1
May  8 07:47:55 debian kernel: [63778.733197] CPU1 attaching sched-domain:
May  8 07:47:55 debian kernel: [63778.733199]  domain 0: span 0-1 level MC
May  8 07:47:55 debian kernel: [63778.733200]   groups: 1 0
May  8 07:47:55 debian kernel: [63778.751046] usb 4-2: USB disconnect, address 20
May  8 07:47:55 debian NetworkManager: <info>  Sleeping...
May  8 07:47:55 debian NetworkManager: <info>  (eth0): now unmanaged
May  8 07:47:55 debian NetworkManager: <info>  (eth0): device state change: 2 -> 1
May  8 07:47:55 debian NetworkManager: <info>  (eth0): cleaning up...
May  8 07:47:55 debian NetworkManager: <info>  (eth0): taking down device.
May  8 07:47:55 debian NetworkManager: <info>  (wlan0): now unmanaged
May  8 07:47:55 debian NetworkManager: <info>  (wlan0): device state change: 8 -> 1
May  8 07:47:55 debian NetworkManager: <info>  (wlan0): deactivating device (reason: 37).
May  8 07:47:55 debian kernel: [63778.819285] PM: Syncing filesystems ... done.




and the NetworkManager related stuff after:

May  8 09:20:09 debian NetworkManager: <WARN>  check_one_route(): (wlan0) error -34 returned from rtnl_route_del(): Sucess#012
May  8 09:20:09 debian NetworkManager: <info>  (wlan0): cleaning up...
May  8 09:20:09 debian NetworkManager: <info>  (wlan0): taking down device.
.
.
.
May  8 09:20:10 debian NetworkManager: <info>  Waking up...
May  8 09:20:10 debian NetworkManager: <info>  (eth0): now managed
May  8 09:20:10 debian NetworkManager: <info>  (eth0): device state change: 1 -> 2
May  8 09:20:10 debian NetworkManager: <info>  (eth0): bringing up device.
.
.
.
May  8 09:20:10 debian NetworkManager: <info>  (eth0): preparing device.
May  8 09:20:10 debian NetworkManager: <info>  (eth0): deactivating device (reason: 2).
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): now managed
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): device state change: 1 -> 2
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): bringing up device.
.
.
.
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): preparing device.
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): deactivating device (reason: 2).
May  8 09:20:10 debian kernel: [63785.077638] wlan0: direct probe to AP 00:1d:68:6b:b4:99 try 1
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): device state change: 2 -> 3
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
May  8 09:20:10 debian wpa_supplicant[14746]: CTRL-EVENT-SCAN-RESULTS
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) starting connection 'WLAN-Caste'
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): device state change: 3 -> 4
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): device state change: 4 -> 5
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0/wireless): connection 'WLAN-Caste' has security, and secrets exist. No new secrets needed.
May  8 09:20:10 debian NetworkManager: <info>  Config: added 'ssid' value 'WLAN-Caste'
May  8 09:20:10 debian NetworkManager: <info>  Config: added 'scan_ssid' value '1'
May  8 09:20:10 debian NetworkManager: <info>  Config: added 'key_mgmt' value 'WPA-PSK'
May  8 09:20:10 debian NetworkManager: <info>  Config: added 'auth_alg' value 'OPEN'
May  8 09:20:10 debian NetworkManager: <info>  Config: added 'psk' value '<omitted>'
May  8 09:20:10 debian NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
May  8 09:20:10 debian NetworkManager: <info>  Config: set interface ap_scan to 1
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> disconnected
May  8 09:20:10 debian wpa_supplicant[14746]: Failed to initiate AP scan.
May  8 09:20:10 debian NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning

This is the output when resuming at work. Note that "WLAN-Caste" is my home AP and should not be in the list anymore or even attempted to be associated to.

Any suggestions?

Peter

On Thu, May 7, 2009 at 17:08, Dan Williams <dcbw redhat com> wrote:

On Wed, 2009-05-06 at 09:18 +0200, Peter Roediger wrote:
> I'm using a self-compiled kernel version 2.6.30-rc4 on an intel 5300
> wifi card with the iwlagn driver built-in. I was eager to see if the
> problem mentioned in the subject is really solved. And indeed it was
> all working fine in 2.6.30-rc1 until 2.6.30-rc3. After installing
> 2.6.30-rc4, though, the problem has returned. I'm using wireless LAN
> at home and at work and when arriving at work I can still see my home
> AP in the list (besides the new APs at work), and even worse, NM tries
> to associate to it. Same thing happens when leaving work and going
> home.
>
> I think, this problem is old and well-known but it was solved and now
> has apparently reappeared. I compared the relevant files in the kernel
> source of 2.6.30-rc4 with the patch that is shown here:
> http://marc.info/?l=linux-wireless&m=123439060131140&w=2 , but they
> are all as they are supposed to be.
>
> Interestingly, when doing an "iwlist wlan0 scan", the old AP is NOT
> found.

Is NM properly being told to go to sleep on suspend?  There's a dbus bug
that causes the pm-utils sleep message to NM to get lost, and NM then
doesn't clear the AP list when it goes to sleep.  Could that be what's
happening here?

Dan