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
