Bug 193402 - [ath] AR9227 hang: ar5416PerCalibrationN: NF calibration didn't finish; delaying CCA
Summary: [ath] AR9227 hang: ar5416PerCalibrationN: NF calibration didn't finish; delay...
Status: New
Alias: None
Product: Base System
Classification: Unclassified
Component: wireless (show other bugs)
Version: CURRENT
Hardware: amd64 Any
: --- Affects Only Me
Assignee: freebsd-wireless (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2014-09-06 22:34 UTC by alex.deiter
Modified: 2014-09-06 22:44 UTC (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description alex.deiter 2014-09-06 22:34:38 UTC
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 :-(


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

wlan interface hang 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


Details:

TP-LINK TL-WN851ND v1

http://www.tp-link.us/products/details/?categoryid=&model=TL-WN851ND
https://wikidevi.com/wiki/TP-LINK_TL-WN851ND

pciconf:
ath0@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
Comment 1 Adrian Chadd freebsd_committer 2014-09-06 22:44:35 UTC
I think that calibration hang means the baseband has gone RX deaf.

I wonder if a full chip reset will fix it, rather than a warm chip reset. I'll have to go experiment.