Windows XP SP2 disconnecting with WPA-EAP

[Jason Carr]

Hello everybody!

I'm having some weird issues with WPA-EAP and Windows XP SP2 clients
disconnecting often.  I am not using wpa_supplicant on this machine,
however I've had the same issues with wpa_supplicant.  It seems like
that this laptop is getting unauthenticated because of an EAP
timeout.

I have compiled hostapd with #define EAPOL_VERSION 1 in ieee802_1x.h
which was a suggestion from a previous post to the mailing list.
That isn't helping at all.

So that brings us to the log.  The machine got the connectop dropped
around July 11, 20:39.  Sorry for the length, but I think it's 
required.

- Jason

Jul 11 21:32:03 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: updated TX/RX stats: Acct-Input-Octets=190662 Acct-Input-Gigawords=0 Acct-Output-Octets=1068178 Acct-Output-Gigawords=0
Jul 11 21:34:32 [hostapd] wlan0: WPA rekeying GTK
Jul 11 21:34:32 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/2 msg of Group Key Handshake
Jul 11 21:34:33 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: EAPOL-Key timeout
Jul 11 21:34:33 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/2 msg of Group Key Handshake
Jul 11 21:34:34 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: EAPOL-Key timeout
Jul 11 21:34:34 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/2 msg of Group Key Handshake
Jul 11 21:34:35 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: EAPOL-Key timeout
Jul 11 21:34:35 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/2 msg of Group Key Handshake
Jul 11 21:34:36 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: deauthenticated due to local deauth request
Jul 11 21:34:36 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: updated TX/RX stats: Acct-Input-Octets=221771 Acct-Input-Gigawords=0 Acct-Output-Octets=1076921 Acct-Output-Gigawords=0
Jul 11 21:34:36 [hostapd] wlan0: RADIUS Sending RADIUS message to accounting server
Jul 11 21:34:36 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:36 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: strict rekeying - force GTK rekey since STA is leaving
Jul 11 21:34:36 [hostapd] wlan0: RADIUS Received 20 bytes from RADIUS server
Jul 11 21:34:36 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:36 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:36 [hostapd] wlan0: WPA rekeying GTK
Jul 11 21:34:43 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: authentication OK (open system)
Jul 11 21:34:43 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: event 0 notification
Jul 11 21:34:43 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: authenticated
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: authentication OK (open system)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: event 0 notification
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: authenticated
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: association OK (aid 1)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.11: associated (aid 1, accounting session 42D2F964-00000009)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: event 1 notification
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: start authentication
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: start authentication
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: unauthorizing port
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: received EAP packet (code=2 id=0 len=28) from STA: EAP Response-Identity (1)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: STA identity 'jayne.wireless.intranet'
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to authentication server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 64 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: using EAP timeout of 30 seconds
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: decapsulated EAP packet (code=1 id=1 len=6) from RADIUS server: EAP-Request-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: received EAP packet (code=2 id=1 len=112) from STA: EAP Response-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to authentication server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 1100 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: using EAP timeout of 30 seconds
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: decapsulated EAP packet (code=1 id=2 len=1034) from RADIUS server: EAP-Request-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: received EAP packet (code=2 id=2 len=6) from STA: EAP Response-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to authentication server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 588 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: using EAP timeout of 30 seconds
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: decapsulated EAP packet (code=1 id=3 len=526) from RADIUS server: EAP-Request-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: received EAP packet (code=2 id=3 len=1020) from STA: EAP Response-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to authentication server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 111 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.01 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: using EAP timeout of 30 seconds
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: decapsulated EAP packet (code=1 id=4 len=53) from RADIUS server: EAP-Request-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: received EAP packet (code=2 id=4 len=6) from STA: EAP Response-TLS (13)
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to authentication server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 185 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: decapsulated EAP packet (code=3 id=4 len=4) from RADIUS server: EAP Success
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/4 msg of 4-Way Handshake
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: received EAPOL-Key frame (2/4 Pairwise)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 3/4 msg of 4-Way Handshake
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: received EAPOL-Key frame (4/4 Pairwise)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: pairwise key handshake completed (WPA)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: sending 1/2 msg of Group Key Handshake
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: authorizing port
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Sending RADIUS message to accounting server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Next RADIUS client retransmit in 3 seconds_
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f IEEE 802.1X: authenticated
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received 20 bytes from RADIUS server
Jul 11 21:34:44 [hostapd] wlan0: RADIUS Received RADIUS message
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f RADIUS: Received RADIUS packet matched with a pending request, round trip time 0.00 sec
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: received EAPOL-Key frame (2/2 Group)
Jul 11 21:34:44 [hostapd] wlan0: STA 00:12:f0:34:60:7f WPA: group key handshake completed (WPA)

-- 
Jason Carr (jason at flacid.org)