espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.36k stars 7.21k forks source link

802.11k/v based roaming not making the transition to another AP (IDFGH-12973) #13925

Closed evoon closed 2 months ago

evoon commented 3 months ago

Answers checklist.

IDF version.

v5.3

Espressif SoC revision.

ESP32-C6 (v0.0)

Operating System used.

Windows

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-C6-WROOM-1

Power Supply used.

USB

What is the expected behavior?

Expected behavior is seamless roaming from AP1 to AP2 via a neighbor report followed by a BSS transition. Network is a 802.11ax with WPA2-PSK and TP-Link Omada hardware (1 router and 1 AP) that has toggled on the roaming features. APs are not on the same channel. In the TP-Link controller, I have tried to disable Fast Roaming/AI Roaming and I tried with Force Disassociate feature.

What is the actual behavior?

The current behavior is this, with the roaming_11kvr code :

Then, a BSS transition query is sent by the ESP32 with :

esp_wnm_send_bss_transition_mgmt_query(REASON_RSSI, neighbor_list, cand_list);

And no other BSS packets are observed after with a wifi adapter in monitor mode (we expect a request from the AP and then optionally a response from STA to AP) : Here is the BSS Transition Query packet : Screenshot BSS Query Packet

Shouldn't the BSS Transition QUery Reason be "Better AP Found" instead of "Load Balancing" (for REASON_RSSI) or "Excessive frame loss/poor conditions" (for REASON_FRAME_LOSS) ? It would make more sense but I don't know if it changes the behavior then. I didn't get a request frame back when using REASON_RSSI or REASON_FRAME_LOSS.

The same scenario repeats itself after, because i set the rssi threshold after each low rssi event (and upon first connexion of course).

As roaming_11kvr is an official roaming example in v5.3 i presume it works with other network setups, but I don't see what would make this fail with mine. Thanks for the help.

Steps to reproduce.

^

Debug Logs.

No response

More Information.

No response

evoon commented 3 months ago

Isn't it possible to initiate a FT request to the connected AP, following this figure from IEEE 802.11-2020 page 2622? The idea "over-the-DS" would be to talk to the neighbor from the neighbor report to initiate the FT, I don't know if that is possible. What did you implement when adding the "ft_enabled" boolean in a STA's config ?

ft_protocol

Thank you for your help!

kapilkedawat commented 3 months ago

Hi @evoon, unfortunately how AP behaves is not in our control. Ideally we should get an BTM request with the candidate AP info and station will move to the candidate.

ESP32 only support over the air which is supported by majorly of APs(very less APs support over the DS so we don't plan to add that overhead).

Since your AP network is not behaving in a standard way, I would suggest you to give a try to our new roaming app, which takes care of these situations. It supports legacy roaming along with BTM and has lots of parameter which you can tune as per your convenience. You can read more about the app here https://github.com/espressif/esp-idf/blob/master/components/esp_wifi/wifi_apps/roaming_app/src/README.md .

app is available here https://github.com/espressif/esp-idf/blob/master/components/esp_wifi/wifi_apps/roaming_app/src/README.md

evoon commented 3 months ago

@kapilkedawat Indeed the legacy method in roaming_app works well, but defeats the purpose of fast roaming.

Can you recommend a router/AP that you had good results with in terms of fast/seamless roaming ? My objective is to get the lowest offline time during the roaming (<150ms).

kapilkedawat commented 2 months ago

Hi @evoon, sorry for the delay,. somehow I missed your reply. You can use tplink deco series which supports 11kvr and generally give response to btm query.

However most new implementations of mesh actually uses their own algo internally and that is the reason they don't respond to btm query and tried to move the station as they seems fit.

evoon commented 2 months ago

Thanks for your help.

hongquan-prog commented 2 weeks ago

@evoon @kapilkedawat I would like to know what the test results are after using fast roaming, how long it takes to switch to a new ap, and if the TCP connection drops. This is important for my subsequent tests. If it doesn't meet the requirements I will consider other options, thanks!

kapilkedawat commented 2 weeks ago

Hi @hongquan-prog, device is able to connect to new AP pretty quick(under 100 ms) if FT-PSK is used. ft(1).pcapng.zip Please see attachment for your reference.

hongquan-prog commented 2 weeks ago

Hi @hongquan-prog, device is able to connect to new AP pretty quick(under 100 ms) if FT-PSK is used. ft(1).pcapng.zip Please see attachment for your reference.

Thank you very much for the data, I don't see that it reacquires the IP address, does this mean that switching AP doesn't cause the socket to disconnect and reacquire the IP?

kapilkedawat commented 2 weeks ago

Hi @hongquan-prog, device is able to connect to new AP pretty quick(under 100 ms) if FT-PSK is used. ft(1).pcapng.zip Please see attachment for your reference.

Thank you very much for the data, I don't see that it reacquires the IP address, does this mean that switching AP doesn't cause the socket to disconnect and reacquire the IP?

The test was executed specifically to measure the time during an FT connection. Retaining the TCP connection depends on various factors and requires AP support. The AP must be able to avoid allocating a new IP address and resume the connection(deleting the older route and add new route for the station). Most APs do not support this so the station may need to request a new IP address.

hongquan-prog commented 2 weeks ago

Hi @hongquan-prog, device is able to connect to new AP pretty quick(under 100 ms) if FT-PSK is used. ft(1).pcapng.zip Please see attachment for your reference.

Thank you very much for the data, I don't see that it reacquires the IP address, does this mean that switching AP doesn't cause the socket to disconnect and reacquire the IP?

The test was executed specifically to measure the time during an FT connection. Retaining the TCP connection depends on various factors and requires AP support. The AP must be able to avoid allocating a new IP address and resume the connection(deleting the older route and add new route for the station). Most APs do not support this so the station may need to request a new IP address.

I noticed in issue 13849 that re-associating the AP disconnects the socket, but the issue arises in traditional roaming, do I need to reconnect to server if I use fast roaming, the AC I am currently using doesn't assign a new IP to it.

kapilkedawat commented 2 weeks ago

I would suggest to verify if everything works okay using static IP first.

hongquan-prog commented 2 weeks ago

I would suggest to verify if everything works okay using static IP first.

Reassigning the IP depends on whether the client initiates a DHCP request, and if the ESP32 does not clear the current IP before reassociating it, then its IP should be unchanged. Other than that I'd like to know if it calls the callback function again after re-association to notify the user that the wifi has been successfully connected.

hongquan-prog commented 2 weeks ago

I would suggest to verify if everything works okay using static IP first.

Although the re-association time is very short, the whole LWIP stack will be offloaded before re-association, and then the LWIP will be re-initialized and the IP will be re-acquired after successful re-association. the actual experience is basically the same as that of legacy roaming.

hongquan-prog commented 2 weeks ago

The only difference is that it follows the 802.11 kvr interaction, but it interrupts the whole business and makes 802.11 r almost useless, because reacquiring the IP and connecting to the server is much more time-consuming than re-associating. While it may consume more memory, I think it should be implemented as a seamless switch, with the user choosing which way to use.

kapilkedawat commented 2 weeks ago

test.patch Could you try attached patch, however I suspect we may need to make more changes to support this.

hongquan-prog commented 2 weeks ago

test.patch Could you try attached patch, however I suspect we may need to make more changes to support this.

Yes, more work may be needed to implement this feature, I hope in the future it will enable seamless switching like other industrial grade modules, which will expand the application scenarios of esp32, which will help a lot in situations where device roaming latency is more sensitive. I'll test this modification later, and if there are any other issues I'll try to fix them and get back to you.

hongquan-prog commented 2 weeks ago

test.patch Could you try attached patch, however I suspect we may need to make more changes to support this.

I have a question, during roaming the state machine of the wifi driver switches to non-running state, in this case if LWIP is still running, how does the wifi driver handle these messages

hongquan-prog commented 2 weeks ago

test.patch Could you try attached patch, however I suspect we may need to make more changes to support this.

After testing and re-associating the network works fine, but in the wifi driver I see it takes three seconds to switch from run to init, this part is not open source, can you optimize this part of the operation.

I (2682) esp_netif_handlers: sta ip: [192.168.112.77](http://192.168.112.77/), mask: [255.255.255.0](http://255.255.255.0/), gw: [192.168.112.1](http://192.168.112.1/)
I (2682) wifi roaming app: got ip:[192.168.112.77](http://192.168.112.77/)
I (2682) wifi roaming app: connected to ap SSID:HC-C00X-huawei password:xxxxxxxx
I (2692) main_task: Returned from app_main()
I (60442) ROAM: roaming_app_rssi_low_handler:bss rssi is=-63
I (60442) ROAM: Issued Scan
I (60442) ROAM: Resetting RSSI Threshold to -67
I (61692) ROAM: Started the periodic scan roam event!
I (61692) ROAM: Triggered periodic rrm event!
I (62052) ROAM: Scan Done properly
I (62052) ROAM: Scanned AP List
I (62052) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -34 authmode : 3
I (62062) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -69 authmode : 3
I (62072) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-34,-73) is : 39 while the threshold is 0 and the best rssi diff yet is 0, thecand_auth is 3
I (62092) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-69,-73) is : 4 while the threshold is 0 and the best rssi diff yet is 39, thecand_auth is 3
I (62102) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (62112) ROAM: Processing trigger roaming request.
I (62122) ROAM: Sent BTM Query
I (62122) ROAM: Received cb for Neighbor Report Request
I (62122) ROAM: rrm: neighbor report len=1
E (62132) ROAM: RRM neighbor report is not valid
I (71692) ROAM: Started the periodic scan roam event!
I (71692) ROAM: Reset the low rssi threshold back to -62
I (81702) ROAM: Started the periodic scan roam event!
I (91702) ROAM: Started the periodic scan roam event!
I (101702) ROAM: Started the periodic scan roam event!
I (101702) ROAM: Issued Scan
I (103432) ROAM: Scan Done properly
I (103432) ROAM: Scanned AP List
I (103432) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -42 authmode : 3
I (103442) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -61 authmode : 3
I (103452) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-42,-67) is : 25 while the threshold is 14 and the best rssi diff yet is 14, thecand_auth is 3
I (103472) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-61,-67) is : 6 while the threshold is 14 and the best rssi diff yet is 25, thecand_auth is 3
I (103482) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (103492) ROAM: Processing trigger roaming request.
I (103502) ROAM: Sent BTM Query
I (111702) ROAM: Started the periodic scan roam event!
I (111702) ROAM: Issued Scan
I (113432) ROAM: Scan Done properly
I (113442) ROAM: Scanned AP List
I (113442) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -36 authmode : 3
I (113442) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -62 authmode : 3
I (113452) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-36,-64) is : 28 while the threshold is 14 and the best rssi diff yet is 14, thecand_auth is 3
I (113472) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-62,-64) is : 2 while the threshold is 14 and the best rssi diff yet is 28, thecand_auth is 3
I (113492) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (113492) ROAM: Processing trigger roaming request.
I (113502) ROAM: Not Sending BTM query as this method has failed too many times.
I (113512) wifi:state: run -> init (0xc00)
I (113512) wifi:pm stop, total sleep time: 94371401 us / 111984821 us

I (113522) wifi:<ba-del>idx:1, tid:0
I (113522) wifi:<ba-del>idx:0, tid:6
I (113522) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1, snd_ch_cfg:0x0
I (113532) ROAM: station got disconnected reason=207
I (113552) ROAM: station roaming, do nothing
I (113552) wifi roaming app: station disconnected during roaming
I (113552) ROAM: Disconnecting and connecting to 28:53:4e:f8:41:d0 on account of better rssi
I (113572) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (113572) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (113582) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (113582) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (113592) wifi:(phy)rx_mcs_map:0xfffa, tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1, max_rate:172
I (113602) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (113612) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (113612) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (113622) wifi:(opr)len:7, TWT Required:0, VHT Opr Info Present:0, 6GHz Opr Info Present:0, Co-Hosted BSS:0(max_indicator:0), Basic MCS and NSS:0xfffc
I (113632) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1023(0 us), ER-SU-Disable:0
I (113642) wifi:(opr)len:7, BSS Color:0, disabled:0, Partial BSS Color:0
I (113652) wifi:(spr)len:2, ctrl:0x10, PSR Disallowed:0, Non-SRG OBSS PD SR Disallowed:0
I (113662) wifi:(spr)len:2, ctrl:0x10, Non-SRG Offset Present:0, SRG Info Present:0
I (116302) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1, snd_ch_cfg:0x0
I (116302) wifi:(connect)dot11_authmode:0x3, pairwise_cipher:0x3, group_cipher:0x3
I (116302) wifi:state: init -> auth (0xb0)
I (116332) wifi:state: auth -> assoc (0x0)
I (116352) wifi:(assoc)RESP, Extended Capabilities length:8, operating_mode_notification:0
I (116352) wifi:(assoc)RESP, Extended Capabilities, MBSSID:0, TWT Responder:0, OBSS Narrow Bandwidth RU In OFDMA Tolerance:0
I (116362) wifi:Extended Capabilities length:8, operating_mode_notification:1
I (116372) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (116382) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (116382) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (116392) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (116402) wifi:(phy)rx_mcs_map:0xfffa, tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1, max_rate:172
I (116402) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (116412) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (116422) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (116432) wifi:(opr)len:7, TWT Required:0, VHT Opr Info Present:0, 6GHz Opr Info Present:0, Co-Hosted BSS:0(max_indicator:0), Basic MCS and NSS:0xfffc
I (116442) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1023(0 us), ER-SU-Disable:0
I (116452) wifi:(opr)len:7, BSS Color:0, disabled:0, Partial BSS Color:0
I (116462) wifi:state: assoc -> run (0x30)
I (116462) wifi:(he)ppe_thresholds_present:1, nominal_packet_padding(rx:0, cfg:2)
I (116472) wifi:(trc)phytype:CBW20-SGI, snr:61, maxRate:172, highestRateIdx:0
W (116472) wifi:(trc)band:2G, phymode:3, highestRateIdx:0, lowestRateIdx:11, dataSchedTableSize:14
I (116482) wifi:(trc)band:2G, rate(S-MCS7, rateIdx:0), ampdu(rate:S-MCS7, schedIdx(0, stop:8)), snr:61, ampduState:wait operational
I (116492) wifi:ifidx:0, rssi:-36, nf:-97, phytype(0x3, CBW20-SGI), phymode(0x7, 11ax), max_rate:172, he:1, vht:0, ht:1
I (116502) wifi:(ht)max.RxAMPDULenExponent:3(65535 bytes), MMSS:0(no restriction)
I (116542) wifi:(extcap)mbssid:0, enhanced_mbssid_advertise:0, complete_nontxbssid_profiles:0, twt_responder: 0
I (116542) wifi:connected with HC-C00X-huawei, aid = 1, channel 1, BW20, bssid = 28:53:4e:f8:41:d0
I (116552) wifi:cipher(pairwise:0x3, group:0x3), pmf:0, security:WPA2-PSK, phy:11ax, rssi:-36
I (116572) wifi:pm start, type: 1, twt_start:0

I (116572) wifi:pm start, type:1, aid:0x1, trans-BSSID:28:53:4e:f8:41:d0, BSSID[5]:0xd0, mbssid(max-indicator:0, index:0), he:1
I (116572) wifi:set rx beacon pti, rx_bcn_pti: 10, bcn_timeout: 25000, mt_pti: 10, mt_time: 10000
I (116602) wifi:[ADDBA]TX addba request, tid:0, dialogtoken:4, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
I (116602) wifi:[ADDBA]TX addba request, tid:7, dialogtoken:5, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x20)
I (116612) wifi:[ADDBA]TX addba request, tid:5, dialogtoken:6, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
W (116622) wifi:<ba-add>idx:0, ifx:0, tid:6, TAHI:0x100d041, TALO:0xf84e5328, (ssn:2, win:64, cur_ssn:2), CONF:0xc0006005
I (116642) wifi:[ADDBA]RX addba response, status:0, tid:0/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116642) wifi:[ADDBA]RX addba response, status:0, tid:7/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116652) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (116662) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (116672) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (116672) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (116682) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (116692) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (116692) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (116702) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (116712) wifi:[ADDBA]RX addba response, status:0, tid:5/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116722) wifi:<ba-del>idx:0, tid:6
W (116722) wifi:<ba-add>idx:0, ifx:0, tid:6, TAHI:0x100d041, TALO:0xf84e5328, (ssn:2, win:64, cur_ssn:2), CONF:0xc0006005
I (116742) ROAM: setting rssi threshold as -62
I (116742) ROAM: Station connected, RRM  supported, BTM  supported
I (116742) ROAM: cleared bssid flag
I (116752) ROAM: Initialised initialise roaming events!
I (121702) ROAM: Triggered periodic rrm event!
I (121702) ROAM: Started the periodic scan roam event!
I (121712) ROAM: Received cb for Neighbor Report Request
I (121712) ROAM: rrm: neighbor report len=1
E (121712) ROAM: RRM neighbor report is not valid
I (126752) ROAM: Started the periodic scan roam event!
I (131702) ROAM: Started the periodic scan roam event!
I (136752) ROAM: Started the periodic scan roam event!
I (141702) ROAM: Started the periodic scan roam event!
I (146752) ROAM: Started the periodic scan roam event!
I (151702) ROAM: Started the periodic scan roam event!
I (156752) ROAM: Started the periodic scan roam event!
I (161702) ROAM: Started the periodic scan roam event!
I (166752) ROAM: Started the periodic scan roam event!
I (171702) ROAM: Started the periodic scan roam event!
I (176752) ROAM: Triggered periodic rrm event!
I (176752) ROAM: Started the periodic scan roam event!
I (176762) ROAM: Received cb for Neighbor Report Request
I (176762) ROAM: rrm: neighbor report len=1
E (176762) ROAM: RRM neighbor report is not valid
hongquan-prog commented 1 week ago

test.patch Could you try attached patch, however I suspect we may need to make more changes to support this.

After testing and re-associating the network works fine, but in the wifi driver I see it takes three seconds to switch from run to init, this part is not open source, can you optimize this part of the operation.

I (2682) esp_netif_handlers: sta ip: [192.168.112.77](http://192.168.112.77/), mask: [255.255.255.0](http://255.255.255.0/), gw: [192.168.112.1](http://192.168.112.1/)
I (2682) wifi roaming app: got ip:[192.168.112.77](http://192.168.112.77/)
I (2682) wifi roaming app: connected to ap SSID:HC-C00X-huawei password:xxxxxxxx
I (2692) main_task: Returned from app_main()
I (60442) ROAM: roaming_app_rssi_low_handler:bss rssi is=-63
I (60442) ROAM: Issued Scan
I (60442) ROAM: Resetting RSSI Threshold to -67
I (61692) ROAM: Started the periodic scan roam event!
I (61692) ROAM: Triggered periodic rrm event!
I (62052) ROAM: Scan Done properly
I (62052) ROAM: Scanned AP List
I (62052) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -34 authmode : 3
I (62062) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -69 authmode : 3
I (62072) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-34,-73) is : 39 while the threshold is 0 and the best rssi diff yet is 0, thecand_auth is 3
I (62092) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-69,-73) is : 4 while the threshold is 0 and the best rssi diff yet is 39, thecand_auth is 3
I (62102) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (62112) ROAM: Processing trigger roaming request.
I (62122) ROAM: Sent BTM Query
I (62122) ROAM: Received cb for Neighbor Report Request
I (62122) ROAM: rrm: neighbor report len=1
E (62132) ROAM: RRM neighbor report is not valid
I (71692) ROAM: Started the periodic scan roam event!
I (71692) ROAM: Reset the low rssi threshold back to -62
I (81702) ROAM: Started the periodic scan roam event!
I (91702) ROAM: Started the periodic scan roam event!
I (101702) ROAM: Started the periodic scan roam event!
I (101702) ROAM: Issued Scan
I (103432) ROAM: Scan Done properly
I (103432) ROAM: Scanned AP List
I (103432) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -42 authmode : 3
I (103442) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -61 authmode : 3
I (103452) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-42,-67) is : 25 while the threshold is 14 and the best rssi diff yet is 14, thecand_auth is 3
I (103472) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-61,-67) is : 6 while the threshold is 14 and the best rssi diff yet is 25, thecand_auth is 3
I (103482) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (103492) ROAM: Processing trigger roaming request.
I (103502) ROAM: Sent BTM Query
I (111702) ROAM: Started the periodic scan roam event!
I (111702) ROAM: Issued Scan
I (113432) ROAM: Scan Done properly
I (113442) ROAM: Scanned AP List
I (113442) ROAM: 0. ssid : HC-C00X-huawei bssid :28:53:4e:f8:41:d0  channel : 1 rssi : -36 authmode : 3
I (113442) ROAM: 1. ssid : HC-C00X-huawei bssid :28:53:4e:f8:64:50  channel : 1 rssi : -62 authmode : 3
I (113452) ROAM: The difference between (28:53:4e:f8:41:d0, 28:53:4e:f8:64:50) with rssi (-36,-64) is : 28 while the threshold is 14 and the best rssi diff yet is 14, thecand_auth is 3
I (113472) ROAM: The difference between (28:53:4e:f8:64:50, 28:53:4e:f8:64:50) with rssi (-62,-64) is : 2 while the threshold is 14 and the best rssi diff yet is 28, thecand_auth is 3
I (113492) ROAM: Found a better AP 28:53:4e:f8:41:d0 at channel 1
I (113492) ROAM: Processing trigger roaming request.
I (113502) ROAM: Not Sending BTM query as this method has failed too many times.
I (113512) wifi:state: run -> init (0xc00)
I (113512) wifi:pm stop, total sleep time: 94371401 us / 111984821 us

I (113522) wifi:<ba-del>idx:1, tid:0
I (113522) wifi:<ba-del>idx:0, tid:6
I (113522) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1, snd_ch_cfg:0x0
I (113532) ROAM: station got disconnected reason=207
I (113552) ROAM: station roaming, do nothing
I (113552) wifi roaming app: station disconnected during roaming
I (113552) ROAM: Disconnecting and connecting to 28:53:4e:f8:41:d0 on account of better rssi
I (113572) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (113572) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (113582) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (113582) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (113592) wifi:(phy)rx_mcs_map:0xfffa, tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1, max_rate:172
I (113602) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (113612) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (113612) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (113622) wifi:(opr)len:7, TWT Required:0, VHT Opr Info Present:0, 6GHz Opr Info Present:0, Co-Hosted BSS:0(max_indicator:0), Basic MCS and NSS:0xfffc
I (113632) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1023(0 us), ER-SU-Disable:0
I (113642) wifi:(opr)len:7, BSS Color:0, disabled:0, Partial BSS Color:0
I (113652) wifi:(spr)len:2, ctrl:0x10, PSR Disallowed:0, Non-SRG OBSS PD SR Disallowed:0
I (113662) wifi:(spr)len:2, ctrl:0x10, Non-SRG Offset Present:0, SRG Info Present:0
I (116302) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1, snd_ch_cfg:0x0
I (116302) wifi:(connect)dot11_authmode:0x3, pairwise_cipher:0x3, group_cipher:0x3
I (116302) wifi:state: init -> auth (0xb0)
I (116332) wifi:state: auth -> assoc (0x0)
I (116352) wifi:(assoc)RESP, Extended Capabilities length:8, operating_mode_notification:0
I (116352) wifi:(assoc)RESP, Extended Capabilities, MBSSID:0, TWT Responder:0, OBSS Narrow Bandwidth RU In OFDMA Tolerance:0
I (116362) wifi:Extended Capabilities length:8, operating_mode_notification:1
I (116372) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (116382) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (116382) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (116392) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (116402) wifi:(phy)rx_mcs_map:0xfffa, tx_mcs_map:0xfffa, stbc_tx:1, bfmer(su:1, mu:1), ldpc:1, max_rate:172
I (116402) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (116412) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (116422) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (116432) wifi:(opr)len:7, TWT Required:0, VHT Opr Info Present:0, 6GHz Opr Info Present:0, Co-Hosted BSS:0(max_indicator:0), Basic MCS and NSS:0xfffc
I (116442) wifi:(opr)len:7, Default PE Duration:4, TXOP RTS Threshold:1023(0 us), ER-SU-Disable:0
I (116452) wifi:(opr)len:7, BSS Color:0, disabled:0, Partial BSS Color:0
I (116462) wifi:state: assoc -> run (0x30)
I (116462) wifi:(he)ppe_thresholds_present:1, nominal_packet_padding(rx:0, cfg:2)
I (116472) wifi:(trc)phytype:CBW20-SGI, snr:61, maxRate:172, highestRateIdx:0
W (116472) wifi:(trc)band:2G, phymode:3, highestRateIdx:0, lowestRateIdx:11, dataSchedTableSize:14
I (116482) wifi:(trc)band:2G, rate(S-MCS7, rateIdx:0), ampdu(rate:S-MCS7, schedIdx(0, stop:8)), snr:61, ampduState:wait operational
I (116492) wifi:ifidx:0, rssi:-36, nf:-97, phytype(0x3, CBW20-SGI), phymode(0x7, 11ax), max_rate:172, he:1, vht:0, ht:1
I (116502) wifi:(ht)max.RxAMPDULenExponent:3(65535 bytes), MMSS:0(no restriction)
I (116542) wifi:(extcap)mbssid:0, enhanced_mbssid_advertise:0, complete_nontxbssid_profiles:0, twt_responder: 0
I (116542) wifi:connected with HC-C00X-huawei, aid = 1, channel 1, BW20, bssid = 28:53:4e:f8:41:d0
I (116552) wifi:cipher(pairwise:0x3, group:0x3), pmf:0, security:WPA2-PSK, phy:11ax, rssi:-36
I (116572) wifi:pm start, type: 1, twt_start:0

I (116572) wifi:pm start, type:1, aid:0x1, trans-BSSID:28:53:4e:f8:41:d0, BSSID[5]:0xd0, mbssid(max-indicator:0, index:0), he:1
I (116572) wifi:set rx beacon pti, rx_bcn_pti: 10, bcn_timeout: 25000, mt_pti: 10, mt_time: 10000
I (116602) wifi:[ADDBA]TX addba request, tid:0, dialogtoken:4, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
I (116602) wifi:[ADDBA]TX addba request, tid:7, dialogtoken:5, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x20)
I (116612) wifi:[ADDBA]TX addba request, tid:5, dialogtoken:6, bufsize:32, A-MSDU:0(not supported), policy:1(IMR), ssn:0(0x0)
W (116622) wifi:<ba-add>idx:0, ifx:0, tid:6, TAHI:0x100d041, TALO:0xf84e5328, (ssn:2, win:64, cur_ssn:2), CONF:0xc0006005
I (116642) wifi:[ADDBA]RX addba response, status:0, tid:0/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116642) wifi:[ADDBA]RX addba response, status:0, tid:7/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116652) wifi:AP's beacon interval = 102400 us, DTIM period = 1
I (116662) wifi:(he)max.RxAMPDULenExponentExtension:3, max.RxAMPDUpre-EOFpaddingBytes:8388607(0x7fffff)
I (116672) wifi:(mac)omc_ul_mu_data_disable_rx:0
I (116672) wifi:(phy)ppe_thresholds_present:1, nominal_packet_padding:0
I (116682) wifi:(phy)dcm tx(constellation:0, nss:0), dcm rx(constellation:0, nss:1)
I (116692) wifi:(phy)nsts:2, ru_index_bitmap:0x3(242:1, 484:1, 996:0, 2*996:0)
I (116692) wifi:(phy)threshold_bits:24, nsts_num:2, ru_num:2, he_cap->len:26, ppe_threshold_len:4(6,11,4)
I (116702) wifi:(ppe)RU242, NSTS0, PPE16:0, PPE8:7, nominal_packet_padding:2
I (116712) wifi:[ADDBA]RX addba response, status:0, tid:5/tb:1(0xa1), bufsize:32, batimeout:0, txa_wnd:32
I (116722) wifi:<ba-del>idx:0, tid:6
W (116722) wifi:<ba-add>idx:0, ifx:0, tid:6, TAHI:0x100d041, TALO:0xf84e5328, (ssn:2, win:64, cur_ssn:2), CONF:0xc0006005
I (116742) ROAM: setting rssi threshold as -62
I (116742) ROAM: Station connected, RRM  supported, BTM  supported
I (116742) ROAM: cleared bssid flag
I (116752) ROAM: Initialised initialise roaming events!
I (121702) ROAM: Triggered periodic rrm event!
I (121702) ROAM: Started the periodic scan roam event!
I (121712) ROAM: Received cb for Neighbor Report Request
I (121712) ROAM: rrm: neighbor report len=1
E (121712) ROAM: RRM neighbor report is not valid
I (126752) ROAM: Started the periodic scan roam event!
I (131702) ROAM: Started the periodic scan roam event!
I (136752) ROAM: Started the periodic scan roam event!
I (141702) ROAM: Started the periodic scan roam event!
I (146752) ROAM: Started the periodic scan roam event!
I (151702) ROAM: Started the periodic scan roam event!
I (156752) ROAM: Started the periodic scan roam event!
I (161702) ROAM: Started the periodic scan roam event!
I (166752) ROAM: Started the periodic scan roam event!
I (171702) ROAM: Started the periodic scan roam event!
I (176752) ROAM: Triggered periodic rrm event!
I (176752) ROAM: Started the periodic scan roam event!
I (176762) ROAM: Received cb for Neighbor Report Request
I (176762) ROAM: rrm: neighbor report len=1
E (176762) ROAM: RRM neighbor report is not valid

@kapilkedawat Is there a solution to this problem?

Shreyas0-7 commented 1 week ago

Hey @hongquan-prog sorry for delay in response. If the issue is easily reproducible, can you please enable debug and supplicant logs and share the results.