[ath] AR9227 hang: ath_rate_findrate: switching quickly..
Alex Deiter
alex.deiter at gmail.com
Sat Sep 6 09:54:32 UTC 2014
Hello Adrian,
Today the network adapter completely hung with messages:
Sep 6 13:26:19 blackbird kernel: ar5416PerCalibrationN: NF calibration
didn't finish; delaying CCA
Sep 6 13:26:49 blackbird kernel: ar5416PerCalibrationN: NF calibration
didn't finish; delaying CCA
Sep 6 13:27:19 blackbird kernel: ar5416PerCalibrationN: NF calibration
didn't finish; delaying CCA
Sep 6 13:27:49 blackbird kernel: ar5416PerCalibrationN: NF calibration
didn't finish; delaying CCA
and clients can not connect.
sysctl dev.ath.0.txagg=1 output:
Sep 6 13:29:28 blackbird kernel: no tx bufs (empty list): 0
Sep 6 13:29:28 blackbird kernel: no tx bufs (was busy): 0
Sep 6 13:29:28 blackbird kernel: aggr single packet: 159053
Sep 6 13:29:28 blackbird kernel: aggr single packet w/ BAW closed: 4291
Sep 6 13:29:28 blackbird kernel: aggr non-baw packet: 1230
Sep 6 13:29:28 blackbird kernel: aggr aggregate packet: 1116991
Sep 6 13:29:28 blackbird kernel: aggr single packet low hwq: 1642117
Sep 6 13:29:28 blackbird kernel: aggr single packet RTS aggr limited: 0
Sep 6 13:29:28 blackbird kernel: aggr sched, no work: 326966
Sep 6 13:29:28 blackbird kernel: 0: 0 1: 0 2:
191070 3: 138685
Sep 6 13:29:28 blackbird kernel: 4: 216793 5: 48158 6:
56315 7: 32509
Sep 6 13:29:28 blackbird kernel: 8: 46740 9: 38002 10:
98295 11: 30125
Sep 6 13:29:28 blackbird kernel: 12: 20621 13: 27663 14:
9649 15: 7418
Sep 6 13:29:28 blackbird kernel: 16: 9114 17: 22346 18:
32944 19: 3902
Sep 6 13:29:28 blackbird kernel: 20: 2299 21: 2135 22:
1895 23: 1896
Sep 6 13:29:28 blackbird kernel: 24: 1718 25: 1739 26:
4926 27: 21511
Sep 6 13:29:28 blackbird kernel: 28: 1445 29: 956 30:
1009 31: 2592
Sep 6 13:29:28 blackbird kernel: 32: 42521 33: 0 34:
0 35: 0
Sep 6 13:29:28 blackbird kernel: 36: 0 37: 0 38:
0 39: 0
Sep 6 13:29:28 blackbird kernel: 40: 0 41: 0 42:
0 43: 0
Sep 6 13:29:28 blackbird kernel: 44: 0 45: 0 46:
0 47: 0
Sep 6 13:29:28 blackbird kernel: 48: 0 49: 0 50:
0 51: 0
Sep 6 13:29:28 blackbird kernel: 52: 0 53: 0 54:
0 55: 0
Sep 6 13:29:28 blackbird kernel: 56: 0 57: 0 58:
0 59: 0
Sep 6 13:29:28 blackbird kernel: 60: 0 61: 0 62:
0 63: 0
Sep 6 13:29:28 blackbird kernel:
Sep 6 13:29:28 blackbird kernel: HW TXQ 0: axq_depth=0, axq_aggr_depth=0,
axq_fifo_depth=0, holdingbf=0
Sep 6 13:29:28 blackbird kernel: HW TXQ 1: axq_depth=0, axq_aggr_depth=0,
axq_fifo_depth=0, holdingbf=0xfffffe0000d33b28
Sep 6 13:29:28 blackbird kernel: HW TXQ 2: axq_depth=0, axq_aggr_depth=0,
axq_fifo_depth=0, holdingbf=0
Sep 6 13:29:28 blackbird kernel: HW TXQ 3: axq_depth=0, axq_aggr_depth=0,
axq_fifo_depth=0, holdingbf=0xfffffe0000d5a8b8
Sep 6 13:29:28 blackbird kernel: HW TXQ 8: axq_depth=0, axq_aggr_depth=0,
axq_fifo_depth=0, holdingbf=0xfffffe0000d5ea10
Sep 6 13:29:28 blackbird kernel: Total TX buffers: 509; Total TX buffers
busy: 0 (509)
Sep 6 13:29:28 blackbird kernel: Total mgmt TX buffers: 32; Total mgmt TX
buffers busy: 0
Sep 6 13:29:28 blackbird kernel: 0: fifolen: 0/0; head=0; tail=0;
m_pending=0, m_holdbf=0xfffffe0000d99b68
Sep 6 13:29:28 blackbird kernel: 1: fifolen: 0/0; head=0; tail=0;
m_pending=0, m_holdbf=0
Sep 6 13:29:28 blackbird kernel: Total RX buffers in free list: 511 buffers
full logs: https://yadi.sk/d/w3FwfrN9b8FkN
2014-09-06 13:39 GMT+04:00 Alex Deiter <alex.deiter at gmail.com>:
> Hello Adrian,
>
> Today the network adapter completely hung with messages:
>
> Sep 6 13:26:19 blackbird kernel: ar5416PerCalibrationN: NF calibration
> didn't finish; delaying CCA
> Sep 6 13:26:49 blackbird kernel: ar5416PerCalibrationN: NF calibration
> didn't finish; delaying CCA
> Sep 6 13:27:19 blackbird kernel: ar5416PerCalibrationN: NF calibration
> didn't finish; delaying CCA
> Sep 6 13:27:49 blackbird kernel: ar5416PerCalibrationN: NF calibration
> didn't finish; delaying CCA
>
> and clients can not connect.
>
> sysctl dev.ath.0.txagg=1 output:
>
> Sep 6 13:29:28 blackbird kernel: no tx bufs (empty list): 0
> Sep 6 13:29:28 blackbird kernel: no tx bufs (was busy): 0
> Sep 6 13:29:28 blackbird kernel: aggr single packet: 159053
> Sep 6 13:29:28 blackbird kernel: aggr single packet w/ BAW closed: 4291
> Sep 6 13:29:28 blackbird kernel: aggr non-baw packet: 1230
> Sep 6 13:29:28 blackbird kernel: aggr aggregate packet: 1116991
> Sep 6 13:29:28 blackbird kernel: aggr single packet low hwq: 1642117
> Sep 6 13:29:28 blackbird kernel: aggr single packet RTS aggr limited: 0
> Sep 6 13:29:28 blackbird kernel: aggr sched, no work: 326966
> Sep 6 13:29:28 blackbird kernel: 0: 0 1: 0 2:
> 191070 3: 138685
> Sep 6 13:29:28 blackbird kernel: 4: 216793 5: 48158 6:
> 56315 7: 32509
> Sep 6 13:29:28 blackbird kernel: 8: 46740 9: 38002 10:
> 98295 11: 30125
> Sep 6 13:29:28 blackbird kernel: 12: 20621 13: 27663 14:
> 9649 15: 7418
> Sep 6 13:29:28 blackbird kernel: 16: 9114 17: 22346 18:
> 32944 19: 3902
> Sep 6 13:29:28 blackbird kernel: 20: 2299 21: 2135 22:
> 1895 23: 1896
> Sep 6 13:29:28 blackbird kernel: 24: 1718 25: 1739 26:
> 4926 27: 21511
> Sep 6 13:29:28 blackbird kernel: 28: 1445 29: 956 30:
> 1009 31: 2592
> Sep 6 13:29:28 blackbird kernel: 32: 42521 33: 0 34:
> 0 35: 0
> Sep 6 13:29:28 blackbird kernel: 36: 0 37: 0 38:
> 0 39: 0
> Sep 6 13:29:28 blackbird kernel: 40: 0 41: 0 42:
> 0 43: 0
> Sep 6 13:29:28 blackbird kernel: 44: 0 45: 0 46:
> 0 47: 0
> Sep 6 13:29:28 blackbird kernel: 48: 0 49: 0 50:
> 0 51: 0
> Sep 6 13:29:28 blackbird kernel: 52: 0 53: 0 54:
> 0 55: 0
> Sep 6 13:29:28 blackbird kernel: 56: 0 57: 0 58:
> 0 59: 0
> Sep 6 13:29:28 blackbird kernel: 60: 0 61: 0 62:
> 0 63: 0
> Sep 6 13:29:28 blackbird kernel:
> Sep 6 13:29:28 blackbird kernel: HW TXQ 0: axq_depth=0, axq_aggr_depth=0,
> axq_fifo_depth=0, holdingbf=0
> Sep 6 13:29:28 blackbird kernel: HW TXQ 1: axq_depth=0, axq_aggr_depth=0,
> axq_fifo_depth=0, holdingbf=0xfffffe0000d33b28
> Sep 6 13:29:28 blackbird kernel: HW TXQ 2: axq_depth=0, axq_aggr_depth=0,
> axq_fifo_depth=0, holdingbf=0
> Sep 6 13:29:28 blackbird kernel: HW TXQ 3: axq_depth=0, axq_aggr_depth=0,
> axq_fifo_depth=0, holdingbf=0xfffffe0000d5a8b8
> Sep 6 13:29:28 blackbird kernel: HW TXQ 8: axq_depth=0, axq_aggr_depth=0,
> axq_fifo_depth=0, holdingbf=0xfffffe0000d5ea10
> Sep 6 13:29:28 blackbird kernel: Total TX buffers: 509; Total TX buffers
> busy: 0 (509)
> Sep 6 13:29:28 blackbird kernel: Total mgmt TX buffers: 32; Total mgmt TX
> buffers busy: 0
> Sep 6 13:29:28 blackbird kernel: 0: fifolen: 0/0; head=0; tail=0;
> m_pending=0, m_holdbf=0xfffffe0000d99b68
> Sep 6 13:29:28 blackbird kernel: 1: fifolen: 0/0; head=0; tail=0;
> m_pending=0, m_holdbf=0
> Sep 6 13:29:28 blackbird kernel: Total RX buffers in free list: 511
> buffers
>
> full logs: https://yadi.sk/d/w3FwfrN9b8FkN
>
>
>
> 2014-09-05 22:26 GMT+04:00 Adrian Chadd <adrian.chadd at gmail.com>:
>
>> Hi!
>>
>> When this happens, can things re-associate?
>>
>> Can yuo do this:
>>
>> sysctl dev.ath.0.txagg=1
>>
>> (and dev.ath.1, dev.ath.2, etc if you have more than one physical
>> atheros NIC in your AP) and paste the results?
>>
>>
>>
>> -a
>>
>>
>>
>> On 5 September 2014 06:24, Alex Deiter <alex.deiter at gmail.com> wrote:
>> > Hello,
>> >
>> > Please help me figure out what's wrong:
>> >
>> > FreeBSD 11.0-CURRENT r270733M amd64, PCI / Atheros 9227, 802.11n hostap
>> mode
>> > Time to time network traffic between clients and AP stops:
>> >
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode off, 1 sta's in ps mode
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_findrate: switching quickly..
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_tx_complete: size 1600 (519 bytes) OK rate/short/long 7 MCS/0/1
>> > nframes/nbad [1/0]
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode on, 2 sta's in ps mode
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode off, 1 sta's in ps mode
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode on, 2 sta's in ps mode
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode off, 1 sta's in ps mode
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_findrate: switching quickly..
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_tx_complete: size 1600 (305 bytes) OK rate/short/long 7 MCS/0/1
>> > nframes/nbad [1/0]
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_findrate: switching quickly..
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd]
>> > ath_rate_tx_complete: size 250 (114 bytes) OK rate/short/long 4 MCS/0/1
>> > nframes/nbad [1/0]
>> > Sep 5 16:18:31 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode on, 2 sta's in ps mode
>> > Sep 5 16:18:32 blackbird kernel: wlan0: [84:7a:88:70:c6:cd] power save
>> > mode off, 1 sta's in ps mode
>> >
>> > it is the same case with all clients: android, windows, FreeBSD.
>> > Workaround - reboot AP system :-(
>> >
>> > Thank you!
>> >
>> > Details:
>> >
>> > pciconf:
>> > ath0 at pci0:4:0:0: class=0x028000 card=0x0300168c chip=0x002d168c
>> > rev=0x01 hdr=0x00
>> > vendor = 'Atheros Communications Inc.'
>> > device = 'AR9227 Wireless Network Adapter'
>> > class = network
>> >
>> > ifconfig:
>> > wlan0: flags=8943<UP,BROADCAST,RUNNING,PROMISC,SIMPLEX,MULTICAST>
>> metric 0
>> > mtu 1500
>> > ether f8:1a:67:89:0c:b8
>> > media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng
>> <hostap>
>> > status: running
>> > ssid blackbird channel 4 (2427 MHz 11g ht/40+) bssid
>> > f8:1a:67:89:0c:b8
>> > regdomain ETSI country RU indoor ecm authmode WPA1+WPA2/802.11i
>> -wps
>> > -tsn privacy MIXED deftxkey 3
>> > TKIP 2:128-bit
>> > TKIP 3:128-bit powersavemode OFF powersavesleep 100 txpower 30
>> > txpowmax 50.0 -dotd rtsthreshold 2346 fragthreshold 2346 bmiss 7
>> > 11a ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
>> > 11b ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
>> > 11g ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
>> > turboA ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
>> > turboG ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
>> > sturbo ucast NONE mgmt 6 Mb/s mcast 6 Mb/s maxretry 6
>> > 11na ucast NONE mgmt 12 MCS mcast 12 MCS maxretry 6
>> > 11ng ucast NONE mgmt 2 MCS mcast 2 MCS maxretry 6
>> > half ucast NONE mgmt 3 Mb/s mcast 3 Mb/s maxretry 6
>> > quarter ucast NONE mgmt 1 Mb/s mcast 1 Mb/s maxretry 6
>> > scanvalid 60 -bgscan bgscanintvl 300 bgscanidle 250
>> > roam:11a rssi 7dBm rate 12 Mb/s
>> > roam:11b rssi 7dBm rate 1 Mb/s
>> > roam:11g rssi 7dBm rate 5 Mb/s
>> > roam:turboA rssi 7dBm rate 12 Mb/s
>> > roam:turboG rssi 7dBm rate 12 Mb/s
>> > roam:sturbo rssi 7dBm rate 12 Mb/s
>> > roam:11na rssi 7dBm MCS 1
>> > roam:11ng rssi 7dBm MCS 1
>> > roam:half rssi 7dBm rate 6 Mb/s
>> > roam:quarter rssi 7dBm rate 3 Mb/s
>> > -pureg protmode CTS ht htcompat ampdu ampdulimit 64k
>> ampdudensity 8
>> > amsdu shortgi htprotmode RTSCTS -puren -smps -rifs wme burst
>> -dwds
>> > -hidessid apbridge dtimperiod 1 doth -dfs inact bintval 100
>> > AC_BE cwmin 4 cwmax 6 aifs 3 txopLimit 0 -acm ack
>> > cwmin 4 cwmax 10 aifs 3 txopLimit 0 -acm
>> > AC_BK cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm ack
>> > cwmin 4 cwmax 10 aifs 7 txopLimit 0 -acm
>> > AC_VI cwmin 3 cwmax 4 aifs 1 txopLimit 94 -acm ack
>> > cwmin 3 cwmax 4 aifs 2 txopLimit 94 -acm
>> > AC_VO cwmin 2 cwmax 3 aifs 1 txopLimit 47 -acm ack
>> > cwmin 2 cwmax 3 aifs 2 txopLimit 47 -acm
>> > groups: wlan
>> >
>> > athstats:
>> > 317346 data frames received
>> > 432914 data frames transmit
>> > 543 tx frames with an alternate rate
>> > 29708 short on-chip tx retries
>> > 41739 long on-chip tx retries
>> > 5700 tx failed 'cuz too many retries
>> > 17 stuck beacon conditions
>> > MCS4 current transmit rate
>> > 3 tx stopped 'cuz no xmit buffer
>> > 209 tx failed 'cuz destination filtered
>> > 2061 tx frames with no ack marked
>> > 421765 tx frames with short preamble
>> > 13990 rx failed 'cuz of bad CRC
>> > 1 rx failed 'cuz frame too short
>> > 1 rx failed 'cuz of PHY err
>> > 1 illegal service
>> > 162287 beacons transmitted
>> > 554 periodic calibrations
>> > -0/+0 TDMA slot adjust (usecs, smoothed)
>> > 50 rssi of last ack
>> > 33 avg recv rssi
>> > -96 rx noise floor
>> > 9348 tx frames through raw api
>> > 205506 A-MPDU sub-frames received
>> > 120913 Half-GI frames received
>> > 751 CRC errors for non-last A-MPDU subframes
>> > 172 CRC errors for last subframe in an A-MPDU
>> > 1 Frames received w/ STBC encoding
>> > 97566 Frames transmitted with HT Protection
>> > 6407 Number of frames retransmitted in software
>> > 336 Number of frames exceeding software retry
>> > 178990 A-MPDU sub-frame TX attempt success
>> > 5884 A-MPDU sub-frame TX attempt failures
>> > 900 A-MPDU TX frame failures
>> > 1514 cabq frames transmitted
>> > 137 cabq xmit overflowed beacon interval
>> > 1 OFDM weak signal detect
>> > 189 listen time
>> > 33 ANI disabled OFDM weak signal detect
>> > 741238 cumulative OFDM phy error count
>> > 346722 cumulative CCK phy error count
>> > 677 ANI forced listen time to zero
>> > 35612 missing ACK's
>> > 50495 RTS without CTS
>> > 73359 successful RTS
>> > 19322 bad FCS
>> > 21 average rssi (beacons only)
>> > Antenna profile:
>> > [0] tx 277449 rx 7401
>> > [1] tx 0 rx 309945
>> >
>> > some logs and outputs (debug messages, tcpdump, etc) also available
>> here:
>> >
>> > logs for windows client https://yadi.sk/d/_Sc9xCYkb6GLR
>> > logs for android client https://yadi.sk/d/IL6qO9Ahb6GLW
>> >
>> >
>> > --
>> > Alex Deiter
>> > _______________________________________________
>> > freebsd-wireless at freebsd.org mailing list
>> > http://lists.freebsd.org/mailman/listinfo/freebsd-wireless
>> > To unsubscribe, send any mail to "
>> freebsd-wireless-unsubscribe at freebsd.org"
>>
>
>
>
> --
> Alex Deiter
>
--
Alex Deiter
More information about the freebsd-wireless
mailing list