ral/wpa_supplicant drops after successful WPA negotiation?

[Peter de Rooij]

On 01/03/06, Sam Leffler <sam at errno.com> wrote:
> ral is hit&miss for me when operating as a station.  Unfortunately I
> don't have chip specs and I haven't figured out what's wrong with the
> driver based on looking at the linux code.  If you want to keep the card
> you can see if ndis will work.  Otherwise you can buy a different card.

So I got a new card (partly because it's flaky under WinXP as well),
atheros based.
Added if_ath_load=YES to load.conf, and the card is detected.  Beyond
that, alas still no connection. In fact, the connection is sometimes
associated, but never even gets to EAPOL negotiation; time-out before
then.  The naked eye suggests it immediately drops from "UP" back to
"DOWN"; in fact I also saw several "ath0: 2 link states coalesced"
messages.

Extracts from wpa_supplicant output (with -dd) and corresponding dmesg
(with net.wlan.0.debug=0x880000) below.

wpa_supplicant:
==========
...
Setting scan request: 0 sec 100000 usec
Starting AP scan (broadcast SSID)
Received 0 bytes of scan results (10 BSSes)
Scan results: 10
Selecting BSS from priority group 0
0: 00:12:bf:07:4b:e1 ssid='belkin54g' wpa_ie_len=26 rsn_ie_len=0
   skip - SSID mismatch
1: 00:11:09:0e:5e:34 ssid='Rupert Rittson-Thomas' wpa_ie_len=24 rsn_ie_len=0
   skip - SSID mismatch
2: 00:80:c8:05:1e:32 ssid='Epsilon3' wpa_ie_len=26 rsn_ie_len=0
   selected
Trying to associate with 00:80:c8:05:1e:32 (SSID='Epsilon3' freq=2422 MHz)
Cancelling scan request
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT WPA-PSK
WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02
01 00 00 50 f2 02 01 00 00 50 f2 02
No keys have been configured - skip key clearing
wpa_driver_bsd_set_drop_unencrypted: enabled=1
wpa_driver_bsd_associate: ssid 'Epsilon3' wpa ie len 24 pairwise 2
group 2 key mgmt 1
wpa_driver_bsd_associate: set PRIVACY 1
Setting authentication timeout: 5 sec 0 usec
Received 0 bytes of scan results (10 BSSes)
Scan results: 10
Selecting BSS from priority group 0
0: 00:12:bf:07:4b:e1 ssid='belkin54g' wpa_ie_len=26 rsn_ie_len=0
   skip - SSID mismatch
1: 00:11:09:0e:5e:34 ssid='Rupert Rittson-Thomas' wpa_ie_len=24 rsn_ie_len=0
   skip - SSID mismatch
2: 00:80:c8:05:1e:32 ssid='Epsilon3' wpa_ie_len=26 rsn_ie_len=0
   selected
Trying to associate with 00:80:c8:05:1e:32 (SSID='Epsilon3' freq=2422 MHz)
Cancelling scan request
Automatic auth_alg selection: 0x1
WPA: using IEEE 802.11i/D3.0
WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2
WPA: using GTK TKIP
WPA: using PTK TKIP
WPA: using KEY_MGMT WPA-PSK
WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 50 f2 02
01 00 00 50 f2 02 01 00 00 50 f2 02
No keys have been configured - skip key clearing
wpa_driver_bsd_set_drop_unencrypted: enabled=1
wpa_driver_bsd_associate: ssid 'Epsilon3' wpa ie len 24 pairwise 2
group 2 key mgmt 1
wpa_driver_bsd_associate: set PRIVACY 1
Setting authentication timeout: 5 sec 0 usec
Association event - clear replay counter
Associated to a new BSS: BSSID=00:80:c8:05:1e:32
No keys have been configured - skip key clearing
Associated with 00:80:c8:05:1e:32
Setting authentication timeout: 10 sec 0 usec
Setting scan request: 0 sec 100000 usec
...
==========
The naked eye suggests the last scan starts immediately after setting
the auth time-out(?)


dmesg:
==========
ath0: ieee80211_newstate: INIT -> SCAN
ath0: ieee80211_newstate: SCAN -> SCAN
...
ath0: ieee80211_newstate: SCAN -> SCAN
ath0: ieee80211_newstate: SCAN -> AUTH
ath0: ieee80211_newstate: AUTH -> SCAN
ath0: ieee80211_newstate: SCAN -> AUTH
ath0: ieee80211_newstate: AUTH -> ASSOC
ath0: [00:80:c8:05:1e:32] assoc success: long preamble, long slot time
ath0: ieee80211_newstate: ASSOC -> RUN
ath0: link state changed to UP
ath0: ieee80211_newstate: RUN -> ASSOC
ath0: link state changed to DOWN
ath0: ieee80211_newstate: INIT -> SCAN
...
==========

I did happen to notice that ath0 shares IRQ 16 with uhci0.  Could that
be the cause of this?

Or is this the bug with the unexpected timer trigger after all?

Peter