PSRAM decreases in do_global_ctors

[jumjum123]

I've added some printf's using esp_get_free_heap_size() in start_cpu0_default (cpu_start.c)
Could bring it down to do_global_ctors, where 1280 kb disappear from heap, see attached log.
Since I've no idea what do_global_ctors is doing,

Code: Select all

I (1413) spiram: Reserving pool of 16K of internal memory for DMA/internal allocations
I (1421) cpu_start: heap after reserving pool:4209012
I (96) cpu_start: heap before do_global_ctors:4208272
I (96) cpu_start: heap after do_global_ctors:2897440
I (97) cpu_start: Starting scheduler on PRO CPU.

[ESP_Angus]

I'm not able to reproduce this with a simple example on the current master branch. What IDF version are you using?

As well, can you please tell us a bit more about your firmware - what features you are using, etc? The simplest explanation I can think of is that the firmware contains static objects with C++ constructors that allocate a lot of heap memory when they are called (or C functions with __attribute__((constructor)), although this is more rarely used).

Angus

[WiFive]

Are you sure that isn't the memory you reserved for espruino jsvars?

[jumjum123]

@WiFive,
yes, I'm sure, since only 2000 JsVars (32k) are reserved and more than 1M is gone.

I had to decrease to 2000 JsVars after starting with BLE for Espruino.
BLE eats memory like crazy, and my plan is to test how wrover could help.

[jumjum123]

Memory decreases by 1280kb in a function called _GLOBAL__sub_I___cxa_allocate_exception
There is nothing like that in my sources.
I've no idea where this function is comin from, and why its taking that much memory.
It does not appear in a project compiled from examples in esp-idf, so there is a way to get rid of it.....
Next step now is to compare flags for compiling and linking, .....

[ESP_Angus]

Hi jumjum,

__cxa_allocate_exception is an internal libstdc++ routine called whenever an exception is thrown, to allocate memory for it. Looks like the exception maybe throws (with an unusually large exception buffer) but is never freed afterwards?

• If you have C++ exception support enabled in menuconfig, you can try disabling it and recompiling everything - in which case instead of throwing this exception the program will abort.
• I noticed espruino may not be using the ESP-IDF build system. If there are multiple build sytems in use, you should check that the C++ exception flags are consistent between them.
• Make sure you have the latest toolchain version. The ESP-IDF build system will issue a warning if this is not the case.
• Did you get this information via heap tracing? Set the heap tracing stack depth a little higher, maybe 4 or 5 frames, and you'll be able to see the routine which triggered the exception in the first place.
• If you have JTAG debugging, you can try setting a breakpoint on the __cxa_allocate_exception address.

[jumjum123]

Hello ESP_ANGUS.
I'm using a 2 steps make
- first one to create a template. This is done with ESP-IDF only
- second one to for Espruino(the project) which uses .o-files from template

Toolchain is the most actual (xtensa-esp32-elf-linux64-1.22.0-80-g6c4433a-5.2.0.tar)
I got this information by adding ESP_EARLY_LOGI(... in do_global_ctors and searching in .lst file
In .map file, thanks for the hint, is this

Code: Select all

                0x000000003f425760                __init_array_start = ABSOLUTE (.)
 *crtbegin.o(.ctors)
 *(EXCLUDE_FILE(*crtend.o) .ctors)
 .ctors         0x000000003f425760        0x4 /home/esp32/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/5.2.0/../../../../xtensa-esp32-elf/lib/libstdc++.a(eh_alloc.o)
 .ctors         0x000000003f425764        0x4 /home/esp32/xtensa-esp32-elf/bin/../lib/gcc/xtensa-esp32-elf/5.2.0/../../../../xtensa-esp32-elf/lib/libstdc++.a(eh_globals.o)
 *(SORT(.ctors.*))
 *(.ctors)
                0x000000003f425768                __init_array_end = ABSOLUTE (.)

Compared this with .map in templates, and could not find 2nd entry there.
After enabling Enable C++ Exceptions in Compiler options 2nd entry appears, so it depends on this flag.

Comparing my CFLAGS/LDFLAGS with template CFLAGS/LDFLAGS found these missing

Code: Select all

-u __cxa_guard_dummy 
-u __cxx_fatal_exception 
-fno-exceptions 

Bad news, after adding them to my make, problem is still the same.

So there is still the question, how do I get rid of this, or at least tell it to use less memory

[jumjum123]

Found a crazy workaround. Any idea what happens here ?

Code: Select all

int x = malloc(0x380000); //reduce heap, so that no heap is available to get lost
ESP_EARLY_LOGI(TAG, "heap after malloc:%d(%d)\n",esp_get_free_heap_size(),x);  
//need to add this log with x, assumption is that otherwise malloc and free are removed in optimization
    do_global_ctors();
free(x); //give heap back so it can be used in application

BTW, I could not find any way how a 1280kb heap is used in our application.
Espruino is Javascript working on less powerful hardware. We never had that much memory.

[ESP_Angus]

Found a crazy workaround. Any idea what happens here ?

That seems quite unexpected!

Can you please remove the workaround and then try:

• Turn on heap tracing in HEAP_TRACE_ALL mode before do_global_ctors, then stop the trace and dump the result afterwards. Description here: https://esp-idf.readthedocs.io/en/lates ... ap-tracing
• Call heap_caps_dump(MALLOC_CAP_SPIRAM) after do_global_ctors() to dump the structure of the heap.

Espruino is Javascript working on less powerful hardware. We never had that much memory.

The best guesses I have are:

• Something is calling esp_get_free_heap_size() in its global constructor and helping itself to 25% of the available heap.
• Something is corrupting memory in a freakish way which causes the heap implementation to lose 1MB of space.

[jumjum123]

Hello ESP_ANGUS
I've added heap like this:

CONFIG_HEAP_POISONING_DISABLED=y
CONFIG_HEAP_POISONING_LIGHT=
CONFIG_HEAP_POISONING_COMPREHENSIVE=
CONFIG_HEAP_TRACING=y
CONFIG_HEAP_TRACING_STACK_DEPTH=2

Code: Select all

ESP_ERROR_CHECK( heap_trace_init_standalone(trace_record, NUM_RECORDS) );
ESP_EARLY_LOGI(TAG, "trace initialised\n"); 
heap_trace_start(HEAP_TRACE_ALL); 
ESP_EARLY_LOGI(TAG, "trace started\n");
    do_global_ctors();
heap_trace_stop();
ESP_EARLY_LOGI(TAG, "trace stopped\n");
heap_trace_dump();

do_global_ctors got an EarlyLogI

Code: Select all

    for (p = &__init_array_end - 1; p >= &__init_array_start; --p) {
        (*p)();
ESP_EARLY_LOGI(TAG, "do_global:%d(%x) = (%d)\n",p,*p,esp_get_free_heap_size());
    }

and got this, which makes it more strange for me

I (105) cpu_start: trace initialised
I (105) cpu_start: trace started
I (105) cpu_start: do_global:1061313188(401178c0) = (4205404)
I (107) cpu_start: do_global:1061313184(401170c8) = (2894584)
I (113) cpu_start: trace stopped
0 allocations trace (100 entry buffer)
0 bytes alive in trace (0/0 allocations)
total allocations 0 total frees 0