All of lore.kernel.org
 help / color / mirror / Atom feed
* Strange problem with ath9k and ASUS N66U AP.
@ 2012-04-24 22:50 Ben Greear
  2012-04-25  0:26 ` Ben Greear
  0 siblings, 1 reply; 6+ messages in thread
From: Ben Greear @ 2012-04-24 22:50 UTC (permalink / raw)
  To: linux-wireless, hostap

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


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Strange problem with ath9k and ASUS N66U AP.
  2012-04-24 22:50 Strange problem with ath9k and ASUS N66U AP Ben Greear
@ 2012-04-25  0:26 ` Ben Greear
  2012-04-25  6:08   ` Jouni Malinen
  0 siblings, 1 reply; 6+ messages in thread
From: Ben Greear @ 2012-04-25  0:26 UTC (permalink / raw)
  To: linux-wireless, hostap

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


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Strange problem with ath9k and ASUS N66U AP.
  2012-04-25  0:26 ` Ben Greear
@ 2012-04-25  6:08   ` Jouni Malinen
  2012-04-25  6:23     ` Ben Greear
  0 siblings, 1 reply; 6+ messages in thread
From: Jouni Malinen @ 2012-04-25  6:08 UTC (permalink / raw)
  To: Ben Greear; +Cc: linux-wireless, hostap

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

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Strange problem with ath9k and ASUS N66U AP.
  2012-04-25  6:08   ` Jouni Malinen
@ 2012-04-25  6:23     ` Ben Greear
  2012-04-25  8:18       ` Nicolas Cavallari
  0 siblings, 1 reply; 6+ messages in thread
From: Ben Greear @ 2012-04-25  6:23 UTC (permalink / raw)
  To: linux-wireless, hostap

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

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Strange problem with ath9k and ASUS N66U AP.
  2012-04-25  6:23     ` Ben Greear
@ 2012-04-25  8:18       ` Nicolas Cavallari
  2012-04-25 17:21         ` Ben Greear
  0 siblings, 1 reply; 6+ messages in thread
From: Nicolas Cavallari @ 2012-04-25  8:18 UTC (permalink / raw)
  To: linux-wireless, hostap

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.

^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Strange problem with ath9k and ASUS N66U AP.
  2012-04-25  8:18       ` Nicolas Cavallari
@ 2012-04-25 17:21         ` Ben Greear
  0 siblings, 0 replies; 6+ messages in thread
From: Ben Greear @ 2012-04-25 17:21 UTC (permalink / raw)
  To: Nicolas Cavallari; +Cc: linux-wireless, hostap

[-- 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 --]

^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2012-04-25 17:21 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-04-24 22:50 Strange problem with ath9k and ASUS N66U AP Ben Greear
2012-04-25  0:26 ` Ben Greear
2012-04-25  6:08   ` Jouni Malinen
2012-04-25  6:23     ` Ben Greear
2012-04-25  8:18       ` Nicolas Cavallari
2012-04-25 17:21         ` Ben Greear

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.