SoftAP Not Detected by Mobile Devices on ESP32-S3, Works Fine on ESP32 (IDFGH-12498)

periclesbgf commented 2 months ago

Answers checklist.

[X] I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
[X] I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
[X] I have searched the issue tracker for a similar issue and not found a similar issue.

General issue report

Hi,

Description:

I initiated the SoftAP example provided with the ESP-IDF and tested it on two devices: an ESP32 and an ESP32-S3. On the ESP32, the SoftAP operates as expected: the SSID is visible on my mobile device, and I am able to connect without any issues. However, when replicating the test in the exact same manner on the ESP32-S3, the SSID of the SoftAP does not appear in the list of available networks on my mobile device, preventing any attempt to connect.

Environment:

Device Model: ESP32-S3 vs. ESP32 ESP-IDF Version: 5.3 (master) SoftAP Settings: see the logs Development Tools: ESP-IDF in vscode

Steps to Reproduce:

Load the SoftAP example onto the ESP32-S3 using the example's default settings. Attempt to view the SoftAP's SSID on a mobile device. Repeat steps 1 and 2 with an ESP32 device, noting that in this case, the SSID is visible and connection is possible.

Expected Result:

The SoftAP's SSID should be visible and accessible for connection on both devices, ESP32 and ESP32-S3.

Actual Result:

The SoftAP's SSID is visible and connectable on the ESP32 but does not appear in the list of available networks on the ESP32-S3.

#include <string.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_mac.h"
#include "esp_wifi.h"
#include "esp_event.h"
#include "esp_log.h"
#include "nvs_flash.h"

#include "lwip/err.h"
#include "lwip/sys.h"

#define EXAMPLE_ESP_WIFI_SSID      CONFIG_ESP_WIFI_SSID
#define EXAMPLE_ESP_WIFI_PASS      CONFIG_ESP_WIFI_PASSWORD
#define EXAMPLE_ESP_WIFI_CHANNEL   CONFIG_ESP_WIFI_CHANNEL
#define EXAMPLE_MAX_STA_CONN       CONFIG_ESP_MAX_STA_CONN`

static const char *TAG = "wifi softAP";

static void wifi_event_handler(void* arg, esp_event_base_t event_base,
                                    int32_t event_id, void* event_data)
{
    if (event_id == WIFI_EVENT_AP_STACONNECTED) {
        wifi_event_ap_staconnected_t* event = (wifi_event_ap_staconnected_t*) event_data;
        ESP_LOGI(TAG, "station "MACSTR" join, AID=%d",
                 MAC2STR(event->mac), event->aid);
    } else if (event_id == WIFI_EVENT_AP_STADISCONNECTED) {
        wifi_event_ap_stadisconnected_t* event = (wifi_event_ap_stadisconnected_t*) event_data;
        ESP_LOGI(TAG, "station "MACSTR" leave, AID=%d",
                 MAC2STR(event->mac), event->aid);
    }
}

void wifi_init_softap(void)
{
    ESP_ERROR_CHECK(esp_netif_init());
    ESP_ERROR_CHECK(esp_event_loop_create_default());
    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_event_handler_instance_register(WIFI_EVENT,
                                                        ESP_EVENT_ANY_ID,
                                                        &wifi_event_handler,
                                                        NULL,
                                                        NULL));

    wifi_config_t wifi_config = {
        .ap = {
            .ssid = EXAMPLE_ESP_WIFI_SSID,
            .ssid_len = strlen(EXAMPLE_ESP_WIFI_SSID),
            .channel = EXAMPLE_ESP_WIFI_CHANNEL,
            .password = EXAMPLE_ESP_WIFI_PASS,
            .max_connection = EXAMPLE_MAX_STA_CONN,
#ifdef CONFIG_ESP_WIFI_SOFTAP_SAE_SUPPORT
            .authmode = WIFI_AUTH_WPA3_PSK,
            .sae_pwe_h2e = WPA3_SAE_PWE_BOTH,
#else /* CONFIG_ESP_WIFI_SOFTAP_SAE_SUPPORT */
            .authmode = WIFI_AUTH_WPA2_PSK,
#endif
            .pmf_cfg = {
                    .required = true,
            },
        },
    };
    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(WIFI_IF_AP, &wifi_config));
    ESP_ERROR_CHECK(esp_wifi_start());

    ESP_LOGI(TAG, "wifi_init_softap finished. SSID:%s password:%s channel:%d",
             EXAMPLE_ESP_WIFI_SSID, EXAMPLE_ESP_WIFI_PASS, EXAMPLE_ESP_WIFI_CHANNEL);
}

void app_main(void)
{
    //Initialize NVS
    esp_err_t ret = nvs_flash_init();
    if (ret == ESP_ERR_NVS_NO_FREE_PAGES || ret == ESP_ERR_NVS_NEW_VERSION_FOUND) {
      ESP_ERROR_CHECK(nvs_flash_erase());
      ret = nvs_flash_init();
    }
    ESP_ERROR_CHECK(ret);

    ESP_LOGI(TAG, "ESP_WIFI_MODE_AP");
    wifi_init_softap();

    while (1) {
        vTaskDelay(10000 / portTICK_PERIOD_MS); // Aguarde 10 segundos entre cada verificação

        wifi_config_t ap_config;
        memset(&ap_config, 0, sizeof(ap_config)); // Zero out the structure

        if (esp_wifi_get_config(WIFI_IF_AP, &ap_config) == ESP_OK) {
            ESP_LOGI(TAG, "SoftAP SSID:%s Password:%s Channel:%d",
                     (char*)ap_config.ap.ssid,
                     (char*)ap_config.ap.password,
                     ap_config.ap.channel);
        } else {
            ESP_LOGE(TAG, "Failed to get SoftAP config");
        }
    }
}

Logs:

Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4037a8ae
0x4037a8ae: esp_cpu_wait_for_intr at C:/Users/peric/esp/master/esp-idf/components/esp_hw_support/cpu.c:150

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2810,len:0x178c
load:0x403c8700,len:0x4
load:0x403c8704,len:0xcb8
load:0x403cb700,len:0x2d9c
entry 0x403c8914
I (26) boot: ESP-IDF v5.3-dev-2815-gbe06a6f5ff 2nd stage bootloader
I (27) boot: compile time Mar 30 2024 13:27:45
I (27) boot: Multicore bootloader
I (31) boot: chip revision: v0.2
I (35) boot.esp32s3: Boot SPI Speed : 80MHz
I (40) boot.esp32s3: SPI Mode       : DIO
I (45) boot.esp32s3: SPI Flash Size : 2MB
I (49) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (58) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (73) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (81) boot:  2 factory          factory app      00 00 00010000 00100000
I (88) boot: End of partition table
I (92) esp_image: segment 0: paddr=00010020 vaddr=3c090020 size=22a80h (141952) map
I (126) esp_image: segment 1: paddr=00032aa8 vaddr=3fc98b00 size=0477ch ( 18300) load
I (130) esp_image: segment 2: paddr=0003722c vaddr=40374000 size=08dech ( 36332) load
I (140) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=80a20h (526880) map
I (235) esp_image: segment 4: paddr=000c0a48 vaddr=4037cdec size=0bc58h ( 48216) load
I (254) boot: Loaded app from partition at offset 0x10000
I (255) boot: Disabling RNG early entropy source...
I (266) cpu_start: Multicore app
I (276) cpu_start: Pro cpu start user code
I (276) cpu_start: cpu freq: 160000000 Hz
I (276) app_init: Application information:
I (279) app_init: Project name:     wifi_softAP
I (284) app_init: App version:      1
I (289) app_init: Compile time:     Mar 30 2024 13:27:24
I (295) app_init: ELF file SHA256:  8cbdebb36...
I (300) app_init: ESP-IDF:          v5.3-dev-2815-gbe06a6f5ff
I (306) efuse_init: Min chip rev:     v0.0
I (311) efuse_init: Max chip rev:     v0.99
I (316) efuse_init: Chip rev:         v0.2
I (321) heap_init: Initializing. RAM available for dynamic allocation:
I (328) heap_init: At 3FCA0D40 len 000489D0 (290 KiB): RAM
I (334) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (340) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (346) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (354) spi_flash: detected chip: winbond
I (357) spi_flash: flash io: dio
W (361) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (375) sleep: Configure to isolate all GPIO pins in sleep state
I (381) sleep: Enable automatic switching of GPIO sleep configuration
I (389) main_task: Started on CPU0
I (399) main_task: Calling app_main()
I (439) wifi softAP: ESP_WIFI_MODE_AP
I (439) pp: pp rom version: e7ae62f
I (439) net80211: net80211 rom version: e7ae62f
I (449) wifi:wifi driver task: 3fcab120, prio:23, stack:6656, core=0
I (469) wifi:wifi firmware version: ca0708907
I (469) wifi:wifi certification version: v7.0
I (469) wifi:config NVS flash: enabled
I (469) wifi:config nano formating: disabled
I (469) wifi:Init data frame dynamic rx buffer num: 32
I (479) wifi:Init static rx mgmt buffer num: 5
I (479) wifi:Init management short buffer num: 32
I (489) wifi:Init dynamic tx buffer num: 32
I (489) wifi:Init static tx FG buffer num: 2
I (499) wifi:Init static rx buffer size: 1600
I (499) wifi:Init static rx buffer num: 10
I (499) wifi:Init dynamic rx buffer num: 32
I (509) wifi_init: rx ba win: 6
I (509) wifi_init: accept mbox: 6
I (509) wifi_init: tcpip mbox: 32
I (519) wifi_init: udp mbox: 6
I (519) wifi_init: tcp mbox: 6
I (529) wifi_init: tcp tx win: 5760
I (529) wifi_init: tcp rx win: 5760
I (529) wifi_init: tcp mss: 1440
I (539) wifi_init: WiFi IRAM OP enabled
I (539) wifi_init: WiFi RX IRAM OP enabled
I (549) phy_init: phy_version 640,cd64a1a,Jan 24 2024,17:28:12
I (589) wifi:mode : softAP (dc:da:0c:2a:13:29)
I (649) wifi:Total power save buffer number: 16
I (649) wifi:Init max length of beacon: 752/752
I (649) wifi:Init max length of beacon: 752/752
I (649) wifi softAP: wifi_init_softap finished. SSID:myssid password:mypassword channel:1
I (649) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1
I (10669) wifi softAP: SoftAP SSID:myssid Password:mypassword Channel:1
I (20669) wifi softAP: SoftAP SSID:myssid Password:mypassword Channel:1
I (30669) wifi softAP: SoftAP SSID:myssid Password:mypassword Channel:1

nishanth-radja commented 2 months ago

@periclesbgf can we have a sniffer capture on channel 1,to see if AP is beaconing. Also if you have a different ESP32S3 can you try on that as well.

AxelLin commented 1 month ago

@periclesbgf Any update for comment https://github.com/espressif/esp-idf/issues/13508#issuecomment-2036189516 ?

periclesbgf commented 1 month ago

I just got another S3 board and tested in the same conditions, and it worked. I think maybe it is a hardware problem.

But I'll try to put a sniffer.

AxelLin commented 1 month ago

@nishanth-radja

I hit this issue (no AP found) when test esp32-camera on esp32s3-wroom-1 using esp-idf v5.2.1-485-g9b3ae86417 . The esp32s3 is running as an AP, but my laptop and mobile phone cannot find the esp32s3's AP (SSID:ICAM_49_40)

esp32s3_no_ap_found2.pcapng.txt esp32s3_no_ap_found3.pcapng.txt

AxelLin commented 1 month ago

@nishanth-radja Also attached the log when the esp32s3's AP (SSID:ICAM_49_40) is found for comparison. It seems if I remove the camera then I have a much better chance to find the esp32s3's AP.

esp32s-ap1.pcapng.txt esp32s-ap2.pcapng.txt

AxelLin commented 1 month ago

Below is the log when I found the AP and try to join it, it seems join success but then disassoc immediately.


V (37544) wifi:updated connection retries to 0
I (56845) wifi:removing station <20:1e:88:5e:2b:3f> after unsuccessful auth/assoc, AID = 0
W (56846) wifi:rm mis
I (56846) wifi:new:<6,0>, old:<6,0>, ap:<6,0>, sta:<0,0>, prof:6
V (73768) wifi:updated connection retries to 0
D (82379) wifi:ap recv assoc/reassoc request
I (82380) wifi:new:<6,0>, old:<6,0>, ap:<6,0>, sta:<0,0>, prof:6
D (82380) wifi:bss=0x3c1ae9c4, resp=16 join
I (82382) wifi:station: 20:1e:88:5e:2b:3f join, AID=1, bgn, 20
D (82388) wpa:   New STA
D (82391) wpa: add sm, index=0 bitmap=1
D (82394) wpa: init wpa sm=0x3fca8a94
D (82398) wpa: rsn_ie - hexdump(len=28):
D (82402) wpa: 30 1a 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 
D (82408) wpa: 00 0f ac 02 80 00 00 00 00 0f ac 06 
D (82413) wifi:join success bss=0x3c1ae9c4, ap send assoc response
D (82419) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITIALIZE

D (82426) wpa: wpa_auth_set_key : key idx  0 alg 0 vlan_id 0 key_len 0 key
D (82433) wpa: ELOOP: wpa_remove_ptk:1252 called to remove timer handler=0x4204ab80, removed count=0
0x4204ab80: wpa_rekey_ptk at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:262

D (82442) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK_GROUP entering state IDLE

D (82449) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state AUTHENTICATION

D (82456) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state AUTHENTICATION2

D (82463) wpa: WPA: Re-initialize GMK/Counter on first station
D (82469) wpa: GMK - hexdump(len=32):
D (82473) wpa: 3a 3c 8d 39 60 0c cc 4a 3d 6c 0a d9 ab a3 54 23 
D (82479) wpa: ee fe fc 55 46 3d 79 20 45 79 af 8d 42 86 04 12 
D (82486) wpa: Key Counter - hexdump(len=32):
D (82490) wpa: f6 e0 20 d5 5a c6 fe 13 29 1d 14 e2 a9 50 16 1b 
D (82495) wpa: 2e 50 11 8f 12 a3 ee 26 f1 38 d9 d6 49 ee 4d 92 
D (82502) wpa: GTK - hexdump(len=16):
D (82505) wpa: f0 85 56 bd d3 11 a4 af 75 98 69 e2 d4 68 83 c8 
D (82512) wpa: IGTK - hexdump(len=16):
D (82515) wpa: 76 ef 76 ad 9b 51 8e 38 1b a2 31 93 2a 7e 48 82 
D (82521) wpa: wpa_auth_set_key : key idx  1 alg 3 vlan_id 0 key_len 16 key
D (82528) wpa: wpa_auth_set_key : igtk idx 4
D (82532) wpa: WPA: Assign ANonce - hexdump(len=32):
D (82537) wpa: 63 03 8a df 8b ef f2 b5 8f b4 bb ba 8a f8 48 b6 
D (82543) wpa: 3c 92 42 09 04 b6 58 21 4b 83 fd 09 e4 99 eb 5d 
D (82549) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITPSK

D (82556) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (82562) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8a94  kdersc=0x0 kde=0x0 nounce=0x3fca8ae4 kde_len=0 keyidx=0 encr=0 force=0
D (82574) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (82584) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (82593) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

V (82602) wifi:tx process: alloc static tx buf, pb=0x0 l=113 hdr=0 data=113
D (82609) wifi:ap recv assoc/reassoc request
D (82612) wifi:Ignore immediate assoc req as processing other assoc req for 20:1e:88:5e:2b:3f
D (82621) wifi:ap recv assoc/reassoc request
D (82625) wifi:Ignore immediate assoc req as processing other assoc req for 20:1e:88:5e:2b:3f
D (83593) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (83594) wpa: resend eapol1
D (83594) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (83600) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8a94  kdersc=0x0 kde=0x0 nounce=0x3fca8ae4 kde_len=0 keyidx=0 encr=0 force=0
D (83611) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (83621) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (83630) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

V (83639) wifi:tx process: alloc static tx buf, pb=0x0 l=113 hdr=0 data=113
D (84630) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (84631) wpa: resend eapol1
D (84631) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (84637) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8a94  kdersc=0x0 kde=0x0 nounce=0x3fca8ae4 kde_len=0 keyidx=0 encr=0 force=0
D (84648) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (84658) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (84667) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

V (84676) wifi:tx process: alloc static tx buf, pb=0x0 l=113 hdr=0 data=113
D (85667) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (85668) wpa: resend eapol1
D (85668) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (85674) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8a94  kdersc=0x0 kde=0x0 nounce=0x3fca8ae4 kde_len=0 keyidx=0 encr=0 force=0
D (85685) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (85695) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (85704) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

V (85713) wifi:tx process: alloc static tx buf, pb=0x0 l=113 hdr=0 data=113
D (86704) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (86704) wpa: resend eapol1
D (86705) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (86711) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state DISCONNECT

D (86717) wpa: wpa_sta_disconnect STA 20:1e:88:5e:2b:3f
D (86723) wifi:Removing node for station 20:1e:88:5e:2b:3f
D (86728) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state DISCONNECTED

D (86735) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITIALIZE

D (86742) wpa: wpa_auth_set_key : key idx  0 alg 0 vlan_id 0 key_len 0 key
D (86749) wpa: ELOOP: wpa_remove_ptk:1252 called to remove timer handler=0x4204ab80, removed count=0
0x4204ab80: wpa_rekey_ptk at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:262

D (113407) wifi:ap recv assoc/reassoc request
I (113408) wifi:new:<6,0>, old:<6,0>, ap:<6,0>, sta:<0,0>, prof:6
D (113408) wifi:bss=0x3c1ae9c4, resp=16 join
I (113411) wifi:station: 20:1e:88:5e:2b:3f join, AID=1, bgn, 20
D (113416) wpa: ELOOP: wpa_auth_sta_deinit:508 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (113426) wpa: del sm, index=0 bitmap=0
D (113430) wpa: wpa_free_sta_sm: free eapol=0x0

D (113435) wpa:   New STA
D (113437) wpa: add sm, index=0 bitmap=1
D (113441) wpa: init wpa sm=0x3fca8984
D (113445) wpa: rsn_ie - hexdump(len=28):
D (113450) wpa: 30 1a 01 00 00 0f ac 04 01 00 00 0f ac 04 01 00 
D (113455) wpa: 00 0f ac 02 80 00 00 00 00 0f ac 06 
D (113461) wifi:join success bss=0x3c1ae9c4, ap send assoc response
D (113467) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITIALIZE

D (113473) wpa: wpa_auth_set_key : key idx  0 alg 0 vlan_id 0 key_len 0 key
D (113480) wpa: ELOOP: wpa_remove_ptk:1252 called to remove timer handler=0x4204ab80, removed count=0
0x4204ab80: wpa_rekey_ptk at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:262

D (113490) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK_GROUP entering state IDLE

D (113497) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state AUTHENTICATION

D (113504) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state AUTHENTICATION2

D (113511) wpa: WPA: Assign ANonce - hexdump(len=32):
D (113517) wpa: 7e d7 46 dd ee 17 39 9d 7d 8d ff 13 4e 73 a9 79 
D (113523) wpa: 7a a2 9f 92 f7 f1 41 78 81 92 b2 16 52 1a 07 e4 
D (113529) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITPSK

D (113535) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (113542) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8984  kdersc=0x0 kde=0x0 nounce=0x3fca89d4 kde_len=0 keyidx=0 encr=0 force=0
D (113553) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (113563) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (113572) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (113582) wifi:ap recv assoc/reassoc request
D (113586) wifi:Ignore immediate assoc req as processing other assoc req for 20:1e:88:5e:2b:3f
D (113619) wifi:ap recv assoc/reassoc request
D (113620) wifi:Ignore immediate assoc req as processing other assoc req for 20:1e:88:5e:2b:3f
D (114573) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (114573) wpa: resend eapol1
D (114573) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (114579) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8984  kdersc=0x0 kde=0x0 nounce=0x3fca89d4 kde_len=0 keyidx=0 encr=0 force=0
D (114591) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (114601) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (114610) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (115610) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (115611) wpa: resend eapol1
D (115611) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (115617) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8984  kdersc=0x0 kde=0x0 nounce=0x3fca89d4 kde_len=0 keyidx=0 encr=0 force=0
D (115628) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (115638) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (115648) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (116648) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (116648) wpa: resend eapol1
D (116648) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (116654) wpa: wpa_auth=0x3fcd03bc sm=0x3fca8984  kdersc=0x0 kde=0x0 nounce=0x3fca89d4 kde_len=0 keyidx=0 encr=0 force=0
D (116666) wpa: WPA: Send EAPOL(version=2 secure=0 mic=0 ack=1 install=0 pairwise=1 kde_len=0 keyidx=0 encr=0)
D (116676) wpa: ELOOP: wpa_send_eapol:1212 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (116685) wpa: ELOOP: Added one timer from wpa_send_eapol:1213 to call 0x420491c8, current order=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (117685) wpa: ELOOP: Running timer fn:0x420491c8 scheduled by wpa_send_eapol:1213 
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (117686) wpa: resend eapol1
D (117686) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state PTKSTART

D (117692) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state DISCONNECT

D (117699) wpa: wpa_sta_disconnect STA 20:1e:88:5e:2b:3f
D (117704) wifi:Removing node for station 20:1e:88:5e:2b:3f
D (117710) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state DISCONNECTED

D (117717) wpa: WPA: 20:1e:88:5e:2b:3f WPA_PTK entering state INITIALIZE

D (117724) wpa: wpa_auth_set_key : key idx  0 alg 0 vlan_id 0 key_len 0 key
D (117731) wpa: ELOOP: wpa_remove_ptk:1252 called to remove timer handler=0x4204ab80, removed count=0
0x4204ab80: wpa_rekey_ptk at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:262

D (123733) wifi:ap recv deauth/disassoc from sta 20:1e:88:5e:2b:3f, reason:3
I (123733) wifi:station: 20:1e:88:5e:2b:3f leave, AID = 1, bss_flags is 33721442, bss:0x3c1ae9c4
I (123737) wifi:new:<6,0>, old:<6,0>, ap:<6,0>, sta:<0,0>, prof:6
D (123743) wpa: ELOOP: wpa_auth_sta_deinit:508 called to remove timer handler=0x420491c8, removed count=0
0x420491c8: resend_eapol_handle at /home/axel/esp/esp-idf/components/wpa_supplicant/src/ap/wpa_auth.c:1184

D (123753) wpa: del sm, index=0 bitmap=0
D (123757) wpa: wpa_free_sta_sm: free eapol=0x0

D (123772) wifi:no bcast bss, send deauth: reason not authed(6)
V (125150) wifi:updated connection retries to 0

AxelLin commented 3 weeks ago

@nishanth-radja

I found this symtom (ESP32S3 AP not visible) only hapeens at certain environment (location). I'm wondering what can cause such issue as I test on the same ESP32S3 with the same laptop and the esp2s3 is very closed to my laptop (Just put on the same desk).

Any feedback about the above sniffer log and debug print above? Is there anything unusual in the no AP found log (https://github.com/espressif/esp-idf/issues/13508#issuecomment-2099804524) ?

nishanth-radja commented 3 weeks ago

@AxelLin Looks like a RF related issue, Even periclesbgf described it to be a RF related issue.

AxelLin commented 1 week ago

@AxelLin Looks like a RF related issue, Even periclesbgf described it to be a RF related issue.

This issue causes very bad user experience because it sometimes works sometimes does not work. The status switches to "In Progress" so I'm wondering if that means you know how to address this issue?

espressif / esp-idf

SoftAP Not Detected by Mobile Devices on ESP32-S3, Works Fine on ESP32 (IDFGH-12498) #13508

Answers checklist.

General issue report