I am trying some ath9k virtual clients against an ASUS N66U.
Kernel is 3.3.3+, but we've been seeing weird things since at
least 3.0 kernel with another Asus AP, but haven't looked at
the problem in detail on older kernels yet.
The issue seems to be that the ath9k side thinks all is well,
but the N66U shows it as not authenticated.
If anyone has any ideas on how to go about debugging
this, please let me know.
sta11 is :0C, and is not working properly
sta12 is :0D, and is working fine.
Here is part of the N66U wifi log showing that it
thinks sta11 is not authorized:
00:95:95:00:00:0C associated
00:95:95:00:00:0D associated authorized
Here's the supplicant logs:
[root@lanner-i7 wifi]# grep sta12 wpa_supplicant_log_wiphy0.txt
1335305195.312287: sta12: Failed to initiate AP scan
1335305195.313249: sta12: Failed to initiate AP scan
1335305196.317750: sta12: Failed to initiate AP scan
1335305197.318436: sta12: Failed to initiate AP scan
1335305198.320208: sta12: Failed to initiate AP scan
1335305198.860472: sta12: SME: Trying to authenticate with c8:60:00:e8:88:b0 (SSID='n66-2.4g' freq=2462 MHz)
1335305198.866465: sta12: Trying to associate with c8:60:00:e8:88:b0 (SSID='n66-2.4g' freq=2462 MHz)
1335305199.074988: sta12: Associated with c8:60:00:e8:88:b0
1335305199.185713: sta12: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP]
1335305199.185740: sta12: CTRL-EVENT-CONNECTED - Connection to c8:60:00:e8:88:b0 completed (auth) [id=0 id_str=]
[root@lanner-i7 wifi]# grep sta11 wpa_supplicant_log_wiphy0.txt
1335305195.289391: sta11: Failed to initiate AP scan
1335305195.290317: sta11: Failed to initiate AP scan
1335305196.297866: sta11: Failed to initiate AP scan
1335305197.298550: sta11: Failed to initiate AP scan
1335305198.298661: sta11: Failed to initiate AP scan
1335305198.860719: sta11: SME: Trying to authenticate with c8:60:00:e8:88:b0 (SSID='n66-2.4g' freq=2462 MHz)
1335305198.871241: sta11: Trying to associate with c8:60:00:e8:88:b0 (SSID='n66-2.4g' freq=2462 MHz)
1335305199.086967: sta11: Associated with c8:60:00:e8:88:b0
1335305199.191947: sta11: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP]
1335305199.191968: sta11: CTRL-EVENT-CONNECTED - Connection to c8:60:00:e8:88:b0 completed (auth) [id=0 id_str=]
1335305199.266207: sta11: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP]
Only thing I notice above is that the key negotiation completed after the connection completed,
and appears duplicated???
[root@lanner-i7 wifi]# iwconfig sta11
sta11 IEEE 802.11abgn ESSID:"n66-2.4g"
Mode:Managed Frequency:2.462 GHz Access Point: C8:60:00:E8:88:B0
Bit Rate:216.7 Mb/s Tx-Power=22 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Encryption key:off
Power Management:off
Link Quality=119/70
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:1 Invalid misc:2364 Missed beacon:0
[root@lanner-i7 wifi]# iwconfig sta12
sta12 IEEE 802.11abgn ESSID:"n66-2.4g"
Mode:Managed Frequency:2.462 GHz Access Point: C8:60:00:E8:88:B0
Bit Rate:1 Mb/s Tx-Power=22 dBm
Retry long limit:7 RTS thr:off Fragment thr:off
Encryption key:off
Power Management:off
Link Quality=10/70
Rx invalid nwid:0 Rx invalid crypt:0 Rx invalid frag:0
Tx excessive retries:0 Invalid misc:51 Missed beacon:0
[root@lanner-i7 wifi]# iw dev sta11 station dump
Station c8:60:00:e8:88:b0 (on sta11)
inactive time: 25 ms
rx bytes: 6160759
rx packets: 58821
tx bytes: 64751
tx packets: 194
tx retries: 357
tx failed: 1
signal: -20 dBm
signal avg: -21 dBm
tx bitrate: 216.7 MBit/s MCS 23 short GI
authorized: yes
authenticated: yes
preamble: long
WMM/WME: yes
MFP: no
TDLS peer: no
[root@lanner-i7 wifi]# iw dev sta12 station dump
Station c8:60:00:e8:88:b0 (on sta12)
inactive time: 12332 ms
rx bytes: 6182842
rx packets: 45350
tx bytes: 11089
tx packets: 81
tx retries: 139
tx failed: 0
signal: -23 dBm
signal avg: -22 dBm
tx bitrate: 1.0 MBit/s
authorized: yes
authenticated: yes
preamble: long
WMM/WME: yes
MFP: no
TDLS peer: no
[root@lanner-i7 wifi]#
Thanks,
Ben
--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com
On 04/25/2012 01:18 AM, Nicolas Cavallari wrote:
> On 25/04/2012 08:23, Ben Greear wrote:
>> On 04/24/2012 11:08 PM, Jouni Malinen wrote:
>>> Either the AP did not receive the first EAPOL-Key 4/4 or processed it
>>> only after retransmitting 3/4. Supplicant side will need to to reply to
>>> retransmitted 3/4 to complete the 4-way handshake. If the AP received
>>> either of these 4/4 messages, it should be fine with the result. If it
>>> didn't receive either, it should disconnect the station. It does not
>>> look like either of those happened.
>>
>> Ok, it seems strange they would have such a lame
>> bug, but maybe they never tried associating several stations at once.
>> (I see around 30% failure rate when using just 15 stations).
>>
>> We have several off-the-shelf APs and home-grown ones (using ath9k) that work fine,
>> even when associating 100+ stations, so at the least the N66U is weird...
>>
>> That said, I'll probably need to attempt a work-around for this. The only
>> obvious thing I see is the extra RX EAPOL (in all error cases I looked at, and none
>> where it associated properly), and the fact that DHCP just fails to acquire a lease.
>>
>> I'll try adding a hack to detect the duplicate RX EAPOL and bounce the connection
>> if that hits, and see if that helps any...
>>
>
> It could look like the old bug i had, where the station would send
> EAPOL-Key 4/4 encrypted when associating. Normally, the AP should
> disconnect the station, it would retry and hopefully succeed next time,
> and no one would have noticed anything, except this AP doesn't
> disconnect the station and it doesn't recover.
>
> Basically, wpa_supplicant sends the EAPOL-Key 4/4, then adds the PTK/GTK
> in the kernel, but due to scheduling/queuing/buffering of the EAPOL
> packet, it would be sent encrypted with the PTK ...
Maybe it sets the key after the first 4/4 response, and then the
key is already in place when the second 4/4 response is sent?
Should wpa_supplicant remove the key from the kernel before
sending the second 4/4 response?
> If when monitoring, you don't see any plaintext EAPOL-Key 4/4 coming
> from the failed stations, then it could be the same problem.
Maybe that is the case. I do not see an obvious plain-text response to the
second EAPOL 3/4 message, but there *is* a packet that goes out
in the right time-frame...maybe it's an encrypted 4/4 response packet?
I'm attaching a filtered capture
(full capture is here: http://www.candelatech.com/~greearb/misc/13-stas-n66.pcap.gz)
Here are the corresponding logs from supplicant:
1335371251.170525: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta10' added
1335371251.170547: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta10' added
1335371251.280369: sta10: RX EAPOL from c8:60:00:e8:88:b0
1335371251.280445: sta10: Setting authentication timeout: 10 sec 0 usec
1335371251.280458: sta10: IEEE 802.1X RX: version=2 type=3 length=117
1335371251.280463: sta10: EAPOL-Key type=2
1335371251.280469: sta10: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1335371251.280473: sta10: key_length=16 key_data_length=22
1335371251.280541: sta10: State: ASSOCIATED -> 4WAY_HANDSHAKE
1335371251.280547: sta10: WPA: RX message 1 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335371251.280571: sta10: RSN: no matching PMKID found
1335371251.281073: sta10: WPA: Sending EAPOL-Key 2/4
1335371252.803896: sta10: RX EAPOL from c8:60:00:e8:88:b0
1335371252.803975: sta10: IEEE 802.1X RX: version=2 type=3 length=175
1335371252.803983: sta10: EAPOL-Key type=2
1335371252.803989: sta10: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1335371252.803993: sta10: key_length=16 key_data_length=80
1335371252.804149: sta10: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1335371252.804155: sta10: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335371252.804186: sta10: WPA: Sending EAPOL-Key 4/4
1335371252.804253: sta10: WPA: Installing PTK to the driver
1335371252.804529: sta10: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1335371252.804547: sta10: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
1335371252.804626: sta10: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP secure=512 dbg=pairwise-gtk]
1335371252.804633: sta10: Cancelling authentication timeout
1335371252.804639: sta10: State: GROUP_HANDSHAKE -> COMPLETED
1335371252.804645: sta10: CTRL-EVENT-CONNECTED - Connection to c8:60:00:e8:88:b0 completed (auth) [id=0 id_str=]
1335371252.805696: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta10' added
1335371252.830295: sta10: RX EAPOL from c8:60:00:e8:88:b0
1335371252.830330: sta10: IEEE 802.1X RX: version=2 type=3 length=175
1335371252.830335: sta10: EAPOL-Key type=2
1335371252.830340: sta10: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1335371252.830344: sta10: key_length=16 key_data_length=80
1335371252.830445: sta10: State: COMPLETED -> 4WAY_HANDSHAKE
1335371252.830452: sta10: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335371252.830487: sta10: WPA: Sending EAPOL-Key 4/4
1335371252.830541: sta10: WPA: Installing PTK to the driver
1335371252.839240: sta10: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1335371252.839256: sta10: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
1335371252.847235: sta10: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP secure=512 dbg=pairwise-gtk]
1335371252.847250: sta10: Cancelling authentication timeout
1335371252.847259: sta10: State: GROUP_HANDSHAKE -> COMPLETED
1335371440.843881: sta10: BSS: Expire BSS 1 due to age
1335371440.843888: sta10: BSS: Remove id 1 BSSID c0:c1:c0:38:e1:cb SSID 'e3k-2g-1'
Thanks,
Ben
--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com
On 04/24/2012 03:50 PM, Ben Greear wrote:
> I am trying some ath9k virtual clients against an ASUS N66U.
>
> Kernel is 3.3.3+, but we've been seeing weird things since at
> least 3.0 kernel with another Asus AP, but haven't looked at
> the problem in detail on older kernels yet.
>
> The issue seems to be that the ath9k side thinks all is well,
> but the N66U shows it as not authenticated.
>
> If anyone has any ideas on how to go about debugging
> this, please let me know.
>
> sta11 is :0C, and is not working properly
> sta12 is :0D, and is working fine.
>
> Here is part of the N66U wifi log showing that it
> thinks sta11 is not authorized:
>
> 00:95:95:00:00:0C associated
> 00:95:95:00:00:0D associated authorized
Here's a better log. Makes me think supplicant might be at fault???
sta8 failed, sta9 works fine. The difference appears to be the extra
RX EAPOL packet that sta8 receives...
1335313181.632116: sta8: Event ASSOC (0) received
1335313181.632121: sta8: Association info event
1335313181.632151: sta8: freq=2462 MHz
1335313181.632155: sta8: State: ASSOCIATING -> ASSOCIATED
1335313181.632171: sta8: Associated to a new BSS: BSSID=c8:60:00:e8:88:b0
1335313181.632194: sta8: No keys have been configured - skip key clearing
1335313181.632199: sta8: Associated with c8:60:00:e8:88:b0
1335313181.632203: sta8: WPA: Association event - clear replay counter
1335313181.632207: sta8: WPA: Clear old PTK
1335313181.632313: sta8: Setting authentication timeout: 10 sec 0 usec
1335313181.632318: sta8: Cancelling scan request
1335313181.965215: sta8: RX EAPOL from c8:60:00:e8:88:b0
1335313181.965261: sta8: Setting authentication timeout: 10 sec 0 usec
1335313181.965276: sta8: IEEE 802.1X RX: version=2 type=3 length=117
1335313181.965286: sta8: EAPOL-Key type=2
1335313181.965294: sta8: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1335313181.965302: sta8: key_length=16 key_data_length=22
1335313181.965358: sta8: State: ASSOCIATED -> 4WAY_HANDSHAKE
1335313181.965364: sta8: WPA: RX message 1 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335313181.965386: sta8: RSN: no matching PMKID found
1335313181.965838: sta8: WPA: Sending EAPOL-Key 2/4
1335313181.999176: sta8: RX EAPOL from c8:60:00:e8:88:b0
1335313181.999235: sta8: IEEE 802.1X RX: version=2 type=3 length=175
1335313181.999241: sta8: EAPOL-Key type=2
1335313181.999248: sta8: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1335313181.999253: sta8: key_length=16 key_data_length=80
1335313181.999414: sta8: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1335313181.999422: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335313181.999465: sta8: WPA: Sending EAPOL-Key 4/4
1335313181.999526: sta8: WPA: Installing PTK to the driver
1335313181.999655: sta8: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1335313181.999671: sta8: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
1335313181.999745: sta8: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP secure=512 dbg=pairwise-gtk]
1335313181.999753: sta8: Cancelling authentication timeout
1335313181.999759: sta8: State: GROUP_HANDSHAKE -> COMPLETED
1335313181.999764: sta8: CTRL-EVENT-CONNECTED - Connection to c8:60:00:e8:88:b0 completed (auth) [id=0 id_str=]
1335313182.000884: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta8' added
1335313182.063407: sta8: RX EAPOL from c8:60:00:e8:88:b0
1335313182.063475: sta8: IEEE 802.1X RX: version=2 type=3 length=175
1335313182.063482: sta8: EAPOL-Key type=2
1335313182.063491: sta8: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1335313182.063497: sta8: key_length=16 key_data_length=80
1335313182.063685: sta8: State: COMPLETED -> 4WAY_HANDSHAKE
1335313182.063695: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335313182.063745: sta8: WPA: Sending EAPOL-Key 4/4
1335313182.063842: sta8: WPA: Installing PTK to the driver
1335313182.069303: sta8: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1335313182.069318: sta8: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
1335313182.082245: sta8: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP secure=512 dbg=pairwise-gtk]
1335313182.082261: sta8: Cancelling authentication timeout
1335313182.082270: sta8: State: GROUP_HANDSHAKE -> COMPLETED
1335313181.588919: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta9' added
1335313181.588949: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta9' added
1335313181.631797: sta9: Event ASSOC (0) received
1335313181.631802: sta9: Association info event
1335313181.631825: sta9: freq=2462 MHz
1335313181.631829: sta9: State: ASSOCIATING -> ASSOCIATED
1335313181.631845: sta9: Associated to a new BSS: BSSID=c8:60:00:e8:88:b0
1335313181.631868: sta9: No keys have been configured - skip key clearing
1335313181.631873: sta9: Associated with c8:60:00:e8:88:b0
1335313181.631877: sta9: WPA: Association event - clear replay counter
1335313181.631881: sta9: WPA: Clear old PTK
1335313181.631984: sta9: Setting authentication timeout: 10 sec 0 usec
1335313181.631990: sta9: Cancelling scan request
1335313181.963212: sta9: RX EAPOL from c8:60:00:e8:88:b0
1335313181.963250: sta9: Setting authentication timeout: 10 sec 0 usec
1335313181.963262: sta9: IEEE 802.1X RX: version=2 type=3 length=117
1335313181.963279: sta9: EAPOL-Key type=2
1335313181.963289: sta9: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
1335313181.963298: sta9: key_length=16 key_data_length=22
1335313181.963409: sta9: State: ASSOCIATED -> 4WAY_HANDSHAKE
1335313181.963420: sta9: WPA: RX message 1 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335313181.963457: sta9: RSN: no matching PMKID found
1335313181.964203: sta9: WPA: Sending EAPOL-Key 2/4
1335313181.997092: sta9: RX EAPOL from c8:60:00:e8:88:b0
1335313181.997141: sta9: IEEE 802.1X RX: version=2 type=3 length=175
1335313181.997148: sta9: EAPOL-Key type=2
1335313181.997156: sta9: key_info 0x13ca (ver=2 keyidx=0 rsvd=0 Pairwise Install Ack MIC Secure Encr)
1335313181.997162: sta9: key_length=16 key_data_length=80
1335313181.997343: sta9: State: 4WAY_HANDSHAKE -> 4WAY_HANDSHAKE
1335313181.997351: sta9: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
1335313181.997402: sta9: WPA: Sending EAPOL-Key 4/4
1335313181.997468: sta9: WPA: Installing PTK to the driver
1335313181.997584: sta9: State: 4WAY_HANDSHAKE -> GROUP_HANDSHAKE
1335313181.997599: sta9: WPA: Installing GTK to the driver (keyidx=1 tx=0 len=32)
1335313181.997688: sta9: WPA: Key negotiation completed with c8:60:00:e8:88:b0 [PTK=CCMP GTK=TKIP secure=512 dbg=pairwise-gtk]
1335313181.997697: sta9: Cancelling authentication timeout
1335313181.997705: sta9: State: GROUP_HANDSHAKE -> COMPLETED
1335313181.997713: sta9: CTRL-EVENT-CONNECTED - Connection to c8:60:00:e8:88:b0 completed (auth) [id=0 id_str=]
1335313181.998971: RTM_NEWLINK, IFLA_IFNAME: Interface 'sta9' added
--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com
On Tue, Apr 24, 2012 at 05:26:07PM -0700, Ben Greear wrote:
> On 04/24/2012 03:50 PM, Ben Greear wrote:
> > I am trying some ath9k virtual clients against an ASUS N66U.
> > Here is part of the N66U wifi log showing that it
> > thinks sta11 is not authorized:
> >
> > 00:95:95:00:00:0C associated
> > 00:95:95:00:00:0D associated authorized
> Here's a better log. Makes me think supplicant might be at fault???
Looks more like an AP bug to me..
> sta8 failed, sta9 works fine. The difference appears to be the extra
> RX EAPOL packet that sta8 receives...
> 1335313181.999422: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
> 1335313181.999465: sta8: WPA: Sending EAPOL-Key 4/4
> 1335313182.063695: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
> 1335313182.063745: sta8: WPA: Sending EAPOL-Key 4/4
Either the AP did not receive the first EAPOL-Key 4/4 or processed it
only after retransmitting 3/4. Supplicant side will need to to reply to
retransmitted 3/4 to complete the 4-way handshake. If the AP received
either of these 4/4 messages, it should be fine with the result. If it
didn't receive either, it should disconnect the station. It does not
look like either of those happened.
--
Jouni Malinen PGP id EFC895FA
On 04/24/2012 11:08 PM, Jouni Malinen wrote:
> On Tue, Apr 24, 2012 at 05:26:07PM -0700, Ben Greear wrote:
>> On 04/24/2012 03:50 PM, Ben Greear wrote:
>>> I am trying some ath9k virtual clients against an ASUS N66U.
>
>>> Here is part of the N66U wifi log showing that it
>>> thinks sta11 is not authorized:
>>>
>>> 00:95:95:00:00:0C associated
>>> 00:95:95:00:00:0D associated authorized
>
>> Here's a better log. Makes me think supplicant might be at fault???
>
> Looks more like an AP bug to me..
>
>> sta8 failed, sta9 works fine. The difference appears to be the extra
>> RX EAPOL packet that sta8 receives...
>
>> 1335313181.999422: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
>> 1335313181.999465: sta8: WPA: Sending EAPOL-Key 4/4
>
>> 1335313182.063695: sta8: WPA: RX message 3 of 4-Way Handshake from c8:60:00:e8:88:b0 (ver=2)
>> 1335313182.063745: sta8: WPA: Sending EAPOL-Key 4/4
>
> Either the AP did not receive the first EAPOL-Key 4/4 or processed it
> only after retransmitting 3/4. Supplicant side will need to to reply to
> retransmitted 3/4 to complete the 4-way handshake. If the AP received
> either of these 4/4 messages, it should be fine with the result. If it
> didn't receive either, it should disconnect the station. It does not
> look like either of those happened.
Ok, it seems strange they would have such a lame
bug, but maybe they never tried associating several stations at once.
(I see around 30% failure rate when using just 15 stations).
We have several off-the-shelf APs and home-grown ones (using ath9k) that work fine,
even when associating 100+ stations, so at the least the N66U is weird...
That said, I'll probably need to attempt a work-around for this. The only
obvious thing I see is the extra RX EAPOL (in all error cases I looked at, and none
where it associated properly), and the fact that DHCP just fails to acquire a lease.
I'll try adding a hack to detect the duplicate RX EAPOL and bounce the connection
if that hits, and see if that helps any...
Thanks,
Ben
--
Ben Greear <[email protected]>
Candela Technologies Inc http://www.candelatech.com
On 25/04/2012 08:23, Ben Greear wrote:
> On 04/24/2012 11:08 PM, Jouni Malinen wrote:
>> Either the AP did not receive the first EAPOL-Key 4/4 or processed it
>> only after retransmitting 3/4. Supplicant side will need to to reply to
>> retransmitted 3/4 to complete the 4-way handshake. If the AP received
>> either of these 4/4 messages, it should be fine with the result. If it
>> didn't receive either, it should disconnect the station. It does not
>> look like either of those happened.
>
> Ok, it seems strange they would have such a lame
> bug, but maybe they never tried associating several stations at once.
> (I see around 30% failure rate when using just 15 stations).
>
> We have several off-the-shelf APs and home-grown ones (using ath9k) that work fine,
> even when associating 100+ stations, so at the least the N66U is weird...
>
> That said, I'll probably need to attempt a work-around for this. The only
> obvious thing I see is the extra RX EAPOL (in all error cases I looked at, and none
> where it associated properly), and the fact that DHCP just fails to acquire a lease.
>
> I'll try adding a hack to detect the duplicate RX EAPOL and bounce the connection
> if that hits, and see if that helps any...
>
It could look like the old bug i had, where the station would send
EAPOL-Key 4/4 encrypted when associating. Normally, the AP should
disconnect the station, it would retry and hopefully succeed next time,
and no one would have noticed anything, except this AP doesn't
disconnect the station and it doesn't recover.
Basically, wpa_supplicant sends the EAPOL-Key 4/4, then adds the PTK/GTK
in the kernel, but due to scheduling/queuing/buffering of the EAPOL
packet, it would be sent encrypted with the PTK ...
If when monitoring, you don't see any plaintext EAPOL-Key 4/4 coming
from the failed stations, then it could be the same problem.