2012-10-18 07:49:29

by Cedric DEBARGE

[permalink] [raw]
Subject: TR: Clear data transit during WPA negociation in case of reassociation

Hi all,

I am not sure if this is the right place to post my question. Please forgive me if not.

I am experimenting roaming between two APs with wpa_supplicant (WPA2 + EAP-TLS).
When WPA_Supplicant come back from an AP for which it has already cached the key, I saw that during WPA2 4 Handshake (in case of reassociation), data are sent through wpa_supplicant unencrypted.

As soon as the WPA2 successfully ends its negotiation, the data are sent encrypted back.

I attached to this email a Wireshark capture of the wireless transaction. Before this capture the frames were correctly encrypted.
You can see the start of the WPA2 4 Handshake protocol at packet number 10.
During this 4 Handshake protocol you could see unencrypted iperf (UDP 5001) packets N?12/17/18/22/24.. until packet 55.
4 Handshake protocol ends at packet 49.

Can you give me some clue how to work it out ?

Compat-Wireless = 20120614 (OpenWRT package) Ath9k WPA_Supplicant = 20120428 (OpenWRT package)

Thank in advance.

Best regards,

Cedric DEBARGE



Attachments:
capture.pcap (38.90 kB)
capture.pcap

2012-10-25 14:48:13

by Johannes Berg

[permalink] [raw]
Subject: Re: TR: Clear data transit during WPA negociation in case of reassociation

Hi Cédric,


> PS : the attached file is not taken from the previous test but I get it in the same way.

Thanks. It looks like a supplicant problem, since we see this in the
log:

nl80211: Associate (ifindex=5)
* bssid=90:a4:de:aa:42:94
* freq=5660
* SSID - hexdump_ascii(len=6):
63 64 74 65 73 74 cdtest
...
* pairwise=0xfac04
* group=0xfac04
* prev_bssid=00:1b:b1:58:f6:dd

...

FT: Stored MDIE and FTIE from (Re)Association Response - hexdump(len=0):
Operating frequency changed from 5680 to 5660 MHz
nl80211: Associated on 5660 MHz
nl80211: Associated with 90:a4:de:aa:42:94

...

wlan0: Associated to a new BSS: BSSID=90:a4:de:aa:42:94

...

wlan0: WPA: Association event - clear replay counter
wlan0: WPA: Clear old PTK
...
wlan0: RX EAPOL from 90:a4:de:aa:42:94 to 90:a4:de:21:4f:53 (bridge)
wlan0: RX EAPOL from 90:a4:de:aa:42:94
...
wlan0: Setting authentication timeout: 70 sec 0 usec
EAPOL: Ignoring WPA EAPOL-Key frame in EAPOL state machines
wlan0: IEEE 802.1X RX: version=2 type=3 length=117
wlan0: EAPOL-Key type=2
wlan0: key_info 0x8a (ver=2 keyidx=0 rsvd=0 Pairwise Ack)
wlan0: key_length=16 key_data_length=22
replay_counter - hexdump(len=8): 00 00 00 00 00 00 00 01
key_nonce - hexdump(len=32): dd 19 32 48 51 93 fb 35 a5 24 94 dc 28 0c ab 09 c9 a1 4d fd 3d f9 4c 95 13 8b 0a 76 fb 1a 07 d6
key_iv - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
key_rsc - hexdump(len=8): 00 00 00 00 00 00 00 00
key_id (reserved) - hexdump(len=8): 00 00 00 00 00 00 00 00
key_mic - hexdump(len=16): 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
WPA: RX EAPOL-Key - hexdump(len=121): 02 03 00 75 02 00 8a 00 10 00 00 00 00 00 00 00 01 dd 19 32 48 51 93 fb 35 a5 24 94 dc 28 0c ab 09 c9 a1 4d fd 3d f9 4c 95 13 8b 0a 76 fb 1a 07 d6 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 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 16 dd 14 00 0f ac 04 11 1c 5b ea 4c 1f 0d 2d da d6 00 51 a8 fe 6b 3f
wlan0: State: ASSOCIATED -> 4WAY_HANDSHAKE
wlan0: WPA: RX message 1 of 4-Way Handshake from 90:a4:de:aa:42:94 (ver=2)
RSN: msg 1/4 key data - hexdump(len=22): dd 14 00 0f ac 04 11 1c 5b ea 4c 1f 0d 2d da d6 00 51 a8 fe 6b 3f
WPA: PMKID in EAPOL-Key - hexdump(len=22): dd 14 00 0f ac 04 11 1c 5b ea 4c 1f 0d 2d da d6 00 51 a8 fe 6b 3f
RSN: PMKID from Authenticator - hexdump(len=16): 11 1c 5b ea 4c 1f 0d 2d da d6 00 51 a8 fe 6b 3f
RSN: matched PMKID - hexdump(len=16): 11 1c 5b ea 4c 1f 0d 2d da d6 00 51 a8 fe 6b 3f
RSN: PMK from PMKSA cache - hexdump(len=32): [REMOVED]
EAPOL: PMKSA caching was used - skip EAPOL
EAPOL: Supplicant port status: Authorized

Here it's already setting authorized, which seems wrong.

Jouni and I just talked about it and he'll have a patch for you to test,
I think.

johannes


2012-10-25 14:01:45

by Cedric DEBARGE

[permalink] [raw]
Subject: RE: TR: Clear data transit during WPA negociation in case of reassociation

Hi,

Thanks for answering.

Please find attached the wpa_supplicant log file (it is quite big because of the EAP-TLS) you asked for.

Here are some explanations :
AP1 : BSSID = 00:1B:B1:58:F6:DD, channel 136, 802.11a
AP2 : BSSID = 90:A4:DE:AA:42:94, channel 132, 802.11a

I simply ask the client to roam using the wpa_cli roam command.
The first roam on each AP is ok (line 167 & line 641) but when the client comes back to the first one (line 1116), I can see unencrypted frames as I've described in the previous email.
Next roams (line 1505 & line 1712) have the same problem.

PS : the attached file is not taken from the previous test but I get it in the same way.

Regards,

Cédric DEBARGE

-----Message d'origine-----
De : Johannes Berg [mailto:[email protected]]
Envoyé : mardi 23 octobre 2012 14:44
À : Cedric Debarge
Cc : [email protected]
Objet : Re: TR: Clear data transit during WPA negociation in case of reassociation

On Thu, 2012-10-18 at 09:30 +0200, Cedric Debarge wrote:
> Hi all,
>
> I am not sure if this is the right place to post my question. Please forgive me if not.
>
> I am experimenting roaming between two APs with wpa_supplicant (WPA2 + EAP-TLS).
> When WPA_Supplicant come back from an AP for which it has already cached the key, I saw that during WPA2 4 Handshake (in case of reassociation), data are sent through wpa_supplicant unencrypted.
>
> As soon as the WPA2 successfully ends its negotiation, the data are sent encrypted back.
>
> I attached to this email a Wireshark capture of the wireless transaction. Before this capture the frames were correctly encrypted.
> You can see the start of the WPA2 4 Handshake protocol at packet number 10.
> During this 4 Handshake protocol you could see unencrypted iperf (UDP 5001) packets N°12/17/18/22/24.. until packet 55.
> 4 Handshake protocol ends at packet 49.
>
> Can you give me some clue how to work it out ?

Can you show the wpa_supplicant debug log for this?

johannes


Attachments:
dump.txt (151.14 kB)

2012-10-23 12:43:25

by Johannes Berg

[permalink] [raw]
Subject: Re: TR: Clear data transit during WPA negociation in case of reassociation

On Thu, 2012-10-18 at 09:30 +0200, Cedric Debarge wrote:
> Hi all,
>
> I am not sure if this is the right place to post my question. Please forgive me if not.
>
> I am experimenting roaming between two APs with wpa_supplicant (WPA2 + EAP-TLS).
> When WPA_Supplicant come back from an AP for which it has already cached the key, I saw that during WPA2 4 Handshake (in case of reassociation), data are sent through wpa_supplicant unencrypted.
>
> As soon as the WPA2 successfully ends its negotiation, the data are sent encrypted back.
>
> I attached to this email a Wireshark capture of the wireless transaction. Before this capture the frames were correctly encrypted.
> You can see the start of the WPA2 4 Handshake protocol at packet number 10.
> During this 4 Handshake protocol you could see unencrypted iperf (UDP 5001) packets N°12/17/18/22/24.. until packet 55.
> 4 Handshake protocol ends at packet 49.
>
> Can you give me some clue how to work it out ?

Can you show the wpa_supplicant debug log for this?

johannes


2012-10-25 14:51:19

by Jouni Malinen

[permalink] [raw]
Subject: Re: TR: Clear data transit during WPA negociation in case of reassociation

On Thu, Oct 25, 2012 at 03:42:56PM +0200, Cédric Debarge - ACKSYS wrote:
> Please find attached the wpa_supplicant log file (it is quite big because of the EAP-TLS) you asked for.

Could you please test this with the following change in wpa_supplicant?


diff --git a/src/eapol_supp/eapol_supp_sm.c b/src/eapol_supp/eapol_supp_sm.c
index 851cf49..f90fb62 100644
--- a/src/eapol_supp/eapol_supp_sm.c
+++ b/src/eapol_supp/eapol_supp_sm.c
@@ -1469,10 +1469,7 @@ void eapol_sm_notify_cached(struct eapol_sm *sm)
if (sm == NULL)
return;
wpa_printf(MSG_DEBUG, "EAPOL: PMKSA caching was used - skip EAPOL");
- sm->SUPP_PAE_state = SUPP_PAE_AUTHENTICATED;
- sm->suppPortStatus = Authorized;
- eapol_sm_set_port_authorized(sm);
- sm->portValid = TRUE;
+ sm->eapSuccess = TRUE;
eap_notify_success(sm->eap);
eapol_sm_step(sm);
}


--
Jouni Malinen PGP id EFC895FA

2012-10-26 09:10:37

by Cedric DEBARGE

[permalink] [raw]
Subject: RE: TR: Clear data transit during WPA negociation in case of reassociation

Hi,

Your patch corrects the problem !!
No unencrypted frame observed anymore.

Thank you very much (and Johannes too).

Regards,

Cédric DEBARGE

-----Message d'origine-----
De : Jouni Malinen [mailto:[email protected]]
Envoyé : jeudi 25 octobre 2012 16:51
À : Cédric Debarge - ACKSYS
Cc : 'Johannes Berg'; [email protected]
Objet : Re: TR: Clear data transit during WPA negociation in case of reassociation

On Thu, Oct 25, 2012 at 03:42:56PM +0200, Cédric Debarge - ACKSYS wrote:
> Please find attached the wpa_supplicant log file (it is quite big because of the EAP-TLS) you asked for.

Could you please test this with the following change in wpa_supplicant?


diff --git a/src/eapol_supp/eapol_supp_sm.c b/src/eapol_supp/eapol_supp_sm.c index 851cf49..f90fb62 100644
--- a/src/eapol_supp/eapol_supp_sm.c
+++ b/src/eapol_supp/eapol_supp_sm.c
@@ -1469,10 +1469,7 @@ void eapol_sm_notify_cached(struct eapol_sm *sm)
if (sm == NULL)
return;
wpa_printf(MSG_DEBUG, "EAPOL: PMKSA caching was used - skip EAPOL");
- sm->SUPP_PAE_state = SUPP_PAE_AUTHENTICATED;
- sm->suppPortStatus = Authorized;
- eapol_sm_set_port_authorized(sm);
- sm->portValid = TRUE;
+ sm->eapSuccess = TRUE;
eap_notify_success(sm->eap);
eapol_sm_step(sm);
}


--
Jouni Malinen PGP id EFC895FA