Re: [2.6.32-rc3] iwlagn lost connection after s2ram (with warnings)

From: Carlos R. Mafra
Date: Wed Oct 14 2009 - 11:17:47 EST


On Thu 8.Oct'09 at 10:44:43 -0700, reinette chatre wrote:
> Hi Carlos,
>
> On Wed, 2009-10-07 at 07:20 -0700, Carlos R. Mafra wrote:
> > I just got these warnings after resuming from a suspend to RAM, and
> > the wireless connection was not resumed (now I am connected via eth0).
> > This is the first time I had a failed wireless resume since 2.6.32-rc1.
> >
> > The full dmesg is here: http://www.aei.mpg.de/~crmafra/dmesg-2.6.32-rc3-wifi.txt
> >
> > [ 3427.570113] Restarting tasks ...
> > [ 3427.585827] wlan0: deauthenticated from 00:0b:86:26:36:f1 (Reason: 6)
> > [ 3427.589451] done.
> > [ 3428.503203] input: PS/2 Mouse as /devices/platform/i8042/serio4/input/input15
> > [ 3428.521064] input: AlpsPS/2 ALPS GlidePoint as /devices/platform/i8042/serio4/input/input16
> > [ 3434.504175] wlan0: direct probe to AP 00:0b:86:26:36:f1 (try 1)
> > [ 3434.507058] wlan0: direct probe responded
> > [ 3434.507062] wlan0: authenticate with AP 00:0b:86:26:36:f1 (try 1)
> > [ 3434.509000] wlan0: authenticated
> > [ 3434.509022] wlan0: associate with AP 00:0b:86:26:36:f1 (try 1)
> > [ 3434.512778] wlan0: RX ReassocResp from 00:0b:86:26:36:f1 (capab=0x431 status=0 aid=2)
> > [ 3434.512782] wlan0: associated
> > [ 3434.563942] wlan0: deauthenticating from 00:0b:86:26:36:f1 by local choice (reason=3)
>
> You mention you are trying to connect again after a resume. The message
> above indicates that userspace (maybe wpa_supplicant ?) requested that
> the connection be closed. Do you maybe know how this could have been
> triggered?
>
> > [ 3434.564023] ------------[ cut here ]------------
> > [ 3434.564039] WARNING: at net/wireless/mlme.c:96 cfg80211_send_rx_assoc+0x193/0x230()
>
> This warning and the one below indicates that there is no information
> available for this BSS. Maybe Johannes knows why this can be?
>
> > [ 3434.564045] Hardware name: VGN-FZ240E
> > [ 3434.564049] Modules linked in: usbhid nvram dvb_usb_dib0700 dib7000p dib7000m dib0070 dvb_usb dib3000mc dib8000 dibx000_common snd_hda_codec_idt uvcvideo snd_hda_intel snd_hda_codec ehci_hcd sg uhci_hcd snd_hwdep sky2 iwlagn i2c_i801 sr_mod evdev ata_piix ahci libata sd_mod scsi_mod
> > [ 3434.564104] Pid: 2319, comm: phy0 Not tainted 2.6.32-rc3 #204
> > [ 3434.564109] Call Trace:
> > [ 3434.564119] [<ffffffff81420dd3>] ? cfg80211_send_rx_assoc+0x193/0x230
> > [ 3434.564131] [<ffffffff81047cb8>] warn_slowpath_common+0x78/0xd0
> > [ 3434.564139] [<ffffffff81047d1f>] warn_slowpath_null+0xf/0x20
> > [ 3434.564147] [<ffffffff81420dd3>] cfg80211_send_rx_assoc+0x193/0x230
> > [ 3434.564156] [<ffffffff814316cb>] ieee80211_sta_work+0x2fb/0x1100
> > [ 3434.564166] [<ffffffff81453b1f>] ? _spin_unlock_bh+0xf/0x20
> > [ 3434.564175] [<ffffffff8142802a>] ? ieee80211_configure_filter+0x11a/0x170
> > [ 3434.564183] [<ffffffff814313d0>] ? ieee80211_sta_work+0x0/0x1100
> > [ 3434.564193] [<ffffffff8105e9e2>] worker_thread+0x182/0x260
> > [ 3434.564203] [<ffffffff81063320>] ? autoremove_wake_function+0x0/0x40
> > [ 3434.564211] [<ffffffff8105e860>] ? worker_thread+0x0/0x260
> > [ 3434.564219] [<ffffffff81062f06>] kthread+0x96/0xb0
> > [ 3434.564229] [<ffffffff8100cd1a>] child_rip+0xa/0x20
> > [ 3434.564237] [<ffffffff81062e70>] ? kthread+0x0/0xb0
> > [ 3434.564245] [<ffffffff8100cd10>] ? child_rip+0x0/0x20
> > [ 3434.564250] ---[ end trace 99d6122abfa316f7 ]---
> > [ 3434.564272] ------------[ cut here ]------------
> > [ 3434.564280] WARNING: at net/wireless/sme.c:417 __cfg80211_connect_result+0x343/0x380()
> > [ 3434.564285] Hardware name: VGN-FZ240E
> > [ 3434.564289] Modules linked in: usbhid nvram dvb_usb_dib0700 dib7000p dib7000m dib0070 dvb_usb dib3000mc dib8000 dibx000_common snd_hda_codec_idt uvcvideo snd_hda_intel snd_hda_codec ehci_hcd sg uhci_hcd snd_hwdep sky2 iwlagn i2c_i801 sr_mod evdev ata_piix ahci libata sd_mod scsi_mod
> > [ 3434.564335] Pid: 2319, comm: phy0 Tainted: G W 2.6.32-rc3 #204
> > [ 3434.564340] Call Trace:
> > [ 3434.564347] [<ffffffff81453b1f>] ? _spin_unlock_bh+0xf/0x20
> > [ 3434.564355] [<ffffffff814236e3>] ? __cfg80211_connect_result+0x343/0x380
> > [ 3434.564364] [<ffffffff81047cb8>] warn_slowpath_common+0x78/0xd0
> > [ 3434.564373] [<ffffffff81047d1f>] warn_slowpath_null+0xf/0x20
> > [ 3434.564381] [<ffffffff814236e3>] __cfg80211_connect_result+0x343/0x380
> > [ 3434.564389] [<ffffffff814509a2>] ? dump_stack+0x72/0x7b
> > [ 3434.564397] [<ffffffff81420e10>] cfg80211_send_rx_assoc+0x1d0/0x230
> > [ 3434.564405] [<ffffffff814316cb>] ieee80211_sta_work+0x2fb/0x1100
> > [ 3434.564413] [<ffffffff81453b1f>] ? _spin_unlock_bh+0xf/0x20
> > [ 3434.564421] [<ffffffff8142802a>] ? ieee80211_configure_filter+0x11a/0x170
> > [ 3434.564429] [<ffffffff814313d0>] ? ieee80211_sta_work+0x0/0x1100
> > [ 3434.564438] [<ffffffff8105e9e2>] worker_thread+0x182/0x260
> > [ 3434.564447] [<ffffffff81063320>] ? autoremove_wake_function+0x0/0x40
> > [ 3434.564455] [<ffffffff8105e860>] ? worker_thread+0x0/0x260
> > [ 3434.564463] [<ffffffff81062f06>] kthread+0x96/0xb0
> > [ 3434.564471] [<ffffffff8100cd1a>] child_rip+0xa/0x20
> > [ 3434.564479] [<ffffffff81062e70>] ? kthread+0x0/0xb0
> > [ 3434.564487] [<ffffffff8100cd10>] ? child_rip+0x0/0x20
> > [ 3434.564492] ---[ end trace 99d6122abfa316f8 ]---
> > [ 3434.962611] Registered led device: iwl-phy0::radio
> > [ 3434.962629] Registered led device: iwl-phy0::assoc
> > [ 3434.962645] Registered led device: iwl-phy0::RX
> > [ 3434.962661] Registered led device: iwl-phy0::TX
> > [ 3435.000526] ADDRCONF(NETDEV_UP): wlan0: link is not ready

Now I got a similar warning and the connection went down. But this
time it was not closely related to a suspend to RAM, as can be noticed
in the dmesg

[ 624.603365] wlan0: direct probe responded
[ 624.603373] wlan0: authenticate with AP 00:0b:86:26:36:f1 (try 1)
[ 624.605285] wlan0: authenticated
[ 624.605316] wlan0: associate with AP 00:0b:86:26:36:f1 (try 1)
[ 624.608055] wlan0: RX ReassocResp from 00:0b:86:26:36:f1 (capab=0x21 status=10 aid=0)
[ 624.608061] wlan0: AP denied association (code=10)
[ 640.704549] wlan0: direct probe to AP 00:0b:86:3e:10:31 (try 1)
[ 640.708848] wlan0: direct probe responded
[ 640.708857] wlan0: authenticate with AP 00:0b:86:3e:10:31 (try 1)
[ 640.710857] wlan0: authenticated
[ 640.710888] wlan0: associate with AP 00:0b:86:3e:10:31 (try 1)
[ 640.719800] wlan0: RX AssocResp from 00:0b:86:3e:10:31 (capab=0x431 status=0 aid=1)
[ 640.719807] wlan0: associated
[ 640.746298] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 650.899995] wlan0: no IPv6 routers present
[ 706.797508] CE: hpet increasing min_delta_ns to 15000 nsec
[ 9523.640903] process `skype' is using obsolete setsockopt SO_BSDCOMPAT
[ 9546.622398] hda-intel: azx_get_response timeout, switching to polling mode: last cmd=0x00af0900
[15443.026527] wlan0: deauthenticated from 00:0b:86:3e:10:31 (Reason: 3)
[15443.032706] ------------[ cut here ]------------
[15443.032723] WARNING: at net/wireless/sme.c:620 __cfg80211_disconnected+0x232/0x240()
[15443.032728] Hardware name: VGN-FZ240E
[15443.032732] deauth failed: -67
[15443.032736] Modules linked in: usbhid nvram snd_hda_codec_idt uvcvideo snd_hda_intel snd_hda_codec evdev i2c_i801 sn d_hwdep uhci_hcd ehci_hcd sr_mod sky2 iwlagn sg ata_piix ahci libata sd_mod scsi_mod
[15443.032779] Pid: 2260, comm: phy0 Not tainted 2.6.32-rc4-dmitry2-00002-g5ce9513 #229
[15443.032784] Call Trace:
[15443.032794] [<ffffffff81421902>] ? __cfg80211_disconnected+0x232/0x240
[15443.032805] [<ffffffff81047cd8>] warn_slowpath_common+0x78/0xd0
[15443.032814] [<ffffffff81047db4>] warn_slowpath_fmt+0x64/0x70
[15443.032823] [<ffffffff81433e99>] ? ieee80211_deauth+0x19/0x20
[15443.032833] [<ffffffff8141e3ad>] ? __cfg80211_mlme_deauth+0xed/0x140
[15443.032842] [<ffffffff81421902>] __cfg80211_disconnected+0x232/0x240
[15443.032851] [<ffffffff8141f35a>] __cfg80211_send_deauth+0x23a/0x270
[15443.032861] [<ffffffff8142d064>] ? ieee80211_set_disassoc+0x1b4/0x230
[15443.032870] [<ffffffff8141f3fa>] cfg80211_send_deauth+0x6a/0x80
[15443.032879] [<ffffffff8142fe82>] ieee80211_sta_work+0x2e2/0x1100
[15443.032888] [<ffffffff8142e175>] ? ieee80211_mgd_probe_ap_send+0x65/0x70
[15443.032897] [<ffffffff8142fba0>] ? ieee80211_sta_work+0x0/0x1100
[15443.032907] [<ffffffff8105e9e2>] worker_thread+0x182/0x260
[15443.032916] [<ffffffff810630d0>] ? autoremove_wake_function+0x0/0x40
[15443.032925] [<ffffffff8105e860>] ? worker_thread+0x0/0x260
[15443.032933] [<ffffffff81062cb6>] kthread+0x96/0xb0
[15443.032944] [<ffffffff8100cd1a>] child_rip+0xa/0x20
[15443.032952] [<ffffffff81062c20>] ? kthread+0x0/0xb0
[15443.032960] [<ffffffff8100cd10>] ? child_rip+0x0/0x20
[15443.032965] ---[ end trace 0c4814007354915e ]---
[15444.898782] wlan0: direct probe to AP 00:0b:86:3e:10:31 (try 1)
[15445.098540] wlan0: direct probe to AP 00:0b:86:3e:10:31 (try 2)
[15445.299332] wlan0: direct probe to AP 00:0b:86:3e:10:31 (try 3)
[15445.498601] wlan0: direct probe to AP 00:0b:86:3e:10:31 timed out
[15449.715917] Registered led device: iwl-phy0::radio
[15449.716554] Registered led device: iwl-phy0::assoc
[15449.717107] Registered led device: iwl-phy0::RX
[15449.717603] Registered led device: iwl-phy0::TX
[15449.749228] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[15449.794402] wlan0: direct probe to AP 00:0b:86:28:21:11 (try 1)
[15449.992691] wlan0: direct probe to AP 00:0b:86:28:21:11 (try 2)
[15450.191950] wlan0: direct probe to AP 00:0b:86:28:21:11 (try 3)
[15450.392681] wlan0: direct probe to AP 00:0b:86:28:21:11 timed out


But after ~7 minutes the connection was recovered (but in the mean time
I had already started eth0), see here the continuation:


[15824.443480] sky2 eth0: enabling interface
[15824.443735] ADDRCONF(NETDEV_UP): eth0: link is not ready
[15826.108242] sky2 eth0: Link is up at 100 Mbps, full duplex, flow control rx
[15826.108864] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[15836.731786] eth0: no IPv6 routers present
[15924.423010] wlan0: direct probe to AP 00:0b:86:26:36:f1 (try 1)
[15924.426094] wlan0: direct probe responded
[15924.426113] wlan0: authenticate with AP 00:0b:86:26:36:f1 (try 1)
[15924.427981] wlan0: authenticated
[15924.428017] wlan0: associate with AP 00:0b:86:26:36:f1 (try 1)
[15924.434504] wlan0: RX ReassocResp from 00:0b:86:26:36:f1 (capab=0x431 status=0 aid=1)
[15924.434511] wlan0: associated
[15924.458575] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[15934.491760] wlan0: no IPv6 routers present
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/