Page MenuHomeFreeBSD
Differential D38753

wpa_supplicant(8): fix the connection-fail problem
AbandonedPublic
Actions

Authored by enweiwu on Feb 24 2023, 5:48 AM.
Tags
Referenced Files
Unknown Object (File)
Fri, Nov 8, 9:31 PM
Unknown Object (File)
Tue, Oct 29, 9:30 PM
Unknown Object (File)
Sat, Oct 19, 7:40 PM
Unknown Object (File)
Fri, Oct 18, 5:42 AM
Unknown Object (File)
Wed, Oct 16, 6:37 PM
Unknown Object (File)
Sep 26 2024, 11:40 AM
Unknown Object (File)
Sep 24 2024, 8:35 PM
Unknown Object (File)
Sep 24 2024, 9:54 AM
View All 52 Files
Subscribers
imp
zlei
wireless

Details

Reviewers
bz
adrian
lwhsu
cy
Summary

Someone may continuously see CTRL-EVENT-SCAN-FAILED and not be able to connect to an AP
when directly using wpa_supplicant(8) in the command line, and someone specifies
ifconfig_wlan0="WPA in /etc/rc.conf will not encounter this problem because commit 5fcdc19a81115 and d06d7eb09131 use a weird way to address the problem. Even though the weird way may not
successfully connect to AP every time.

The problem is that wpa_supplicant fail to request scan since net80211(4) has already
fired a scan, and sometimes it will continue to be issued by net80211, and never
end (see D38508).

I have added a timer in wpa_driver_ops::scan2() when scan request fails, so wpa_supplicant
will get EVENT_SCAN_RESULTS and call wpa_driver_ops::get_scan_results2() for scan results
when a timeout occurs.

This patch is just for testing, the codes should be merged upstream (hostap.git).

Diff Detail

Repository
rG FreeBSD src repository
Lint
Lint Skipped
Unit
Tests Skipped

Event Timeline

enweiwu created this revision.Feb 24 2023, 5:48 AM
Herald added a subscriber: imp. · View Herald TranscriptFeb 24 2023, 5:48 AM
enweiwu requested review of this revision.Feb 24 2023, 5:48 AM
enweiwu updated this revision to Diff 117852.Feb 24 2023, 6:03 AM
enweiwu updated this revision to Diff 117853.
cy added a comment.Feb 24 2023, 5:19 PM

The code looks reasonable to me, so far. I'll test it later tonight.

BTW, upstream list address is, hostap@lists.infradead.org.

cy added a comment.Feb 25 2023, 4:46 AM

Having tested this, I'm seeing these in syslog and no carrier. It doesn't fix the problem.

Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:62 reason=3 locally_generated=1
Feb 24 20:15:57 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Can't assign requested address
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all

Re-adding the rc.d postcmd (ifconfig down; ifconfig up) works around the issue like before.

The problem was introduced by upstream commit d807e289db96 (https://w1.fi/cgit/hostap/commit/?id=d807e289db96366da9682505d93ab899fe52739b).

enweiwu added a comment.Feb 26 2023, 6:54 AM
In D38753#882303, @cy wrote:

Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:62 reason=3 locally_generated=1
Feb 24 20:15:57 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Can't assign requested address
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all

Could you provide more logs for tracing? Just guessing by the three lines, the CTRL-EVENT-DISCONNECTED has reason code = 3 in the disauthentication frame, and by the spec, it means "Station has left the basic service area or extended service area and is disauthenticated", it seems weird because you said that re-adding rc scripts will work.

cy added a comment.Feb 27 2023, 3:10 AM
In D38753#882743, @enweiwu wrote:
In D38753#882303, @cy wrote:

Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:62 reason=3 locally_generated=1
Feb 24 20:15:57 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Can't assign requested address
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all

Could you provide more logs for tracing? Just guessing by the three lines, the CTRL-EVENT-DISCONNECTED has reason code = 3 in the disauthentication frame, and by the spec, it means "Station has left the basic service area or extended service area and is disauthenticated", it seems weird because you said that re-adding rc scripts will work.

Sure. Here's everything from that session.

Feb 24 20:05:49 slippy wpa_supplicant[4652]: Successfully initialized wpa_supplicant
Feb 24 20:05:49 slippy wpa_supplicant[4652]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument
Feb 24 20:05:50 slippy wpa_supplicant[4653]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:05:59 slippy wpa_supplicant[4653]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:06:02 slippy wpa_supplicant[4653]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:06:40 slippy wpa_supplicant[4653]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:06:40 slippy wpa_supplicant[4653]: wlan0: CTRL-EVENT-TERMINATING
Feb 24 20:06:44 slippy wpa_supplicant[5025]: Successfully initialized wpa_supplicant
Feb 24 20:06:44 slippy wpa_supplicant[5025]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument
Feb 24 20:06:44 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:06:53 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:06:54 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:06:55 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:07:53 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:07:53 slippy wpa_supplicant[5026]: wlan0: CTRL-EVENT-TERMINATING
Feb 24 20:08:03 slippy wpa_supplicant[5212]: Successfully initialized wpa_supplicant
Feb 24 20:08:03 slippy wpa_supplicant[5212]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument
Feb 24 20:08:03 slippy wpa_supplicant[5213]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:08:13 slippy wpa_supplicant[5213]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:08:16 slippy wpa_supplicant[5213]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:13:03 slippy wpa_supplicant[5213]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:13:03 slippy wpa_supplicant[5213]: wlan0: CTRL-EVENT-TERMINATING
Feb 24 20:13:09 slippy wpa_supplicant[6714]: Successfully initialized wpa_supplicant
Feb 24 20:13:09 slippy wpa_supplicant[6714]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument
Feb 24 20:13:10 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:13:22 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:13:57 slippy wpa_supplicant[6715]: wlan0: Trying to associate with 4c:60:de:31:3c:61 (SSID='KQNGN2' freq=5805 MHz)
Feb 24 20:13:57 slippy wpa_supplicant[6715]: wlan0: Associated with 4c:60:de:31:3c:61
Feb 24 20:13:58 slippy wpa_supplicant[6715]: wlan0: WPA: Key negotiation completed with 4c:60:de:31:3c:61 [PTK=CCMP GTK=CCMP]
Feb 24 20:13:58 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-CONNECTED - Connection to 4c:60:de:31:3c:61 completed [id=1 id_str=]
Feb 24 20:14:36 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:61 reason=3 locally_generated=1
Feb 24 20:14:36 slippy wpa_supplicant[6715]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Can't assign requested address
Feb 24 20:14:36 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:14:36 slippy wpa_supplicant[6715]: wlan0: CTRL-EVENT-TERMINATING
Feb 24 20:14:52 slippy wpa_supplicant[7098]: Successfully initialized wpa_supplicant
Feb 24 20:14:52 slippy wpa_supplicant[7098]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Invalid argument
Feb 24 20:14:52 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=103, val=0, arg_len=128]: Operation now in progress
Feb 24 20:14:52 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:14:53 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=103, val=0, arg_len=128]: Operation now in progress
Feb 24 20:14:53 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-SCAN-FAILED ret=-1 retry=1
Feb 24 20:15:03 slippy wpa_supplicant[7099]: wlan0: Authentication with 4c:60:de:31:3c:61 timed out.
Feb 24 20:15:03 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:61 reason=3 locally_generated=1
Feb 24 20:15:03 slippy wpa_supplicant[7099]: BSSID 4c:60:de:31:3c:61 ignore list count incremented to 2, ignoring for 10 seconds
Feb 24 20:15:03 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:15:04 slippy wpa_supplicant[7099]: wlan0: Associated with 4c:60:de:31:3c:62
Feb 24 20:15:04 slippy wpa_supplicant[7099]: wlan0: WPA: Key negotiation completed with 4c:60:de:31:3c:62 [PTK=CCMP GTK=CCMP]
Feb 24 20:15:04 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-CONNECTED - Connection to 4c:60:de:31:3c:62 completed [id=0 id_str=]
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DISCONNECTED bssid=4c:60:de:31:3c:62 reason=3 locally_generated=1
Feb 24 20:15:57 slippy wpa_supplicant[7099]: ioctl[SIOCS80211, op=20, val=0, arg_len=7]: Can't assign requested address
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Feb 24 20:15:57 slippy wpa_supplicant[7099]: wlan0: CTRL-EVENT-TERMINATING

cy added a comment.EditedFeb 27 2023, 3:29 AM

IMO we should revert the specific upstream commit or set IFF_UP when the interface is downed or brought up. The below should work.

diff --git a/contrib/wpa/src/drivers/driver_bsd.c b/contrib/wpa/src/drivers/driver_bsd.c
index 345bbb892ecf..ebedf313a35f 100644
--- a/contrib/wpa/src/drivers/driver_bsd.c
+++ b/contrib/wpa/src/drivers/driver_bsd.c
@@ -526,6 +526,9 @@ bsd_set_ieee8021x(void *priv, struct wpa_bss_params *params)
 			   __func__);
 		return -1;
 	}
+#ifdef __FreeBSD__
+	drv->ifr_flags |= IFF_UP;
+#endif
 	return 0;
 }
 
@@ -1033,6 +1036,10 @@ bsd_init(struct hostapd_data *hapd, struct wpa_init_params *params)
 	if (bsd_get_iface_flags(drv) < 0)
 		goto bad;
 
+#ifdef __FreeBSD__
+	drv->ifr_flags &= ~IFF_UP;
+#endif
+
 	if (bsd_set_mediaopt(drv, IFM_OMASK, IFM_IEEE80211_HOSTAP) < 0) {
 		wpa_printf(MSG_ERROR, "%s: failed to set operation mode",
 			   __func__);
@@ -1688,6 +1695,10 @@ wpa_driver_bsd_deinit(void *priv)
 	if (drv->ifindex != 0 && !drv->if_removed) {
 		wpa_driver_bsd_set_wpa(drv, 0);
 
+#ifdef __FreeBSD__
+		drv->ifr_flags &= ~IFF_UP;
+#endif
+
 		wpa_driver_bsd_set_wpa_internal(drv, drv->prev_wpa,
 						drv->prev_privacy);

The above has been submitted in https://reviews.freebsd.org/D38805.

zlei added a subscriber: zlei.Feb 27 2023, 10:02 AM
bz added a comment.Feb 27 2023, 10:24 AM
In D38753#883103, @cy wrote:

IMO we should revert the specific upstream commit or set IFF_UP when the interface is downed or brought up. The below should work.

..

The above has been submitted in https://reviews.freebsd.org/D38805.

Analysis of the in-tree wpa_supplicant has shown that the interface state is correct at each time we need it down or up (even without the up/down in the rc script). I'll upload the change with logging for that and post the review here.

bz added a comment.Feb 27 2023, 10:30 AM

The "backout+logging" change is at https://reviews.freebsd.org/D38807

cy added a comment.Feb 27 2023, 12:54 PM
In D38753#883173, @bz wrote:

The "backout+logging" change is at https://reviews.freebsd.org/D38807

Thanks. This is the change I sent to you, and have been running here for about a year now. Upstream did not accept it, hence the alternative patch.

enweiwu mentioned this in D38508: net80211(4): fix the connection-fail problem in wpa_supplicant(8).Mar 2 2023, 12:40 PM
enweiwu abandoned this revision.Mar 5 2023, 7:51 AM

See D38807.

enweiwu mentioned this in D36243: wtap(4): Implement STA/HostAP mode and support WPA/WPA2.Mar 5 2023, 8:05 AM
bz mentioned this in rGbfb202c4554a: WPA: driver_bsd.c: backout upstream IFF_ change and add logging.Mar 23 2023, 11:51 PM
bz mentioned this in rGded53e898c7b: rc/WPA: driver_bsd.c: backout upstream IFF_ change and add logging.Jun 26 2023, 12:08 PM
cy mentioned this in R11:bf01744fb255: security/wpa_supplicant: driver_bsd.c: backout upstream IFF_ change and add….Sep 12 2023, 5:53 AM
cy mentioned this in R11:ba9d1c4fdcc2: security/wpa_supplicant-devel: driver_bsd.c: backout upstream IFF_ change and….
cy mentioned this in R11:8668ee87415b: net/hostapd-devel: driver_bsd.c: backout upstream IFF_ change and add logging.
cy mentioned this in R11:087cebebd616: net/hostapd: driver_bsd.c: backout upstream IFF_ change and add logging.
cy mentioned this in R11:0a98996fe276: security/wpa_supplicant: driver_bsd.c: backout upstream IFF_ change and add….Sep 15 2023, 2:08 PM
cy mentioned this in R11:c5c914750fa6: security/wpa_supplicant-devel: driver_bsd.c: backout upstream IFF_ change and….
cy mentioned this in R11:5d8ede11d81e: net/hostapd: driver_bsd.c: backout upstream IFF_ change and add logging.
cy mentioned this in R11:662d7b7df237: net/hostapd-devel: driver_bsd.c: backout upstream IFF_ change and add logging.

Revision Contents
Changeset List

PathSize
contrib/
wpa/
src/
drivers/
54 lines
libexec/
rc/
rc.d/
7 lines
sys/
dev/
wtap/
tools/
tools/

Diff 117851

View Options

.DS_Store

Loading...
View Options

contrib/wpa/src/drivers/driver_bsd.c

Loading...
View Options

libexec/rc/rc.d/wpa_supplicant

Loading...
View Options

sys/dev/wtap/.DS_Store

Loading...
View Options

tools/tools/.DS_Store

Loading...