Crash in xTaskRemoveFromEventList (IDFGH-14155)

[jimmyw]

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.2.2

Operating System used.

Linux

How did you build your project?

Command line with CMake

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

None

What is the expected behavior?

I expect it not to crash

What is the actual behavior?

In production with 1000X devices, i get 30 completely random crash reports every day, with similar pattern.

Steps to reproduce.

No specific way to reproduce, in fact have never seen it reproduced my self.

Build or installation Logs.

Example output from crash #7870

Stack trace from tiT task:

==================== CURRENT THREAD STACK =====================
#0  0x40381018 in xTaskRemoveFromEventList (pxEventList=<optimized out>) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/tasks.c:3869
#1  0x4037e906 in xQueueGenericSend (xQueue=0x3fcd976c, pvItemToQueue=0x0, xTicksToWait=<optimized out>, xCopyPosition=0) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/queue.c:993
#2  0x420ab7dd in sys_sem_signal (sem=0x3c2cfc1c) at /opt/esp/idf/components/lwip/port/freertos/sys_arch.c:134
#3  0x420accbe in lwip_netconn_do_dns_found (name=0x3c2b8438 <dns_table+36> "", ipaddr=0x3c2b8418 <dns_table+4>, arg=0x3fcb772c <s_mqtt_client_stack+5172>) at /opt/esp/idf/components/lwip/lwip/src/api/api_msg.c:2215
#4  0x42096a64 in dns_call_found (idx=0 '\000', addr=0x3c2b8418 <dns_table+4>) at /opt/esp/idf/components/lwip/lwip/src/core/dns.c:1026
#5  0x42096b48 in dns_correct_response (idx=0 '\000', ttl=60) at /opt/esp/idf/components/lwip/lwip/src/core/dns.c:1224
#6  0x42097784 in dns_recv (arg=<optimized out>, pcb=<optimized out>, p=0x3c2de9d4, addr=<optimized out>, port=<optimized out>) at /opt/esp/idf/components/lwip/lwip/src/core/dns.c:1371
#7  0x4209e531 in udp_input (p=0x3c2de9d4, inp=0x3fcf7558) at /opt/esp/idf/components/lwip/lwip/src/core/udp.c:404
#8  0x420a1d49 in ip4_input (p=0x3c2de9d4, inp=0x3fcf7558) at /opt/esp/idf/components/lwip/lwip/src/core/ipv4/ip4.c:746
#9  0x420a7e99 in ethernet_input (p=0x3c2de9d4, netif=0x3fcf7558) at /opt/esp/idf/components/lwip/lwip/src/netif/ethernet.c:186
#10 0x42096318 in tcpip_thread_handle_msg (msg=0x3c2d08fc) at /opt/esp/idf/components/lwip/lwip/src/api/tcpip.c:174
#11 0x42096378 in tcpip_thread (arg=0x0) at /opt/esp/idf/components/lwip/lwip/src/api/tcpip.c:148
#12 0x4037ee08 in vPortTaskWrapper (pxCode=0x4209634c <tcpip_thread>, pvParameters=0x0) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:134

Stack from task that does dns request:

==================== THREAD 18 (TCB: 0x3fcb7af8, name: 'mqtt_task') =====================
#0  0x400559e0 in ?? ()
#1  0x4037f0b5 in vPortClearInterruptMaskFromISR (prev_level=<optimized out>) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/include/freertos/portmacro.h:564
#2  vPortExitCritical (mux=0x3fcd97c0) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:504
#3  0x4037ec50 in xQueueSemaphoreTake (xQueue=0x3fcd976c, xTicksToWait=<optimized out>) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/queue.c:1853
#4  0x420ab80c in sys_arch_sem_wait (sem=0x3c2cfc1c, timeout=0) at /opt/esp/idf/components/lwip/port/freertos/sys_arch.c:165
#5  0x42096464 in tcpip_send_msg_wait_sem (fn=0x420ae05c <lwip_netconn_do_gethostbyname>, apimsg=0x3fcb772c <s_mqtt_client_stack+5172>, sem=0x3c2cfc1c) at /opt/esp/idf/components/lwip/lwip/src/api/tcpip.c:456
#6  0x420acc50 in netconn_gethostbyname_addrtype (name=0x3c2cfa5c <error: Cannot access memory at address 0x3c2cfa5c>, addr=0x3fcb7778 <s_mqtt_client_stack+5248>, dns_addrtype=2 '\002') at /opt/esp/idf/components/lwip/lwip/src/api/api_lib.c:1325
#7  0x420936e4 in lwip_getaddrinfo (nodename=0x3c2cfa5c <error: Cannot access memory at address 0x3c2cfa5c>, servname=0x0, hints=0x3fcb77d0 <s_mqtt_client_stack+5336>, res=0x3fcb77cc <s_mqtt_client_stack+5332>) at /opt/esp/idf/components/lwip/lwip/src/api/netdb.c:345
#8  0x420be50c in getaddrinfo (res=0x3fcb77cc <s_mqtt_client_stack+5332>, hints=0x3fcb77d0 <s_mqtt_client_stack+5336>, servname=0x0, nodename=0x3c2cfa5c <error: Cannot access memory at address 0x3c2cfa5c>) at /opt/esp/idf/components/lwip/include/lwip/netdb.h:23
#9  esp_tls_hostname_to_fd (host=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, hostlen=45, port=8883, addr_family=<optimized out>, address=0x3fcb7854 <s_mqtt_client_stack+5468>, fd=0x3fcb782c <s_mqtt_client_stack+5428>) at /opt/esp/idf/components/esp-tls/esp_tls.c:203
#10 0x420be905 in tcp_connect (host=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, hostlen=45, port=8883, cfg=0x3c2cf6ac, error_handle=0x3c2cf728, sockfd=0x3c2e81fc) at /opt/esp/idf/components/esp-tls/esp_tls.c:340
#11 0x420bec1e in esp_tls_low_level_conn (hostname=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, hostlen=45, port=8883, cfg=0x3c2cf6ac, tls=0x3c2e79a0) at /opt/esp/idf/components/esp-tls/esp_tls.c:440
#12 0x420befa0 in esp_tls_conn_new_sync (hostname=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, hostlen=45, port=8883, cfg=0x3c2cf6ac, tls=0x3c2e79a0) at /opt/esp/idf/components/esp-tls/esp_tls.c:528
#13 0x420c0975 in ssl_connect (t=0x3c2cfa08, host=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, port=8883, timeout_ms=10000) at /opt/esp/idf/components/tcp_transport/transport_ssl.c:111
#14 0x4213df70 in esp_transport_connect (t=0x3c2cfa08, host=0x3c2cfbb4 <error: Cannot access memory at address 0x3c2cfbb4>, port=8883, timeout_ms=10000) at /opt/esp/idf/components/tcp_transport/transport.c:123
#15 0x42057d3a in esp_mqtt_task (pv=0x3c2e5f84) at /opt/esp/idf/components/mqtt/esp-mqtt/mqtt_client.c:1629
#16 0x4037ee08 in vPortTaskWrapper (pxCode=0x42057c28 <esp_mqtt_task>, pvParameters=0x3c2e5f84) at /opt/esp/idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:134

Register setup:

================== CURRENT THREAD REGISTERS ===================
exccause       0x1c (LoadProhibitedCause)
excvaddr       0x4
epc1           0x40044290
epc2           0x42062d88
epc3           0x0
epc4           0x0
epc5           0x0
epc6           0x0
eps2           0x60a20
eps3           0x0
eps4           0x0
eps5           0x0
eps6           0x0
pc             0x40381018          0x40381018 <xTaskRemoveFromEventList+180>
a0             0x8037e906          -2143819514
a1             0x3fcc1fb0          1070342064
a2             0x3fcb7b10          1070299920
a3             0x0                 0
a4             0x0                 0
a5             0x1                 1
a6             0x1                 1
a7             0x3fcb7af8          1070299896
a8             0x0                 0
a9             0x3fca5678          1070225016
a10            0x3fca3b44          1070218052
a11            0xffffffff          -1
a12            0x60b23             396067
a13            0x60b23             396067
a14            0x1592              5522
a15            0xabab              43947

Code executed

queue.c:

BaseType_t xQueueGenericSend( QueueHandle_t xQueue,
                              const void * const pvItemToQueue,
                              TickType_t xTicksToWait,
                              const BaseType_t xCopyPosition )
....
                        if( listLIST_IS_EMPTY( &( pxQueue->xTasksWaitingToReceive ) ) == pdFALSE )
                        {
                            if( xTaskRemoveFromEventList( &( pxQueue->xTasksWaitingToReceive ) ) != pdFALSE )

task.c:

    BaseType_t xTaskRemoveFromEventList( const List_t * const pxEventList )
....
                if( taskCAN_BE_SCHEDULED( pxUnblockedTCB ) == pdTRUE )
                {
                    listREMOVE_ITEM( &( pxUnblockedTCB->xStateListItem ) ); <----- HERE
                    prvAddTaskToReadyList( pxUnblockedTCB );

list.h:

#define listREMOVE_ITEM( pxItemToRemove ) \
    {                                     \
        List_t * const pxList = ( pxItemToRemove )->pxContainer;    <-- NULL     \
                                                                                 \
        ( pxItemToRemove )->pxNext->pxPrevious = ( pxItemToRemove )->pxPrevious; \
        ( pxItemToRemove )->pxPrevious->pxNext = ( pxItemToRemove )->pxNext;     \
CRASH-> if( pxList->pxIndex == ( pxItemToRemove ) )                              \
        {                                                                        \
            pxList->pxIndex = ( pxItemToRemove )->pxPrevious;                    \
        }                                                                        \
                                                                                 \
        ( pxItemToRemove )->pxContainer = NULL;                                  \
        ( pxList->uxNumberOfItems )--;                                           \
    }

Its clearly some kind of race condition, where pxContainer is NULL, and derefering the value in pxList->pxIndex Causes a read of NULL + 0x4, that causes a LoadProhibitedCause

This stack trace is not unique, this happens in other places when calling xTaskRemoveFromEventList.

Is there anyone that recognizes this, or can give me guidance on where to go from here?

The issue here is that this is so rare that i need 1000 devices to trigger the error. All my attempts to trigger it locally have failed, so i just cant try master version, or randomly change stuff.

### More Information.

_No response_

[KonstantinKondrashov]

Hi @jimmyw!
Thanks for the report. Please add sdkconfig and specify which chip you use. I guess it is a two-core chip.

[jimmyw]

ESP32S3, Using External SPI ram. Will add sdkconfig shortly.

[jimmyw]

# This file was generated using idf.py save-defconfig. It can be edited manually.
# Espressif IoT Development Framework (ESP-IDF) 5.2.2 Project Minimal Configuration
#
CONFIG_IDF_TARGET="esp32s3"
CONFIG_BOOTLOADER_PROJECT_VER=2
CONFIG_BOOTLOADER_APP_ROLLBACK_ENABLE=y
CONFIG_SECURE_SIGNED_APPS_NO_SECURE_BOOT=y
CONFIG_APP_RETRIEVE_LEN_ELF_SHA=16
CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y
CONFIG_PARTITION_TABLE_CUSTOM=y
CONFIG_PARTITION_TABLE_CUSTOM_FILENAME="partitions_ecu.csv"
CONFIG_CLI_UART_STATIC_TASK=y
CONFIG_COMPILER_HIDE_PATHS_MACROS=n
CONFIG_COMPILER_CXX_EXCEPTIONS=y
CONFIG_COMPILER_STACK_CHECK_MODE_NORM=y
CONFIG_COMPILER_WARN_WRITE_STRINGS=y
CONFIG_RMT_ISR_IRAM_SAFE=y
CONFIG_RMT_SUPPRESS_DEPRECATE_WARN=y
CONFIG_ESP_TLS_SERVER_SESSION_TICKETS=y
CONFIG_ESP_EVENT_POST_FROM_ISR_SIZE=64
CONFIG_ESP_HTTP_CLIENT_ENABLE_BASIC_AUTH=y
CONFIG_ESP_HTTP_CLIENT_ENABLE_DIGEST_AUTH=y
CONFIG_HTTPD_MAX_REQ_HDR_LEN=1024
CONFIG_ESP_HTTPS_SERVER_ENABLE=y
CONFIG_ESP_SLEEP_FLASH_LEAKAGE_WORKAROUND=n
CONFIG_ESP_SLEEP_GPIO_RESET_WORKAROUND=n
CONFIG_ESP_PHY_REDUCE_TX_POWER=y
CONFIG_SPIRAM=y
CONFIG_SPIRAM_ALLOW_STACK_EXTERNAL_MEMORY=n
CONFIG_SPIRAM_SPEED_80M=y
CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL=1024
CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y
CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL=196608
CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY=y
CONFIG_ESP_DEFAULT_CPU_FREQ_MHZ_240=y
CONFIG_ESP_SYSTEM_EVENT_TASK_STACK_SIZE=4096
CONFIG_ESP_MAIN_TASK_STACK_SIZE=8192
CONFIG_ESP_MAIN_TASK_STATIC=y
CONFIG_ESP_CONSOLE_USB_SERIAL_JTAG=y
CONFIG_ESP_TASK_WDT_PANIC=y
CONFIG_ESP_TASK_WDT_TIMEOUT_S=10
CONFIG_ESP_IPC_TASK_STACK_SIZE=2048
CONFIG_ESP_TIMER_TASK_STACK_SIZE=4608
CONFIG_ESP_WIFI_STATIC_RX_BUFFER_NUM=10
CONFIG_ESP_WIFI_CACHE_TX_BUFFER_NUM=16
CONFIG_ESP_WIFI_RX_BA_WIN=6
CONFIG_ESP_WIFI_STA_DISCONNECTED_PM_ENABLE=n
CONFIG_ESP_COREDUMP_ENABLE_TO_FLASH=y
CONFIG_FREERTOS_HZ=1000
CONFIG_FREERTOS_THREAD_LOCAL_STORAGE_POINTERS=2
CONFIG_FREERTOS_VTASKLIST_INCLUDE_COREID=y
CONFIG_FREERTOS_GENERATE_RUN_TIME_STATS=y
CONFIG_FREERTOS_WATCHPOINT_END_OF_STACK=y
CONFIG_FREERTOS_ISR_STACKSIZE=2100
CONFIG_HEAP_POISONING_LIGHT=y
CONFIG_HEAP_TASK_TRACKING=y
CONFIG_HEAP_ABORT_WHEN_ALLOCATION_FAILS=y
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y
CONFIG_LOG_COLORS=n
CONFIG_LWIP_LOCAL_HOSTNAME="tibber_bridge"
CONFIG_LWIP_L2_TO_L3_COPY=y
CONFIG_LWIP_MAX_SOCKETS=16
CONFIG_LWIP_IP_FORWARD=y
CONFIG_LWIP_IPV4_NAPT=y
CONFIG_LWIP_IPV6_AUTOCONFIG=y
CONFIG_LWIP_IPV6_FORWARD=y
CONFIG_LWIP_IPV6_DHCP6=y
CONFIG_LWIP_TCP_SND_BUF_DEFAULT=5744
CONFIG_LWIP_TCP_WND_DEFAULT=5744
CONFIG_LWIP_TCPIP_TASK_STACK_SIZE=4096
CONFIG_LWIP_PPP_SUPPORT=y
CONFIG_LWIP_PPP_NOTIFY_PHASE_SUPPORT=y
CONFIG_LWIP_PPP_PAP_SUPPORT=y
CONFIG_LWIP_PPP_SERVER_SUPPORT=y
CONFIG_LWIP_ENABLE_LCP_ECHO=y
CONFIG_LWIP_PPP_DEBUG_ON=y
CONFIG_LWIP_DNS_MAX_SERVERS=9
CONFIG_LWIP_DEBUG=y
CONFIG_LWIP_DEBUG_ESP_LOG=y
CONFIG_MBEDTLS_EXTERNAL_MEM_ALLOC=y
CONFIG_MBEDTLS_AES_USE_INTERRUPT=n
CONFIG_MBEDTLS_MPI_USE_INTERRUPT=n
CONFIG_MQTT_SKIP_PUBLISH_IF_DISCONNECTED=y
CONFIG_MQTT_USE_CUSTOM_CONFIG=y
CONFIG_MQTT_TASK_STACK_STATIC=y
CONFIG_MQTT_OUTBOX_DATA_ON_EXTERNAL_MEMORY=y
CONFIG_SPI_FLASH_ERASE_YIELD_TICKS=10
CONFIG_SPI_FLASH_SUPPORT_BOYA_CHIP=n
CONFIG_SPI_FLASH_SUPPORT_TH_CHIP=n
CONFIG_FMB_TCP_UID_ENABLED=y
CONFIG_FMB_COMM_MODE_RTU_EN=n
CONFIG_FMB_COMM_MODE_ASCII_EN=n
CONFIG_FMB_MASTER_DELAY_MS_CONVERT=300
CONFIG_FMB_PORT_TASK_PRIO=13
CONFIG_FMB_PORT_TASK_AFFINITY_CPU1=y
CONFIG_FMB_CONTROLLER_SLAVE_ID_SUPPORT=n
CONFIG_FMB_CONTROLLER_STACK_STATIC=y
CONFIG_FMB_TIMER_USE_ISR_DISPATCH_METHOD=y
CONFIG_ESP_MODEM_USE_STATIC_TASK_STACK=y
CONFIG_ESP_MODEM_CMUX_USE_SHORT_PAYLOADS_ONLY=y

[KonstantinKondrashov]

It seems like the item has already been removed from the list ( pxItemToRemove )->pxContainer = NULL; so the next call of listREMOVE_ITEM() leads to this issue, I guess. Yes, it's probably a race condition issue.
We will try to investigate it further.

[jimmyw]

So i managed to bitsect and deploy with various features enabled/disabled that we did over the last releases.

The thing that made this crash, was that we changed from xTaskCreate to xTaskCreateStatic to static allocate tasks. We have noticed for example the mqtt client when we disconnect and connect, that memory might be so fragmented that we dont have a chunk of 6k internal ram available, and chip and to reset.

Rolling back to the version we did heap allocation of the stack, this rare crash completely stopped.

This could be an coincident, with us having a bug that managed to write to random ram, and it accidentally was in the TCL of the mqtt task, even if i find that unlikely. Everything pointed to a race.

I have no idea what could have happened, if it was a memory alignment issue or something like that.

We also noticed that the crash was when there was a high memory pressure, and the system malloc started to hand out PSRAM instead of internal ram that was emptied.

So i guess we can close this one, i got no way to reproduce this locally, and it was rarely happening in production with low ram and static tasks. Unless you have any idea on where to look.

[jimmyw]

This was my patch that made it faile:

diff --git c/Kconfig w/Kconfig
index 9eb6c0b..c128e9d 100644
--- c/Kconfig
+++ w/Kconfig
@@ -109,6 +109,13 @@ menu "ESP-MQTT Configurations"
         help
             MQTT task stack size
 
+    config MQTT_TASK_STACK_STATIC
+        bool "Use static stack for MQTT task"
+        default n
+        depends on MQTT_USE_CUSTOM_CONFIG
+        help
+            Use static stack for MQTT task
+
     config MQTT_DISABLE_API_LOCKS
         bool "Disable API locks"
         default n
diff --git c/mqtt_client.c w/mqtt_client.c
index cece4fd..99ada46 100644
--- c/mqtt_client.c
+++ w/mqtt_client.c
@@ -43,6 +43,11 @@ static int mqtt_message_receive(esp_mqtt_client_handle_t client, int read_poll_t
 static void esp_mqtt_client_dispatch_transport_error(esp_mqtt_client_handle_t client);
 static esp_err_t send_disconnect_msg(esp_mqtt_client_handle_t client);
 
+#if CONFIG_MQTT_TASK_STACK_STATIC
+static StaticTask_t s_mqtt_client_task;
+static StackType_t s_mqtt_client_stack[MQTT_TASK_STACK];
+#endif
+
 /**
  * @brief Processes error reported from transport layer (considering the message read status)
  *
@@ -1748,6 +1753,26 @@ esp_err_t esp_mqtt_client_start(esp_mqtt_client_handle_t client)
         return ESP_FAIL;
     }
     esp_err_t err = ESP_OK;
+#if CONFIG_MQTT_TASK_STACK_STATIC
+    if (client->config->task_stack != MQTT_TASK_STACK) {
+        ESP_LOGE(TAG, "MQTT task stack size must be %d", MQTT_TASK_STACK);
+        return ESP_FAIL;
+    }
+
+#if MQTT_CORE_SELECTION_ENABLED
+    ESP_LOGD(TAG, "Core selection enabled on %u", MQTT_TASK_CORE);
+    if (!(client->task_handle=xTaskCreateStaticPinnedToCore(esp_mqtt_task, "mqtt_task", MQTT_TASK_STACK, client, client->config->task_prio, s_mqtt_client_stack, &s_mqtt_client_task, MQTT_TASK_CORE))) {
+        ESP_LOGE(TAG, "Error create mqtt task");
+        err = ESP_FAIL;
+    }
+#else
+    ESP_LOGD(TAG, "Core selection disabled");
ent->config->task_prio, s_mqtt_client_stack, &s_mqtt_client_task))) {
+        ESP_LOGE(TAG, "Error create mqtt task");
+        err = ESP_FAIL;
+    }
+#endif
+#else
 #if MQTT_CORE_SELECTION_ENABLED
     ESP_LOGD(TAG, "Core selection enabled on %u", MQTT_TASK_CORE);
config->task_prio, &client->task_handle, MQTT_TASK_CORE) != pdTRUE) {
@@ -1760,6 +1785,7 @@ esp_err_t esp_mqtt_client_start(esp_mqtt_client_handle_t client)
         ESP_LOGE(TAG, "Error create mqtt task");
         err = ESP_FAIL;
     }
+#endif
 #endif
     MQTT_API_UNLOCK(client);
     return err;

[euripedesrocha]

@jimmyw could you please share the mqtt event handler that you are using? In particular, I'm interested to see the handling of the disconnected event.

From the first stack trace it looks like this happens just after a disconnection, am I correct?

Unrelated (but important for me :) ), could you share your reasoning for the mqtt task to be static, which problem you were targeting to solve with that change?

[jimmyw]

Now i`m not personally responsible for this code, as it might not be the most pretty. But i cant see any wrong with it.

void mqtt_change_bit_and_fire_event(bool set, EventBits_t bit)
{
    mqtt_event_data_t event_data = {.bit = bit, .set = set};

    if (set) {
        xEventGroupSetBits(mqtt_event_group, bit);
    } else {
        xEventGroupClearBits(mqtt_event_group, bit);
    }

    ESP_ERROR_CHECK(esp_event_post(TIBBER_MQTT_EVENT, TIBBER_MQTT_EVENT_STATUS_CHANGE, &event_data, sizeof(mqtt_event_data_t),
                                   MS_TO_TICKS(CONFIG_TIBBER_MAX_POST_EVENT_BLOCK_MS)));
}

static void mqtt_event_handler(void *handler_args, esp_event_base_t base, int32_t event_id, void *event_data)
{
    (void)base;
    esp_mqtt_event_handle_t event = event_data;

    switch ((esp_mqtt_event_id_t)event->event_id) {
    case MQTT_EVENT_CONNECTED:
        ESP_LOGD(TAG, "MQTT_EVENT_CONNECTED");
        memset(&last_mqtt_error, 0, sizeof(last_mqtt_error));
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_DISCONNECTED_BIT);
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_CONNECTING_BIT);
        mqtt_change_bit_and_fire_event(BIT_SET, MQTT_CONNECTED_BIT);
        break;
    case MQTT_EVENT_DISCONNECTED:
        ESP_LOGW(TAG, "MQTT_EVENT_DISCONNECTED");
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_CONNECTING_BIT);
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_CONNECTED_BIT);
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_PUBLISHED);
        mqtt_change_bit_and_fire_event(BIT_CLEAR, MQTT_SUBSCRIBED_BIT);
        mqtt_change_bit_and_fire_event(BIT_SET, MQTT_DISCONNECTED_BIT);
        break;
...

[jimmyw]

So the reason why we tried static tasks, is that we have high memory pressure, and when changing mqtt server or on a network issues, we will reconnect mqtt again.

Doing esp_mqtt_client_start we will create a mqtt task, allocated on the heap.

esp_err_t esp_mqtt_client_start(esp_mqtt_client_handle_t client)
...
    if (xTaskCreate(esp_mqtt_task, "mqtt_task", client->config->task_stack, client, client->config->task_prio, &client->task_handle) != pdTRUE) {
        ESP_LOGE(TAG, "Error create mqtt task");
        err = ESP_FAIL;
    }

This requires 6kb of continuous ram, and in production we have clients with months of runtime causing memory fragmentation to that extent that we did not have 6kb free to allocate. This made the xTaskCreate fail, and the system to restart.

Moving the task to static memory, did solve this issue, as we used the same memory address all the time. It also helped debugging crashes, as the memory offsets where the same in similar crashes, so we could learn the pattern so i kind of liked this approach.

We since then solved the worst contenders in memory fragmentation so its not as great of a problem right now, that why we could safely revert that change.

[jimmyw]

This is one thing that helped memory fragmentation a lot.

We highly rely on esp_events that runs callbacks, that allocates ram.

The allocation of the event always happens before the callback, and then freed after leaving a minimal hole in between.

I solved that to put the data (Usually just an integer or a pointer) directly in the queue, if there was space. Also to fit some of our small structs i made the size of the in queue storage configurable.

If you are interested, i can set up a PR with this change.

commit f98338600d58c3bfce0ee0282617af5c614db7b3
Author: Jimmy Wennlund <jimmy@wennlund.nu>
Date:   Sat Nov 23 00:42:52 2024 +0100

    Allow a event to carry data without allocating on the heap. Avoids memory fragmentation

diff --git a/components/esp_event/Kconfig b/components/esp_event/Kconfig
index 0ad0f90655..fe3a68e6d8 100644
--- a/components/esp_event/Kconfig
+++ b/components/esp_event/Kconfig
@@ -14,6 +14,14 @@ menu "Event Loop Library"
         help
             Enable posting events from interrupt handlers.
 
+    config ESP_EVENT_POST_FROM_ISR_SIZE
+        int "Max size of data from events"
+        default 4
+        depends on ESP_EVENT_POST_FROM_ISR
+        help
+            Enable posting events from interrupt handlers.
+
+
     config ESP_EVENT_POST_FROM_IRAM_ISR
         bool "Support posting events from ISRs placed in IRAM"
         default y
diff --git a/components/esp_event/esp_event.c b/components/esp_event/esp_event.c
index d1b0e7bb4e..ef4c24fc57 100644
--- a/components/esp_event/esp_event.c
+++ b/components/esp_event/esp_event.c
@@ -839,19 +839,29 @@ esp_err_t esp_event_post_to(esp_event_loop_handle_t event_loop, esp_event_base_t
     memset((void*)(&post), 0, sizeof(post));
 
     if (event_data != NULL && event_data_size != 0) {
+#if CONFIG_ESP_EVENT_POST_FROM_ISR
+
+        if (event_data_size > sizeof(post.data.val)) {
+             post.data.ptr = calloc(1, event_data_size);
+
+            if (post.data.ptr == NULL) {
+                return ESP_ERR_NO_MEM;
+            }
+            post.data_allocated = true;
+            memcpy(post.data.ptr, event_data, event_data_size);
+        } else {
+            memcpy((void*)(&(post.data.val)), event_data, event_data_size);
+        }
+
+        post.data_set = true;
+#else
         // Make persistent copy of event data on heap.
         void* event_data_copy = calloc(1, event_data_size);
 
         if (event_data_copy == NULL) {
             return ESP_ERR_NO_MEM;
         }
-
         memcpy(event_data_copy, event_data, event_data_size);
-#if CONFIG_ESP_EVENT_POST_FROM_ISR
-        post.data.ptr = event_data_copy;
-        post.data_allocated = true;
-        post.data_set = true;
-#else
         post.data = event_data_copy;
 #endif
     }
diff --git a/components/esp_event/private_include/esp_event_internal.h b/components/esp_event/private_include/esp_event_internal.h
index dd403f6d7c..ea7a1bd9dc 100644
--- a/components/esp_event/private_include/esp_event_internal.h
+++ b/components/esp_event/private_include/esp_event_internal.h
@@ -93,7 +93,7 @@ typedef struct esp_event_loop_instance {
 
 #if CONFIG_ESP_EVENT_POST_FROM_ISR
 typedef union esp_event_post_data {
-    uint32_t val;
+    uint8_t val[CONFIG_ESP_EVENT_POST_FROM_ISR_SIZE];
     void *ptr;
 } esp_event_post_data_t;
 #else

 

[jimmyw]

Here is another good one that kind of helped, i combining two heap allocations into one in the lwip stack and it seemed to help, but also boosted performance avoiding contention in the heap allocator.

The main issue here was really that the small 4 byte heap allocation that was done just as a 4 byte pointer to a queue, was done in external ram if you had the CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP option enabled. This is problematic trying to access internal ram possibly in interrupts, by accessing a 4 byte pointer stored in external ram.

This patch allocated the struct and the semaphore in the same go, always in internal ram and helped a lot with stability/performance. Also let me know if you like a PR on this.

diff --git a/components/esp_netif/lwip/esp_netif_lwip.c b/components/esp_netif/lwip/esp_netif_lwip.c
index b534fcbfe7..04532455d6 100644
--- a/components/esp_netif/lwip/esp_netif_lwip.c
+++ b/components/esp_netif/lwip/esp_netif_lwip.c
@@ -203,8 +203,8 @@ static void netif_unset_garp_flag(struct netif *netif)
 #endif  // CONFIG_LWIP_GARP_TMR_INTERVAL
 
 #if !LWIP_TCPIP_CORE_LOCKING
-static sys_sem_t api_sync_sem = NULL;
-static sys_sem_t api_lock_sem = NULL;
+static sys_sem_t api_sync_sem = {0};
+static sys_sem_t api_lock_sem = {0};
 #endif
 
 /**
@@ -563,14 +563,14 @@ esp_err_t esp_netif_init(void)
     }
 
 #if !LWIP_TCPIP_CORE_LOCKING
-    if (!api_sync_sem) {
+    if (!sys_sem_valid(&api_sync_sem)) {
         if (ERR_OK != sys_sem_new(&api_sync_sem, 0)) {
             ESP_LOGE(TAG, "esp netif api sync sem init fail");
             return ESP_FAIL;
         }
     }
 
-    if (!api_lock_sem) {
+    if (!sys_sem_valid(&api_lock_sem)) {
         if (ERR_OK != sys_sem_new(&api_lock_sem, 1)) {
             ESP_LOGE(TAG, "esp netif api lock sem init fail");
             return ESP_FAIL;
diff --git a/components/lwip/port/freertos/include/arch/sys_arch.h b/components/lwip/port/freertos/include/arch/sys_arch.h
index ba85471397..b2d53764a1 100644
--- a/components/lwip/port/freertos/include/arch/sys_arch.h
+++ b/components/lwip/port/freertos/include/arch/sys_arch.h
@@ -18,13 +18,14 @@ extern "C" {
 #endif
 
 
-typedef SemaphoreHandle_t sys_sem_t;
+typedef StaticSemaphore_t sys_sem_t;
 typedef SemaphoreHandle_t sys_mutex_t;
 typedef TaskHandle_t sys_thread_t;
 
 typedef struct sys_mbox_s {
-  QueueHandle_t os_mbox;
+  StaticQueue_t os_mbox;
   void *owner;
+  uint8_t buffer[0];
 }* sys_mbox_t;
 
 /** This is returned by _fromisr() sys functions to tell the outermost function
@@ -42,7 +43,6 @@ void sys_delay_ms(uint32_t ms);
 #define sys_mutex_set_invalid( x ) ( ( *x ) = NULL )
 #endif
 
-#define sys_mbox_valid( x ) ( ( ( *x ) == NULL) ? pdFALSE : pdTRUE )
 
 /* Define the sys_mbox_set_invalid() to empty to support lock-free mbox in ESP LWIP.
  *
@@ -61,10 +61,11 @@ void sys_delay_ms(uint32_t ms);
  * However, if the sys_mbox_set_invalid() is not called after sys_mbox_free(), e.g. in netconn_alloc(),
  * we need to initialize the mbox to invalid explicitly since sys_mbox_set_invalid() now is empty.
  */
+#define sys_mbox_valid( x ) ( ( ( *x ) == NULL) ? pdFALSE : pdTRUE )
 #define sys_mbox_set_invalid( x )  *x = NULL
 
-#define sys_sem_valid( x ) ( ( ( *x ) == NULL) ? pdFALSE : pdTRUE )
-#define sys_sem_set_invalid( x ) ( ( *x ) = NULL )
+#define sys_sem_valid( x ) ( ( memcmp(( x ), &(StaticSemaphore_t){0}, sizeof(StaticSemaphore_t)) == 0) ? pdFALSE : pdTRUE )
+#define sys_sem_set_invalid( x ) memset((x), 0, sizeof(StaticSemaphore_t))
 
 void sys_delay_ms(uint32_t ms);
 sys_sem_t* sys_thread_sem_init(void);
diff --git a/components/lwip/port/freertos/sys_arch.c b/components/lwip/port/freertos/sys_arch.c
index 0f8cb26376..92f1016ec5 100644
--- a/components/lwip/port/freertos/sys_arch.c
+++ b/components/lwip/port/freertos/sys_arch.c
@@ -108,14 +108,14 @@ sys_sem_new(sys_sem_t *sem, u8_t count)
   LWIP_ASSERT("initial_count invalid (neither 0 nor 1)",
              (count == 0) || (count == 1));
 
-  *sem = xSemaphoreCreateBinary();
-  if (*sem == NULL) {
+  QueueHandle_t res = xSemaphoreCreateBinaryStatic(sem);
+  if ((sys_sem_t *)res != sem) {
       LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("sys_sem_new: out of mem\r\n"));
       return ERR_MEM;
   }
 
   if (count == 1) {
-      BaseType_t ret = xSemaphoreGive(*sem);
+      BaseType_t ret = xSemaphoreGive(sem);
       LWIP_ASSERT("sys_sem_new: initial give failed", ret == pdTRUE);
       (void)ret;
   }
@@ -131,7 +131,7 @@ sys_sem_new(sys_sem_t *sem, u8_t count)
 void
 sys_sem_signal(sys_sem_t *sem)
 {
-  BaseType_t ret = xSemaphoreGive(*sem);
+  BaseType_t ret = xSemaphoreGive(sem);
   /* queue full is OK, this is a signal only... */
   LWIP_ASSERT("sys_sem_signal: sane return value",
              (ret == pdTRUE) || (ret == errQUEUE_FULL));
@@ -144,7 +144,7 @@ int
 sys_sem_signal_isr(sys_sem_t *sem)
 {
     BaseType_t woken = pdFALSE;
-    xSemaphoreGiveFromISR(*sem, &woken);
+    xSemaphoreGiveFromISR(sem, &woken);
     return woken == pdTRUE;
 }
 
@@ -162,7 +162,7 @@ sys_arch_sem_wait(sys_sem_t *sem, u32_t timeout)
 
   if (!timeout) {
     /* wait infinite */
-    ret = xSemaphoreTake(*sem, portMAX_DELAY);
+    ret = xSemaphoreTake((QueueHandle_t)sem, portMAX_DELAY);
     LWIP_ASSERT("taking semaphore failed", ret == pdTRUE);
   } else {
     /* Round up the number of ticks.
@@ -172,7 +172,7 @@ sys_arch_sem_wait(sys_sem_t *sem, u32_t timeout)
      * 1 tick before triggering a timeout. Thus, we need to pass 2 ticks as a timeout
      * to `xSemaphoreTake`. */
     TickType_t timeout_ticks = ((timeout + portTICK_PERIOD_MS - 1) / portTICK_PERIOD_MS) + 1;
-    ret = xSemaphoreTake(*sem, timeout_ticks);
+    ret = xSemaphoreTake((QueueHandle_t)sem, timeout_ticks);
     if (ret == errQUEUE_EMPTY) {
       /* timed out */
       return SYS_ARCH_TIMEOUT;
@@ -191,8 +191,8 @@ sys_arch_sem_wait(sys_sem_t *sem, u32_t timeout)
 void
 sys_sem_free(sys_sem_t *sem)
 {
-  vSemaphoreDelete(*sem);
-  *sem = NULL;
+  vSemaphoreDelete((QueueHandle_t)sem);
+  memset(sem, 0, sizeof(*sem));
 }
 
 /**
@@ -205,15 +205,15 @@ sys_sem_free(sys_sem_t *sem)
 err_t
 sys_mbox_new(sys_mbox_t *mbox, int size)
 {
-  *mbox = mem_malloc(sizeof(struct sys_mbox_s));
+  *mbox = (sys_mbox_t)heap_caps_malloc(sizeof(struct sys_mbox_s) + (size * sizeof(void *)), ( MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT ));
   if (*mbox == NULL){
     LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("fail to new *mbox\n"));
     return ERR_MEM;
   }
 
-  (*mbox)->os_mbox = xQueueCreate(size, sizeof(void *));
+  QueueHandle_t res = xQueueCreateStatic(size, sizeof(void *), (*mbox)->buffer, &(*mbox)->os_mbox);
 
-  if ((*mbox)->os_mbox == NULL) {
+  if ((QueueHandle_t)&(*mbox)->os_mbox != res) {
     LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("fail to new (*mbox)->os_mbox\n"));
     free(*mbox);
     return ERR_MEM;
@@ -223,7 +223,7 @@ sys_mbox_new(sys_mbox_t *mbox, int size)
   (*mbox)->owner = NULL;
 #endif
 
-  LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("new *mbox ok mbox=%p os_mbox=%p\n", *mbox, (*mbox)->os_mbox));
+  LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("new *mbox ok mbox=%p os_mbox=%p\n", *mbox, (QueueHandle_t)&(*mbox)->os_mbox));
   return ERR_OK;
 }
 
@@ -236,7 +236,7 @@ sys_mbox_new(sys_mbox_t *mbox, int size)
 void
 sys_mbox_post(sys_mbox_t *mbox, void *msg)
 {
-  BaseType_t ret = xQueueSendToBack((*mbox)->os_mbox, &msg, portMAX_DELAY);
+  BaseType_t ret = xQueueSendToBack((QueueHandle_t)&(*mbox)->os_mbox, &msg, portMAX_DELAY);
   LWIP_ASSERT("mbox post failed", ret == pdTRUE);
   (void)ret;
 }
@@ -253,10 +253,10 @@ sys_mbox_trypost(sys_mbox_t *mbox, void *msg)
 {
   err_t xReturn;
 
-  if (xQueueSend((*mbox)->os_mbox, &msg, 0) == pdTRUE) {
+  if (xQueueSend((QueueHandle_t)&(*mbox)->os_mbox, &msg, 0) == pdTRUE) {
     xReturn = ERR_OK;
   } else {
-    LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("trypost mbox=%p fail\n", (*mbox)->os_mbox));
+    LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("trypost mbox=%p fail\n", (QueueHandle_t)&(*mbox)->os_mbox));
     xReturn = ERR_MEM;
   }
 
@@ -278,7 +278,7 @@ sys_mbox_trypost_fromisr(sys_mbox_t *mbox, void *msg)
   BaseType_t ret;
   BaseType_t xHigherPriorityTaskWoken = pdFALSE;
 
-  ret = xQueueSendFromISR((*mbox)->os_mbox, &msg, &xHigherPriorityTaskWoken);
+  ret = xQueueSendFromISR((QueueHandle_t)&(*mbox)->os_mbox, &msg, &xHigherPriorityTaskWoken);
   if (ret == pdTRUE) {
     if (xHigherPriorityTaskWoken == pdTRUE) {
       return ERR_NEED_SCHED;
@@ -310,11 +310,11 @@ sys_arch_mbox_fetch(sys_mbox_t *mbox, void **msg, u32_t timeout)
 
   if (timeout == 0) {
     /* wait infinite */
-    ret = xQueueReceive((*mbox)->os_mbox, &(*msg), portMAX_DELAY);
+    ret = xQueueReceive((QueueHandle_t)&(*mbox)->os_mbox, &(*msg), portMAX_DELAY);
     LWIP_ASSERT("mbox fetch failed", ret == pdTRUE);
   } else {
     TickType_t timeout_ticks = timeout / portTICK_PERIOD_MS;
-    ret = xQueueReceive((*mbox)->os_mbox, &(*msg), timeout_ticks);
+    ret = xQueueReceive((QueueHandle_t)&(*mbox)->os_mbox, &(*msg), timeout_ticks);
     if (ret == errQUEUE_EMPTY) {
       /* timed out */
       *msg = NULL;
@@ -342,7 +342,7 @@ sys_arch_mbox_tryfetch(sys_mbox_t *mbox, void **msg)
   if (msg == NULL) {
     msg = &msg_dummy;
   }
-  ret = xQueueReceive((*mbox)->os_mbox, &(*msg), 0);
+  ret = xQueueReceive((QueueHandle_t)&(*mbox)->os_mbox, &(*msg), 0);
   if (ret == errQUEUE_EMPTY) {
     *msg = NULL;
     return SYS_MBOX_EMPTY;
@@ -372,10 +372,10 @@ sys_mbox_free(sys_mbox_t *mbox)
   if ((NULL == mbox) || (NULL == *mbox)) {
     return;
   }
-  UBaseType_t msgs_waiting = uxQueueMessagesWaiting((*mbox)->os_mbox);
+  UBaseType_t msgs_waiting = uxQueueMessagesWaiting((QueueHandle_t)&(*mbox)->os_mbox);
   LWIP_ASSERT("mbox quence not empty", msgs_waiting == 0);
 
-  vQueueDelete((*mbox)->os_mbox);
+  vQueueDelete((QueueHandle_t)&(*mbox)->os_mbox);
   free(*mbox);
   *mbox = NULL;
 
@@ -503,31 +503,34 @@ sys_thread_sem_free(void* data) // destructor for TLS semaphore
 {
   sys_sem_t *sem = (sys_sem_t*)(data);
 
-  if (sem && *sem){
-    LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("sem del, sem=%p\n", *sem));
-    vSemaphoreDelete(*sem);
+  if (sem){
+    LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("sem del, sem=%p\n", sem));
+    vSemaphoreDelete((QueueHandle_t)sem);
   }
 
   if (sem) {
     LWIP_DEBUGF(ESP_THREAD_SAFE_DEBUG, ("sem pointer del, sem_p=%p\n", sem));
-    free(sem);
+    heap_caps_free(sem);
   }
 }
 
 sys_sem_t*
 sys_thread_sem_init(void)
 {
-  sys_sem_t *sem = (sys_sem_t*)mem_malloc(sizeof(sys_sem_t*));
+  // Always allocate semaphores from internal memory
+  sys_sem_t *sem = (sys_sem_t*)heap_caps_malloc(sizeof(StaticSemaphore_t), ( MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT ));
 
   if (!sem){
     ESP_LOGE(TAG, "thread_sem_init: out of memory");
     return 0;
   }
 
-  *sem = xSemaphoreCreateBinary();
-  if (!(*sem)){
-    free(sem);
-    ESP_LOGE(TAG, "thread_sem_init: out of memory");
+  // If successful, create a binary semaphore the pointer to the semaphore is returned
+  QueueHandle_t res = xSemaphoreCreateBinaryStatic(sem);
+
+  if (res != (QueueHandle_t)sem){
+    heap_caps_free(sem);
+    ESP_LOGE(TAG, "thread_sem_init: unable to create semaphore %p != %p", res, sem);
     return 0;
   }