search

espressif / esp-idf

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

In AP+STA mode joining to AP causes disconnection of STA joined to ESP32. (IDFGH-6933) #8553

Closed sakamoto330 closed 1 year ago

sakamoto330 commented 2 years ago

Environment

Problem Description

In AP+STA mode joining to AP(router) causes disconnection of STA (PC etc.) joined to AP (ESP32).

Issue

Connection of STA (PC etc.) joined to AP (ESP32) will lost. It is the part of "/// STA (PC etc.) disconnects from AP (ESP32) ///" described in the Debug Logs.

Expected Behavior

STAs (PC etc.) joined to AP (ESP32) keep connection.

Steps to reproduce

  1. Boot in AP+STA mode.
  2. Join to AP (ESP32) from STA (PC etc.).
  3. Connect to AP (router) with STA (ESP32)

Code to reproduce this issue

    ESP_ERROR_CHECK(esp_netif_init());
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    esp_netif_create_default_wifi_ap();
    esp_netif_create_default_wifi_sta();
    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK(esp_wifi_init(&cfg));

    wifi_config_t wifi_config = {
            .sta = {
                    .bssid_set = false,
                    .ssid = "logitec62",
                    .password = "abcd1234",
                    .threshold.authmode = WIFI_AUTH_WPA2_PSK
                    }
    };
    wifi_config_t wifi_config1 = {
            .ap = {
                    .ssid = "123",
                    .password = "abcd1234",
                    .max_connection = 10,
                    .authmode = WIFI_AUTH_WPA_WPA2_PSK
            }
    };
    ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_APSTA));
    ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_STA, &wifi_config));
    ESP_ERROR_CHECK(esp_wifi_set_config(WIFI_IF_AP, &wifi_config1));
    ESP_ERROR_CHECK(esp_wifi_start());

    vTaskDelay(60000); // connect to AP with STA during delay.

    ESP_ERROR_CHECK(esp_wifi_connect()); // The issue occurs when this function is called.

Debug Logs

[2022-03-10 16:59:15.681] I (8899) pp: pp rom version: e7ae62f
[2022-03-10 16:59:15.681] I (8899) net80211: net80211 rom version: e7ae62f
[2022-03-10 16:59:15.686] I (8901) wifi:wifi driver task: 3fca27bc, prio:23, stack:6656, core=0
[2022-03-10 16:59:15.694] I (8904) system_api: Base MAC address is not set
[2022-03-10 16:59:15.698] I (8909) system_api: read default base MAC address from EFUSE
[2022-03-10 16:59:15.715] I (8932) wifi:wifi firmware version: 63017e0
[2022-03-10 16:59:15.715] I (8932) wifi:wifi certification version: v7.0
[2022-03-10 16:59:15.720] I (8932) wifi:config NVS flash: enabled
[2022-03-10 16:59:15.728] I (8932) wifi:config nano formating: disabled
[2022-03-10 16:59:15.728] I (8937) wifi:Init data frame dynamic rx buffer num: 32
[2022-03-10 16:59:15.731] I (8942) wifi:Init management frame dynamic rx buffer num: 32
[2022-03-10 16:59:15.737] I (8947) wifi:Init management short buffer num: 32
[2022-03-10 16:59:15.744] I (8952) wifi:Init static tx buffer num: 16
[2022-03-10 16:59:15.748] I (8956) wifi:Init tx cache buffer num: 32
[2022-03-10 16:59:15.748] I (8959) wifi:Init static tx FG buffer num: 2
[2022-03-10 16:59:15.753] I (8963) wifi:Init static rx buffer size: 1600
[2022-03-10 16:59:15.761] I (8968) wifi:Init static rx buffer num: 10
[2022-03-10 16:59:15.764] I (8971) wifi:Init dynamic rx buffer num: 32
[2022-03-10 16:59:15.764] I (8976) wifi_init: rx ba win: 6
[2022-03-10 16:59:15.769] I (8979) wifi_init: tcpip mbox: 32
[2022-03-10 16:59:15.777] I (8983) wifi_init: udp mbox: 6
[2022-03-10 16:59:15.780] I (8987) wifi_init: tcp mbox: 6
[2022-03-10 16:59:15.780] I (8991) wifi_init: tcp tx win: 5744
[2022-03-10 16:59:15.786] I (8995) wifi_init: tcp rx win: 5744
[2022-03-10 16:59:15.792] I (8999) wifi_init: tcp mss: 1440
[2022-03-10 16:59:15.798] I (9003) wifi_init: WiFi IRAM OP enabled
[2022-03-10 16:59:15.798] I (9008) wifi_init: WiFi RX IRAM OP enabled
[2022-03-10 16:59:15.803] I (9019) phy_init: phy_version 402,fbd66bc,Jan 28 2022,11:04:07
[2022-03-10 16:59:15.879] I (9096) wifi:mode : sta (7c:df:a1:e0:5a:48) + softAP (7c:df:a1:e0:5a:49)
[2022-03-10 16:59:15.887] I (9097) wifi:enable tsf
[2022-03-10 16:59:15.887] I (9100) wifi:Total power save buffer number: 8
[2022-03-10 16:59:15.895] I (9100) wifi:Init max length of beacon: 752/752
[2022-03-10 16:59:15.900] I (9103) wifi:Init max length of beacon: 752/752
////////////////////////////////// AP+STA mode started ///////////////////////////////////
[2022-03-10 16:59:22.548] I (15765) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
[2022-03-10 16:59:22.555] I (15765) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40U
[2022-03-10 16:59:23.003] I (16219) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2
[2022-03-10 16:59:27.226] W (20444) wifi:<ba-add>idx:2 (ifx:1, c8:09:a8:7e:fa:bd), tid:0, ssn:159, winSize:64
////////////////////////////////// join to AP (ESP32) from STA (PC etc.)  ///////////////////////////////////
[2022-03-10 17:00:16.352] I (69566) wifi:switch to channel 13
[2022-03-10 17:00:16.352] I (69566) wifi:ap channel adjust o:1,1 n:13,2
[2022-03-10 17:00:16.358] I (69566) wifi:new:<13,0>, old:<1,1>, ap:<13,2>, sta:<0,0>, prof:1
[2022-03-10 17:00:16.360] I (69569) wifi:new:<13,2>, old:<13,0>, ap:<13,2>, sta:<13,0>, prof:1
[2022-03-10 17:00:16.365] I (69575) wifi:state: init -> auth (b0)
[2022-03-10 17:00:16.370] I (69585) wifi:state: auth -> assoc (0)
[2022-03-10 17:00:16.370] I (69590) wifi:state: assoc -> run (10)
[2022-03-10 17:00:16.390] I (69608) wifi:connected with logitec62, aid = 1, channel 13, BW20, bssid = 00:01:8e:9a:6d:3b
[2022-03-10 17:00:16.396] I (69609) wifi:security: WPA2-PSK, phy: bgn, rssi: -28
[2022-03-10 17:00:16.402] I (69614) wifi:pm start, type: 1
[2022-03-10 17:00:16.402] I (69614) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000
[2022-03-10 17:00:16.460] I (69677) wifi:BcnInt:102400, DTIM:1
[2022-03-10 17:00:17.179] I (70397) esp_netif_handlers: sta ip: 192.168.2.100, mask: 255.255.255.0, gw: 192.168.2.1
[2022-03-10 17:00:18.269] W (71485) wifi:<ba-del>idx
[2022-03-10 17:00:18.269] I (71486) wifi:new:<13,2>, old:<13,2>, ap:<13,2>, sta:<13,0>, prof:1
////////////////////////////////// Join to AP (ESP32) from STA (PC etc.)  ///////////////////////////////////
[2022-03-10 17:00:18.273] I (71486) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40D
[2022-03-10 17:00:22.273] I (75491) wifi:station: c8:09:a8:7e:fa:bd leave, AID = 1, bss_flags is 658530, bss:0x3fcae534
////////////////////////////////// STA (PC etc.) disconnects from AP (ESP32)  ///////////////////////////////////
[2022-03-10 17:00:22.280] I (75492) wifi:new:<13,0>, old:<13,2>, ap:<13,2>, sta:<13,0>, prof:1
[2022-03-10 17:00:22.337] I (75555) wifi:new:<13,2>, old:<13,0>, ap:<13,2>, sta:<13,0>, prof:1
[2022-03-10 17:00:22.344] I (75557) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40D
[2022-03-10 17:00:22.382] I (75599) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2
[2022-03-10 17:00:40.003] W (93218) wifi:<ba-add>idx:2 (ifx:1, c8:09:a8:7e:fa:bd), tid:0, ssn:244, winSize:64
////////////////////////////////// STA (PC etc.) reconnects to the AP (ESP32) automaticaly  ///////////////////////////////////
nishanth-radja commented 2 years ago

@sakamoto330 Since the ESP32-AP switches channel from channel 1 to channel 13 after the ESP32 client connects to the "logitec62", Other clients that are connected to the ESP32-AP will go for a background scan and automatically start listening to the current channel of the ESP32-AP. If the STA does not go for scan in all the channels,It will disconnect and start a fresh scan and connect. are all the client you have used,disconnect and connect back or is it only some of them,Can you mention the details of the STA that disconnected and reconnected back to the ESP32-AP,what was the laptop make and the OS used, Can we have a sniffer capture on channel 1 and channel 13 to see if any deauth was sent .

sakamoto330 commented 2 years ago

@nishanth-radja Thanks! Actually, ”ESP-IDF Programming Guide” has the following description.

  1. ESP32 is limited to only one channel, so when in the soft-AP+station mode, the soft-AP will adjust its channel automatically to be the same as the channel of the ESP32 station.

URL https://docs.espressif.com/projects/esp-idf/en/latest/esp32s3/api-reference/network/esp_wifi.html?highlight=wifi#c.ESP_ERR_WIFI_POST

My laptop information: OS : Windows10 Home manufacturer : Dynabook Inc. Model number : P1-X4JP-EG

Sorry, I could not do sniffer capture on channel 1 and channel 13 in my environment. If any deauth has been sent, is this issue as expected phenomenon? Is it inevitable this issue because it is the effect of automatically adjusting the channel?

sakamoto330 commented 2 years ago

When I unify the channel to 1ch so thatthe channel did not automatically change from 1ch to 13ch, the disconnection did not occur.

nishanth-radja commented 2 years ago

@sakamoto330 when the AP changes channel,It displays a channel switch announcement in beacon ,To help the client shift to the channel easily. image

The client should be able to understand it and move to the new channel without disconnection. instead of 13, can you see if the issue occurs when the AP shifts from channel 1 to channel 11. if we can get the beacons of AP on channel 1 before it changes to another channel,We will be able to see if its including the channel switch announcement or not. I have tried the Issue on commit "121ddb87e5130314e4fcc5e9cb260a81b7d30d36" on both ESP32 and ESP32 S3 ,both of them had a channel switch announcement.

Can you enable the wpa_supplicant logs and mbedtls logs and try switching between channel 1 to channel 11.

sakamoto330 commented 2 years ago

Thanks!

I enabled wpa_supplicant logging and mbedtls logging and tried switching from channel 1 to channel 11, but it looks like the log is not displayed. And the same issue has occurred. I added below code, is it correct?

sdkconfig.h

#define CONFIG_MBEDTLS_DEBUG 1
#define CONFIG_MBEDTLS_DEBUG_LEVEL_VERBOSE 1
#define CONFIG_MBEDTLS_DEBUG_LEVEL 4

#define CONFIG_WPA_DEBUG_PRINT 1

main code

esp_log_level_set("*", ESP_LOG_VERBOSE);

log

[2022-03-29 16:43:28.839] I (8908) pp: pp rom version: e7ae62f
[2022-03-29 16:43:28.848] I (8909) net80211: net80211 rom version: e7ae62f
[2022-03-29 16:43:28.853] I (8911) wifi:wifi driver task: 3fca4a7c, prio:23, stack:6656, core=0
[2022-03-29 16:43:28.859] I (8922) system_api: Base MAC address is not set
[2022-03-29 16:43:28.863] I (8923) system_api: read default base MAC address from EFUSE
[2022-03-29 16:43:28.881] I (8951) wifi:wifi firmware version: 7679c42
[2022-03-29 16:43:28.881] I (8952) wifi:wifi certification version: v7.0
[2022-03-29 16:43:28.887] I (8952) wifi:config NVS flash: enabled
[2022-03-29 16:43:28.893] I (8953) wifi:config nano formating: disabled
[2022-03-29 16:43:28.893] I (8964) wifi:Init data frame dynamic rx buffer num: 32
[2022-03-29 16:43:28.898] I (8965) wifi:Init management frame dynamic rx buffer num: 32
[2022-03-29 16:43:28.903] I (8976) wifi:Init management short buffer num: 32
[2022-03-29 16:43:28.908] I (8977) wifi:Init static tx buffer num: 16
[2022-03-29 16:43:28.914] I (8978) wifi:Init tx cache buffer num: 32
[2022-03-29 16:43:28.914] I (8979) wifi:Init static tx FG buffer num: 2
[2022-03-29 16:43:28.920] I (8990) wifi:Init static rx buffer size: 1600
[2022-03-29 16:43:28.925] I (8991) wifi:Init static rx buffer num: 10
[2022-03-29 16:43:28.931] I (8992) wifi:Init dynamic rx buffer num: 32
[2022-03-29 16:43:28.931] I (9003) wifi_init: rx ba win: 6
[2022-03-29 16:43:28.937] I (9004) wifi_init: tcpip mbox: 32
[2022-03-29 16:43:28.942] I (9005) wifi_init: udp mbox: 6
[2022-03-29 16:43:28.947] I (9016) wifi_init: tcp mbox: 6
[2022-03-29 16:43:28.947] I (9016) wifi_init: tcp tx win: 5744
[2022-03-29 16:43:28.953] I (9017) wifi_init: tcp rx win: 5744
[2022-03-29 16:43:28.959] I (9028) wifi_init: tcp mss: 1440
[2022-03-29 16:43:28.964] I (9029) wifi_init: WiFi IRAM OP enabled
[2022-03-29 16:43:28.964] I (9029) wifi_init: WiFi RX IRAM OP enabled
[2022-03-29 16:43:28.976] I (9046) phy_init: phy_version 302,3ddfab3,Dec  3 2021,14:39:12
[2022-03-29 16:43:29.026] I (9095) wifi:mode : sta (7c:df:a1:e0:5a:48) + softAP (7c:df:a1:e0:5a:49)
[2022-03-29 16:43:29.033] I (9097) wifi:enable tsf
[2022-03-29 16:43:29.033] I (9101) wifi:Total power save buffer number: 8
[2022-03-29 16:43:29.038] I (9103) wifi:Init max length of beacon: 752/752
[2022-03-29 16:43:29.047] I (9104) wifi:Init max length of beacon: 752/752
////////////////////////////////// AP+STA mode started ///////////////////////////////////
[2022-03-29 16:43:34.967] I (15036) wifi:new:<1,1>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
[2022-03-29 16:43:34.974] I (15037) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40U
[2022-03-29 16:43:35.329] I (15398) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2
[2022-03-29 16:43:37.809] W (17878) wifi:<ba-add>idx:2 (ifx:1, c8:09:a8:7e:fa:bd), tid:0, ssn:100, winSize:64
////////////////////////////////// join to AP (ESP32) from STA (PC etc.)  ///////////////////////////////////
[2022-03-29 16:44:29.483] I (69549) wifi:switch to channel 11
[2022-03-29 16:44:29.483] I (69550) wifi:ap channel adjust o:1,1 n:11,2
[2022-03-29 16:44:29.488] I (69551) wifi:new:<11,0>, old:<1,1>, ap:<11,2>, sta:<0,0>, prof:1
[2022-03-29 16:44:29.491] I (69553) wifi:new:<11,2>, old:<11,0>, ap:<11,2>, sta:<11,0>, prof:1
[2022-03-29 16:44:29.496] I (69564) wifi:state: init -> auth (b0)
[2022-03-29 16:44:29.504] I (69568) wifi:state: auth -> assoc (0)
[2022-03-29 16:44:29.504] I (69574) wifi:state: assoc -> run (10)
[2022-03-29 16:44:29.524] I (69594) wifi:connected with logitec62, aid = 1, channel 11, BW20, bssid = 00:01:8e:9a:6d:3b
[2022-03-29 16:44:29.531] I (69596) wifi:security: WPA2-PSK, phy: bgn, rssi: -32
[2022-03-29 16:44:29.537] I (69601) wifi:pm start, type: 1
[2022-03-29 16:44:29.537] I (69602) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000
[2022-03-29 16:44:29.591] I (69659) wifi:BcnInt:102400, DTIM:1
[2022-03-29 16:44:30.339] I (70407) esp_netif_handlers: sta ip: 192.168.2.101, mask: 255.255.255.0, gw: 192.168.2.1
[2022-03-29 16:44:31.239] W (71307) wifi:<ba-del>idx
[2022-03-29 16:44:31.239] I (71308) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:1
////////////////////////////////// Join to AP (ESP32) from STA (PC etc.)  ///////////////////////////////////
[2022-03-29 16:44:31.244] I (71309) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40D
[2022-03-29 16:44:35.255] I (75323) wifi:station: c8:09:a8:7e:fa:bd leave, AID = 1, bss_flags is 658530, bss:0x3fcae81c
////////////////////////////////// STA (PC etc.) disconnects from AP (ESP32)  ///////////////////////////////////
[2022-03-29 16:44:35.260] I (75325) wifi:new:<11,0>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:1
[2022-03-29 16:44:35.330] I (75398) wifi:new:<11,2>, old:<11,0>, ap:<11,2>, sta:<11,0>, prof:1
[2022-03-29 16:44:35.338] I (75400) wifi:station: c8:09:a8:7e:fa:bd join, AID=1, bgn, 40D
[2022-03-29 16:44:35.380] I (75448) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2
[2022-03-29 16:44:51.249] W (91316) wifi:<ba-add>idx:2 (ifx:1, c8:09:a8:7e:fa:bd), tid:0, ssn:176, winSize:64
nishanth-radja commented 2 years ago

@sakamoto330 can you enable these in the sdkconfig, Also sniffer capture in channel 1 will be helpful when DUT changes from channel 1 to channel 11. can you edit the SDK config as shown below.

CONFIG_LOG_DEFAULT_LEVEL_VERBOSE=y CONFIG_LOG_DEFAULT_LEVEL=5 CONFIG_LOG_MAXIMUM_EQUALS_DEFAULT=y CONFIG_LOG_MAXIMUM_LEVEL=5 CONFIG_LOG_COLORS=y CONFIG_LOG_TIMESTAMP_SOURCE_RTOS=y

CONFIG_MBEDTLS_DEBUG=y CONFIG_MBEDTLS_DEBUG_LEVEL_VERBOSE=y CONFIG_MBEDTLS_DEBUG_LEVEL=4

CONFIG_WPA_DEBUG_PRINT=y

sakamoto330 commented 2 years ago

Thanks!

I edit the SDK config as shown below.

define CONFIG_LOG_DEFAULT_LEVEL_VERBOSE 1

define CONFIG_LOG_DEFAULT_LEVEL 5

define CONFIG_LOG_MAXIMUM_EQUALS_DEFAULT 1

define CONFIG_LOG_MAXIMUM_LEVEL 5

define CONFIG_LOG_COLORS 1

define CONFIG_LOG_TIMESTAMP_SOURCE_RTOS 1

define CONFIG_MBEDTLS_DEBUG 1

define CONFIG_MBEDTLS_DEBUG_LEVEL_VERBOSE 1

define CONFIG_MBEDTLS_DEBUG_LEVEL 4

define CONFIG_WPA_DEBUG_PRINT 1

I can get the log, so I attach it. ap_sta2.log

nishanth-radja commented 2 years ago

@sakamoto330 Thanks for the logs,From the logs,looks like the In-AP(ESP32AP) received an reassoc packet from client after it changed the channel.Hence the whole association happened again.

[2022-03-31 16:50:50.922] D (72506) wifi:ap recv assoc/reassoc request [2022-03-31 16:50:50.929] W (72507) wifi:idx [2022-03-31 16:50:50.929] I (72508) wifi:new:<11,2>, old:<11,2>, ap:<11,2>, sta:<11,0>, prof:1 [2022-03-31 16:50:50.933] D (72519) wifi:bss=0x3fcaea7c, resp=48 join

If we get the capture on channel 1,we can see if the ap is advertising the channel change,Even after advertising the channel change,If the external -STA chooses to re-associate,Then this behavior is expected.

sakamoto330 commented 2 years ago

Thanks! But, I could not do sniffer capture on channel 1 in my environment (windows10 and wireshark app). Is there any good way or reference URL?

And in the case of the above, is disconnection inevitable?

nishanth-radja commented 2 years ago

yes,It is inevitable,As STA has chosen to reconnect after the channel change. Can you try with an ESP32 client if it reconnects. Do you have any MAC or Linux machine? It is easier to start the sniffer on those and I can guide you for the same.

sakamoto330 commented 2 years ago

I see.

Can you try with an ESP32 client if it reconnects.

Sorry, I don't understand the procedure. For example, what should I do in "Steps to reproduce".

Do you have any MAC or Linux machine?

Yes, I have Linux machine (Ubuntu).

nishanth-radja commented 2 years ago

For the sniffer,Use the following script on ubuntu. 1.Install wireshark on ubuntu. https://linuxhint.com/install_configure_wireshark_ubuntu/ 2.Run the following script. killall wpa_supplicant ifconfig down iwconfig mode monitor ifconfig up iwconfig channel 1 wireshark

For the esp32 as client, 1.If you have 2 esp32's, use one as DUT mode 2.Use the other esp32 as client to connect to the In-AP of the DUT. you can use the example/wifi/getting_started/station example for the same. use idf.py menuconfig to configure the SSID and password. 3.Now connect the In-STA of DUT to the Ex-AP which is in channel 11. 4.The second esp32,acting as a client will automatically move to channel 11 without re connection.

sakamoto330 commented 2 years ago

Thanks! But sorry, WiFi didn't work on my Linux machine. Since it is a PC several years ago, some functions seem to be broken.

Also, I only have one ESP32.

I would like to confirm it at a later date.

sakamoto330 commented 2 years ago

when the AP changes channel,It displays a channel switch announcement in beacon ,To help the client shift to the channel easily.

We performed a packet capture in our environment and confirmed a channel switch announcement in beacon. I think that the disconnection is caused by the PC I was using.

Thanks for your cooperation.

Alvin1Zhang commented 1 year ago

Thanks for reporting and sharing the updates, feel free to reopen. Thanks.