From owner-freebsd-wireless@FreeBSD.ORG Sat Sep 6 09:54:32 2014 Return-Path: Delivered-To: freebsd-wireless@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 1A299217 for ; Sat, 6 Sep 2014 09:54:32 +0000 (UTC) Received: from mail-la0-x236.google.com (mail-la0-x236.google.com [IPv6:2a00:1450:4010:c03::236]) (using TLSv1 with cipher ECDHE-RSA-RC4-SHA (128/128 bits)) (Client CN "smtp.gmail.com", Issuer "Google Internet Authority G2" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4B83D1EED for ; Sat, 6 Sep 2014 09:54:31 +0000 (UTC) Received: by mail-la0-f54.google.com with SMTP id b17so15264029lan.13 for ; Sat, 06 Sep 2014 02:54:29 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :content-type; bh=uicbRJ41VDkBER4K4eKv1pDas/6SfQkyz3YRQJbJgFI=; b=n7JUzYTDxgZOLGjMIADMEEQ0uiaslsndICrcl4YGItlv9SLsP/3hqnNU0SC3AD+F42 9rMbQeClOQ1hJTt/6S6rReujl6fep7EuSQfMpItNW25Nfxer0Rw7wg0YEN0wL2Pb6kMp 2PhGvi/YgWuzHqCEH97eDt9dY4e2Jb4v7kRoY0w2la+8aSO3hyQ/MJ6eAISe5LzQ61Nr CvkAP0Kc8Vn+WZMLkE+9JA/iO0TeT/CVK0eqG5X9MhMd7Sl2/73gjaxkX23V404gl1Y6 /fYLgOTph6k5EXJPYYVot8OsDj8gCKOm0iSBCAefK64NUL3Xf0pua66KMV69VOoIzRIS INxw== MIME-Version: 1.0 X-Received: by 10.112.28.8 with SMTP id x8mr726524lbg.104.1409997268972; Sat, 06 Sep 2014 02:54:28 -0700 (PDT) Received: by 10.25.157.4 with HTTP; Sat, 6 Sep 2014 02:54:28 -0700 (PDT) In-Reply-To: References: Date: Sat, 6 Sep 2014 13:54:28 +0400 Message-ID: Subject: Re: [ath] AR9227 hang: ath_rate_findrate: switching quickly.. From: Alex Deiter To: freebsd-wireless@freebsd.org Content-Type: text/plain; charset=UTF-8 X-Content-Filtered-By: Mailman/MimeDel 2.1.18-1 X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.18-1 Precedence: list List-Id: "Discussions of 802.11 stack, tools device driver development." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Sat, 06 Sep 2014 09:54:32 -0000 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 : > 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 : > >> 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 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 >> metric 0 >> > mtu 1500 >> > ether f8:1a:67:89:0c:b8 >> > media: IEEE 802.11 Wireless Ethernet autoselect mode 11ng >> >> > 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