Re: wireless link flaps (ath ar9280)

2013-02-06 Thread Vincent Hoffman 
Just an update that after updating to the latest -HEAD these have
disappeared again.


Vince

On 28/01/2013 01:45, Adrian Chadd wrote:
> Right, this looks like you're missing beacons.
>
> My latest -HEAD changes causes a non-loss hardware reset, in case it's
> gone deaf.
>
> But if you are going deaf and missing the occasional beacon, it
> shouldn't be disconnecting you. I wonder how that logic is working..
>
>
> Adrian
>
>
> On 27 January 2013 13:56, Vincent Hoffman  wrote:
>> On 27/01/2013 17:11, Adrian Chadd wrote:
>>> Hm, see if it's a beacon miss thing:
>>>
>>>
>>> sysctl dev.ath.0.debug=0x80
>> now with added debugging.
>>
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
>> 33171100 intval 100 (100)
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
>> 33967936054 tsf:tu 33171814 intval 100 nexttbtt 33171900 dtim 100
>> nextdtim 33171900 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
>> 33171900 timoffset 0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33967937503
>> lastrx 727896 (33967209607) bmiss 716800
>> Jan 27 21:49:09 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
>> bssid=e0:91:f5:48:5b:b9 reason=0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
>> 33171100 intval 100 (100)
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
>> 33968652767 tsf:tu 33172514 intval 100 nexttbtt 33172600 dtim 100
>> nextdtim 33172600 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
>> 33172600 timoffset 0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33968654221
>> lastrx 1444614 (33967209607) bmiss 716800
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: norm:
>> node 0xff800b388000: bf=0xff80008c3140: addbaw=0, dobaw=1,
>> seqno=2485, retry=0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
>> 0xff800b388000: bf=0xff80008c3140: txq[1] axq_depth=0,
>> axq_aggr_depth=0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
>> 0xff800b388000: bf=0xff80008c3140: tid txq_depth=4 hwq_depth=0,
>> bar_wait=1, isfiltered=0
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
>> 0xff800b388000: tid 0: sched=0, paused=1, incomp=0, baw_head=98,
>> baw_tail=98 txa_start=2485, ni_txseqs=2489
>> Jan 27 21:49:09 ostracod kernel: TODS
>> 00:24:23:07:fb:5d->60:33:4b:0d:e1:f8(e0:91:f5:48:5b:b9) data QoS [TID 0]
>> WEP [IV 05 34 00 09 00 00 KID 0] 0M
>> Jan 27 21:49:09 ostracod kernel: 8841  e091 f548 5bb9 0024 2307 fb5d
>> 6033 4b0d e1f8 509b  dec0 0534 0020 0900   0300  0800
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
>> added: seqno 2485
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
>> added: seqno 2486
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
>> added: seqno 2487
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
>> added: seqno 2488
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
>> 0xff80008c3140: seqno 2485: dobaw should've been cleared!
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
>> 0xff80008c1e20: seqno 2486: dobaw should've been cleared!
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
>> 0xff80008a6178: seqno 2487: dobaw should've been cleared!
>> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
>> 0xff80008b7b90: seqno 2488: dobaw should've been cleared!
>> Jan 27 21:49:09 ostracod kernel: wlan0: link state changed to DOWN
>> Jan 27 21:49:12 ostracod wpa_supplicant[568]: Trying to associate with
>> e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
>> Jan 27 21:49:12 ostracod wpa_supplicant[568]: Associated with
>> e0:91:f5:48:5b:b9
>> Jan 27 21:49:12 ostracod kernel: wlan0: link state changed to UP
>> Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: nexttbtt 7300
>> intval 100 (100)
>> Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: tsf
>> 33971573916 tsf:tu 33175367 intval 100 nexttbtt 33175400 dtim 100
>> nextdtim 33175400 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
>> 33175400 timoffset 0
>> Jan 27 21:49:13 ostracod wpa_supplicant[568]: WPA: Key negotiation
>> completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP]
>> Jan 27 21:49:13 ostracod wpa_supplicant[568]: CTRL-EVENT-CONNECTED -
>> Connection to e0:91:f5:48:5b:b9 completed (reauth) [id=0 id_str=]
>>
>>
>> Thanks as ever for all the work Adrian,
>>
>> Vince
>>
>>
>>>
>>> adrian
>>>
>>> On 27 January 2013 04:31, Vincent Hoffman  wrote:
 Hi all,
 I'm running a recent -current (r245741) and seem to be getting
 interface flaps. Since this machine is mainly used for home mail and a
 little light file serving I'm not sure when they started occuring as i
 only have logging going back

Re: wireless link flaps (ath ar9280)

2013-01-27 Thread Adrian Chadd 
Right, this looks like you're missing beacons.

My latest -HEAD changes causes a non-loss hardware reset, in case it's
gone deaf.

But if you are going deaf and missing the occasional beacon, it
shouldn't be disconnecting you. I wonder how that logic is working..


Adrian


On 27 January 2013 13:56, Vincent Hoffman  wrote:
> On 27/01/2013 17:11, Adrian Chadd wrote:
>> Hm, see if it's a beacon miss thing:
>>
>>
>> sysctl dev.ath.0.debug=0x80
> now with added debugging.
>
> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
> 33171100 intval 100 (100)
> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
> 33967936054 tsf:tu 33171814 intval 100 nexttbtt 33171900 dtim 100
> nextdtim 33171900 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
> 33171900 timoffset 0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33967937503
> lastrx 727896 (33967209607) bmiss 716800
> Jan 27 21:49:09 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
> bssid=e0:91:f5:48:5b:b9 reason=0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
> 33171100 intval 100 (100)
> Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
> 33968652767 tsf:tu 33172514 intval 100 nexttbtt 33172600 dtim 100
> nextdtim 33172600 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
> 33172600 timoffset 0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33968654221
> lastrx 1444614 (33967209607) bmiss 716800
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: norm:
> node 0xff800b388000: bf=0xff80008c3140: addbaw=0, dobaw=1,
> seqno=2485, retry=0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff800b388000: bf=0xff80008c3140: txq[1] axq_depth=0,
> axq_aggr_depth=0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff800b388000: bf=0xff80008c3140: tid txq_depth=4 hwq_depth=0,
> bar_wait=1, isfiltered=0
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff800b388000: tid 0: sched=0, paused=1, incomp=0, baw_head=98,
> baw_tail=98 txa_start=2485, ni_txseqs=2489
> Jan 27 21:49:09 ostracod kernel: TODS
> 00:24:23:07:fb:5d->60:33:4b:0d:e1:f8(e0:91:f5:48:5b:b9) data QoS [TID 0]
> WEP [IV 05 34 00 09 00 00 KID 0] 0M
> Jan 27 21:49:09 ostracod kernel: 8841  e091 f548 5bb9 0024 2307 fb5d
> 6033 4b0d e1f8 509b  dec0 0534 0020 0900   0300  0800
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 2485
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 2486
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 2487
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 2488
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008c3140: seqno 2485: dobaw should've been cleared!
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008c1e20: seqno 2486: dobaw should've been cleared!
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008a6178: seqno 2487: dobaw should've been cleared!
> Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008b7b90: seqno 2488: dobaw should've been cleared!
> Jan 27 21:49:09 ostracod kernel: wlan0: link state changed to DOWN
> Jan 27 21:49:12 ostracod wpa_supplicant[568]: Trying to associate with
> e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
> Jan 27 21:49:12 ostracod wpa_supplicant[568]: Associated with
> e0:91:f5:48:5b:b9
> Jan 27 21:49:12 ostracod kernel: wlan0: link state changed to UP
> Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: nexttbtt 7300
> intval 100 (100)
> Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: tsf
> 33971573916 tsf:tu 33175367 intval 100 nexttbtt 33175400 dtim 100
> nextdtim 33175400 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
> 33175400 timoffset 0
> Jan 27 21:49:13 ostracod wpa_supplicant[568]: WPA: Key negotiation
> completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP]
> Jan 27 21:49:13 ostracod wpa_supplicant[568]: CTRL-EVENT-CONNECTED -
> Connection to e0:91:f5:48:5b:b9 completed (reauth) [id=0 id_str=]
>
>
> Thanks as ever for all the work Adrian,
>
> Vince
>
>
>>
>>
>> adrian
>>
>> On 27 January 2013 04:31, Vincent Hoffman  wrote:
>>> Hi all,
>>> I'm running a recent -current (r245741) and seem to be getting
>>> interface flaps. Since this machine is mainly used for home mail and a
>>> little light file serving I'm not sure when they started occuring as i
>>> only have logging going back to the 18th Jan.
>>>
>>> Sample log messages are:
>>> Jan 24 16:26:22 ostracod kernel: ar5416StopDmaReceive: dma failed to
>>> stop in 10ms
>>> Jan 24 16:26:22 ostracod kernel: AR_CR=0x0024
>>> Jan 24 16:26:22 ostracod kernel: AR_DIAG_SW=0

Re: wireless link flaps (ath ar9280)

2013-01-27 Thread Vincent Hoffman 
On 27/01/2013 17:11, Adrian Chadd wrote:
> Hm, see if it's a beacon miss thing:
>
>
> sysctl dev.ath.0.debug=0x80
now with added debugging.

Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
33171100 intval 100 (100)
Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
33967936054 tsf:tu 33171814 intval 100 nexttbtt 33171900 dtim 100
nextdtim 33171900 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
33171900 timoffset 0
Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33967937503
lastrx 727896 (33967209607) bmiss 716800
Jan 27 21:49:09 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
bssid=e0:91:f5:48:5b:b9 reason=0
Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_proc: pending 1
Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: nexttbtt
33171100 intval 100 (100)
Jan 27 21:49:09 ostracod kernel: ath0: ath_beacon_config: tsf
33968652767 tsf:tu 33172514 intval 100 nexttbtt 33172600 dtim 100
nextdtim 33172600 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
33172600 timoffset 0
Jan 27 21:49:09 ostracod kernel: ath0: ath_bmiss_vap: tsf 33968654221
lastrx 1444614 (33967209607) bmiss 716800
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: norm:
node 0xff800b388000: bf=0xff80008c3140: addbaw=0, dobaw=1,
seqno=2485, retry=0
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff800b388000: bf=0xff80008c3140: txq[1] axq_depth=0,
axq_aggr_depth=0
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff800b388000: bf=0xff80008c3140: tid txq_depth=4 hwq_depth=0,
bar_wait=1, isfiltered=0
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff800b388000: tid 0: sched=0, paused=1, incomp=0, baw_head=98,
baw_tail=98 txa_start=2485, ni_txseqs=2489
Jan 27 21:49:09 ostracod kernel: TODS
00:24:23:07:fb:5d->60:33:4b:0d:e1:f8(e0:91:f5:48:5b:b9) data QoS [TID 0]
WEP [IV 05 34 00 09 00 00 KID 0] 0M
Jan 27 21:49:09 ostracod kernel: 8841  e091 f548 5bb9 0024 2307 fb5d
6033 4b0d e1f8 509b  dec0 0534 0020 0900   0300  0800
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 2485
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 2486
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 2487
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 2488
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008c3140: seqno 2485: dobaw should've been cleared!
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008c1e20: seqno 2486: dobaw should've been cleared!
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008a6178: seqno 2487: dobaw should've been cleared!
Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008b7b90: seqno 2488: dobaw should've been cleared!
Jan 27 21:49:09 ostracod kernel: wlan0: link state changed to DOWN
Jan 27 21:49:12 ostracod wpa_supplicant[568]: Trying to associate with
e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
Jan 27 21:49:12 ostracod wpa_supplicant[568]: Associated with
e0:91:f5:48:5b:b9
Jan 27 21:49:12 ostracod kernel: wlan0: link state changed to UP
Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: nexttbtt 7300
intval 100 (100)
Jan 27 21:49:12 ostracod kernel: ath0: ath_beacon_config: tsf
33971573916 tsf:tu 33175367 intval 100 nexttbtt 33175400 dtim 100
nextdtim 33175400 bmiss 7 sleep 100 cfp:period 100 maxdur 0 next
33175400 timoffset 0
Jan 27 21:49:13 ostracod wpa_supplicant[568]: WPA: Key negotiation
completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP]
Jan 27 21:49:13 ostracod wpa_supplicant[568]: CTRL-EVENT-CONNECTED -
Connection to e0:91:f5:48:5b:b9 completed (reauth) [id=0 id_str=]


Thanks as ever for all the work Adrian,

Vince


>
>
> adrian
>
> On 27 January 2013 04:31, Vincent Hoffman  wrote:
>> Hi all,
>> I'm running a recent -current (r245741) and seem to be getting
>> interface flaps. Since this machine is mainly used for home mail and a
>> little light file serving I'm not sure when they started occuring as i
>> only have logging going back to the 18th Jan.
>>
>> Sample log messages are:
>> Jan 24 16:26:22 ostracod kernel: ar5416StopDmaReceive: dma failed to
>> stop in 10ms
>> Jan 24 16:26:22 ostracod kernel: AR_CR=0x0024
>> Jan 24 16:26:22 ostracod kernel: AR_DIAG_SW=0x4220
>> Jan 24 16:26:23 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
>> bssid=e0:91:f5:48:5b:b9 reason=0
>> Jan 24 16:26:23 ostracod kernel: wlan0: link state changed to DOWN
>> Jan 24 16:26:26 ostracod wpa_supplicant[568]: Trying to associate with
>> e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
>> Jan 24 16:26:26 ostracod wpa_supplicant[568]: Associated with
>> e0:91:f5:48:5b:b9
>> Jan 24 16:26:26 ostracod kernel: wlan0: link state changed to UP
>> Jan 24 16:26:27 ostracod wp

Re: wireless link flaps (ath ar9280)

2013-01-27 Thread Adrian Chadd 
Hm, see if it's a beacon miss thing:


sysctl dev.ath.0.debug=0x80



adrian

On 27 January 2013 04:31, Vincent Hoffman  wrote:
> Hi all,
> I'm running a recent -current (r245741) and seem to be getting
> interface flaps. Since this machine is mainly used for home mail and a
> little light file serving I'm not sure when they started occuring as i
> only have logging going back to the 18th Jan.
>
> Sample log messages are:
> Jan 24 16:26:22 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 24 16:26:22 ostracod kernel: AR_CR=0x0024
> Jan 24 16:26:22 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 24 16:26:23 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
> bssid=e0:91:f5:48:5b:b9 reason=0
> Jan 24 16:26:23 ostracod kernel: wlan0: link state changed to DOWN
> Jan 24 16:26:26 ostracod wpa_supplicant[568]: Trying to associate with
> e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
> Jan 24 16:26:26 ostracod wpa_supplicant[568]: Associated with
> e0:91:f5:48:5b:b9
> Jan 24 16:26:26 ostracod kernel: wlan0: link state changed to UP
> Jan 24 16:26:27 ostracod wpa_supplicant[568]: WPA: Key negotiation
> completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP]
>
> I sometime get just
>
>
>
> Jan 25 00:57:36 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 25 00:57:36 ostracod kernel: AR_CR=0x0024
> Jan 25 00:57:36 ostracod kernel: AR_DIAG_SW=0x4220
>
> or
>
> Jan 25 09:39:24 ostracod wpa_supplicant[568]: WPA: Group rekeying
> completed with e0:91:f5:48:5b:b9 [GTK=TKIP]
> Jan 25 09:41:13 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 25 09:41:13 ostracod kernel: AR_CR=0x0024
> Jan 25 09:41:13 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 25 09:46:50 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 25 09:46:50 ostracod kernel: AR_CR=0x0024
> Jan 25 09:46:50 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 25 09:49:24 ostracod wpa_supplicant[568]: WPA: Group rekeying
> completed with e0:91:f5:48:5b:b9 [GTK=TKIP]
> Jan 25 09:52:10 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 25 09:52:10 ostracod kernel: AR_CR=0x0024
> Jan 25 09:52:10 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 25 09:57:07 ostracod kernel: ath0: bb hang detected (0x4), resetting
>
> or
>
> Jan 26 17:24:46 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 26 17:24:46 ostracod kernel: AR_CR=0x0024
> Jan 26 17:24:46 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 26 17:25:31 ostracod kernel: ar5416PerCalibrationN: NF calibration
> didn't finish; delaying CCA
>
> with no interface flaps.
> And sometimes much more info
>
> Jan 25 16:56:27 ostracod kernel: ar5416StopDmaReceive: dma failed to
> stop in 10ms
> Jan 25 16:56:27 ostracod kernel: AR_CR=0x0024
> Jan 25 16:56:27 ostracod kernel: AR_DIAG_SW=0x4220
> Jan 25 16:56:28 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
> bssid=e0:91:f5:48:5b:b9 reason=0
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: norm:
> node 0xff8014828000: bf=0xff80008b23e8: addbaw=1, dobaw=1,
> seqno=3447, retry=6
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff8014828000: bf=0xff80008b23e8: txq[1] axq_depth=0,
> axq_aggr_depth=0
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff8014828000: bf=0xff80008b23e8: tid txq_depth=10 hwq_depth=0,
> bar_wait=1, isfiltered=0
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
> 0xff8014828000: tid 0: sched=0, paused=1, incomp=0, baw_head=114,
> baw_tail=116 txa_start=3446, ni_txseqs=3456
> Jan 25 16:56:28 ostracod kernel: TODS
> 00:24:23:07:fb:5d->e0:91:f5:48:5b:b9(e0:91:f5:48:5b:b9) data QoS [TID 0]
> WEP [IV b6 89 00 0c 00 00 KID 0] 0M
> Jan 25 16:56:28 ostracod kernel: 8849  e091 f548 5bb9 0024 2307 fb5d
> e091 f548 5bb9 70d7  dec0 b689 0020 0c00   0300  0800
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3448
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3449
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3450
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3451
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3452
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3453
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3454
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
> added: seqno 3455
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008a9e08: seqno 3448: dobaw should've been cleared!
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
> 0xff80008aa468: seqno 3449: dobaw should've been cleared!
> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_de

wireless link flaps (ath ar9280)

2013-01-27 Thread Vincent Hoffman 
Hi all,
I'm running a recent -current (r245741) and seem to be getting
interface flaps. Since this machine is mainly used for home mail and a
little light file serving I'm not sure when they started occuring as i
only have logging going back to the 18th Jan.

Sample log messages are:
Jan 24 16:26:22 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 24 16:26:22 ostracod kernel: AR_CR=0x0024
Jan 24 16:26:22 ostracod kernel: AR_DIAG_SW=0x4220
Jan 24 16:26:23 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
bssid=e0:91:f5:48:5b:b9 reason=0
Jan 24 16:26:23 ostracod kernel: wlan0: link state changed to DOWN
Jan 24 16:26:26 ostracod wpa_supplicant[568]: Trying to associate with
e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz)
Jan 24 16:26:26 ostracod wpa_supplicant[568]: Associated with
e0:91:f5:48:5b:b9
Jan 24 16:26:26 ostracod kernel: wlan0: link state changed to UP
Jan 24 16:26:27 ostracod wpa_supplicant[568]: WPA: Key negotiation
completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP]

I sometime get just



Jan 25 00:57:36 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 25 00:57:36 ostracod kernel: AR_CR=0x0024
Jan 25 00:57:36 ostracod kernel: AR_DIAG_SW=0x4220

or

Jan 25 09:39:24 ostracod wpa_supplicant[568]: WPA: Group rekeying
completed with e0:91:f5:48:5b:b9 [GTK=TKIP]
Jan 25 09:41:13 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 25 09:41:13 ostracod kernel: AR_CR=0x0024
Jan 25 09:41:13 ostracod kernel: AR_DIAG_SW=0x4220
Jan 25 09:46:50 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 25 09:46:50 ostracod kernel: AR_CR=0x0024
Jan 25 09:46:50 ostracod kernel: AR_DIAG_SW=0x4220
Jan 25 09:49:24 ostracod wpa_supplicant[568]: WPA: Group rekeying
completed with e0:91:f5:48:5b:b9 [GTK=TKIP]
Jan 25 09:52:10 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 25 09:52:10 ostracod kernel: AR_CR=0x0024
Jan 25 09:52:10 ostracod kernel: AR_DIAG_SW=0x4220
Jan 25 09:57:07 ostracod kernel: ath0: bb hang detected (0x4), resetting

or

Jan 26 17:24:46 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 26 17:24:46 ostracod kernel: AR_CR=0x0024
Jan 26 17:24:46 ostracod kernel: AR_DIAG_SW=0x4220
Jan 26 17:25:31 ostracod kernel: ar5416PerCalibrationN: NF calibration
didn't finish; delaying CCA

with no interface flaps.
And sometimes much more info

Jan 25 16:56:27 ostracod kernel: ar5416StopDmaReceive: dma failed to
stop in 10ms
Jan 25 16:56:27 ostracod kernel: AR_CR=0x0024
Jan 25 16:56:27 ostracod kernel: AR_DIAG_SW=0x4220
Jan 25 16:56:28 ostracod wpa_supplicant[568]: CTRL-EVENT-DISCONNECTED
bssid=e0:91:f5:48:5b:b9 reason=0
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: norm:
node 0xff8014828000: bf=0xff80008b23e8: addbaw=1, dobaw=1,
seqno=3447, retry=6
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff8014828000: bf=0xff80008b23e8: txq[1] axq_depth=0,
axq_aggr_depth=0
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff8014828000: bf=0xff80008b23e8: tid txq_depth=10 hwq_depth=0,
bar_wait=1, isfiltered=0
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node
0xff8014828000: tid 0: sched=0, paused=1, incomp=0, baw_head=114,
baw_tail=116 txa_start=3446, ni_txseqs=3456
Jan 25 16:56:28 ostracod kernel: TODS
00:24:23:07:fb:5d->e0:91:f5:48:5b:b9(e0:91:f5:48:5b:b9) data QoS [TID 0]
WEP [IV b6 89 00 0c 00 00 KID 0] 0M
Jan 25 16:56:28 ostracod kernel: 8849  e091 f548 5bb9 0024 2307 fb5d
e091 f548 5bb9 70d7  dec0 b689 0020 0c00   0300  0800
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3448
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3449
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3450
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3451
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3452
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3453
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3454
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_pkt: wasn't
added: seqno 3455
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008a9e08: seqno 3448: dobaw should've been cleared!
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008aa468: seqno 3449: dobaw should've been cleared!
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008c8a80: seqno 3450: dobaw should've been cleared!
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008cf080: seqno 3451: dobaw should've been cleared!
Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf
0xff80008a8488: seqno 3452: dobaw should've been cleared!
Jan