WiFi scan while connected

Remi.G 1 month ago

Does the NCS stack + nRF7002 support scanning while connected? I would expect it could, to support handoff, but getting errors.

Using nRF7002-DK and NCS 2.8.0.

Compile the wifi/shell example for nrf7002dk/nrf5340/cpuapp, no other changes.

*** Booting nRF Connect SDK v2.8.0-a2386bfc8401 *** *** Using Zephyr OS v3.7.99-0bc3393fb112 *** Starting nrf7002dk with CPU frequency: 128 MHz [00:00:00.532,226] <inf> wifi_supplicant: wpa_supplicant initialized

uart:~$ wifi connect -s Hizzulon <my AP credentials> Connection requested Connected [00:00:19.725,433] <inf> wpa_supp: MBO: Disable MBO/OCE due to misbehaving AP not having enabled PMF [00:00:19.726,226] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:54 (SSID='Hizzulon' freq=5220 MHz) [00:00:20.086,120] <inf> wpa_supp: wlan0: Trying to associate with fc:34:97:af:71:54 (SSID='Hizzulon' freq=5220 MHz) [00:00:20.102,874] <inf> wpa_supp: wlan0: Associated with fc:34:97:af:71:54 [00:00:20.103,027] <inf> wpa_supp: MBO: Disable MBO/OCE due to misbehaving AP not having enabled PMF [00:00:20.103,118] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 [00:00:20.122,253] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with fc:34:97:af:71:54 [PTK=CCMP GTK=CCMP] [00:00:20.122,467] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to fc:34:97:af:71:54 completed [id=0 id_str=] [00:00:20.137,420] <inf> net_dhcpv4: Received: 192.168.1.203

uart:~$ wifi status Status: successful ================== State: COMPLETED Interface Mode: STATION Link Mode: WIFI 6 (802.11ax/HE) SSID: Hizzulon BSSID: FC:34:97:AF:71:54 Band: 5GHz Channel: 44 Security: WPA2-PSK MFP: Optional RSSI: -34 Beacon Interval: 100 DTIM: 1 TWT: Supported Current PHY rate : 26000

uart:~$ wifi scan Scan requested

[wait ~30 seconds]

Scan request failed (-116)

[wait another ~30 seconds]

[00:01:33.363,311] <err> wifi_nrf: nrf_wifi_fmac_chg_vif_state: RPU is unresponsive for 10 sec [00:01:33.363,342] <err> wifi_nrf: nrf_wifi_if_stop_zep: nrf_wifi_fmac_chg_vif_state failed [00:01:33.364,013] <inf> wifi_supplicant: Network interface 1 (0x200013c0) down [00:01:33.375,396] <inf> wpa_supp: wlan0: CTRL-EVENT-DSCP-POLICY clear_all [00:01:33.375,854] <inf> wpa_supp: wlan0: CTRL-EVENT-DSCP-POLICY clear_all [00:01:35.533,050] <inf> wifi_supplicant: Network interface 1 (0x200013c0) up uart:~$ wifi status Status: successful ================== State: DISCONNECTED uart:~$

So the scan fails, but later there's another error that looks like the low-level nRF7002 driver failing and recovering (CONFIG_NRF_WIFI_RPU_RECOVERY is enabled by default).

If scan while connected isn't a supported feature, I would expect it to error immediately, not get into a state where it drops the connection?

A probably related issue: if I issue "wifi connect" with invalid credentials, wifi status is "SCANNING" forever (certainly much longer than the 30 second scan timeout), and later connect requests fail with:

uart:~$ wifi connect <credentials> Connection requested [00:01:58.298,828] <inf> wpa_supp: wlan0: CTRL-EVENT-DSCP-POLICY clear_all [00:01:58.302,124] <inf> wpa_supp: wlan0: Reject scan trigger since one is already pending [00:01:58.302,246] <wrn> wpa_supp: wlan0: Failed to initiate AP scan [00:01:58.304,992] <inf> wpa_supp: wlan0: Reject scan trigger since one is already pending [00:01:58.305,114] <wrn> wpa_supp: wlan0: Failed to initiate AP scan

I need to explicitly do "wifi disconnect" before it will stop scanning and allow another connection. Normally, issuing a connect command while already connected disconnects automatically then initiates the new connection.

0 Remi.G 24 days ago in reply to Remi.G

Here are the results with the 5270.zephyr.hex test image:

[00:00:00.616,210] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.616,241] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.616,241] <inf> fs_nvs: data wra: 0, 0
*** Booting nRF Connect SDK v2.8.0-1d192a274cd7 ***
*** Using Zephyr OS v3.7.99-cbd75f256cc9 ***
Starting nrf7002dk with CPU frequency: 128 MHz
[00:00:00.618,194] <inf> wifi_supplicant: wpa_supplicant initialized

uart:~$ wifi scan -b 5
Scan requested
uart:~$ debug event 1122 0000 0000
debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 113001 0000 0000

Num | SSID (len) | Chan (Band) | RSSI | Security | BSSID | MFP
1 | 0 | 161 (5GHz ) | -58 | WPA2-PSK | BA:34:97:AF:71:3D | Disable
2 | 0 | 161 (5GHz ) | -58 | WPA2-PSK | FC:34:97:AF:71:38 | Disable
3 | Hizzulon 8 | 48 (5GHz ) | -63 | WPA2-PSK | FC:34:97:AF:71:34 | Disable
4 | 0 | 48 (5GHz ) | -80 | WPA2-PSK | 22:EF:BD:34:5E:DF | Disable
Scan request done

uart:~$ wifi connect -s Hizzulon <credentials>
debug event 1122 0000 0000
Connection requested
uart:~$ debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 113001 0000 0000
debug event 1122 0000 0000
debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 113001 0000 0000
Connected
[00:01:30.862,121] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:34 (SSID='Hizzulon' freq=5240 MHz)
[00:01:31.221,954] <inf> wpa_supp: wlan0: Trying to associate with fc:34:97:af:71:34 (SSID='Hizzulon' freq=5240 MHz)
[00:01:31.238,494] <inf> wpa_supp: wlan0: Associated with fc:34:97:af:71:34
[00:01:31.238,677] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[00:01:31.257,659] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with fc:34:97:af:71:34 [PTK=CCMP GTK=CCMP]
[00:01:31.257,873] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to fc:34:97:af:71:34 completed [id=0 id_str=]
[00:01:31.269,042] <inf> net_dhcpv4: Received: 192.168.1.237
uart:~$ debug event 114000 0000 0020

uart:~$ wifi status
Status: successful
==================
State: COMPLETED
Interface Mode: STATION
Link Mode: WIFI 6 (802.11ax/HE)
SSID: Hizzulon
BSSID: FC:34:97:AF:71:34
Band: 5GHz
Channel: 48
Security: WPA2-PSK
MFP: Optional
RSSI: -61
Beacon Interval: 100
DTIM: 1
TWT: Supported
Current PHY rate : 34400
uart:~$

uart:~$ wifi scan -b 5 -c 5:48
Scan requested
uart:~$ debug event 1122 0000 0000
debug event 112500 0000 0000
debug event 112501 0000 0000
debug event 112502 0000 0000
debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 113001 0000 0000

Num | SSID (len) | Chan (Band) | RSSI | Security | BSSID | MFP
1 | 0 | 48 (5GHz ) | -81 | WPA2-PSK | 22:EF:BD:34:5E:DF | Disable
Scan request done

uart:~$ wifi scan -b 5 -c 5:48
Scan requested
uart:~$ debug event 1122 0000 0000
debug event 112500 0000 0000
debug event 112501 0000 0000
debug event 112502 0000 0000
debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 113001 0000 0000

Num | SSID (len) | Chan (Band) | RSSI | Security | BSSID | MFP
1 | Hizzulon 8 | 48 (5GHz ) | -61 | WPA2-PSK | FC:34:97:AF:71:34 | Disable
Scan request done

uart:~$ wifi scan -b 5 -c 5:165
Scan requested
uart:~$ debug event 1122 0000 0000
debug event 112500 0000 0000
debug event 112501 0000 0000
debug event 112502 0000 0000
debug event 1124 0000 0000
debug event 113000 0000 0000
debug event 114000 0008 0004

... repeats "debug event 114000 0008 0004" forever

Note that there are two devices on channel 48 in the initial scan - the "Hizzulon" AP, and a device with BSSID 22:EF:BD:34:5E:DF at low RSSI (a Roku). The above log shows that the first scan on channel 48 after connecting showed only the second device, not the AP. Doing another scan immediately afterward found the AP. That behavior isn't consistent - it may find one or both. Just including it in the log as it seems unexpected that the scan wouldn't always show the much stronger AP.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Simonr 22 days ago

We're working on a .hex file with a potential fix to this issue. We've also gotten the same AP model as you now, but have not been able to reproduce this issue on our end.

Best regards,

Simon
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Remi.G 10 days ago in reply to Simonr

I was experimenting with this today and have some additional observations - not related directly to scanning while connected, but related to the 2.4GHz connection issues I was seeing. Including it here in case it may have the same root cause as your potential fix, but I can file under a new issue if not.

As mentioned above, I can always connect reliably at 5GHz, but 2.4GHz is flaky. Some devices with some APs will never connect to 2.4GHz, but I have had some devices switch between working and not-working over time. When they fail, they fail always, on every connection attempt. Resets/power cycling on both the AP and the device have no effect.

I discovered that specifying the channel or band explicitly in the "wifi connect" command will connect reliably at 2.4GHz.

These logs are with the NCS 2.8.0 wifi shell sample, and using the Asus AP mentioned above as well as a Pixel8 hotspot. The Asus AP has simultaneous 2.4GHz "Hizzulon2" and 5GHz "Hizzulon" (note different SSID names).

Connecting to 5GHz always works, on all devices I've tried:

uart:~$ wifi scan
Scan requested

Num | SSID (len) | Chan (Band) | RSSI | Security | BSSID | MFP
1 | Hizzulon 8 | 44 (5GHz ) | -55 | WPA2-PSK | FC:34:97:AF:71:34 | Disable
2 | Hizzulon2 9 | 7 (2.4GHz) | -55 | WPA2-PSK | FC:34:97:AF:71:30 | Disable
3 | 0 | 116 (5GHz ) | -67 | WPA2-PSK | BA:34:97:AF:71:3D | Disable
4 | 0 | 116 (5GHz ) | -68 | WPA2-PSK | FC:34:97:AF:71:38 | Disable
5 | DIRECT-roku-45P-0E44CB 22 | 44 (5GHz ) | -81 | WPA2-PSK | 22:EF:BD:34:5E:DF | Disable
6 | Tims House 10 | 6 (2.4GHz) | -86 | WPA2-PSK | 90:D0:92:04:1B:84 | Optional
7 | ATT8H862E9 10 | 3 (2.4GHz) | -88 | WPA2-PSK | 90:9D:7D:60:6A:90 | Optional
Scan request done

uart:~$ wifi connect -s Hizzulon -p <password> -k 1
Connection requested
Connected
[00:00:36.496,307] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:34 (SSID='Hizzulon' freq=5220 MHz)
[00:00:36.853,179] <inf> wpa_supp: wlan0: Trying to associate with fc:34:97:af:71:34 (SSID='Hizzulon' freq=5220 MHz)
[00:00:36.869,873] <inf> wpa_supp: wlan0: Associated with fc:34:97:af:71:34
[00:00:36.870,056] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[00:00:36.889,587] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with fc:34:97:af:71:34 [PTK=CCMP GTK=CCMP]
[00:00:36.889,801] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to fc:34:97:af:71:34 completed [id=0 id_str=]
[00:00:36.900,817] <inf> net_dhcpv4: Received: 192.168.1.203

uart:~$ wifi status
Status: successful
==================
State: COMPLETED
Interface Mode: STATION
Link Mode: WIFI 6 (802.11ax/HE)
SSID: Hizzulon
BSSID: FC:34:97:AF:71:34
Band: 5GHz
Channel: 44
Security: WPA2-PSK
MFP: Optional
RSSI: -56
Beacon Interval: 100
DTIM: 1
TWT: Supported
Current PHY rate : 34400

Connecting to 2.4GHz always fails, on this device at this time (device was reset after above test). After ~30 seconds (much longer than a successful connection) it outputs the "trying to authenticate" message but doesn't get any further.

uart:~$ wifi connect -s Hizzulon2 -p <password> -k 1
Connection requested
[00:01:03.028,717] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:30 (SSID='Hizzulon2' freq=2442 MHz)

uart:~$ wifi status
Status: successful
==================
State: DISCONNECTED

But if I specify the band (-b 2) or channel (-c 7) explicitly, it works (device resets between every test):

uart:~$ wifi connect -s Hizzulon2 -p <password> -k 1 -b 2
Connection requested
Connected
[00:00:37.813,201] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:30 (SSID='Hizzulon2' freq=2442 MHz)
[00:00:38.180,236] <inf> wpa_supp: wlan0: Trying to associate with fc:34:97:af:71:30 (SSID='Hizzulon2' freq=2442 MHz)
[00:00:38.198,913] <inf> wpa_supp: wlan0: Associated with fc:34:97:af:71:30
[00:00:38.199,096] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[00:00:38.220,581] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with fc:34:97:af:71:30 [PTK=CCMP GTK=CCMP]
[00:00:38.220,794] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to fc:34:97:af:71:30 completed [id=0 id_str=]
[00:00:38.237,854] <inf> net_dhcpv4: Received: 192.168.1.203

uart:~$ wifi status
Status: successful
==================
State: COMPLETED
Interface Mode: STATION
Link Mode: WIFI 4 (802.11n/HT)
SSID: Hizzulon2
BSSID: FC:34:97:AF:71:30
Band: 2.4GHz
Channel: 7
Security: WPA2-PSK
MFP: Optional
RSSI: -53
Beacon Interval: 100
DTIM: 1
TWT: Not supported
Current PHY rate : 26000

uart:~$ wifi connect -s Hizzulon2 -p <password> -k 1 -c 7
Connection requested
Connected
[00:00:15.888,732] <inf> wpa_supp: wlan0: SME: Trying to authenticate with fc:34:97:af:71:30 (SSID='Hizzulon2' freq=2442 MHz)
[00:00:16.256,256] <inf> wpa_supp: wlan0: Trying to associate with fc:34:97:af:71:30 (SSID='Hizzulon2' freq=2442 MHz)
[00:00:16.274,841] <inf> wpa_supp: wlan0: Associated with fc:34:97:af:71:30
[00:00:16.275,024] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[00:00:16.293,670] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with fc:34:97:af:71:30 [PTK=CCMP GTK=CCMP]
[00:00:16.293,884] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to fc:34:97:af:71:30 completed [id=0 id_str=]
[00:00:16.310,699] <inf> net_dhcpv4: Received: 192.168.1.203

uart:~$ wifi status
Status: successful
==================
State: COMPLETED
Interface Mode: STATION
Link Mode: WIFI 4 (802.11n/HT)
SSID: Hizzulon2
BSSID: FC:34:97:AF:71:30
Band: 2.4GHz
Channel: 7
Security: WPA2-PSK
MFP: Optional
RSSI: -54
Beacon Interval: 100
DTIM: 1
TWT: Not supported
Current PHY rate : 26000

Pixel8 results are similar, except it uses 2.4GHz channel 11, and it has SSID name "Pixel" for both 2.4 and 5GHz.

So something related to band/channel specific connection vs "any" band/channel.
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Simonr 2 days ago

Happy new year Remi!

Thank you for your thorough testing yet again. I'm sorry to say that we've not been able to get a .hex with a fix ready for you over the holiday period, as we've been short on staff the last few weeks. I'll keep you updated on what I hear from the devs regarding both the fix .hex as well as the status on these new findings.

Best regards,

Simon
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel
0 Simonr 1 day ago

Hi Remi

Today I got hex files from the devs, that has a potential fix to the scan issues at least. Please test them for both the scan and connection issues on your end and report back what you're seeing.

zephyr (1).hex & zephyr_with_logs_enabled.hex

There should be logging enabled on one of them that might give us an idea of what's wrong if this doesn't fix the problem(s).

Best regards,

Simon
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel