External ram allocation fail on one esp32 but not on the others?

[zekageri]

Board

esp-wrover-kit

Device Description

esp32-wrover-e ( 8mb psram 16mb flash )

Hardware Configuration

ETH_Lan8720, DS3231 (i2c), Heavy serial 1 ( modbus ), SPI display

Version

latest development Release Candidate (RC-X)

IDE Name

Platform IO

Operating System

Windows 10

Flash frequency

80Mhz

PSRAM enabled

yes

Upload speed

115200

Description

External ram memory allocation assert fail. Happens on one esp32-wrover-e but not on others with the exact same sketch.
How to capture the exception?

Sketch

// Crash is at total random allocations but all looks like this ( using ArduinoJSON ):

#include <Arduino.h>
#include <ArduinoJson.h>

struct SpiRamAllocator {
    void* allocate(size_t size) {return heap_caps_malloc(size, MALLOC_CAP_SPIRAM);}
    void deallocate(void* pointer) {heap_caps_free(pointer);}
    void* reallocate(void* ptr, size_t new_size) {return heap_caps_realloc(ptr, new_size, MALLOC_CAP_SPIRAM);}
};
using SpiRamJsonDocument = BasicJsonDocument<SpiRamAllocator>;



SpiRamJsonDocument data(DATA_SIZE);


// Example function when using SpiRamJsonDocument:


#define GRAPH_SIZE 20000
char * graph;
graph = (char *) ps_malloc (GRAPH_SIZE * sizeof (char));  

void thermSystem::trimGraph(){
    // Check if previous allocation was a success.
    if( graph == NULL ) { Serial.println("Failed to allocate memory for graph data"); return; }

    SpiRamJsonDocument allGraphData(GRAPH_SIZE);
    DeserializationError error = deserializeJson(allGraphData, (const char *)graph, GRAPH_SIZE);
    if (!error) {
        // Get only the graph where the zoneID matches.
        JsonObject graphData = allGraphData[zoneID];
        if( !graphData.isNull() ){
            if( serializeJson(graphData, graph, GRAPH_SIZE) ) {
                #if THERM_DEBUG
                    Serial.printf("Trimmed graph\n");
                #endif
            }
        }
    }else{
        #if THERM_DEBUG
            Serial.printf("Failed to deserialize ALL therm graph. Error: %s\n",error.c_str());
        #endif
    }
}

Debug Message

E (1851) gpio: gpio_set_level(226): GPIO output gpio_num error
E (1851) gpio: gpio_set_level(226): GPIO output gpio_num error

assert failed: block_trim_free heap_tlsf.c:377 (block_is_free(block) && "block must be free")


Backtrace:0x40083cbd:0x3ffd57f00x4008ece5:0x3ffd5810 0x400944d9:0x3ffd5830 0x40093621:0x3ffd5960 0x40093e67:0x3ffd5980 0x400940e8:0x3ffd59a0 0x400840a2:0x3ffd59c0 0x400840b5:0x3ffd59f0 0x400d2b8a:0x3ffd5a10 0x400dd47e:0x3ffd5a30 0x400dd4e1:0x3ffd5aa0 0x400ddb01:0x3ffd5ac0 0x400f42aa:0x3ffd5b00 0x400f484a:0x3ffd5d90 0x400f487b:0x3ffd5db0 0x400f48e9:0x3ffd5dd0 

  #0  0x40083cbd:0x3ffd57f0 in panic_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/panic.c:402   
  #1  0x4008ece5:0x3ffd5810 in esp_system_abort at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_system/esp_system.c:128
  #2  0x400944d9:0x3ffd5830 in __assert_func at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/newlib/assert.c:85     
  #3  0x40093621:0x3ffd5960 in block_locate_free at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_tlsf.c:447
      (inlined by) tlsf_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_tlsf.c:757
  #4  0x40093e67:0x3ffd5980 in multi_heap_malloc_impl at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap.c:197
  #5  0x400940e8:0x3ffd59a0 in multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c:230
      (inlined by) multi_heap_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/multi_heap_poisoning.c:219  #6  0x400840a2:0x3ffd59c0 in heap_caps_malloc_base at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c:147
  #7  0x400840b5:0x3ffd59f0 in heap_caps_malloc at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/heap/heap_caps.c:167  #8  0x400d2b8a:0x3ffd5a10 in SpiRamAllocator::allocate(unsigned int) at src/utilities/globals.h:8
      (inlined by) ArduinoJson6192_F1::AllocatorOwner<SpiRamAllocator>::allocate(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:20
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::allocPool(unsigned int) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:137
      (inlined by) ArduinoJson6192_F1::BasicJsonDocument<SpiRamAllocator>::BasicJsonDocument(unsigned int, SpiRamAllocator) at lib/ArduinoJson-6.x/src/ArduinoJson/Document/BasicJsonDocument.hpp:44
  #9  0x400dd47e:0x3ffd5a30 in shutterSys::trimSunGraph() at src/utilities/components/shuttersGraph.cpp:55
  #10 0x400dd4e1:0x3ffd5aa0 in shutterSys::loadSunCycles() at src/utilities/components/shuttersGraph.cpp:12
  #11 0x400ddb01:0x3ffd5ac0 in shutterSys::update(ArduinoJson6192_F1::ObjectRef, char const*, int, char const*) at src/utilities/components/shuttersInit.cpp:53 
  #12 0x400f42aa:0x3ffd5b00 in zSystem::createComponents(int) at src/utilities/zones.cpp:284
  #13 0x400f484a:0x3ffd5d90 in zSystem::readSavedZones() at src/utilities/zones.cpp:113
  #14 0x400f487b:0x3ffd5db0 in zSystem::setup() at src/utilities/zones.cpp:76   
  #15 0x400f48e9:0x3ffd5dd0 in zonesTask(void*) at src/utilities/zones.cpp:822  




ELF file SHA256: 0000000000000000

Rebooting...

Other Steps to Reproduce

I'm using ArduinoJsonAllocator for a lot of JSON serialization / deserialization.
This error happens on only one esp32 ( tested on 5 chip with the exact same parameters )

I can not capture this exception because it happens internally.

Error:
assert failed: block_trim_free heap_tlsf.c:377 (block_is_free(block) && "block must be free")

I have found two issues that stated that problem but it seems to me that it was patched a long time ago.

1. One case in github
2. Other case in github

I have a check in setup which looks like this but it did not help:

void setup() {
    Serial.begin(115200,SERIAL_8N1,DEBUG_RX,DEBUG_TX);
    vTaskDelay(1000);
   
    // The following line evaulates to true.
    if( !psramFound() ){
        Serial.println("Something wrong with the external ram.");
        while(1){ vTaskDelay(1); }
    }
}

I have checked existing issues, online documentation and the Troubleshooting Guide

• I confirm I have checked existing issues, online documentation and Troubleshooting guide.

[zekageri]

This crash happened again. The chip can not boot because of this error.

Here is the crash now:

New light updated with name: Spot and id: r_l7syypoc_jb29u
New light updated with name: Csillár and id: k_l7syz7o9_fibq8
New light updated with name: Spot and id: b_l7sz1dne_r6qqh
New light updated with name: Spot and id: q_l7sz3188_5h976
New light updated with name: Spot and id: v_l7sz4gau_lslwi

assert failed: block_trim_free heap_tlsf.c:377 (block_is_free(block) && "block must be free")


Backtrace:0x40083cbd:0x3ffd57e00x4008ece5:0x3ffd5800 0x400944d9:0x3ffd5820 0x40093621:0x3ffd5950 0x40093e67:0x3ffd5970 0x400940e8:0x3ffd5990 0x400840a2:0x3ffd59b0 0x400840b5:0x3ffd59e0 0x400d297e:0x3ffd5a00 0x400ddf85:0x3ffd5a20 0x400ddfe5:0x3ffd5a90 0x400de60d:0x3ffd5ab0 0x400f60d9:0x3ffd5af0 0x400f669e:0x3ffd5d90 0x400f66cf:0x3ffd5db0 0x400f673d:0x3ffd5dd0 

  #0  0x40083cbd:0x3ffd57e0 in esp_rom_uart_tx_wait_idle at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/esp_rom/patches/esp_rom_uart.c:41
  #1  0x4008ece5:0x3ffd5800 in cpu_ll_get_core_id at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/hal/esp32/include/hal/cpu_ll.h:35
      (inlined by) xPortGetCoreID at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/port/xtensa/include/freertos/portmacro.h:634
      (inlined by) xTaskRemoveFromEventList at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/freertos/tasks.c:3705
  #2  0x400944d9:0x3ffd5820 in ?? ??:0
  #3  0x40093621:0x3ffd5950 in spi_flash_chip_generic_erase_block at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/spi_flash/spi_flash_chip_generic.c:191
  #4  0x40093e67:0x3ffd5970 in ?? ??:0
  #5  0x400940e8:0x3ffd5990 in ?? ??:0
  #6  0x400840a2:0x3ffd59b0 in heap_caps_realloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:381
      (inlined by) heap_caps_realloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:347
  #7  0x400840b5:0x3ffd59e0 in heap_caps_realloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:382     
      (inlined by) heap_caps_realloc_base at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/heap/heap_caps.c:347
  #8  0x400d297e:0x3ffd5a00 in _stext at ??:?
  #9  0x400ddf85:0x3ffd5a20 in MDNSResponder::addService(char*, char*, unsigned short) at C:/Users/zekag/.platformio/packages/framework-arduinoespressif32/libraries/ESPmDNS/src/ESPmDNS.cpp:147
  #10 0x400ddfe5:0x3ffd5a90 in MDNSResponder::addServiceTxt(char*, char*, char*, char*) at C:/Users/zekag/.platformio/packages/framework-arduinoespressif32/libraries/ESPmDNS/src/ESPmDNS.cpp:155
  #11 0x400de60d:0x3ffd5ab0 in ErriezDS3231::readBuffer(unsigned char, void*, unsigned char) at lib/ErriezDS3231/src/ErriezDS3231.cpp:898       
  #12 0x400f60d9:0x3ffd5af0 in wpa_supplicant_process_1_of_2_wpa at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:1415
      (inlined by) wpa_supplicant_process_1_of_2 at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:1541
      (inlined by) wpa_sm_rx_eapol at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:2031      
  #13 0x400f669e:0x3ffd5d90 in wpa_supplicant_activate_ptk at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:1265
      (inlined by) wpa_supplicant_send_4_of_4_txcallback at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:1281
      (inlined by) eapol_txcb at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:2469
  #14 0x400f66cf:0x3ffd5db0 in wpa_supplicant_send_4_of_4_txcallback at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:1298
      (inlined by) eapol_txcb at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:2469
  #15 0x400f673d:0x3ffd5dd0 in wpa_sta_in_4way_handshake at /Users/ficeto/Desktop/ESP32/ESP32S2/esp-idf-public/components/wpa_supplicant/src/rsn_supp/wpa.c:2493




ELF file SHA256: 0000000000000000

This is a different ESP from the same modell. Heavy PS-ram use.
Ps ram is allocated on class creation, but the class creation is not at startup, but inside setup() so the ps ram is inited.

Plus the sketch uses ps ram before this error without issue.

My sketch initializing tasks one by one at startup.

void initTasks(){
    // Every init is a task creation.
    hsh_modbus.init(-1,3,MODBUS_SYS_STACK_SIZE);
    vTaskDelay(100);
    hsh_Server.init(1,2,SERVER_SYS_STACK_SIZE);
    hsh_Performance.init(1,2,PERFORMANCE_SYS_STACK_SIZE);
    hsh_timeSystem.init(1,2,TIME_SYS_STACK_SIZE);
    zones.init(1,3,ZONES_SYS_STACK_SIZE);

    xTaskCreateUniversal(shaderTask, "HSH_SHADER_TASK", 4000, NULL, 4, NULL, 1);
}

The crash happens in the zones task at it's setup.
Inside this task i read a config file from LitleFS in JSON format and start to loop over it.
For every component inside the JSON file i create a class dynamically like this (Using ArduinoJSON):

SpiRamJsonDocument zonesObj(ZONES_OBJ_SIZE);
DeserializationError error = deserializeJson(zonesObj, (const char *)zones, ZONES_OBJ_SIZE);
if (error) { return; }
JsonObject zones = zonesObj.as<JsonObject>();
for (JsonPair zoneRef : zones) {
    const char* zoneID  = zoneRef.key().c_str();
    JsonObject zone     = zones[zoneID];
    boolean isZone      = zone["isZone"].as<boolean>();
    if( !isZone ){ continue; }

   JsonObject lightsObj   = zone["lights"].as<JsonObject>();
    if( !lightsObj.isNull() ){
        for (JsonPair componentRef : lightsObj) {
            if( lightCount >= MAX_LIGHTS ){break;}
            const char* componentID  = componentRef.key().c_str();
            JsonObject component     = lightsObj[componentID];
            lightsArray[lightCount]  = new lightSystem();
            if( !lightsArray[lightCount] ){ continue; }
            lightsArray[lightCount]->update(component,componentID,lightCount,zoneID);
            lightCount++;
        }
    }
}

As you can see in the error log, it start to create the light classes and suddenly it crashes with this error.

Light class constructor and descructor looks like this:

// Constructor
void lightSystem::allocateResources(){
    outputs  = (char *) ps_malloc (IO_SIZE * sizeof (char));
    inputs   = (char *) ps_malloc (IO_SIZE * sizeof (char));
    triggerInputs = (char *) ps_malloc (IO_SIZE * sizeof (char));

    id       = (char *) ps_malloc (IDS_AND_NAMES_SIZE * sizeof (char));
    zoneID   = (char *) ps_malloc (IDS_AND_NAMES_SIZE * sizeof (char));
    name     = (char *) ps_malloc (IDS_AND_NAMES_SIZE * sizeof (char));

    if( outputs == NULL || inputs == NULL || triggerInputs == NULL || id == NULL || zoneID == NULL || name == NULL ){
        Serial.println("[LIGHT_SYS] - Failed to allocate resources");
    }
}
// Descurtor
void lightSystem::freeResources(){
    free(id);
    free(zoneID);
    free(name);
    free(outputs);
    free(inputs);
    free(triggerInputs);
}

LightsArray holds the class pointers. It looks like this:

extern lightSystem* lightsArray[MAX_LIGHTS];

What could be the problem?

[me-no-dev]

@zekageri this happens only with one particular board, but not with any other one, correct? Even though both traces are the same, the cause looks to be the same.

@igrr do you have any pointers what could be going wrong with PSRAM? This seems to be an ECO3 ESP32, so could it be the PSRAM chip is failing in some way?

[zekageri]

This is both an ESP32-Wrover with 8mb ps ram and 16mb flash. Both chip is the same type. I ditched the other one because of this error. I thought that the ext ram died in one and replaced the chip. But this one does it too.

[zekageri]

Now it could start but i got this on serial

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc was called but failed to allocate 500000 bytes with 0x400 capabilities.

my free heap is 1.5mb

[zekageri]

I randomly get these messages

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities. 
heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

[igrr]

heap_caps_malloc_default was called but failed to allocate 0 bytes with 0x1000 capabilities.

This bug should be fixed in IDF by espressif/esp-idf@b43e777 (available on release/v4.4 branch, will be part of v4.4.3)

[zekageri]

But i did not try to allocate 0 byte

[VojtechBartoska]

@zekageri if you check out manually Arduino core master branch, it's supposed to be solved. Our current master use ESP-IDF 4.4.3.