Authentication / Association Problem with 2.6.31

Michael Hirsch m.hirsch
Sun Sep 27 01:30:40 PDT 2009 

Hello all,

I have a issue with hostapd running on my server:

After a number of successful associations and authentications (let's say 
around 5) following associations do not work any more. I can't see a 
request in hostapd's output any more.

Restarting the client does not help, also other linux based systems 
can't connect any more.

The only solution is to restart hostapd.

On both system Linux kernel 2.6.31 is used.
The client uses a libertas_sdio, the server ath5k

here is the hostapd output:

---> Association works:

946693398.852547: wlan0: STA 00:19:88:11:dc:3c IEEE 802.11: associated 
(aid 1)
946693398.852775: wlan0: STA 00:19:88:11:dc:3c MLME: 
MLME-ASSOCIATE.indication(00:19:88:11:dc:3c)
946693398.852904: wlan0: STA 00:19:88:11:dc:3c MLME: 
MLME-DELETEKEYS.request(00:19:88:11:dc:3c)
946693398.856344: wlan0: STA 00:19:88:11:dc:3c WPA: event 1 notification
946693398.856600: wlan0: STA 00:19:88:11:dc:3c WPA: start authentication
946693398.856648: WPA: 00:19:88:11:dc:3c WPA_PTK entering state INITIALIZE
946693398.856917: wlan0: STA 00:19:88:11:dc:3c IEEE 802.1X: 
unauthorizing port
946693398.856964: WPA: 00:19:88:11:dc:3c WPA_PTK_GROUP entering state IDLE
946693398.857037: WPA: 00:19:88:11:dc:3c WPA_PTK entering state 
AUTHENTICATION
946693398.857113: WPA: 00:19:88:11:dc:3c WPA_PTK entering state 
AUTHENTICATION2
946693398.857186: WPA: 00:19:88:11:dc:3c WPA_PTK entering state INITPSK
946693398.857261: WPA: 00:19:88:11:dc:3c WPA_PTK entering state PTKSTART
946693398.857392: wlan0: STA 00:19:88:11:dc:3c WPA: sending 1/4 msg of 
4-Way Handshake
946693398.857436: WPA: Send EAPOL(version=1 secure=0 mic=0 ack=1 
install=0 pairwise=8 kde_len=0 keyidx=0 encr=0)
946693398.859256: IEEE 802.1X: 00:19:88:11:dc:3c TX status - version=2 
type=3 length=95 - ack=1
946693398.863783: IEEE 802.1X: 121 bytes from 00:19:88:11:dc:3c
946693398.863862:    IEEE 802.1X: version=1 type=3 length=117
946693398.863993: wlan0: STA 00:19:88:11:dc:3c WPA: received EAPOL-Key 
frame (2/4 Pairwise)
946693398.864044: WPA: 00:19:88:11:dc:3c WPA_PTK entering state 
PTKCALCNEGOTIATING
946693398.864257: WPA: PTK derivation - A1=00:0b:6b:2f:47:7d 
A2=00:19:88:11:dc:3c
946693398.864360: WPA: PMK - hexdump(len=32): 5a 51 4e e7 08 36 b8 11 01 
5a f5 bb cf 6c 2d fb e9 d5 92 cf fa 53 a2 d3 7b 89 0c 0d 4f 8b 9f 8f
946693398.864655: WPA: PTK - hexdump(len=64): 92 fc 6b 64 d5 8c b4 e8 ad 
55 f0 70 7d 27 15 1f 10 55 0f 17 48 79 4f e1 44 3d 3f 69 75 96 97 82 13 
ce ac 06 bb d7 6e 4f 3d b6 7d ec 1c 2e fe ef c5 c3 99 d1 22 eb e0 0b 82 
38 b2 97 1f b0 dc 34
946693398.865222: WPA: 00:19:88:11:dc:3c WPA_PTK entering state 
PTKCALCNEGOTIATING2
946693398.865299: WPA: 00:19:88:11:dc:3c WPA_PTK entering state 
PTKINITNEGOTIATING
946693398.865571: wlan0: STA 00:19:88:11:dc:3c WPA: sending 3/4 msg of 
4-Way Handshake
946693398.865624: WPA: Send EAPOL(version=1 secure=1 mic=1 ack=1 
install=1 pairwise=8 kde_len=86 keyidx=1 encr=1)
946693398.865720: Plaintext EAPOL-Key Key Data - hexdump(len=86): 30 14 
01 00 00 0f ac 02 01 00 00 0f ac 02 01 00 00 0f ac 02 0c 00 dd 16 00 50 
f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02 dd 26 00 0f 
ac 01 01 00 a1 91 02 90 a8 af d6 7f e0 5a 5c 48 98 c2 b6 9b a3 82 a0 21 
21 0d 6e 55 82 af b4 29 03 ba 7d 42
946693398.869673: IEEE 802.1X: 00:19:88:11:dc:3c TX status - version=2 
type=3 length=181 - ack=1
946693398.873990: IEEE 802.1X: 99 bytes from 00:19:88:11:dc:3c
946693398.874071:    IEEE 802.1X: version=1 type=3 length=95
946693398.874200: wlan0: STA 00:19:88:11:dc:3c WPA: received EAPOL-Key 
frame (4/4 Pairwise)
946693398.874272: WPA: 00:19:88:11:dc:3c WPA_PTK entering state PTKINITDONE
946693398.874615: wlan0: STA 00:19:88:11:dc:3c IEEE 802.1X: authorizing port
946693398.874731: wlan0: STA 00:19:88:11:dc:3c RADIUS: starting 
accounting session 386D6441-0000000E
946693398.875052: wlan0: STA 00:19:88:11:dc:3c WPA: pairwise key 
handshake completed (RSN)
946693403.837124: unknown vendor specific information element ignored 
(vendor OUI 00:03:47 len=7)
946693403.837941: unknown vendor specific information element ignored 
(vendor OUI 00:03:47 len=7)
946693403.838111: STA 00:1b:77:a2:97:57 sent probe request for broadcast 
SSID
946693403.839947: MGMT (TX callback) ACK
946693403.840005: mgmt::proberesp cb
946693403.853153: unknown vendor specific information element ignored 
(vendor OUI 00:03:47 len=7)
946693403.853418: STA 00:1b:77:a2:97:57 sent probe request for broadcast 
SSID
946693403.855250: MGMT (TX callback) ACK
946693403.855298: mgmt::proberesp cb
946693407.749200: MGMT
946693407.749270: mgmt::deauth

------>I disconnect:
946693407.749313: deauthentication: STA=00:19:88:11:dc:3c reason_code=3
946693407.749473: wlan0: STA 00:19:88:11:dc:3c WPA: event 3 notification
946693407.749662: WPA: 00:19:88:11:dc:3c WPA_PTK entering state DISCONNECTED
946693407.749746: WPA: 00:19:88:11:dc:3c WPA_PTK entering state INITIALIZE


946693407.750033: wlan0: STA 00:19:88:11:dc:3c IEEE 802.1X: 
unauthorizing port
946693407.750137: wlan0: STA 00:19:88:11:dc:3c IEEE 802.11: deauthenticated
946693407.750269: wlan0: STA 00:19:88:11:dc:3c MLME: 
MLME-DEAUTHENTICATE.indication(00:19:88:11:dc:3c, 3)
946693407.750399: wlan0: STA 00:19:88:11:dc:3c MLME: 
MLME-DELETEKEYS.request(00:19:88:11:dc:3c)

-> new requests seem to be ignored:

946693414.373969: STA 00:19:88:11:dc:3c sent probe request for broadcast 
SSID
946693414.375804: MGMT (TX callback) ACK
946693414.375855: mgmt::proberesp cb
946693421.140081: STA 00:19:88:11:dc:3c sent probe request for broadcast 
SSID
946693421.141917: MGMT (TX callback) ACK
946693421.141968: mgmt::proberesp cb
946693421.256939: STA 00:19:88:11:dc:3c sent probe request for broadcast 
SSID
946693421.258780: MGMT (TX callback) ACK
946693421.258836: mgmt::proberesp cb
946693428.140399: STA 00:19:88:11:dc:3c sent probe request for broadcast 
SSID


sometimes it may happen, that in the moment of a authentification 
request from the client, I see in hostapds output:

946693476.290632: mgmt::proberesp cb
946693478.986731: unknown vendor specific information element ignored 
(vendor OUI 00:10:18 len=9)
946693478.993254: unknown vendor specific information element ignored 
(vendor OUI 00:10:18 len=9)
946693479.002524: unknown vendor specific information element ignored 
(vendor OUI 00:10:18 len=9)
946693479.009253: unknown vendor specific information element ignored 
(vendor OUI 00:10:18 len=9)
946693479.025043: unknown vendor specific information element ignored 
(vendor OUI 00:10:18 len=9)



Here is my host.conf:
ssid=->myssid...
wpa_psk=my key
channel=2
country_code=de
ieee80211d=1

interface=wlan0
bridge=br0
driver=nl80211
hw_mode=g
wpa=3
wpa_pairwise=TKIP
wpa_key_mgmt=WPA-PSK
wme_enabled=1


Any idea where I can start searching?


Best regards and thanks for helping

Michael

More information about the Hostap mailing list