What does this logentry mean: received EAPOL-Key 2/2 Group with unexpected replay counter

[Paul Geraedts]

>On Sun, May 01, 2011 at 05:31:59PM +0200, Klaus M?ller wrote:
>> I'm using hostapd and WPA2 / TLS and get lot of these messages:
>> 
>> 10:29:59 hostapd: wlan0: STA 33:33:33:33:33:33 WPA: group key 
>> handshake completed (RSN)
>> 10:29:59 hostapd: wlan0: STA 33:33:33:33:33:33 WPA: received 
>> EAPOL-Key 2/2 Group with unexpected replay counter
>
>It indicates that an unexpected EAPOL-Key frame was seen in group key
>handshake and was ignored by hostapd.
>
>> What does this mean? Did I do something wrong? Is there a fix for 
>> this or is it just normal?
>
>This is most likely caused by hostapd having retried sending of the
>EAPOL-Key message 1/2 and then receiving replies to both attempts of
>that message and then ignoring the second response. This is most likely
>normal behavior and should not cause problems. There have been some
>changes recently to avoid similar issues by using a longer timeout for
>EAPOL-Key frames. If you are seeing real issues (e.g., connection
>failing), you could try the current snapshot of the development branch
>(0.8.x) which includes those changes.
>
>-- 
>Jouni Malinen                                           PGP id EFC895FA


Interesting to read your explanation; I accidentally spotted it while
browsing the mailing list archive.

I have also seen various 'unexpected replay counter' entries in my
OpenWrt logs recently, both concerning the 4-way handshake and the group
rekeying. Interestingly, I got a huge amount of them when my MSI Wind
U100 netbook was on battery power. I guess the netbook goes into some
sort of power saving mode in which the EAPOL timeouts get too small; I
tested with both the original Realtek RTL8187SE card and a replacement
Atheros AR9287 card and the same thing happens for both. The OpenWrt
version I use contains hostapd v0.8.x of 27-05-2011, so I guess it
includes the changes that you mentioned.

A recent patch [1] got rid of the GTK-related 'unexpected replay
counter' entries in my log. The patch accomplish this by increasing the
first 100ms GTK timeout to 1s, just like the later 3 timeouts. This
patch actually triggered me to see what is going on. Some testing
brought me to the next conclusion.

During every 'transaction' of the 4-way handshake (2x) and group
rekeying (1x), hostapd tries (at most) 4 times to receive a reply,
whereupon it accepts whichever reply that comes in first, *but does not
discard the other 3*. As a result, these later replies are processed as
well and typically result in 'unexpected replay counter' log entries.
Apart of that, the timeout of the first of every 4 tries is pretty
tight: only 100ms (possibly for standard compliance?); during my testing
I found that under normal conditions it can take a station upto
200-300ms to reply.

Personally, I think the later 3 replies should not be processed
whatsoever. In that way the 'unexpected replay counter' log entries will
only pop up when something is really wrong. I feel that this is the most
important thing. Apart of that, I think increasing the first timeouts
from 100ms to say 200ms would result in faster (re)connects (especially
interesting in WDS handover situations).

Strictly speaking, the 'unexpected replay counter' log entries are not
correct: the replay counter in the key is not unexpected (hostapd just
asked for this specific key a moment ago). Apart of that, I think it is
a good thing to exclusively use these log entries for warnings; they are
probably meant to warn for replay attacks I guess. Lastly, these log
entries currently make up a significant part of my log, which makes it
hard to go back a day or so (read: I like clean logs :).

I'm interested in your opinion on the matter.

Best regards,

Paul Geraedts


[1] https://dev.openwrt.org/changeset/27822