Return-path: Received: from mail-wg0-f49.google.com ([74.125.82.49]:43256 "EHLO mail-wg0-f49.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756484Ab3AQDMh (ORCPT ); Wed, 16 Jan 2013 22:12:37 -0500 Received: by mail-wg0-f49.google.com with SMTP id 15so1377401wgd.16 for ; Wed, 16 Jan 2013 19:12:35 -0800 (PST) MIME-Version: 1.0 In-Reply-To: References: Date: Wed, 16 Jan 2013 19:12:35 -0800 Message-ID: (sfid-20130117_041245_063880_B0C34DBF) Subject: Re: Auth Packet TX Delay From: Adrian Chadd To: Robert Shade Cc: linux-wireless@vger.kernel.org, ath9k-devel@lists.ath9k.org Content-Type: text/plain; charset=ISO-8859-1 Sender: linux-wireless-owner@vger.kernel.org List-ID: Find where the fast channel change code is (maybe) called, and just disable it so it always calls the full channel change? Adrian On 16 January 2013 17:00, Robert Shade wrote: > I was able to grab a log with debugging on when the issue started all > the way to when it started timing out association due to TX delay: > https://dl.dropbox.com/u/12121487/delay-messages.gz > > On Wed, Jan 16, 2013 at 6:09 PM, Adrian Chadd wrote: >> Hm, that register is AR_PHY_RFBUS_GNT, which iirc is only involved in >> fast channel change. >> >> Maybe ath9k's fast channel change code isn't working right, and it's >> not trying a full channel change afterwards? >> >> >> >> Adrian >> >> >> On 15 January 2013 14:06, Robert Shade wrote: >>> I'm seeing a periodic issue where the device seems to get stuck in a >>> state where the TX of authentication packets is delayed so that >>> authentication fails. The log snippet below shows the auth packets >>> getting queued after each "wlan0: send auth to XX", but they're not >>> actually sent until after it gives up and restarts scanning. Once the >>> device gets into this state, it stays in a SCAN->AUTH->AUTH >>> FAILED->SCAN cycle indefinitely. However, if I do a ifconfig wlan0 >>> down, the device usually recovers and works correctly for a few minutes to >>> hours. >>> >>> This is with the latest compat-drivers. The authentication is EAP-TLS >>> and it's in an environment where it periodically roams using >>> wpa_supplicant's bgscan. >>> >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 1 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 2 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 3 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TXQ, inactive queue: 4 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TXQ, inactive queue: 5 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TXQ, inactive queue: 6 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TXQ, inactive queue: 7 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 8 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Reset TX queue: 9 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: tx ok 0x0 err 0x0 desc >>> 0x10f eol 0x10f urn 0x0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ver 64.1 opmode 2 chan 2437 Mhz/0xc0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ah->misc_mode 0x4 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: enabling ADC Gain Calibration >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: enabling ADC DC Calibration >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: enabling IQ Calibration >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: starting ADC Gain Calibration >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Enable MIB counters >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Restore history: opmode 2 >>> chan 2437 Mhz/0xc0 is_scanning=0 ofdm:8 cck:6 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: **** ofdmlevel 8=>8, >>> rssi=67[lo=7 hi=40] >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ** ch 2437: level >>> 3=>7[def:3] cycpwrThr1[level]=14 ini=6 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ** ch 2437: level >>> 3=>7[def:3] cycpwrThr1Ext[level]=14 ini=6 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ANI parameters: SI=7, >>> ofdmWS=on FS=2 MRCcck=off listenTime=0 ofdmErrs=0 cckErrs=0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ** ch 2437: level >>> 2=>6[def:2] firstep[level]=10 ini=2 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ** ch 2437: level >>> 2=>6[def:2] firstep_low[level]=14 ini=6 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ANI parameters: SI=7, >>> ofdmWS=on FS=6 MRCcck=off listenTime=0 ofdmErrs=0 cckErrs=0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ** ch 2437: ofdm weak signal: on=>off >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: ANI parameters: SI=7, >>> ofdmWS=off FS=6 MRCcck=off listenTime=0 ofdmErrs=0 cckErrs=0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: **** ccklevel 6=>6, >>> rssi=67[lo=7 hi=40] >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: New interrupt mask 0xf4040071 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: new IMR 0x918404b0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Do not enable IER ref count -1 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: STA is not yet >>> associated..skipping beacon config >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Beacon already configured >>> for a station interface >>> Nov 20 11:24:33 MR89253 kernel: wlan0: Inserted STA 00:24:6c:74:0a:40 >>> Nov 20 11:24:33 MR89253 kernel: wlan0: send auth to 00:24:6c:74:0a:40 (try 1/3) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: transmitting packet, skb: >>> ffff880137846a80 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: qnum: 0, txq depth: 0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: TXDP[0] = 378480c8 (ffff8800378480c8) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Enable TXE on queue: 0 >>> Nov 20 11:24:33 MR89253 NetworkManager[1821]: (wlan0): >>> supplicant interface state: scanning -> authenticating >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: RTM_NEWLINK: operstate=0 >>> ifi_flags=0x1003 ([UP]) >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: RTM_NEWLINK, >>> IFLA_IFNAME: Interface 'wlan0' added >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: if_removed >>> already cleared - ignore event >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Event message available >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: New station >>> 00:24:6c:74:0a:40 >>> Nov 20 11:24:33 MR89253 kernel: wlan0: send auth to 00:24:6c:74:0a:40 (try 2/3) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: transmitting packet, skb: >>> ffff8801265cc2c0 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: qnum: 0, txq depth: 1 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: link[0] >>> (ffff8800378480c8)=37847568 (ffff880037847568) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Enable TXE on queue: 0 >>> Nov 20 11:24:33 MR89253 kernel: wlan0: send auth to 00:24:6c:74:0a:40 (try 3/3) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: transmitting packet, skb: >>> ffff8801261aac80 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: qnum: 0, txq depth: 2 >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: link[0] >>> (ffff880037847568)=378465f8 (ffff8800378465f8) >>> Nov 20 11:24:33 MR89253 kernel: ath: phy0: Enable TXE on queue: 0 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Event message available >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Delete station >>> 00:24:6c:74:0a:40 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Event message available >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: MLME event 37; >>> timeout with 00:24:6c:74:0a:40 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: Event >>> AUTH_TIMED_OUT (14) received >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: SME: >>> Authentication timed out >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: Added BSSID >>> 00:24:6c:74:0a:40 into blacklist >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: Another BSS in >>> this ESS has been seen; try it next >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: BSSID 00:24:6c:74:0a:40 >>> blacklist count incremented to 2 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: Setting scan >>> request: 0 sec 100000 usec >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: State: >>> AUTHENTICATING -> DISCONNECTED >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: >>> wpa_driver_nl80211_set_operstate: operstate 0->0 (DORMANT) >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: netlink: Operstate: >>> linkmode=-1, operstate=5 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: EAPOL: External >>> notification - portEnabled=0 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: EAPOL: Supplicant port >>> status: Unauthorized >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: EAPOL: External >>> notification - portValid=0 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: EAPOL: Supplicant port >>> status: Unauthorized >>> Nov 20 11:24:33 MR89253 kernel: wlan0: authentication with >>> 00:24:6c:74:0a:40 timed out >>> Nov 20 11:24:33 MR89253 kernel: wlan0: Removed STA 00:24:6c:74:0a:40 >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: dbus: >>> flush_object_timeout_handler: Timeout - sending changed properties of >>> object /fi/w1/wpa_supplicant1/Interfaces/1 >>> Nov 20 11:24:33 MR89253 NetworkManager[1821]: (wlan0): >>> supplicant interface state: authenticating -> disconnected >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: State: >>> DISCONNECTED -> SCANNING >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: wlan0: Starting AP scan >>> for wildcard SSID >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2412 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2417 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2422 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2427 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2432 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2437 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2442 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2447 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2452 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2457 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2462 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2467 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2472 MHz >>> Nov 20 11:24:33 MR89253 wpa_supplicant[1841]: nl80211: Scan frequency 2484 MHz >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: AWAKE -> FULL-SLEEP >>> Nov 20 11:24:34 MR89253 kernel: wlan0: Destroyed STA 00:24:6c:74:0a:40 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: FULL-SLEEP -> AWAKE >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: AWAKE -> FULL-SLEEP >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: FULL-SLEEP -> AWAKE >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: Set channel: 2437 MHz type: 0 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF calibrated [ctl] [chain 0] is -50 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF[0] (-50) > MAX (-80), >>> correcting to MAX >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF calibrated [ctl] [chain 1] is -50 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF[1] (-50) > MAX (-80), >>> correcting to MAX >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF calibrated [ctl] [chain 2] is -50 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: NF[2] (-50) > MAX (-80), >>> correcting to MAX >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: Stopping ANI >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: disable IER >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: Disable MIB counters >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: TX complete: skb: ffff880137846a80 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: TX complete: skb: ffff8801265cc2c0 >>> Nov 20 11:24:34 MR89253 kernel: ath: phy0: TX complete: skb: ffff8801261aac80 >>> >>> 17:00.0 Network controller: Atheros Communications Inc. AR9160 >>> Wireless Network Adapter [AR9001 802.11(a)bgn] (rev 01) >>> Subsystem: Ubiquiti Networks, Inc. SR71-A 802.11abgn Wireless >>> Mini PCI Adapter >>> Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- >>> Stepping- SERR- FastB2B- DisINTx- >>> Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- >>> SERR- >> Latency: 168, Cache Line Size: 32 bytes >>> Interrupt: pin A routed to IRQ 18 >>> Region 0: Memory at fd5f0000 (32-bit, non-prefetchable) [size=64K] >>> Capabilities: [44] Power Management version 2 >>> Flags: PMEClk- DSI- D1- D2- AuxCurrent=100mA >>> PME(D0+,D1-,D2-,D3hot+,D3cold-) >>> Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME- >>> Kernel driver in use: ath9k >>> Kernel modules: ath9k >>> >>> The last time I saw this on a device that I could debug with, I saw >>> the following in the log just before it entered this state: >>> >>> Jan 15 16:36:53 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:53 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:53 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9c20: 0x00000000 & 0x00000001 != 0x00000001 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Could not kill baseband RX >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9c20: 0x00000000 & 0x00000001 != 0x00000001 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Could not kill baseband RX >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:54 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9c20: 0x00000000 & 0x00000001 != 0x00000001 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Could not kill baseband RX >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:55 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9c20: 0x00000000 & 0x00000001 != 0x00000001 >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: Could not kill baseband RX >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Event message available >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: New scan >>> results available >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Event >>> SCAN_RESULTS (3) received >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Associated on 2412 MHz >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Associated with >>> 00:17:59:2c:c3:20 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Received scan >>> results (45 BSSes) >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Scan results >>> indicate BSS status with 00:17:59:2c:c3:20 as associated >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: New scan results available >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: bgscan simple: scan >>> result notification >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Selecting BSS >>> from priority group 0 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: 0: >>> 00:17:59:2c:c3:20 ssid='l0c0m0t1v3' wpa_ie_len=24 rsn_ie_len=0 >>> caps=0xc31 level=-56 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: selected based on WPA IE >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: selected BSS >>> 00:17:59:2c:c3:20 ssid='l0c0m0t1v3' >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Checking for >>> other virtual interfaces sharing same radio (phy1) in >>> event_scan_results >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: dbus: >>> flush_object_timeout_handler: Timeout - sending changed properties of >>> object /fi/w1/wpa_supplicant1/Interfaces/1 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: RTM_NEWLINK: operstate=1 >>> ifi_flags=0x11043 ([UP][RUNNING][LOWER_UP]) >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: RTM_NEWLINK, >>> IFLA_IFNAME: Interface 'wlan0' added >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: if_removed >>> already cleared - ignore event >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: timeout (100000 us) on reg >>> 0x9860: 0x00048d21 & 0x00000001 != 0x00000000 >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: Unable to reset channel, >>> reset status -5 >>> Jan 15 16:36:56 MR89251 kernel: ath: phy1: Unable to set channel >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Event message available >>> Jan 15 16:36:56 MR89251 kernel: wlan0: Failed to send nullfunc to AP >>> 00:17:59:2c:c3:20 after 500ms, disconnecting >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Event message available >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Delete station >>> 00:17:59:2c:c3:20 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Event message available >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: MLME event 39 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: MLME event >>> frame - hexdump(len=26): c0 00 00 00 00 17 59 2c c3 20 00 15 6d 84 d7 >>> 14 00 17 59 2c c3 20 00 00 04 00 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: nl80211: Deauthenticate event >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Event DEAUTH (12) received >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Deauthentication >>> notification >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: * reason 4 >>> (locally generated) >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: * address >>> 00:17:59:2c:c3:20 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: Deauthentication frame >>> IE(s) - hexdump(len=0): [NULL] >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: >>> CTRL-EVENT-DISCONNECTED bssid=00:17:59:2c:c3:20 reason=4 >>> locally_generated=1 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Auto connect >>> enabled: try to reconnect (wps=0 wpa_state=9) >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Setting scan >>> request: 0 sec 100000 usec >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: Added BSSID >>> 00:17:59:2c:c3:20 into blacklist >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Another BSS in >>> this ESS has been seen; try it next >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: BSSID 00:17:59:2c:c3:20 >>> blacklist count incremented to 2 >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Not rescheduling >>> scan to ensure that specific SSID scans occur >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: wlan0: Disconnect event >>> - remove keys >>> Jan 15 16:36:56 MR89251 wpa_supplicant[1964]: >>> wpa_driver_nl80211_set_key: ifindex=13 alg=0 addr=(nil) key_idx=0 >>> set_tx=0 seq_len=0 key_len=0 >>> Jan 15 16:36:56 MR89251 kernel: wlan0: moving STA 00:17:59:2c:c3:20 to state 3 >>> Jan 15 16:36:56 MR89251 kernel: wlan0: moving STA 00:17:59:2c:c3:20 to state 2 >>> Jan 15 16:36:56 MR89251 kernel: wlan0: moving STA 00:17:59:2c:c3:20 to state 1 >>> Jan 15 16:36:56 MR89251 kernel: wlan0: Removed STA 00:17:59:2c:c3:20 >>> (goes into associate timeout loop) >>> >>> Please let me know if you need any additional information or testing >>> done. Thanks. >>> -- >>> To unsubscribe from this list: send the line "unsubscribe linux-wireless" in >>> the body of a message to majordomo@vger.kernel.org >>> More majordomo info at http://vger.kernel.org/majordomo-info.html > -- > To unsubscribe from this list: send the line "unsubscribe linux-wireless" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html