Authentication / Association Problem with 2.6.31

Michael Hirsch m.hirsch
Sun Oct 4 22:07:13 PDT 2009 

Hello all,

can anybody help? Maybe not enough or wrong info?

Best

Michael


Michael Hirsch wrote:
> 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
> 
> 
> 
> _______________________________________________
> HostAP mailing list
> HostAP at lists.shmoo.com
> http://lists.shmoo.com/mailman/listinfo/hostap
> 


-- 
Michael Hirsch
Managing Director

RAUMFELD GmbH | Reichenberger Strasse 124 | 10999 Berlin | Germany

T: +49 (0) 30  62 90 14 50
F: +49 (0) 30  62 90 14 49
M: +49 (0) 151 23 03 69 65
m.hirsch at raumfeld.com

More information about the Hostap mailing list