From owner-freebsd-wireless@FreeBSD.ORG Mon Jan 28 01:45:57 2013 Return-Path: Delivered-To: freebsd-wireless@freebsd.org Received: from mx1.freebsd.org (mx1.FreeBSD.org [8.8.178.115]) by hub.freebsd.org (Postfix) with ESMTP id CFB112B4 for ; Mon, 28 Jan 2013 01:45:57 +0000 (UTC) (envelope-from adrian.chadd@gmail.com) Received: from mail-we0-x22a.google.com (we-in-x022a.1e100.net [IPv6:2a00:1450:400c:c03::22a]) by mx1.freebsd.org (Postfix) with ESMTP id 5F3A7DE for ; Mon, 28 Jan 2013 01:45:57 +0000 (UTC) Received: by mail-we0-f170.google.com with SMTP id z53so1181656wey.15 for ; Sun, 27 Jan 2013 17:45:55 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:x-received:sender:in-reply-to:references:date :x-google-sender-auth:message-id:subject:from:to:cc:content-type; bh=Zme5FLV39mjDng4EWbfA0kmtFnzc0rM5u59AIZdM/9I=; b=rSvku7G0IEBxPnmPTtx0arJeeQ1w5rK+cBKjk2UeeeJ1DcNnYUveLg/3NCUU0BraaA AQ9gyYuf+1U6nTQNK6MBNRH1YJ0HZ6KuYfSUMxtzSULOgkpfmpcIRfk9hEP8HyLwEg9P z8MPbsP8pxEScUCyhCmPUhQDTBwwtCjCfon6zL5eVGo2deWoVFAsF7L0YU3hRQwqzDrL fsUp3Zf3bUNoR8Xk86kqI+AdFadg/fTKKk/GhzsoCovsCjaInSgz3ZdxqNR9v7gsUcjd x6OA+IqJUaCR0hp13TAeIEbmR478rSJ2FKSYVxe4KSYaJJpt/s1NcZl/IHpjlajeWHpE 3Qtw== MIME-Version: 1.0 X-Received: by 10.180.8.130 with SMTP id r2mr7012554wia.28.1359337555745; Sun, 27 Jan 2013 17:45:55 -0800 (PST) Sender: adrian.chadd@gmail.com Received: by 10.216.67.6 with HTTP; Sun, 27 Jan 2013 17:45:55 -0800 (PST) In-Reply-To: <5105A2A9.2020803@unsane.co.uk> References: <51051E26.1050300@unsane.co.uk> <5105A2A9.2020803@unsane.co.uk> Date: Sun, 27 Jan 2013 17:45:55 -0800 X-Google-Sender-Auth: Inehy-HTb3E94OL6LeemiC8lt9g Message-ID: Subject: Re: wireless link flaps (ath ar9280) From: Adrian Chadd To: Vincent Hoffman Content-Type: text/plain; charset=ISO-8859-1 Cc: "freebsd-wireless@freebsd.org" X-BeenThere: freebsd-wireless@freebsd.org X-Mailman-Version: 2.1.14 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: Mon, 28 Jan 2013 01:45:57 -0000 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 0xffffff800b388000: bf=0xffffff80008c3140: addbaw=0, dobaw=1, > seqno=2485, retry=0 > Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node > 0xffffff800b388000: bf=0xffffff80008c3140: txq[1] axq_depth=0, > axq_aggr_depth=0 > Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_tid_drain_print: node > 0xffffff800b388000: bf=0xffffff80008c3140: 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 > 0xffffff800b388000: 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 0000 e091 f548 5bb9 0024 2307 fb5d > 6033 4b0d e1f8 509b 0000 dec0 0534 0020 0900 0000 aaaa 0300 0000 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 > 0xffffff80008c3140: seqno 2485: dobaw should've been cleared! > Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf > 0xffffff80008c1e20: seqno 2486: dobaw should've been cleared! > Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf > 0xffffff80008a6178: seqno 2487: dobaw should've been cleared! > Jan 27 21:49:09 ostracod kernel: ath0: ath_tx_default_comp: bf > 0xffffff80008b7b90: 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=0x00000024 >>> Jan 24 16:26:22 ostracod kernel: AR_DIAG_SW=0x42000020 >>> 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=0x00000024 >>> Jan 25 00:57:36 ostracod kernel: AR_DIAG_SW=0x42000020 >>> >>> 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=0x00000024 >>> Jan 25 09:41:13 ostracod kernel: AR_DIAG_SW=0x42000020 >>> Jan 25 09:46:50 ostracod kernel: ar5416StopDmaReceive: dma failed to >>> stop in 10ms >>> Jan 25 09:46:50 ostracod kernel: AR_CR=0x00000024 >>> Jan 25 09:46:50 ostracod kernel: AR_DIAG_SW=0x42000020 >>> 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=0x00000024 >>> Jan 25 09:52:10 ostracod kernel: AR_DIAG_SW=0x42000020 >>> 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=0x00000024 >>> Jan 26 17:24:46 ostracod kernel: AR_DIAG_SW=0x42000020 >>> 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=0x00000024 >>> Jan 25 16:56:27 ostracod kernel: AR_DIAG_SW=0x42000020 >>> 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 0xffffff8014828000: bf=0xffffff80008b23e8: addbaw=1, dobaw=1, >>> seqno=3447, retry=6 >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node >>> 0xffffff8014828000: bf=0xffffff80008b23e8: txq[1] axq_depth=0, >>> axq_aggr_depth=0 >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_tid_drain_print: node >>> 0xffffff8014828000: bf=0xffffff80008b23e8: 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 >>> 0xffffff8014828000: 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 0000 e091 f548 5bb9 0024 2307 fb5d >>> e091 f548 5bb9 70d7 0000 dec0 b689 0020 0c00 0000 aaaa 0300 0000 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 >>> 0xffffff80008a9e08: seqno 3448: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008aa468: seqno 3449: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008c8a80: seqno 3450: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008cf080: seqno 3451: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008a8488: seqno 3452: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008a64a8: seqno 3453: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008aa930: seqno 3454: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: ath0: ath_tx_default_comp: bf >>> 0xffffff80008a8ae8: seqno 3455: dobaw should've been cleared! >>> Jan 25 16:56:28 ostracod kernel: wlan0: link state changed to DOWN >>> Jan 25 16:56:39 ostracod wpa_supplicant[568]: Trying to associate with >>> e0:91:f5:48:5b:b9 (SSID='vhoff' freq=2462 MHz) >>> Jan 25 16:56:39 ostracod wpa_supplicant[568]: Associated with >>> e0:91:f5:48:5b:b9 >>> Jan 25 16:56:39 ostracod kernel: wlan0: link state changed to UP >>> Jan 25 16:56:40 ostracod wpa_supplicant[568]: WPA: Key negotiation >>> completed with e0:91:f5:48:5b:b9 [PTK=CCMP GTK=TKIP] >>> >>> >>> Device is >>> ath0: mem 0xfebf0000-0xfebfffff irq 16 at device 0.0 on pci4 >>> ath0: [HT] enabling HT modes >>> ath0: [HT] 2 RX streams; 1 TX streams >>> ath0: AR9280 mac 128.2 RF5133 phy 13.0 >>> ath0: 2GHz radio: 0x0000; 5GHz radio: 0x00c0 >>> >>> Any suggestions? I'm happy to provide more info if needed. >>> >>> Vince >>> _______________________________________________ >>> 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" >