AR9160 / AR9106 On Thu, Feb 7, 2013 at 12:06 AM, Adrian Chadd <adrian@xxxxxxxxxxx> wrote: > Okay. Then the radio is truely confused. :-( > > Which chipset is this again? > > > > Adrian > > > On 6 February 2013 14:58, Robert Shade <robert.shade@xxxxxxxxx> wrote: >> I tested this all the way up to 1s and am still able to replicate the timeout. >> >> Out of curiosity I collected how long the calibration usually takes: >> avg 825.829us, min 620us, max 830us (16k+ samples) >> >> On Wed, Feb 6, 2013 at 7:53 AM, Robert Shade <robert.shade@xxxxxxxxx> wrote: >>> The "1ms" in the message is hard coded. The actual timeout on the >>> register poll is 100ms. >>> >>> On Tue, Feb 5, 2013 at 10:08 PM, Adrian Chadd <adrian@xxxxxxxxxxx> wrote: >>>> Try bumping that up to 10ms. >>>> >>>> >>>> >>>> adrian >>>> >>>> On 5 February 2013 18:51, Robert Shade <robert.shade@xxxxxxxxx> wrote: >>>>> I was finally able to do some additional testing on this. I disabled >>>>> the one and only block that calls ath9k_hw_do_fastcc. The issue is >>>>> still reproducible[1], starting with a timeout on AR_PHY_AGC_CONTROL >>>>> >>>>> kernel: ath: phy1: timeout (100000 us) on reg 0x9860: 0x00048d21 & >>>>> 0x00000001 != 0x00000000 >>>>> kernel: ath: phy1: offset calibration failed to complete in 1ms; noisy >>>>> environment? >>>>> kernel: ath: phy1: Unable to reset channel, reset status -5 >>>>> kernel: ath: phy1: Unable to set channel >>>>> >>>>> It fails to change channel a number of times as it tries to scan, then >>>>> auth. After it gives up on the auth it goes through a AWAKE -> >>>>> FULL-SLEEP, FULL-SLEEP -> AWAKE, AWAKE -> FULL-SLEEP, FULL-SLEEP -> >>>>> AWAKE cycle. Afterward, it's able to change channel to the channel >>>>> the SSID is on and xmit the auth requests, however by that time it's >>>>> too late. >>>>> >>>>> It continues to scan and re-auth, however the auth packets are not >>>>> sent until it gives up and goes through another AWAKE/FULL-SLEEP cycle >>>>> after the auth times out. >>>>> >>>>> The radio seems to actually be transmitting because I see the SSID >>>>> probe requests going out and I see my non-broadcasted SSID in the scan >>>>> logs. >>>>> >>>>> [1] It happens randomly on my devices in the field, but I'm able to >>>>> make it happen pretty quickly if I start a flood ping to my wireless >>>>> gw and do continuous scans with iw. >>>>> >>>>> On Wed, Jan 16, 2013 at 10:12 PM, Adrian Chadd <adrian@xxxxxxxxxxx> wrote: >>>>>> 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 <robert.shade@xxxxxxxxx> 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 <adrian@xxxxxxxxxxx> 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 <robert.shade@xxxxxxxxx> 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]: <info> (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]: <info> (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- >>>>>>>>> <TAbort- <MAbort- >SERR- <PERR- INTx- >>>>>>>>> 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@xxxxxxxxxxxxxxx >>>>>>>>> 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@xxxxxxxxxxxxxxx >>>>>>> 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@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
