esp-idf: CORRUPT HEAP after WiFi reconnect if previous connection loss has not been recognized by ESP32 (IDFGH-8519)

Answers checklist.

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

IDF version.

v5.0-beta1-641-gc321739074

Operating System used.

Linux

How did you build your project?

Command line with idf.py

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

No response

Development Kit.

ESP32-S2-WROVER and ESP32-S3-WROOM-1-N8R8

Power Supply used.

USB

What is the expected behavior?

If an external device reconnects to the ESP32 AP, the connection should be handled correctly, even if the previous connection loss has not been recognized by ESP32.

What is the actual behavior?

If an external device reconnects to the ESP32 AP and the previous connection loss has not been recognized by ESP32, the following error occurs:

CORRUPT HEAP: Invalid data at 0x3ffdd4a0. Expected 0xfefefefe got 0x00000000

Steps to reproduce.

Configuration: ESP32 is in WiFi mode WIFI_MODE_APSTA Heap corruption detection = Comprehensive authmode of ESP-AP = WIFI_AUTH_WPA2_PSK

Action:

1. Step: Smartphone connects to ESP32 AP (channel 1)
2. Step: ESP32 STA connects to external accesspoint (channel 3 … 11)

• ESP32 has to switch from channel 1 to 3 … 11 (STA and AP)
• Smartphone is not capable to switch channel during a connection, so the connection gets lost
• The ESP32 does not recognize the connection loss to the smartphone

1. Step: The smartphone connects again to the ESP32 AP -> CORRUPT HEAP: Invalid data at 0x3ffdd4a0. Expected 0xfefefefe got 0x00000000

Code:

#include "esp_log.h"
#include "esp_wifi.h"
#include "nvs_flash.h"
#include "lwip/ip_addr.h"

static const char* TAG = "main.c";
static uint16_t connect_timer = 0;

static void wifi_event_handler(void* arg, esp_event_base_t event_base, int32_t event_id, void* event_data)
{
  ESP_LOGI(TAG, "event_base = %i, event_id = %i", (int16_t) *event_base, (int16_t) event_id);

  if ((event_base == WIFI_EVENT) && (event_id == WIFI_EVENT_STA_START))
  { connect_timer = 1; }

  else if ((event_base == WIFI_EVENT) && (event_id == WIFI_EVENT_STA_DISCONNECTED))
  { connect_timer = 1; }

  else if ((event_base == IP_EVENT) && (event_id == IP_EVENT_STA_GOT_IP))
  {
    ip_event_got_ip_t* event = (ip_event_got_ip_t*) event_data;
    ESP_LOGI(TAG, "got ip:" IPSTR, IP2STR(&event->ip_info.ip));
  }
}

void app_main(void)
{
  esp_netif_t* wifiAP;
  esp_netif_t* wifiSTA;

  esp_err_t ret;

  wifi_config_t s_wifi_config_ap = \
  {
    .ap = \
    {
      .channel = 1,
      .authmode = WIFI_AUTH_WPA_WPA2_PSK,
      .max_connection = 4,
    },
  };

  wifi_config_t wifi_config_sta = \
  {
    .sta = \
    {
      .ssid = "externalSSID",
      .password = "sectretPASSWORD",
    },
  };

  ret = nvs_flash_init();

  if ((ret == ESP_ERR_NVS_NO_FREE_PAGES) || (ret == ESP_ERR_NVS_NEW_VERSION_FOUND))
  {
    // NVS partition was truncated and needs to be erased
    // retry nvs_flash_init
    ESP_ERROR_CHECK(nvs_flash_erase());
    ret = nvs_flash_init();
  }

  ESP_ERROR_CHECK(ret);

  ESP_ERROR_CHECK(esp_netif_init());
  ESP_ERROR_CHECK(esp_event_loop_create_default());

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

  if (ret != ESP_OK) { ESP_LOGE(TAG, "esp_wifi_init(&cfg): ret = %s", esp_err_to_name(ret)); }

  esp_wifi_set_mode(WIFI_MODE_NULL);

  ESP_ERROR_CHECK(esp_event_handler_instance_register(IP_EVENT, IP_EVENT_STA_GOT_IP, &wifi_event_handler, NULL, NULL));
  ESP_ERROR_CHECK(esp_event_handler_instance_register(WIFI_EVENT, ESP_EVENT_ANY_ID, &wifi_event_handler, NULL, NULL));

  esp_wifi_set_storage(WIFI_STORAGE_FLASH);
  wifiAP = esp_netif_create_default_wifi_ap();
  assert(wifiAP);
  wifiSTA = esp_netif_create_default_wifi_sta();
  assert(wifiSTA);

  ESP_LOGI(TAG, "start AP STA");

  ESP_ERROR_CHECK(esp_wifi_set_mode(WIFI_MODE_APSTA));

  // AP
  esp_netif_ip_info_t ipInfo;

  strcpy((char*) s_wifi_config_ap.ap.ssid, "test123");
  s_wifi_config_ap.ap.ssid_len = strlen((char*) s_wifi_config_ap.ap.ssid);

  strcpy((char*) s_wifi_config_ap.ap.password, "mypassword");

  IP4_ADDR(&ipInfo.ip, 192,168,4,1);
  IP4_ADDR(&ipInfo.gw, 192,168,4,1);
  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);
  ESP_LOGI(TAG, "IP: " IPSTR, IP2STR(&ipInfo.ip));
  ESP_LOGI(TAG, "GW: " IPSTR, IP2STR(&ipInfo.gw));
  ESP_LOGI(TAG, "Mask: " IPSTR, IP2STR(&ipInfo.netmask));

  // AP
  ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_AP, &s_wifi_config_ap));

  ESP_LOGI(TAG, "wifi_init_softap finished. SSID: %s password: %s", \
           (char*) s_wifi_config_ap.ap.ssid, (char*) s_wifi_config_ap.ap.password);

  // STA
  ESP_ERROR_CHECK(esp_wifi_set_config(ESP_IF_WIFI_STA, &wifi_config_sta));

  ESP_ERROR_CHECK(esp_wifi_start());

  while (true)
  {
    if (connect_timer >= 300)
    {
      connect_timer = 0;
      esp_wifi_connect();
    }

    else if (connect_timer > 0) { connect_timer++; }

    vTaskDelay(pdMS_TO_TICKS(10));
  }
}

Debug Logs.

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6108,len:0x17a8
load:0x4004c000,len:0xaa4
load:0x40050000,len:0x3138
entry 0x4004c1bc
I (21) boot: ESP-IDF v5.0-beta1-641-gc321739074 2nd stage bootloader
I (21) boot: compile time 01:55:58
I (22) boot: chip revision: V000
I (26) boot.esp32s2: SPI Speed      : 80MHz
I (30) boot.esp32s2: SPI Mode       : DIO
I (35) boot.esp32s2: SPI Flash Size : 2MB
I (40) boot: Enabling RNG early entropy source...
I (45) boot: Partition Table:
I (49) boot: ## Label            Usage          Type ST Offset   Length
I (56) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (64) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (71) boot:  2 factory          factory app      00 00 00010000 00100000
I (79) boot: End of partition table
I (83) esp_image: segment 0: paddr=00010020 vaddr=3f000020 size=1d124h (119076) map
I (115) esp_image: segment 1: paddr=0002d14c vaddr=3ffc5a00 size=02ecch ( 11980) load
I (118) esp_image: segment 2: paddr=00030020 vaddr=40080020 size=71998h (465304) map
I (213) esp_image: segment 3: paddr=000a19c0 vaddr=3ffc88cc size=0073ch (  1852) load
I (214) esp_image: segment 4: paddr=000a2104 vaddr=40022000 size=139fch ( 80380) load
I (239) esp_image: segment 5: paddr=000b5b08 vaddr=50000000 size=00010h (    16) load
I (249) boot: Loaded app from partition at offset 0x10000
I (250) boot: Disabling RNG early entropy source...
I (262) cache: Instruction cache 	: size 8KB, 4Ways, cache line size 32Byte
I (262) cpu_start: Pro cpu up.
I (281) cpu_start: Pro cpu start user code
I (281) cpu_start: cpu freq: 160000000 Hz
I (281) cpu_start: Application information:
I (284) cpu_start: Project name:     wifi_test
I (289) cpu_start: App version:      1
I (293) cpu_start: Compile time:     Oct 12 2022 01:55:50
I (299) cpu_start: ELF file SHA256:  d73d438bf07a0c2a...
I (305) cpu_start: ESP-IDF:          v5.0-beta1-641-gc321739074
I (312) heap_init: Initializing. RAM available for dynamic allocation:
I (320) heap_init: At 3FFCCD98 len 0002F268 (188 KiB): DRAM
I (325) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (332) heap_init: At 3FF9E000 len 00002000 (8 KiB): RTCRAM
I (339) spi_flash: detected chip: generic
I (343) spi_flash: flash io: dio
W (347) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (361) cpu_start: Starting scheduler on PRO CPU.
I (396) wifi:wifi driver task: 3ffd5730, prio:23, stack:6656, core=0
I (396) system_api: Base MAC address is not set
I (396) system_api: read default base MAC address from EFUSE
I (406) wifi:wifi firmware version: 6ce7887
I (406) wifi:wifi certification version: v7.0
I (406) wifi:config NVS flash: enabled
I (406) wifi:config nano formating: disabled
I (416) wifi:Init data frame dynamic rx buffer num: 32
I (416) wifi:Init management frame dynamic rx buffer num: 32
I (426) wifi:Init management short buffer num: 32
I (426) wifi:Init dynamic tx buffer num: 32
I (436) wifi:Init static rx buffer size: 1600
I (436) wifi:Init static rx buffer num: 10
I (436) wifi:Init dynamic rx buffer num: 32
I (446) wifi_init: rx ba win: 6
I (446) wifi_init: tcpip mbox: 32
I (456) wifi_init: udp mbox: 6
I (456) wifi_init: tcp mbox: 6
I (456) wifi_init: tcp tx win: 5744
I (466) wifi_init: tcp rx win: 5744
I (466) wifi_init: tcp mss: 1440
I (476) wifi_init: WiFi IRAM OP enabled
I (476) wifi_init: WiFi RX IRAM OP enabled
I (496) main.c: start AP STA
I (496) main.c: IP: 192.168.4.1
I (496) main.c: GW: 192.168.4.1
I (496) main.c: Mask: 255.255.255.0
I (496) main.c: wifi_init_softap finished. SSID: test123 password: mypassword
I (526) phy_init: phy_version 2300,d67cf06,Feb 10 2022,10:03:07
I (566) wifi:mode : sta (68:67:25:29:7e:04) + softAP (68:67:25:29:7e:05)
I (566) wifi:enable tsf
I (566) wifi:Total power save buffer number: 16
I (566) wifi:Init max length of beacon: 752/752
I (576) wifi:Init max length of beacon: 752/752
I (576) main.c: event_base = 87, event_id = 2
I (576) main.c: event_base = 87, event_id = 12
I (6416) main.c: event_base = 87, event_id = 5
I (12256) main.c: event_base = 87, event_id = 5
I (18096) main.c: event_base = 87, event_id = 5
I (23936) main.c: event_base = 87, event_id = 5
I (27826) wifi:new:<1,0>, old:<1,1>, ap:<1,1>, sta:<0,0>, prof:1
I (27826) wifi:scan in process, ignore set current channel
I (27826) wifi:station: a0:10:81:c2:d9:36 join, AID=1, bgn, 20
I (27966) main.c: event_base = 87, event_id = 14
I (28276) esp_netif_lwip: DHCP server assigned IP to a client, IP is: 192.168.4.2
W (28576) wifi:<ba-add>idx:2 (ifx:1, a0:10:81:c2:d9:36), tid:0, ssn:3, winSize:64
W (29356) wifi:<ba-del>idx
W (29366) wifi:<ba-add>idx:2 (ifx:1, a0:10:81:c2:d9:36), tid:0, ssn:9, winSize:64
W (29746) wifi:<ba-del>idx
W (29746) wifi:<ba-add>idx:2 (ifx:1, a0:10:81:c2:d9:36), tid:0, ssn:12, winSize:64
I (29776) main.c: event_base = 87, event_id = 5
I (32776) wifi:primary chan differ, old=1, new=4, start CSA timer
I (33176) wifi:switch to channel 4
I (33176) wifi:ap channel adjust o:1,1 n:4,1
I (33176) wifi:new:<4,0>, old:<1,0>, ap:<4,1>, sta:<0,0>, prof:1
I (33186) wifi:new:<4,1>, old:<4,0>, ap:<4,1>, sta:<4,0>, prof:1
I (34866) wifi:state: init -> auth (b0)
I (34876) wifi:state: auth -> assoc (0)
I (34886) wifi:state: assoc -> run (10)
I (34946) wifi:connected with externalSSID, aid = 1, channel 4, BW20, bssid = 46:41:73:c6:ba:83
I (34946) wifi:security: WPA2-PSK, phy: bgn, rssi: -45
I (34956) wifi:pm start, type: 1

I (34956) main.c: event_base = 87, event_id = 4
I (34956) wifi:AP's beacon interval = 102400 us, DTIM period = 2
W (34976) wifi:<ba-add>idx:0 (ifx:0, 46:41:73:c6:ba:83), tid:0, ssn:0, winSize:64
I (35856) main.c: event_base = 73, event_id = 0
I (35856) main.c: got ip:192.168.195.159
I (35856) esp_netif_handlers: sta ip: 192.168.195.159, mask: 255.255.255.0, gw: 192.168.195.250
I (55036) main.c: event_base = 87, event_id = 15
W (55036) wifi:<ba-del>idx
I (55036) wifi:new:<4,0>, old:<4,1>, ap:<4,1>, sta:<4,0>, prof:1
I (55036) wifi:Send SA Query req with transaction id 280a
I (55246) wifi:Send SA Query req with transaction id 9752
I (55456) wifi:Send SA Query req with transaction id 12af
I (55656) wifi:Send SA Query req with transaction id 3110
I (55866) wifi:Send SA Query req with transaction id bb33
I (56066) wifi:STA not responded to 5 SA Query attempts, Reset connection sending disassoc
I (56066) wifi:station: a0:10:81:c2:d9:36 leave, AID = 1, bss_flags is 658531, bss:0x3ffdd1a0
I (56076) wifi:new:<4,0>, old:<4,0>, ap:<4,1>, sta:<4,0>, prof:1
I (56076) main.c: event_base = 87, event_id = 15
I (56556) wifi:new:<4,0>, old:<4,0>, ap:<4,1>, sta:<4,0>, prof:1
I (56556) wifi:station: a0:10:81:c2:d9:36 join, AID=1, bgn, 20
CORRUPT HEAP: Invalid data at 0x3ffdd4a0. Expected 0xfefefefe got 0x00000000

assert failed: multi_heap_malloc multi_heap_poisoning.c:256 (ret)


Backtrace: 0x40023912:0x3ffd51c0 0x4002a045:0x3ffd51e0 0x400309ad:0x3ffd5200 0x4002e96e:0x3ffd5320 0x40023a7d:0x3ffd5340 0x40023adb:0x3ffd5360 0x40026535:0x3ffd5380 0x400efd81:0x3ffd53a0 0x400330e5:0x3ffd53d0 0x400ac729:0x3ffd5400 0x400ac24d:0x3ffd5420 0x400a042a:0x3ffd5440 0x400a19d6:0x3ffd5480 0x400ab312:0x3ffd54a0 0x40098596:0x3ffd5510 0x40098cd1:0x3ffd5620 0x400973f3:0x3ffd5680 0x40033cf9:0x3ffd56a0 0x400320ac:0x3ffd56c0 0x4002c9c1:0x3ffd56f0




ELF file SHA256: d73d438bf07a0c2a

Rebooting...

More Information.

The problem occurs if authmode of ESP32-AP is WIFI_AUTH_WPA2_PSK. The problem doesn’t occur if authmode of ESP32-AP is WIFI_AUTH_OPEN.

I tested with ESP32-S2-WROVER and ESP32-S3-WROOM-1-N8R8 and got similar results. I tested with PSRAM enabled and disabled and got similar results.

The problem doesn’t occur always.