Re: Strange problem with ath9k and ASUS N66U AP.

[Ben Greear <greearb@candelatech.com>]

[-- Attachment #1: Type: text/plain, Size: 5808 bytes --]

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 <greearb@candelatech.com>
Candela Technologies Inc  http://www.candelatech.com


[-- Attachment #2: sta10.pcap.gz --]
[-- Type: application/x-gzip, Size: 2707 bytes --]