Skip site navigation (1)Skip section navigation (2)
Date:      Sat, 6 Sep 2014 13:54:28 +0400
From:      Alex Deiter <alex.deiter@gmail.com>
To:        freebsd-wireless@freebsd.org
Subject:   Re: [ath] AR9227 hang: ath_rate_findrate: switching quickly..
Message-ID:  <CAAi9sia6k9DSw=d%2BFeaSYuucufZC=tr=%2BKOmx9cRPOv_94m8tQ@mail.gmail.com>
In-Reply-To: <CAAi9siaHijuEHeY8wWw-t3v1e4uVe0KCdG2N7uYDB9Wzeu2jqw@mail.gmail.com>
References:  <CAAi9siYROfG7Pjg=MLibXLWKDAO5UnPafS2ZJ-SxQ8oN1=JCMA@mail.gmail.com> <CAJ-Vmonh7G%2B2aWE288mEOjqQkX=s-4n0q2h2AQ9-=xeCUJrg2A@mail.gmail.com> <CAAi9siaHijuEHeY8wWw-t3v1e4uVe0KCdG2N7uYDB9Wzeu2jqw@mail.gmail.com>

next in thread | previous in thread | raw e-mail | index | archive | help
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@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@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@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@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@freebsd.org mailing list
>> > http://lists.freebsd.org/mailman/listinfo/freebsd-wireless
>> > To unsubscribe, send any mail to "
>> freebsd-wireless-unsubscribe@freebsd.org"
>>
>
>
>
> --
> Alex Deiter
>



-- 
Alex Deiter



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAAi9sia6k9DSw=d%2BFeaSYuucufZC=tr=%2BKOmx9cRPOv_94m8tQ>