Re: Wifi-Event for when initial 4-way completes?

[Wojciech Dubowik]

Hello Ben,

Yes, you are right. There is a case when wpa supplicant is in connected 
state


but the last EAPOL to AP was lost. Client won't be able to communicate 
and AP will


deauthenticate after a while or not. It's easily reproducible with a 
frame corrupter


patch I have sent some time ago. The worst case is when last EAPOL is 
lost and


deauthentication frame from AP as well. It can leave client in dead 
state for


minutes.


I have been debugging such case reported by our customers and it turns out

that supplicant is using L2 send for EAPOL messages without any feedback 
from


mac80211 layer. It means that client has no idea whether these frames have

been acked or not. AP (in mac80211) is using nl command and gets the 
status of the ack


although it's not the last message in the chain.

I have made a patch to send EAPOL on the station with same command as AP

and check for this case i.e. deauthenticate immediately when client is in

connected state but last EAPOL hasn't been acked.

I will try to send it upstream as soon as it's cleaned up a bit.

Br,

Wojtek


On 08/06/17 17:41, Ben Greear wrote:

On 06/08/2017 08:21 AM, Ben Greear wrote:

On 06/07/2017 12:25 AM, Wojciech Dubowik wrote:

Hello Ben,

I have been using this part of wpa_supplicant to notify that 4-Way 
handshake is completed.


around line 868 in wpa_supplicant.c

#if defined(CONFIG_CTRL_IFACE) || !defined(CONFIG_NO_STDOUT_DEBUG)
wpa_msg(wpa_s, MSG_INFO, WPA_EVENT_CONNECTED "- 
Connection to "

MACSTR " completed [id=%d id_str=%s%s]",
MAC2STR(wpa_s->bssid),
ssid ? ssid->id : -1,
ssid && ssid->id_str ? ssid->id_str : "",
fils_hlp_sent ? " FILS_HLP_SENT" : "");
#endif /* CONFIG_CTRL_IFACE || !CONFIG_NO_STDOUT_DEBUG */

You can pack whatever notification message inside the if statement.


I'm not sure that actually is correct?  For instance, I see this in a 
case where

WPA-2 was not succesfully negotiated (note the reason-2 disconnect)

IFNAME=sta9 <3>SME: Trying to authenticate with 00:0e:8e:f8:73:96 
(SSID='ota-9k-2 space' freq=5180 MHz)
IFNAME=sta9 <3>Trying to associate with 00:0e:8e:f8:73:96 
(SSID='ota-9k-2 space' freq=5180 MHz)

IFNAME=sta9 <3>Associated with 00:0e:8e:f8:73:96
IFNAME=sta9 <3>CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 
[PTK=CCMP GTK=CCMP]
IFNAME=sta9 <3>CTRL-EVENT-CONNECTED - Connection to 00:0e:8e:f8:73:96 
completed [id=0 id_str=]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 
[PTK=CCMP GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 
[PTK=CCMP GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 
[PTK=CCMP GTK=CCMP]

IFNAME=sta9 <3>CTRL-EVENT-DISCONNECTED bssid=00:0e:8e:f8:73:96 reason=2


Looks like I might need to add another message about EAPOL 4-way 
completing?


Based on a sniff, it seems that the 3/4 was sent in this case, but the 
4/4 was not
received from the AP.  Maybe the 3/4 is (re)sent incorrectly 
sometimesI have run into similar

bugs in the past.

Thanks,
Ben

Re: Wifi-Event for when initial 4-way completes?

[Ben Greear]

On 06/08/2017 08:21 AM, Ben Greear wrote:

On 06/07/2017 12:25 AM, Wojciech Dubowik wrote:

Hello Ben,

I have been using this part of wpa_supplicant to notify that 4-Way handshake is 
completed.

around line 868 in wpa_supplicant.c

#if defined(CONFIG_CTRL_IFACE) || !defined(CONFIG_NO_STDOUT_DEBUG)
wpa_msg(wpa_s, MSG_INFO, WPA_EVENT_CONNECTED "- Connection to "
MACSTR " completed [id=%d id_str=%s%s]",
MAC2STR(wpa_s->bssid),
ssid ? ssid->id : -1,
ssid && ssid->id_str ? ssid->id_str : "",
fils_hlp_sent ? " FILS_HLP_SENT" : "");
#endif /* CONFIG_CTRL_IFACE || !CONFIG_NO_STDOUT_DEBUG */

You can pack whatever notification message inside the if statement.


I'm not sure that actually is correct?  For instance, I see this in a case where
WPA-2 was not succesfully negotiated (note the reason-2 disconnect)

IFNAME=sta9 <3>SME: Trying to authenticate with 00:0e:8e:f8:73:96 
(SSID='ota-9k-2 space' freq=5180 MHz)
IFNAME=sta9 <3>Trying to associate with 00:0e:8e:f8:73:96 (SSID='ota-9k-2 
space' freq=5180 MHz)
IFNAME=sta9 <3>Associated with 00:0e:8e:f8:73:96
IFNAME=sta9 <3>CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>CTRL-EVENT-CONNECTED - Connection to 00:0e:8e:f8:73:96 completed 
[id=0 id_str=]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>CTRL-EVENT-DISCONNECTED bssid=00:0e:8e:f8:73:96 reason=2


Looks like I might need to add another message about EAPOL 4-way completing?


Based on a sniff, it seems that the 3/4 was sent in this case, but the 4/4 was 
not
received from the AP.  Maybe the 3/4 is (re)sent incorrectly sometimesI 
have run into similar
bugs in the past.

Thanks,
Ben


--
Ben Greear 
Candela Technologies Inc  http://www.candelatech.com

Re: Wifi-Event for when initial 4-way completes?

[Ben Greear]

On 06/07/2017 12:25 AM, Wojciech Dubowik wrote:

Hello Ben,

I have been using this part of wpa_supplicant to notify that 4-Way handshake is 
completed.

around line 868 in wpa_supplicant.c

#if defined(CONFIG_CTRL_IFACE) || !defined(CONFIG_NO_STDOUT_DEBUG)
wpa_msg(wpa_s, MSG_INFO, WPA_EVENT_CONNECTED "- Connection to "
MACSTR " completed [id=%d id_str=%s%s]",
MAC2STR(wpa_s->bssid),
ssid ? ssid->id : -1,
ssid && ssid->id_str ? ssid->id_str : "",
fils_hlp_sent ? " FILS_HLP_SENT" : "");
#endif /* CONFIG_CTRL_IFACE || !CONFIG_NO_STDOUT_DEBUG */

You can pack whatever notification message inside the if statement.


I'm not sure that actually is correct?  For instance, I see this in a case where
WPA-2 was not succesfully negotiated (note the reason-2 disconnect)

IFNAME=sta9 <3>SME: Trying to authenticate with 00:0e:8e:f8:73:96 
(SSID='ota-9k-2 space' freq=5180 MHz)
IFNAME=sta9 <3>Trying to associate with 00:0e:8e:f8:73:96 (SSID='ota-9k-2 
space' freq=5180 MHz)
IFNAME=sta9 <3>Associated with 00:0e:8e:f8:73:96
IFNAME=sta9 <3>CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>CTRL-EVENT-CONNECTED - Connection to 00:0e:8e:f8:73:96 completed 
[id=0 id_str=]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>WPA: Key negotiation completed with 00:0e:8e:f8:73:96 [PTK=CCMP 
GTK=CCMP]
IFNAME=sta9 <3>CTRL-EVENT-DISCONNECTED bssid=00:0e:8e:f8:73:96 reason=2


Looks like I might need to add another message about EAPOL 4-way completing?

Thanks,
Ben




Br,

Wojtek


On 07/06/17 02:46, Ben Greear wrote:

I have been tracking down a nasty EAPOL related bug in ath10k, and found 
something that may be peripheral, or maybe
it is significant.

My logic is basically to kick supplicant, watch 'iw events', and then when I 
see something
like "sta62 (phy #5): connected to 00:0e:8e:f8:73:96", I consider it connected 
and start
dhcpd.

But, it appears that the 'connected' message comes out before the EAPOL 4-way 
completes, so
I am starting dhclient before the encryption is really set up properly.  At 
best, this slows
things down and makes dhclient have to retry.

Is there some existing event or state I can probe to determine when the initial 
4-way is complete?

In case there is not, maybe that event would be worth adding?

Or, should I hack on supplicant instead and grab the info out of it somehow?

Thanks,
Ben






--
Ben Greear 
Candela Technologies Inc  http://www.candelatech.com

Re: Wifi-Event for when initial 4-way completes?

[Ben Greear]

On 06/07/2017 12:25 AM, Wojciech Dubowik wrote:

Hello Ben,

I have been using this part of wpa_supplicant to notify that 4-Way handshake is 
completed.

around line 868 in wpa_supplicant.c

#if defined(CONFIG_CTRL_IFACE) || !defined(CONFIG_NO_STDOUT_DEBUG)
wpa_msg(wpa_s, MSG_INFO, WPA_EVENT_CONNECTED "- Connection to "
MACSTR " completed [id=%d id_str=%s%s]",
MAC2STR(wpa_s->bssid),
ssid ? ssid->id : -1,
ssid && ssid->id_str ? ssid->id_str : "",
fils_hlp_sent ? " FILS_HLP_SENT" : "");
#endif /* CONFIG_CTRL_IFACE || !CONFIG_NO_STDOUT_DEBUG */

You can pack whatever notification message inside the if statement.


Thanks for the hint.  How do you receive this?  By leaving 'wpa_cli' running?

I am having my supplicant manage 64+ station vdevs...is there a way to make it
get events from all of them at once so that I don't need 64+ monitor processes?

Thanks,
Ben



Br,

Wojtek


On 07/06/17 02:46, Ben Greear wrote:

I have been tracking down a nasty EAPOL related bug in ath10k, and found 
something that may be peripheral, or maybe
it is significant.

My logic is basically to kick supplicant, watch 'iw events', and then when I 
see something
like "sta62 (phy #5): connected to 00:0e:8e:f8:73:96", I consider it connected 
and start
dhcpd.

But, it appears that the 'connected' message comes out before the EAPOL 4-way 
completes, so
I am starting dhclient before the encryption is really set up properly.  At 
best, this slows
things down and makes dhclient have to retry.

Is there some existing event or state I can probe to determine when the initial 
4-way is complete?

In case there is not, maybe that event would be worth adding?

Or, should I hack on supplicant instead and grab the info out of it somehow?

Thanks,
Ben






--
Ben Greear 
Candela Technologies Inc  http://www.candelatech.com

Re: Wifi-Event for when initial 4-way completes?

[Arend van Spriel]

+ hostap list

On 6/7/2017 2:46 AM, Ben Greear wrote:
I have been tracking down a nasty EAPOL related bug in ath10k, and found 
something that may be peripheral, or maybe

it is significant.

My logic is basically to kick supplicant, watch 'iw events', and then 
when I see something
like "sta62 (phy #5): connected to 00:0e:8e:f8:73:96", I consider it 
connected and start

dhcpd.

But, it appears that the 'connected' message comes out before the EAPOL 
4-way completes, so
I am starting dhclient before the encryption is really set up properly.  
At best, this slows

things down and makes dhclient have to retry.

Is there some existing event or state I can probe to determine when the 
initial 4-way is complete?


In case there is not, maybe that event would be worth adding?

Or, should I hack on supplicant instead and grab the info out of it 
somehow?


The completion of the 4-way handshake is a supplicant state. Reaching 
that state the PTK is set in the driver. It fires a CTRL-EVENT to the 
wpa_s control interface. Actually found a python script eapol_test.py in 
hostap repo that catches that event. So you may check it out.


Gr. AvS

Re: Wifi-Event for when initial 4-way completes?

[Wojciech Dubowik]

Hello Ben,

I have been using this part of wpa_supplicant to notify that 4-Way 
handshake is completed.


around line 868 in wpa_supplicant.c

#if defined(CONFIG_CTRL_IFACE) || !defined(CONFIG_NO_STDOUT_DEBUG)
wpa_msg(wpa_s, MSG_INFO, WPA_EVENT_CONNECTED "- 
Connection to "

MACSTR " completed [id=%d id_str=%s%s]",
MAC2STR(wpa_s->bssid),
ssid ? ssid->id : -1,
ssid && ssid->id_str ? ssid->id_str : "",
fils_hlp_sent ? " FILS_HLP_SENT" : "");
#endif /* CONFIG_CTRL_IFACE || !CONFIG_NO_STDOUT_DEBUG */

You can pack whatever notification message inside the if statement.

Br,

Wojtek


On 07/06/17 02:46, Ben Greear wrote:
I have been tracking down a nasty EAPOL related bug in ath10k, and 
found something that may be peripheral, or maybe

it is significant.

My logic is basically to kick supplicant, watch 'iw events', and then 
when I see something
like "sta62 (phy #5): connected to 00:0e:8e:f8:73:96", I consider it 
connected and start

dhcpd.

But, it appears that the 'connected' message comes out before the 
EAPOL 4-way completes, so
I am starting dhclient before the encryption is really set up 
properly.  At best, this slows

things down and makes dhclient have to retry.

Is there some existing event or state I can probe to determine when 
the initial 4-way is complete?


In case there is not, maybe that event would be worth adding?

Or, should I hack on supplicant instead and grab the info out of it 
somehow?


Thanks,
Ben

Wifi-Event for when initial 4-way completes?

[Ben Greear]

I have been tracking down a nasty EAPOL related bug in ath10k, and found 
something that may be peripheral, or maybe
it is significant.

My logic is basically to kick supplicant, watch 'iw events', and then when I 
see something
like "sta62 (phy #5): connected to 00:0e:8e:f8:73:96", I consider it connected 
and start
dhcpd.

But, it appears that the 'connected' message comes out before the EAPOL 4-way 
completes, so
I am starting dhclient before the encryption is really set up properly.  At 
best, this slows
things down and makes dhclient have to retry.

Is there some existing event or state I can probe to determine when the initial 
4-way is complete?

In case there is not, maybe that event would be worth adding?

Or, should I hack on supplicant instead and grab the info out of it somehow?

Thanks,
Ben

--
Ben Greear 
Candela Technologies Inc  http://www.candelatech.com