espressif / esp-idf

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

Clients can't connect to ESP32 SoftAP. Not getting IP address (IDFGH-4256) #6108

Closed AxelLin closed 1 year ago

AxelLin commented 3 years ago

Environment

Problem Description

The ESP32 is running as SoftAP, sometimes my laptop joins the AP fails, sometimes join success seems success but cannot get IP address.

Below is one of the join failure log on my laptop: NetworkManager[729]: [1605173871.7544] device (wlp2s0): Activation: (wifi) access point 'ESP32_8C_6C' has security, but secrets are required. NetworkManager[729]: [1605173871.7544] device (wlp2s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed') NetworkManager[729]: [1605173871.7573] device (wlp2s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed') NetworkManager[729]: [1605173871.7593] device (wlp2s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed') NetworkManager[729]: [1605173871.7596] device (wlp2s0): Activation: (wifi) connection 'ESP32_8C_6C' has security, and secrets exist. No new secrets needed. NetworkManager[729]: [1605173876.7903] device (wlp2s0): supplicant interface state: disconnected -> scanning NetworkManager[729]: [1605173881.6559] device (wlp2s0): supplicant interface state: scanning -> authenticating NetworkManager[729]: [1605173881.6661] device (wlp2s0): supplicant interface state: authenticating -> associating NetworkManager[729]: [1605173881.6822] device (wlp2s0): supplicant interface state: associating -> associated NetworkManager[729]: [1605173881.6991] device (wlp2s0): supplicant interface state: associated -> 4-way handshake NetworkManager[729]: [1605173881.7071] device (wlp2s0): supplicant interface state: 4-way handshake -> completed NetworkManager[729]: [1605173881.7072] device (wlp2s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "ESP32_8C_6C" NetworkManager[729]: [1605173881.7079] device (wlp2s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed') NetworkManager[729]: [1605173881.7095] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds) NetworkManager[729]: [1605173926.7282] dhcp4 (wlp2s0): request timed out NetworkManager[729]: [1605173926.7283] dhcp4 (wlp2s0): state changed unknown -> timeout NetworkManager[729]: [1605173926.7285] device (wlp2s0): state change: ip-config -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed') NetworkManager[729]: [1605173926.7321] device (wlp2s0): Activation: failed for connection 'ESP32_8C_6C' NetworkManager[729]: [1605173926.7325] device (wlp2s0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed') NetworkManager[729]: [1605173926.7351] dhcp4 (wlp2s0): canceled DHCP transaction NetworkManager[729]: [1605173926.7352] dhcp4 (wlp2s0): state changed timeout -> done NetworkManager[729]: [1605173926.7611] sup-iface[0x558f016c8120,wlp2s0]: connection disconnected (reason -3) NetworkManager[729]: [1605173926.7622] device (wlp2s0): supplicant interface state: completed -> disconnected

Expected Behavior

The laptop should be able to join ESP32 softap and get IP address.

Actual Behavior

Sometimes failed to join AP, sometimes fail to get IP address.

Steps to reproduce

I don't have good way to reproduce this issue, it just happen sometimes. This issue was also reported by different people on https://www.esp32.com/viewtopic.php?f=13&t=13748 Also note my device running the latest esp-idf v4.3-dev-1720-g494a124d961c hit this issue, but I recall also hit the same issue will older esp-idf versions.

YouDONG-ESP commented 3 years ago

HI @AxelLin , could you show me the log of ESP32? Thanks.

AxelLin commented 3 years ago

I didn't save the log, but I remember ESP32 does not show anything wrong. Will update if I hit the issue again.

When join success but client does not get IP, it looks like the same as reported on https://www.esp32.com/viewtopic.php?f=13&t=13748 the ESP32 shows SYSTEM_EVENT_AP_STAIPASSIGNED, but the client (my linux laptop) does not get ip.

YouDONG-ESP commented 3 years ago

@AxelLin It is hard to debug just by this information. Is this issue often happens? Could you try to reproduce it and provide us a paket capture and the log?

AxelLin commented 3 years ago

Hi @YouDONG-ESP

It's indeed not easy to reproduce. I only hit a few times in the past months. (I didn't test softAP frequently, most of my testing is on STA mode) I even didn't realize it could be something wrong until I found someone reports the same symptoms on the forum. I don't see any error messages on ESP32 when the issue happen, so I guess most people just reset device when hit the issue. Maybe someone else can provide more detail information...

YouDONG-ESP commented 3 years ago

@AxelLin yeah, we had fixed some related issues, but the causes are different, I suggest you update IDF and see if this issue reproduce. It may relate to your device, can you provde the model of your laptop and network adapter?

ScottBonomi commented 3 years ago

I can provide a wireshark capture and associated log files as needed. I thought. Getting wireshark to record activity prior to a connection is failing. I have a log file with almost everything turned on. Still looking for a way to capture the pre-connection packets. Lots of no relevant data in the file, not connected to remote devices.

SB_P70_TurboLog_20201120_131933.log

YouDONG-ESP commented 3 years ago

Hi @ScottBonomi suggest you open a new issue, it seems like something went wrong in 4-way handshake.

MightyPork commented 3 years ago

I just had the same issue in v4.1, the esp's DHCP server appeared to not hand out IPs.

In my case, it was caused by the AP's WPA2 password being too short, at least that's what I think. It started working after I made it longer, and set ssid_len to the correct value (not zero).

btw, esp_wifi_set_config returned undefined error 11, but the invalid config was still saved (?)

YouDONG-ESP commented 3 years ago

@MightyPork It might happens depanding on scenarios, could you show me the steps to reproduce this error codes, I will take a look.

MightyPork commented 3 years ago

@YouDONG-ESP This should give you error 11:

ESP_ERROR_CHECK(esp_netif_init());
esp_netif_create_default_wifi_sta();
esp_netif_create_default_wifi_ap();
wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
ESP_ERROR_CHECK(esp_wifi_init(&cfg));
ESP_ERROR_CHECK(esp_wifi_set_storage(WIFI_STORAGE_FLASH));
ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_APSTA));

wifi_config_t apconf = {};
ESP_ERROR_CHECK(esp_wifi_get_config(ESP_IF_WIFI_AP, &apconf));

strcpy((char*)apconf.ap.ssid, "esp-ap");
apconf.ap.ssid_len = 0;

strcpy((char*)apconf.ap.password, "aaa");
apconf.ap.authmode = WIFI_AUTH_WPA2_PSK;

// here is the strange error code
esp_err_t rv = esp_wifi_set_config(ESP_IF_WIFI_AP, &apconf);
if (rv != ESP_OK) {
    ESP_LOGE(TAG, "Error set AP config: %d, %s\n", rv, esp_err_to_name(rv));
}

Output is

I (834) wifi:wifi firmware version: 3ea4c76
I (834) wifi:config NVS flash: enabled
I (834) wifi:config nano formating: disabled
I (835) wifi:Init dynamic tx buffer num: 32
I (838) wifi:Init data frame dynamic rx buffer num: 32
I (843) wifi:Init management frame dynamic rx buffer num: 32
I (848) wifi:Init management short buffer num: 32
I (853) wifi:Init static rx buffer size: 1600
I (858) wifi:Init static rx buffer num: 10
I (861) wifi:Init dynamic rx buffer num: 32
W (866) wifi:password less than 8

E (868) wifi_init: Error set AP config: 11, ERROR

I checked and the bad password was NOT saved to flash, so only the error code is wrong

AxelLin commented 3 years ago

W (866) wifi:password less than 8

E (868) wifi_init: Error set AP config: 11, ERROR



I checked and the bad password was NOT saved to flash, so only the error code is wrong

Looks like it should return ESP_ERR_WIFI_PASSWORD, i.e. (ESP_ERR_WIFI_BASE + 11), rather than 11.

YouDONG-ESP commented 3 years ago

@MightyPork Just checked, it returned ESP_ERR_WIFI_PASSWORD as @AxelLin said. Only the authentication mode and password had been saved

YouDONG-ESP commented 3 years ago

@MightyPork Just checked, it returned ESP_ERR_WIFI_PASSWORD as @AxelLin said. Only the ssid, password, authentication mode had been saved.

PilotAware commented 3 years ago

I am seeing a similar issue to the problem reported here. I have 3 clients connected to the SoftAP, If I pull the power on the esp32, then reboot, some of the clients reconnect using the IP they had previously, but are reported by the esp as having IP 0.0.0.0 This then conflicts with other clients using the same IP address

To explain in more detail

Boot 1: esp reports client1 192.168.1.2 client2 192.168.1.3 client3 192.168.1.4

Boot 2: esp reports client1 0.0.0.0 client2 192.168.1.2 client3 192.168.1.3

When I look at the IP address on the device client1, it still thinks it has 192.168.1.2, so now there is a conflict between - client1 and client2, both thinking they have the same IP Address

Is there a way to flush the IP addresses, or force the lease renewal ?

eroom1966 commented 3 years ago

Further info, the only way to get around this seems to be multiple reboots, or telling the clients to ‘forget network’ then reconnect, once they get reallocated an ip traffic seems to resume

PilotAware commented 3 years ago

code is based upon the simple sofAP example, only difference is that the ip, gw and netmask are bespoke

#define EXAMPLE_ESP_WIFI_SSID      "Testcase"
#define EXAMPLE_ESP_WIFI_PASS      "12345678"
#define EXAMPLE_MAX_STA_CONN       4
void wifi_init_softap(void)
{
    ESP_ERROR_CHECK(esp_netif_init());
    ESP_ERROR_CHECK(esp_event_loop_create_default());

    esp_netif_t* wifiAP = esp_netif_create_default_wifi_ap();

    esp_netif_ip_info_t ipInfo;
    IP4_ADDR(&ipInfo.ip, 192,168,1,1);
    IP4_ADDR(&ipInfo.gw, 0,0,0,0); // do not advertise as a gateway router
    IP4_ADDR(&ipInfo.netmask, 255,255,255,0);
    esp_netif_dhcps_stop(wifiAP);
    esp_netif_set_ip_info(wifiAP, &ipInfo);
    esp_netif_dhcps_start(wifiAP);

    wifi_init_config_t cfg = WIFI_INIT_CONFIG_DEFAULT();
    ESP_ERROR_CHECK(esp_wifi_init(&cfg));

    ESP_ERROR_CHECK(esp_event_handler_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &wifi_event_handler, NULL));

    wifi_config_t wifi_config = {
        .ap = {
            .ssid = "default",
            .ssid_len = 7,
            .password = EXAMPLE_ESP_WIFI_PASS,
            .max_connection = EXAMPLE_MAX_STA_CONN,
            .authmode = WIFI_AUTH_OPEN // WIFI_AUTH_WPA_WPA2_PSK
        },
    };

    char ssid[32];
    sprintf(ssid, "%s-%06X", EXAMPLE_ESP_WIFI_SSID, 0x123456);
    memcpy(wifi_config.ap.ssid, ssid, 32);
    wifi_config.ap.ssid_len = strlen(ssid);

    if (strlen(EXAMPLE_ESP_WIFI_PASS) == 0) {
        wifi_config.ap.authmode = WIFI_AUTH_OPEN;
    }

    ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_AP));
    ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_AP, &wifi_config));
    ESP_ERROR_CHECK(esp_wifi_start());
}
PilotAware commented 3 years ago

I can reproduce with the standard Soft-AP example and some addtional logging

This is the good case of a station joining for the first time I (47186) wifi softAP: station 00:0f:00:e1:d4:8f join, AID=2 I (47186) wifi softAP: I (47196) wifi softAP: [0]: 4AAE3DE79E6B 192.168.4.2 I (47196) wifi softAP: [1]: 000F00E1D48F 0.0.0.0 I (47596) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.3 I (50766) wifi softAP: I (50766) wifi softAP: [0]: 4AAE3DE79E6B 192.168.4.2 I (50766) wifi softAP: [1]: 000F00E1D48F 192.168.4.3

on a hard power reset of the ESP, I do not see the call to "esp_netif_lwip: DHCP server assigned IP to a station" I (3786) wifi softAP: station 00:0f:00:e1:d4:8f join, AID=2 I (3786) wifi softAP: I (3796) wifi softAP: [0]: 4AAE3DE79E6B 0.0.0.0 I (3796) wifi softAP: [1]: 000F00E1D48F 0.0.0.0 ..repeat

softap_example_main.c.txt

ScottBonomi commented 3 years ago

Our design was having this issue, and similar failing to communicate and a nice odd message that said max stations already connected, even though nothing had shown on the monitor with all debugging turned on. We went back and re-evaluated everything and saw that others had been attenuating 5 MHz Wifi band signals in their filter in addition to closer noise. When wi did that, we got one system that is connecting every time. I am not going to say that everyone has the same issue, but it is worth looking into. Our dev environments were all pretty saturated with WiFi signals from everyone and we had not yet tried running in a Faraday Cage. It looks like we will not have to.

JJDS commented 3 years ago

In mu case was changing from STA mode to AP Mode. I hadn't the esp_netif_create_default_wifi_ap(); only the esp_netif_create_default_wifi_sta();

GeorgeFlorian commented 3 years ago

I have the same exact issue. I am using ESP-IDF v4.3 and my devices do not get an IP address from the softAP:

I (103324) DB_ESP32: Wifi AP started!
I (110754) wifi:new:<1,0>, old:<1,0>, ap:<1,0>, sta:<255,255>, prof:1
I (110754) wifi:station: 58:96:1d:be:d4:30 join, AID=1, b, 20
I (114814) wifi:station: 58:96:1d:be:d4:30 leave, AID = 1, bss_flags is 655392, bss:0x3ffbccc4
I (114814) wifi:new:<1,0>, old:<1,0>, ap:<1,0>, sta:<255,255>, prof:1
I (115974) wifi:new:<1,0>, old:<1,0>, ap:<1,0>, sta:<255,255>, prof:1
I (115974) wifi:station: 58:96:1d:be:d4:30 join, AID=1, b, 20
I (162364) wifi:station: 58:96:1d:be:d4:30 leave, AID = 1, bss_flags is 655393, bss:0x3ffbccc4
I (162364) wifi:new:<1,0>, old:<1,0>, ap:<1,0>, sta:<255,255>, prof:1
I (162364) DB_ESP32: Wifi AP started!
ozanoner commented 2 years ago

I have a similar issue with M5Stack-Core2 AWS kit.

My tests include 2 different kits: 1- M5Core2-AWS 2- ESP-WROVER Kit

And 3 different Wifi clients: 1- My PC (Ubuntu 18.04 Kernel: 5.4.0-91-generic) 2- An Android mobile device (Android 12) 3- An iOS device (14.8.1)

I'm using PlatformIO: (penv) $ pio --version PlatformIO Core, version 5.2.3

Here is the platformio.ini: [env:m5stack-core2] platform = espressif32@3.2.1 board = m5stack-core2 framework = espidf monitor_speed = 115200

[env:esp-wrover-kit] platform = espressif32@3.2.1 board = esp-wrover-kit framework = espidf monitor_speed = 115200

The code is: https://raw.githubusercontent.com/espressif/esp-idf/master/examples/wifi/getting_started/softAP/main/softap_example_main.c

Observation: 1- My PC connects to any softAP application running on any ESP32 device without any problem. The first try is always successful. 2- My mobile devices (both Android and iOS) connect to the softAP running on the ESP-WROVER kit without any problem. The first try is always successful. 3- My mobile devices (both Android and iOS) SOMETIMES connect to the softAP running on the M5Core2-AWS kit. The initial several tries may connect after several rounds. If connects successfully, when I disconnect my mobile device and retry a new connection, it definitely fails. I need to reboot the M5Core2-AWS kit to get a successful connection.

Here is the logs from the M5Core2-AWS run:

//// softAP starts ␛[0;32mI (779) wifi softAP: wifi_init_softap finished. SSID:Printer_4401 password:deneme123 channel:1␛[0m I (6729) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<255,255>, prof:1 I (6739) wifi:station: 1a:3f:85:cf:86:7a join, AID=1, bgn, 20 ␛[0;32mI (6849) wifi softAP: station 1a:3f:85:cf:86:7a join, AID=1␛[0m

//// mobile device connects successfully ␛[0;32mI (7179) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m I (16579) wifi:station: 1a:3f:85:cf:86:7a leave, AID = 1, bss_flags is 134243, bss:0x3ffb8e54 I (16579) wifi:new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1

//// mobile device is disconnected intentionally ␛[0;32mI (16589) wifi softAP: station 1a:3f:85:cf:86:7a leave, AID=1␛[0m

//// mobile device tries to connect I (20099) wifi:new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1 I (20099) wifi:station: 1a:3f:85:cf:86:7a join, AID=1, bgn, 20 ␛[0;32mI (20149) wifi softAP: station 1a:3f:85:cf:86:7a join, AID=1␛[0m ␛[0;32mI (20359) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (21439) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (23289) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (25429) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (26339) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (28309) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m ␛[0;32mI (32439) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.2␛[0m

//// !!!! I see a message on the mobile device saying failed to obtain an IP, and it leaves I (38209) wifi:station: 1a:3f:85:cf:86:7a leave, AID = 1, bss_flags is 134243, bss:0x3ffb8e54 I (38209) wifi:new:<1,0>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1 ␛[0;32mI (38209) wifi softAP: station 1a:3f:85:cf:86:7a leave, AID=1␛[0m

//// trying with my PC, success I (57719) wifi:new:<1,1>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1 I (57719) wifi:station: bc:a8:a6:bd:a4:5c join, AID=1, bgn, 40U ␛[0;32mI (57739) wifi softAP: station bc:a8:a6:bd:a4:5c join, AID=1␛[0m ␛[0;32mI (57779) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.3␛[0m

//// leave intentionally I (68079) wifi:station: bc:a8:a6:bd:a4:5c leave, AID = 1, bss_flags is 134243, bss:0x3ffb8e54 I (68079) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<255,255>, prof:1 ␛[0;32mI (68079) wifi softAP: station bc:a8:a6:bd:a4:5c leave, AID=1␛[0m

//// trying with my PC, success I (78369) wifi:new:<1,1>, old:<1,0>, ap:<1,1>, sta:<255,255>, prof:1 I (78369) wifi:station: bc:a8:a6:bd:a4:5c join, AID=1, bgn, 40U ␛[0;32mI (78389) wifi softAP: station bc:a8:a6:bd:a4:5c join, AID=1␛[0m ␛[0;32mI (78429) esp_netif_lwip: DHCP server assigned IP to a station, IP is: 192.168.4.3␛[0m

//// leave intentionally I (96269) wifi:station: bc:a8:a6:bd:a4:5c leave, AID = 1, bss_flags is 134243, bss:0x3ffb8e54 I (96269) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<255,255>, prof:1 ␛[0;32mI (96269) wifi softAP: station bc:a8:a6:bd:a4:5c leave, AID=1␛[0m

I also tried with the latest version of ESP-IDF and I got the same results.

Any help would be highly appreciated.

X-Ryl669 commented 2 years ago

For me, the solution was to move esp_event_loop_create_default();

before: esp_netif_create_default_wifi_ap();

Else, lwip does not start correctly and neither the DHCP server.

mkfrey commented 2 years ago

I am having the same (or at least similar) issue on v4.4. Wireshark shows the DHCP discover messages from my client, but no offer is returned by the ESP32.

The ESP32 is receiving the discovery packet and assembles and sends an offer packet without any indication of an error. But the offer packet never arrives at the client side.

EDIT: I think I found the reason for my problem. I was passively scanning BLE in the background (with interval = 5s and window= 1s). Looks like this doesn't play nice with WiFi in AP mode. In STA mode, there aren't that many problems.

EDIT2: A similar issue also occurs when invalid static IP settings are provided for the AP. Turns out esp_netif_set_ip_info does not validate the settings and accepts 255.255.255.1 as valid netmask.

jack0c commented 2 years ago

@AxelLin your issue is actually same as #6289 , right?

jack0c commented 2 years ago

@JJDS do you have the same issue? Or you have a workaround?

jack0c commented 2 years ago

@GeorgeFlorian your issue is related with GPIOs, right? Can you keep GPIOs silent, no input, no output? Can you try @X-Ryl669 's fix?

jack0c commented 2 years ago

@junexuesp It looks in some examples, esp_event_loop_create_default(); is not used before esp_netif_create_default_wifi_ap(); PTAL

AxelLin commented 1 year ago

@AxelLin your issue is actually same as #6289 , right?

Yes, I think so.