linksys WRT54GX2 replay counter bug?

Mon Sep 4 09:26:55 PDT 2006

Sorry if this is a duplicate, I've been having email problems.

>From: Jouni Malinen <jkmaline at cc.hut.fi>
>To: hostap at shmoo.com
>Subject: Re: linksys WRT54GX2 replay counter bug?
>Date: Sun, 3 Sep 2006 08:14:55 -0700
>
>On Sun, Sep 03, 2006 at 08:07:18AM -0700, Chuck T. wrote:
> > I'm having a problem with wpa_supplicant and a WRT54GX2 w/ the latest
> > firmware.  Sometimes it works, but most of the time the reply_counter of 
>"RX
> > message 1 of Group Key Handshake" is the same as that of the "RX message 
>3
> > of 4-Way Handshake".  As a result wpa_supplicant fails (correctly) with 
>a
> > "WPA: EAPOL-Key Replay Counter did not increase - dropping packet" 
>error.
>
>Could you please send a wpa_supplicant debug log showing this behavior?
>I would like to see the exact message sequence that is seen at the
>supplicant.

Sure.  I've modified the logging slightly to show the replay_key and add 
timestamps.  See below.

>
> > When it works the reply_counter advance by 1 between the 4-Way handshake
> > rather than the 2 that the spec appears to require.  I also have a 
>WRT54G
> > (non x2) which works correctly every time and does advance the 
>reply_counter
> > by 2.
>
>What is this comment about spec requiring replay counter jumping by
>based on? The counter needs to increment for each new EAPOL-Key frame,
>but I'm not aware of any requirement for it to increase by two.

I misread the spec.  It says "N+2", I was taking N to be the previous count 
were clearly it's the count at the start of the handshake sequence.  Sorry.

Here's the log:

Sep 2 19:08:27 Initializing interface 'eth0' conf 
'/mnt/ramfs/supplicant.cfg' driver 'linuxdrv'
Sep 2 19:08:27 Configuration file '/mnt/ramfs/supplicant.cfg' -> 
'/mnt/ramfs/supplicant.cfg'
Sep 2 19:08:27 Reading configuration file '/mnt/ramfs/supplicant.cfg'
Sep 2 19:08:27 ap_scan=1
Sep 2 19:08:27 ctrl_interface='/var/run/wpa_supplicant'
Sep 2 19:08:27 Line: 3 - start of a new network block
Sep 2 19:08:27 ssid - hexdump_ascii(len=6):
Sep 2 19:08:27      73 72 78 32 30 30                                 srx200
Sep 2 19:08:27 PSK - hexdump(len=32): [REMOVED]
Sep 2 19:08:27 Priority group 0
Sep 2 19:08:27    id=0 ssid='srx200'
Sep 2 19:08:27 Daemonize..
Sep 2 19:08:27 Initializing interface (2) 'eth0'
Sep 2 19:08:27 EAPOL: SUPP_PAE entering state DISCONNECTED
Sep 2 19:08:27 EAPOL: KEY_RX entering state NO_KEY_RECEIVE
Sep 2 19:08:27 EAPOL: SUPP_BE entering state INITIALIZE
Sep 2 19:08:27 EAP: EAP entering state DISABLED
Sep 2 19:08:27 EAPOL: External notification - portEnabled=0
Sep 2 19:08:27 EAPOL: External notification - portValid=0
Sep 2 19:08:27 Own MAC address: 00:80:3f:06:20:00
Sep 2 19:08:27 Setting scan request: 0 sec 100000 usec
Sep 2 19:08:27 Starting AP scan (broadcast SSID)
Sep 2 19:08:28 Wireless event: cmd=0x8b19 len=12
Sep 2 19:08:28 Scan results: 3
Sep 2 19:08:28 Selecting BSS from priority group 0
Sep 2 19:08:28 0: 00:16:b6:60:17:14 ssid='srx200' wpa_ie_len=24 rsn_ie_len=0
Sep 2 19:08:28    selected
Sep 2 19:08:28 Trying to associate with 00:16:b6:60:17:14 (SSID='srx200' 
freq=2412 MHz)
Sep 2 19:08:28 Cancelling scan request
Sep 2 19:08:28 Automatic auth_alg selection: 0x1
Sep 2 19:08:28 WPA: using IEEE 802.11i/D3.0
Sep 2 19:08:28 WPA: Selected cipher suites: group 8 pairwise 8 key_mgmt 2
Sep 2 19:08:28 WPA: using GTK TKIP
Sep 2 19:08:28 WPA: using PTK TKIP
Sep 2 19:08:28 WPA: using KEY_MGMT WPA-PSK
Sep 2 19:08:28 WPA: Own WPA IE - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 
50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Sep 2 19:08:28 No keys have been configured - skip key clearing
Sep 2 19:08:28 Setting authentication timeout: 5 sec 0 usec
Sep 2 19:08:28 EAPOL: External notification - EAP success=0
Sep 2 19:08:28 EAPOL: External notification - EAP fail=0
Sep 2 19:08:28 EAPOL: External notification - portControl=Auto
Sep 2 19:08:28 EAPOL: Port Timers tick - authWhile=0 heldWhile=0 startWhen=0 
idleWhile=0
Sep 2 19:08:28 Wireless event: cmd=0x8c02 len=34
Sep 2 19:08:28 Custom wireless event: 'EVENT-ASSOC.indication'
Sep 2 19:08:28 Association event - clear replay counter
Sep 2 19:08:28 Associated to a new BSS: BSSID=00:16:b6:60:17:14
Sep 2 19:08:28 No keys have been configured - skip key clearing
Sep 2 19:08:28 Associated with 00:16:b6:60:17:14
Sep 2 19:08:28 EAPOL: External notification - portEnabled=0
Sep 2 19:08:28 EAPOL: External notification - portValid=0
Sep 2 19:08:28 EAPOL: External notification - EAP success=0
Sep 2 19:08:28 EAPOL: External notification - portEnabled=1
Sep 2 19:08:28 EAPOL: SUPP_PAE entering state CONNECTING
Sep 2 19:08:28 EAPOL: txStart
Sep 2 19:08:28 WPA: drop TX EAPOL in non-IEEE 802.1X mode (type=1 len=0)
Sep 2 19:08:28 EAPOL: SUPP_BE entering state IDLE
Sep 2 19:08:28 EAP: EAP entering state INITIALIZE
Sep 2 19:08:28 EAP: EAP entering state IDLE
Sep 2 19:08:28 Setting authentication timeout: 10 sec 0 usec
Sep 2 19:08:29 RX EAPOL from 00:16:b6:60:17:14
Sep 2 19:08:29 RX EAPOL - hexdump(len=99): 01 03 00 5f fe 00 89 00 20 a0 96 
9b cc 00 00 00 01 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98 04 51 81
Sep 2 19:08:29  dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00
Sep 2 19:08:29 Setting authentication timeout: 10 sec 0 usec
Sep 2 19:08:29 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Sep 2 19:08:29 IEEE 802.1X RX: version=1 type=3 length=95
Sep 2 19:08:29   EAPOL-Key type=254
Sep 2 19:08:29 WPA: RX EAPOL-Key - hexdump(len=99): 01 03 00 5f fe 00 89 00 
20 a0 96 9b cc 00 00 00 01 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98
Sep 2 19:08:29  51 81 61 dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 00 00
Sep 2 19:08:29 WPA: RX message 1 of 4-Way Handshake from 00:16:b6:60:17:14 
(ver=1)
Sep 2 19:08:29 WPA: Renewed SNonce - hexdump(len=32): 73 eb 02 b3 cc 68 1c 
53 c9 c6 3d ea 4d 13 8a af 2f e2 52 ac d1 8b 55 88 6d a8 f3 a4 36
Sep 2 19:08:29  4b 59
Sep 2 19:08:29 WPA: PMK - hexdump(len=32): [REMOVED]
Sep 2 19:08:29 WPA: PTK - hexdump(len=64): [REMOVED]
Sep 2 19:08:29 WPA: EAPOL-Key MIC - hexdump(len=16): 30 bc e7 8f 3e db 84 26 
da eb 11 ed ed 64 22 4e
Sep 2 19:08:29 WPA: Sending EAPOL-Key 2/4
Sep 2 19:08:29 WPA: TX EAPOL-Key 2/4 - hexdump(len=137): 00 16 b6 60 17 14 
00 80 3f 06 20 00 88 8e 01 03 00 77 fe 01 09 00 20 a0 96 9b cc 00
Sep 2 19:08:29  00 01 73 eb 02 b3 cc 68 1c 53 c9 c6 3d ea 4d 13 8a af 2f e2 
52 ac d1 8b 55 88 6d a8 f3 a4 36 3d 4b 59 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 30 bc e7 8f 3e db 84 26 da eb 11 ed ed 64 22 4e 00 18 dd
Sep 2 19:08:29  00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00 00 50 
f2 02
Sep 2 19:08:29 RX EAPOL from 00:16:b6:60:17:14
Sep 2 19:08:29 RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 a0 96 
9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98 04 51 8
Sep 2 19:08:29  dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 cf f7 38 
00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00
Sep 2 19:08:29  50 f2 02
Sep 2 19:08:29 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Sep 2 19:08:29 IEEE 802.1X RX: version=1 type=3 length=119
Sep 2 19:08:29   EAPOL-Key type=254
Sep 2 19:08:29 WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 
20 a0 96 9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 9
Sep 2 19:08:29  51 81 61 dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 
cf f7 38 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2
Sep 2 19:08:29  01 00 00 50 f2 02
Sep 2 19:08:29 WPA: RX message 3 of 4-Way Handshake from 00:16:b6:60:17:14 
(ver=1)
Sep 2 19:08:29 WPA: IE KeyData - hexdump(len=24): dd 16 00 50 f2 01 01 00 00 
50 f2 02 01 00 00 50 f2 02 01 00 00 50 f2 02
Sep 2 19:08:29 WPA: Sending EAPOL-Key 4/4
Sep 2 19:08:29 WPA: TX EAPOL-Key 4/4 - hexdump(len=113): 00 16 b6 60 17 14 
00 80 3f 06 20 00 88 8e 01 03 00 5f fe 01 09 00 20 a0 96 9b cc 00
Sep 2 19:08:29  00 02 73 eb 02 b3 cc 68 1c 53 c9 c6 3d ea 4d 13 8a af 2f e2 
52 ac d1 8b 55 88 6d a8 f3 a4 36 3d 4b 59 00 00 00 00 00 00 00 00
Sep 2 19:08:29  00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 
00 00 00 63 64 3d 2f 39 1a aa 03 41 ca 07 a6 de 4c 94 f9 00 00
Sep 2 19:08:29 WPA: Installing PTK to the driver.
Sep 2 19:08:29 WPA: RSC - hexdump(len=6): 00 00 00 00 00 00
Sep 2 19:08:29 EAPOL: Port Timers tick - authWhile=0 heldWhile=0 
startWhen=29 idleWhile=59
Sep 2 19:08:30 RX EAPOL from 00:16:b6:60:17:14
Sep 2 19:08:30 RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 a0 96 
9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98 04 51 8
Sep 2 19:08:30  dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:30  00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 cf f7 38 
00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00
Sep 2 19:08:30  50 f2 02
Sep 2 19:08:30 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Sep 2 19:08:30 IEEE 802.1X RX: version=1 type=3 length=119
Sep 2 19:08:30   EAPOL-Key type=254
Sep 2 19:08:30 WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 
20 a0 96 9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 9
Sep 2 19:08:30  51 81 61 dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:30  00 00 00 00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 
cf f7 38 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2
Sep 2 19:08:30  01 00 00 50 f2 02
Sep 2 19:08:30 WPA: EAPOL-Key Replay Counter did not increase - dropping 
packet
Sep 2 19:08:30 key->replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 00 
02
Sep 2 19:08:30 wpa_s->rx_replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 
00 02
Sep 2 19:08:30 EAPOL: Port Timers tick - authWhile=0 heldWhile=0 
startWhen=28 idleWhile=58
Sep 2 19:08:31 RX EAPOL from 00:16:b6:60:17:14
Sep 2 19:08:31 RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 a0 96 
9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98 04 51 8
Sep 2 19:08:31  dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:31  00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 cf f7 38 
00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00
Sep 2 19:08:31  50 f2 02
Sep 2 19:08:31 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Sep 2 19:08:31 IEEE 802.1X RX: version=1 type=3 length=119
Sep 2 19:08:31   EAPOL-Key type=254
Sep 2 19:08:31 WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 
20 a0 96 9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 9
Sep 2 19:08:31  51 81 61 dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:31  00 00 00 00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 
cf f7 38 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2
Sep 2 19:08:31  01 00 00 50 f2 02
Sep 2 19:08:31 WPA: EAPOL-Key Replay Counter did not increase - dropping 
packet
Sep 2 19:08:31 key->replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 00 
02
Sep 2 19:08:31 wpa_s->rx_replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 
00 02
Sep 2 19:08:31 EAPOL: Port Timers tick - authWhile=0 heldWhile=0 
startWhen=27 idleWhile=57
Sep 2 19:08:32 RX EAPOL from 00:16:b6:60:17:14
Sep 2 19:08:32 RX EAPOL - hexdump(len=123): 01 03 00 77 fe 01 c9 00 20 a0 96 
9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 98 04 51 8
Sep 2 19:08:32  dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:32  00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 cf f7 38 
00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2 02 01 00
Sep 2 19:08:32  50 f2 02
Sep 2 19:08:32 EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
Sep 2 19:08:32 IEEE 802.1X RX: version=1 type=3 length=119
Sep 2 19:08:32   EAPOL-Key type=254
Sep 2 19:08:32 WPA: RX EAPOL-Key - hexdump(len=123): 01 03 00 77 fe 01 c9 00 
20 a0 96 9b cc 00 00 00 02 16 f8 22 9f b5 4f 2c 8a 69 9c 38 89 9
Sep 2 19:08:32  51 81 61 dc 36 70 13 93 7c e6 e3 14 73 d6 e1 fc 10 0e 00 00 
00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Sep 2 19:08:32  00 00 00 00 00 00 00 81 df 7b a8 b7 a0 3c ca be e8 39 f3 e4 
cf f7 38 00 18 dd 16 00 50 f2 01 01 00 00 50 f2 02 01 00 00 50 f2
Sep 2 19:08:32  01 00 00 50 f2 02
Sep 2 19:08:32 WPA: EAPOL-Key Replay Counter did not increase - dropping 
packet
Sep 2 19:08:32 key->replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 00 
02
Sep 2 19:08:32 wpa_s->rx_replay_counter: - hexdump(len=8): a0 96 9b cc 00 00 
00 02
Sep 2 19:08:32 EAPOL: Port Timers tick - authWhile=0 heldWhile=0 
startWhen=26 idleWhile=56
Sep 2 19:08:33 Wireless event: cmd=0x8c02 len=37
Sep 2 19:08:33 Custom wireless event: 'EVENT-DISASSOC.indication'
Sep 2 19:08:33 Setting scan request: 0 sec 100000 usec
Sep 2 19:08:33 Added BSSID 00:16:b6:60:17:14 into blacklist
Sep 2 19:08:33 EAPOL: External notification - portEnabled=0
Sep 2 19:08:33 EAPOL: SUPP_PAE entering state DISCONNECTED