2009-12-09 06:03:39

by Jeffrey Baker

[permalink] [raw]
Subject: WARNING at mac80211_ieee80211_rx

My access point with an AR9220 stopped passing traffic, and these were
seen in dmesg. I am using compat-wireless 2009-11-06.

also at pastebin: http://pastebin.com/m527862e9

[505869.263259] ------------[ cut here ]----------- -
[505869.269520] WARNING: at
/root/compat-wireless-2009-11-06/net/mac80211/rx.c:2486
mac80211_ieee80211_rx+0xc9/0x51a [mac80211]()
[505869.273388] Modules linked in: bridge stp loop arc4 ath9k evdev
ath9k_hw snd_pcsp ohci_hcd mac80211 ath snd_pcm ehci_hcd snd_timer ecb
aes_i586 snd soundcore aes_generic cfg80211 snd_page_alloc usbcore
geode_aes rfkill_backport via_rhine geode_rng cs5535_gpio rng_core mii
led_class ext2 mbcache ide_gd_mod thermal_sys ide_pci_generic
ata_generic libata scsi_mod amd74xx cs5536 ide_core
[505869.372485] Pid: 0, comm: swapper Tainted: G W 2.6.30-2-486 #1
[505869.376345] Call Trace:
[505869.380338] [<d0bcf12f>] ? mac80211_ieee80211_rx+0xc9/0x51a [mac80211]
[505869.384236] [<d0bcf12f>] ? mac80211_ieee80211_rx+0xc9/0x51a [mac80211]
[505869.388353] [<c011e7dc>] ? warn_slowpath_common+0x5e/0x8a
[505869.393089] [<c011e812>] ? warn_slowpath_null+0xa/0xc
[505869.397070] [<d0bcf12f>] ? mac80211_ieee80211_rx+0xc9/0x51a [mac80211]
[505869.401013] [<d0caf4b4>] ? ath_rx_tasklet+0x739/0x780 [ath9k]
[505869.404946] [<c012f4c6>] ? ktime_get+0xf/0x2b
[505869.408423] [<c0130b80>] ? commit_creds+0x57/0xec
[505869.412401] [<c0130804>] ? sched_clock_tick+0x63/0x137
[505869.415073] [<d0cad928>] ? ath9k_tasklet+0x3f/0xa1 [ath9k]
[505869.420072] [<c0121e01>] ? tasklet_action+0x49/0x79
[505869.424054] [<c0122163>] ? __do_softirq+0x82/0x125
[505869.427238] [<c0122233>] ? do_softirq+0x2d/0x37
[505869.432319] [<c01222f6>] ? irq_exit+0x25/0x4e
[505869.436302] [<c0104614>] ? do_IRQ+0x53/0x63
[505869.439044] [<c0103609>] ? common_interrupt+0x29/0x30
[505869.443025] [<c01135fc>] ? native_safe_halt+0x2/0x3
[505869.446729] [<c0107ce7>] ? default_idle+0x3c/0x65
[505869.452591] [<c0102336>] ? cpu_idle+0x28/0x42
[505869.456573] [<c0402925>] ? start_kernel+0x291/0x294
[505869.461386] ---[ end trace 65ec8d5e106d761d ]---


2009-12-09 18:23:02

by Luis R. Rodriguez

[permalink] [raw]
Subject: Re: WARNING at mac80211_ieee80211_rx

On Wed, Dec 9, 2009 at 10:13 AM, Jeffrey Baker <[email protected]> wrote:
> On Wed, Dec 9, 2009 at 9:18 AM, Luis R. Rodriguez <[email protected]> wrote:
>> On Tue, Dec 8, 2009 at 10:03 PM, Jeffrey Baker <[email protected]> wrote:
>>> My access point with an AR9220 stopped passing traffic,
>>
>> Jeffrey, thanks for your report, can you be a little more verbose here
>> and elaborate as to what you mean by this? Do you mean that you stop
>> hostapd or that it hostapd is still running and that somehow you
>> notice it stops sending data between its associated STAs?
>
> Yes, hostapd was still running, however stations were unable to pass
> traffic.  Actually the AP also stopped sending beacons I think,
> because the AP no longer appeared in scans.  Restarting hostapd had no
> effect.  I rebooted the machine.

Well something told mac80211 it was stopped, so curious if you can
provide more logs, both from hostapd and the kernel. Are you using git
version of hostapd?

Luis

2009-12-09 18:18:25

by Jeffrey Baker

[permalink] [raw]
Subject: Re: WARNING at mac80211_ieee80211_rx

On Wed, Dec 9, 2009 at 9:18 AM, Luis R. Rodriguez <[email protected]> wrote:
> On Tue, Dec 8, 2009 at 10:03 PM, Jeffrey Baker <[email protected]> wrote:
>> My access point with an AR9220 stopped passing traffic,
>
> Jeffrey, thanks for your report, can you be a little more verbose here
> and elaborate as to what you mean by this? Do you mean that you stop
> hostapd or that it hostapd is still running and that somehow you
> notice it stops sending data between its associated STAs?

Yes, hostapd was still running, however stations were unable to pass
traffic. Actually the AP also stopped sending beacons I think,
because the AP no longer appeared in scans. Restarting hostapd had no
effect. I rebooted the machine.

>
>> and these were
>> seen in dmesg. ?I am using compat-wireless 2009-11-06.
>>
>> also at pastebin: http://pastebin.com/m527862e9
>>
>> [505869.263259] ------------[ cut here ]----------- ? ? ? ? ? ? -
>> [505869.269520] WARNING: at
>> /root/compat-wireless-2009-11-06/net/mac80211/rx.c:2486
>
> This would be from:
>
> ? ? ? ?/*
> ? ? ? ? * The same happens when we're not even started,
> ? ? ? ? * but that's worth a warning.
> ? ? ? ? */
> ? ? ? ?if (WARN_ON(!local->started))
> ? ? ? ? ? ? ? ?goto drop
>
> So somehow the RX tasklet kicked in and ath9k RX engine was still running.

2009-12-09 17:18:26

by Luis R. Rodriguez

[permalink] [raw]
Subject: Re: WARNING at mac80211_ieee80211_rx

On Tue, Dec 8, 2009 at 10:03 PM, Jeffrey Baker <[email protected]> wrote:
> My access point with an AR9220 stopped passing traffic,

Jeffrey, thanks for your report, can you be a little more verbose here
and elaborate as to what you mean by this? Do you mean that you stop
hostapd or that it hostapd is still running and that somehow you
notice it stops sending data between its associated STAs?

> and these were
> seen in dmesg.  I am using compat-wireless 2009-11-06.
>
> also at pastebin: http://pastebin.com/m527862e9
>
> [505869.263259] ------------[ cut here ]-----------             -
> [505869.269520] WARNING: at
> /root/compat-wireless-2009-11-06/net/mac80211/rx.c:2486

This would be from:

/*
* The same happens when we're not even started,
* but that's worth a warning.
*/
if (WARN_ON(!local->started))
goto drop

So somehow the RX tasklet kicked in and ath9k RX engine was still running.

Luis

2009-12-09 18:41:25

by Luis R. Rodriguez

[permalink] [raw]
Subject: Re: WARNING at mac80211_ieee80211_rx

On Wed, Dec 9, 2009 at 10:36 AM, Jeffrey Baker <[email protected]> wrote:
> On Wed, Dec 9, 2009 at 10:22 AM, Luis R. Rodriguez <[email protected]> wrote:
>> On Wed, Dec 9, 2009 at 10:13 AM, Jeffrey Baker <[email protected]> wrote:
>>> On Wed, Dec 9, 2009 at 9:18 AM, Luis R. Rodriguez <[email protected]> wrote:
>>>> On Tue, Dec 8, 2009 at 10:03 PM, Jeffrey Baker <[email protected]> wrote:
>>>>> My access point with an AR9220 stopped passing traffic,
>>>>
>>>> Jeffrey, thanks for your report, can you be a little more verbose here
>>>> and elaborate as to what you mean by this? Do you mean that you stop
>>>> hostapd or that it hostapd is still running and that somehow you
>>>> notice it stops sending data between its associated STAs?
>>>
>>> Yes, hostapd was still running, however stations were unable to pass
>>> traffic.  Actually the AP also stopped sending beacons I think,
>>> because the AP no longer appeared in scans.  Restarting hostapd had no
>>> effect.  I rebooted the machine.
>>
>> Well something told mac80211 it was stopped, so curious if you can
>> provide more logs, both from hostapd and the kernel. Are you using git
>> version of hostapd?
>
> No, I'm using 0.6.9-3 package from Debian.

Can't say I keep track of the differences of hostapd from old stable
to now so can you try latest hostapd? I should note if using
compat-wireless you'll be using newer drivers and hostapd from git
will likely take advantage of any new features introduced. Can't also
say if the 0.6.9 release you are using might have issues expected with
using bleeding edge code so CC'ing hostap mailing list in case someone
there does.

> I don't see anything in
> daemon.log relating to hostapd other than the usual.  Here's a snippet
> around the time in question:
>
> Dec  8 12:28:00 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: authenticated
> Dec  8 12:28:00 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: associated (aid 1)
> Dec  8 12:28:00 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb RADIUS:
> starting accounting session 386D440C-00000046
> Dec  8 12:33:05 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: disassociated due to inactivity
> Dec  8 12:33:06 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: deauthenticated due to inactivity
> Dec  8 21:21:59 mango hostapd: wlan0: STA 00:1d:e0:38:18:d7 IEEE
> 802.11: authenticated
> Dec  8 21:21:59 mango hostapd: wlan0: STA 00:1d:e0:38:18:d7 IEEE
> 802.11: associated (aid 1)
> Dec  8 21:21:59 mango hostapd: wlan0: STA 00:1d:e0:38:18:d7 RADIUS:
> starting accounting session 4B1F3304-00000000
> Dec  8 21:46:43 mango hostapd: wlan0: STA 00:1d:e0:38:18:d7 IEEE
> 802.11: disassociated
> Dec  8 21:46:44 mango hostapd: wlan0: STA 00:1d:e0:38:18:d7 IEEE
> 802.11: deauthenticated due to inactivity
> Dec  8 22:35:26 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: authenticated
> Dec  8 22:35:26 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: associated (aid 1)
> Dec  8 22:35:26 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb RADIUS:
> starting accounting session 4B1F3304-00000001
> Dec  8 22:48:16 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: disassociated due to inactivity
> Dec  8 22:48:17 mango hostapd: wlan0: STA 04:1e:64:ec:22:eb IEEE
> 802.11: deauthenticated due to inactivity
>
> I'm not sure that this kernel stack is the definite cause of the AP
> stopping, because now that I look in kern.log I see many instances of
> it.  Just about one every other day, on average.

Can you still share the kernel log?

Luis