Re: [PATCH] netdev: handle disconnect event during the 4-way handshake

[Denis Kenzior <denkenz@gmail.com>]

Hi James,

On 7/17/24 9:00 AM, James Prestwood wrote:
> If a disconnect arrives during the 4-way handshake this would result
> in netdev sending a disconnect event to station. If this is a
> reassociation this case is unhandled in station and causes a hang as
> it expects any connection failure to be handled via the reassociation
> callback, not a random disconnect event.
> 
> To handle this case the disconnect event can check if there is a
> pending connect callback and call that instead of the event handler.
> 
> Below are logs showing the "Unexpected disconnect event" which
> prevents IWD from cleaning up its state and ultimately results in a
> hang:
> 
> Jul 16 18:16:13: src/station.c:station_transition_reassociate()
> Jul 16 18:16:13: event: state, old: connected, new: roaming
> Jul 16 18:16:13: src/wiphy.c:wiphy_radio_work_done() Work item 65 done
> Jul 16 18:16:13: src/wiphy.c:wiphy_radio_work_next() Starting work item 66
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20)
> Jul 16 18:16:13: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Deauthenticate(39)
> Jul 16 18:16:13: src/netdev.c:netdev_deauthenticate_event()
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification New Station(19)
> Jul 16 18:16:13: src/station.c:station_netdev_event() Associating
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Authenticate(37)
> Jul 16 18:16:13: src/netdev.c:netdev_authenticate_event()
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Associate(38)
> Jul 16 18:16:13: src/netdev.c:netdev_associate_event()
> Jul 16 18:16:13: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Connect(46)
> Jul 16 18:16:13: src/netdev.c:netdev_connect_event()
> Jul 16 18:16:13: src/netdev.c:netdev_connect_event() aborting and ignore_connect_event not set, proceed
> Jul 16 18:16:13: src/netdev.c:netdev_connect_event() expect_connect_failure not set, proceed
> Jul 16 18:16:13: src/netdev.c:parse_request_ies()
> Jul 16 18:16:13: src/netdev.c:netdev_connect_event() Request / Response IEs parsed
> Jul 16 18:16:13: src/netdev.c:netdev_get_oci()
> Jul 16 18:16:13: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:13: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:13: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:13: src/netdev.c:netdev_get_oci_cb() Obtained OCI: freq: 5220, width: 3, center1: 5210, center2: 0
> Jul 16 18:16:13: src/eapol.c:eapol_start()
> Jul 16 18:16:13: src/netdev.c:netdev_unicast_notify() Unicast notification Control Port Frame(129)
> Jul 16 18:16:13: src/netdev.c:netdev_control_port_frame_event()
> Jul 16 18:16:13: src/eapol.c:eapol_handle_ptk_1_of_4() ifindex=6
> Jul 16 18:16:13: src/netdev.c:netdev_mlme_notify() MLME notification Control Port TX Status(139)
> Jul 16 18:16:14: src/netdev.c:netdev_mlme_notify() MLME notification Notify CQM(64)
> Jul 16 18:16:14: src/netdev.c:netdev_cqm_event() Signal change event (above=1 signal=-60)
> Jul 16 18:16:17: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:17: src/netdev.c:netdev_mlme_notify() MLME notification Del Station(20)
> Jul 16 18:16:17: src/netdev.c:netdev_mlme_notify() MLME notification Deauthenticate(39)
> Jul 16 18:16:17: src/netdev.c:netdev_deauthenticate_event()
> Jul 16 18:16:17: src/netdev.c:netdev_mlme_notify() MLME notification Disconnect(48)
> Jul 16 18:16:17: src/netdev.c:netdev_disconnect_event()
> Jul 16 18:16:17: Received Deauthentication event, reason: 15, from_ap: true
> Jul 16 18:16:17: src/wiphy.c:wiphy_radio_work_done() Work item 66 done
> Jul 16 18:16:17: src/station.c:station_disconnect_event() 6
> Jul 16 18:16:17: Unexpected disconnect event
> Jul 16 18:16:17: src/netdev.c:netdev_link_notify() event 16 on ifindex 6
> Jul 16 18:16:17: src/wiphy.c:wiphy_reg_notify() Notification of command Reg Change(36)
> Jul 16 18:16:17: src/wiphy.c:wiphy_update_reg_domain() New reg domain country code for (global) is XX
> ---
>   src/netdev.c | 15 ++++++++++++++-
>   1 file changed, 14 insertions(+), 1 deletion(-)
> 

<snip>

> @@ -1310,9 +1312,20 @@ static void netdev_disconnect_event(struct l_genl_msg *msg,
>   
>   	event_filter = netdev->event_filter;
>   	event_data = netdev->user_data;
> +	connect_cb = netdev->connect_cb;
> +	user_data = netdev->user_data;
>   	netdev_connect_free(netdev);
>   
> -	if (!event_filter)
> +	/*
> +	 * If a deauth frame come in after the connect event during the 4-way
> +	 * handshake we need to handle this via the connect callback since its
> +	 * still effectively a connection failure.
> +	 */
> +	if (connect_cb) {
> +		connect_cb(netdev, NETDEV_RESULT_AUTHENTICATION_FAILED,
> +				&reason_code, user_data);
> +		return;
> +	} else if (!event_filter)
>   		return;

Can we use netdev_disconnected() instead?

>   
>   	if (disconnect_by_ap)

Regards,
-Denis