Group key renewal problem

[Henrik Brix Andersen]

On Sat, Mar 11, 2006 at 09:49:40PM +0100, Henrik Brix Andersen wrote:
> After the rekeying and disconnection of the client, the below messages
> appear in the AP system log:
> 
> Mar 11 21:44:15 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: deauthenticated due to local deauth request
> Mar 11 21:44:20 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: authenticated
> Mar 11 21:44:20 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: associated (aid 1, accounting session 441334F8-00000007)
> Mar 11 21:44:20 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: pairwise key handshake completed (RSN)
> 
> Where 00:0e:35:fd:81:94 is the MAC address of the client. As you can
> see, the client is reauthenticated 5 seconds after the group key
> renewal kicked it off the AP.

I had forgotten to enable debug output to the system log, here are the
messages with logger_syslog=-1 and logger_syslog_level=1:

Mar 12 12:33:18 osgiliath hostapd: wlan0: WPA rekeying GTK
Mar 12 12:33:18 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 1/2 msg of Group Key Handshake
Mar 12 12:33:19 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: EAPOL-Key timeout
Mar 12 12:33:19 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 1/2 msg of Group Key Handshake
Mar 12 12:33:20 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: EAPOL-Key timeout
Mar 12 12:33:20 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 1/2 msg of Group Key Handshake
Mar 12 12:33:21 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: EAPOL-Key timeout
Mar 12 12:33:21 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 1/2 msg of Group Key Handshake
Mar 12 12:33:21 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.1X: unauthorizing port
Mar 12 12:33:21 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: deauthenticated due to local deauth request
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: authentication OK (open system)
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: authenticated
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: association OK (aid 1)
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.11: associated (aid 1, accounting session 441406C2-00000002)
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: event 1 notification
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: start authentication
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.1X: unauthorizing port
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 1/4 msg of 4-Way Handshake
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: received EAPOL-Key frame (2/4 Pairwise)
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: sending 3/4 msg of 4-Way Handshake
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: received EAPOL-Key frame (4/4 Pairwise)
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 IEEE 802.1X: authorizing port
Mar 12 12:34:26 osgiliath hostapd: wlan0: STA 00:0e:35:fd:81:94 WPA: pairwise key handshake completed (RSN)

The first four "WPA: sending 1/2 msg of Group Key Handshake" are the
ones causing the "CCMP: received packet without ExtIV flag from
00:02:6f:37:fc:68" messages on the client.

Would you like me to open a bug report about this?

Regards,
Brix
-- 
Henrik Brix Andersen <brix at gentoo.org>
Gentoo Metadistribution | Mobile computing herd
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 213 bytes
Desc: not available
Url : http://lists.shmoo.com/pipermail/hostap/attachments/20060312/20047ae5/attachment.pgp