If wpa_supplicant is killed Driver state machine is left to unstable state

kstauffer uglymouse
Sat Apr 21 03:29:26 PDT 2007 

Wpa_supplicant: 0.4.10
Mode: 11a

I have a problem when disabling encryption.
When Encryption is disabled (wpa_supplicant killed) it leaves the driver State machine to unstable state.
This can not be fixed by recreating the interface, only
reloading the ATH_PCI module helps permanently.

What happens in practic (when encryption is disabled) is that when ever AP changes channel (in case automatic
channel selection is used, AP changes channel almost every time when some parameter is changed),
driver in station is in state where it never initates
new scanning. The logs reviel that ieee80211_tx_timeout function is newer called
in case WPA_SUPPLICANT is killed.
WPA_SUPPLICANT doesn't use this function, but driver uses. WPA_SUPPLICANT has
some inner mechanism to notice when scanning is required.
When Driver state is changed: __ieee80211_newstate: RUN -> ASSOC, it should
reset the timeout how long the driver is waiting for AP to be heard on same channel. Timer is
resetted but for some reason, driver is in state where it never notice that
timeout (which appears to be 5sec) has exceeded and this leads to situation
where the state is never changed ( state is not changed to:
__ieee80211_newstate: ASSOC -> SCAN).

Station of course reassociates if the channel remains the same.
Also in case the wpa_supplicant is restarted with null configuration everything works.


Some logs:

###Change channel in AP without WPA_SUPPLICANT and encryption (normal situation):

Apr 20 16:41:51 192.168.204.1 kernel: wlan0: [00:80:48:41:6d:04] recv
disassociate (reason 8)
###Channel is changed in AP

Apr 20 16:41:51 192.168.204.1 kernel: ath_newstate: wifi0: RUN -> ASSOC
Apr 20 16:41:51 192.168.204.1 kernel: ath_newstate: RX filter 0x117 bssid
00:80:48:41:6d:04 aid 0x0
Apr 20 16:41:51 192.168.204.1 kernel: wlan0: __ieee80211_newstate: RUN -> ASSOC
### At this point timer is resetted

Apr 20 16:41:53 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:41:53 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:41:54 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:41:54 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:41:55 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:41:55 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:41:56 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:41:56 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:41:56 192.168.204.1 kernel: wlan0: ieee80211_tx_timeout: state ASSOC
###Timeout happens, change state

Apr 20 16:41:56 192.168.204.1 kernel: ath_newstate: wifi0: ASSOC -> SCAN
Apr 20 16:41:56 192.168.204.1 kernel: ath_newstate: RX filter 0x117 bssid
00:80:48:41:6d:04 aid 0x0
Apr 20 16:41:56 192.168.204.1 kernel: wlan0: __ieee80211_newstate: ASSOC -> SCAN
Apr 20 16:41:56 192.168.204.1 kernel: ath_scan_start: RX filter 0x117 bssid
ff:ff:ff:ff:ff:ff aid 0
### Scan is intiated

Apr 20 16:41:56 192.168.204.1 kernel: ath_chan_set: 108 (5540 MHz) -> 100 (5500 MHz)
Apr 20 16:41:56 192.168.204.1 kernel: ath_draintxq: beacon queue 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [0] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [1] 067240a0,
link c67240a0
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [2] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [3] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [4] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [7] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: ath_tx_stopdma: tx queue [8] 00000000,
link 00000000
Apr 20 16:41:56 192.168.204.1 kernel: T (c67240a0 67240a0) 00000000 065a76b0
03220057 06000053 00040000 0000000b ec0d0402 00038005 !
Apr 20 16:41:56 192.168.204.1 kernel: ath_stoprecv: rx queue 0672b4d8, link c672b4b0
Apr 20 16:41:56 192.168.204.1 kernel: ath_startrecv: mtu 1500 cachelsz 32
rxbufsize 3104
Apr 20 16:41:56 192.168.204.1 kernel: ath_mode_init: RX filter 0x17, MC filter
00000000:00000040
Apr 20 16:41:56 192.168.204.1 kernel: ath_chan_set: 100 (5500 MHz) -> 104 (5520 MHz)
Apr 20 16:41:56 192.168.204.1 kernel: ath_draintxq: beacon queue 00000000

### And association to with new channel happens after a while.


###Change channel in AP, WPA_SUPPLICANT running (either encryption or empty
configuration)

### Channel is changed in AP and noticed by Station
Apr 20 16:44:37 192.168.204.1 kernel: ath_newstate: wifi0: RUN -> ASSOC
Apr 20 16:44:37 192.168.204.1 kernel: ath_newstate: RX filter 0x117 bssid
00:80:48:41:6d:04 aid 0x0
Apr 20 16:44:38 192.168.204.1 kernel: ath_scan_start: RX filter 0x117 bssid
ff:ff:ff:ff:ff:ff aid 0
### Scan is initated

Apr 20 16:44:38 192.168.204.1 kernel: ath_chan_set: 120 (5600 MHz) -> 100 (5500 MHz)
Apr 20 16:44:38 192.168.204.1 kernel: ath_draintxq: beacon queue 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [0] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [1] 06724460,
link c6724460
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [2] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [3] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [4] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [7] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: ath_tx_stopdma: tx queue [8] 00000000,
link 00000000
Apr 20 16:44:38 192.168.204.1 kernel: T (c6724460 6724460) 00000000 06657038
43220097 0600808b 24348000 0004b50c be2f0001 00030011 *
Apr 20 16:44:38 192.168.204.1 kernel: ath_stoprecv: rx queue 0672b348, link c672b320
Apr 20 16:44:38 192.168.204.1 kernel: ath_startrecv: mtu 1500 cachelsz 32
rxbufsize 3104
Apr 20 16:44:38 192.168.204.1 kernel: ath_mode_init: RX filter 0x17, MC filter
00000000:00000040
Apr 20 16:44:38 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:44:40 192.168.204.1 kernel: ath_chan_set: 100 (5500 MHz) -> 104 (5520 MHz)
Apr 20 16:44:40 192.168.204.1 kernel: ath_draintxq: beacon queue 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [0] 00000000,
link 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [1] 06724460,
link 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [2] 00000000,
link 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [3] 00000000,
link 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [4] 00000000,
link 00000000
Apr 20 16:44:40 192.168.204.1 kernel: ath_tx_stopdma: tx queue [7] 00000000,
link 00000000
### And association to with new channel happens after a while.


###Changing channel in AP AFTER WPA_SUPPLICANT killed without reloading ATH_PCI module:

Apr 20 16:47:14 192.168.204.1 kernel: wlan0: [00:80:48:41:6d:04] recv
disassociate (reason 8)
### Channel is changed in AP and noticed by Station

Apr 20 16:47:14 192.168.204.1 kernel: ath_newstate: wifi0: RUN -> ASSOC
### State is changed

Apr 20 16:47:14 192.168.204.1 kernel: ath_newstate: RX filter 0x117 bssid
00:80:48:41:6d:04 aid 0x0
Apr 20 16:47:14 192.168.204.1 kernel: wlan0: __ieee80211_newstate: RUN -> ASSOC
Apr 20 16:47:14 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:14 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:15 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:15 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:16 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:16 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:16 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:16 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:17 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:17 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:18 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:18 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:19 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:19 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:19 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:19 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:20 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:20 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:21 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:21 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:21 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:21 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:22 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:22 192.168.204.1 kernel: wlan0: beacon miss
Apr 20 16:47:23 192.168.204.1 kernel: ath_bmiss_tasklet
Apr 20 16:47:23 192.168.204.1 kernel: wlan0: beacon miss
### Timeout never exceeds


-Kristian

More information about the Hostap mailing list