Esp-idf: [TW#15756] New toolchain (1.22.0-73-ge28a011) reduces free heap by 20Kb

[mkonnov]

Updated from xtensa-esp32-elf-linux64-1.22.0-61-gab8375a to xtensa-esp32-elf-linux64-1.22.0-73-ge28a011.
Added some logs into xTaskCreatePinnedToCore to trace this failure:

...
ESP_LOGI("", "creating %s, allocating %d of stack from %d of free heap\n\n",
                                        pcName, usStackDepth, xPortGetFreeHeapSize());

pxStack = ( StackType_t * ) pvPortMallocStackMem( ( ( ( size_t ) usStackDepth ) * sizeof( StackType_t ) ) ); /*lint !e961 MISRA exception as the casts are only redundant for some ports. */
                        if( pxStack != NULL )
...

Estimating the following during startup:
gab8375a revision (works fine):

I (275) : creating esp_timer, allocating 4096 of stack from 29580 of free heap
I (276) : creating ipc0, allocating 1024 of stack from 24396 of free heap
I (281) : creating ipc1, allocating 1024 of stack from 22920 of free heap
I (289) : creating dport, allocating 768 of stack from 21532 of free heap
I (297) : creating main, allocating 6144 of stack from 20312 of free heap
I (310) : creating IDLE, allocating 1024 of stack from 13804 of free heap
I (318) : creating IDLE, allocating 1024 of stack from 12416 of free heap
...

ge28a011 revision (fails)

I (277) : creating esp_timer, allocating 4096 of stack from 29548 of free heap
I (278) : creating ipc0, allocating 1024 of stack from 5176 of free heap
I (283) : creating ipc1, allocating 1024 of stack from 3700 of free heap
I (291) : creating dport, allocating 768 of stack from 2312 of free heap
I (298) : creating main, allocating 6144 of stack from 1092 of free heap
assertion "res == pdTRUE" failed: file "esp-idf/components/e
sp32/./cpu_start.c", line 347, function: start_cpu0_default
abort() was called at PC 0x401079ef on core 0

In an old revision, there's 24396 left against 5176 in a new one after "esp_timer" task creating.
Where's my 20kb ? I need my money back.

[mkonnov]

I have added some debug outputs in do_global_ctors()

static void do_global_ctors(void)
{
    static struct object ob;

    __register_frame_info( __eh_frame, &ob );

    void (**p)(void);
        ESP_LOGI("cpu_start", "%s: %d free heap %d bytes", __FILE__, __LINE__, xPortGetFreeHeapSize());

    for (p = &__init_array_end - 1; p >= &__init_array_start; --p) {
        (*p)();
    }
        ESP_LOGI("cpu_start", "%s: %d free heap %d bytes", __FILE__, __LINE__, xPortGetFreeHeapSize());

}

The output:

I (329) cpu_start: esp-idf/components/esp32/./cpu_start.c: 386 free heap 116040 bytes
I (336) cpu_start: esp-idf/components/esp32/./cpu_start.c: 391 free heap 96972 bytes

I have no access to __init_array_end symbol.
Espressif guys, your turn.

[projectgus]

Hi @mkonnov,

Thanks for reporting this. After investigating, I've determined this was caused by enabling libstdc++ exception support in the new toolchain. There's a global constructor in libstdc++-v3/libsupc++/eh_alloc.cc which allocates a default global exception object pool of 32*512 byte objects (plus some metadata overhead, I assume). This is fine for a "big" system, but clearly not what we want on the ESP32 platform.

Unfortunately because the rest of libstdc++ is compiled with exception support, and some parts of ESP-IDF use libstdc++, I don't believe we can fix this without releasing a new toolchain.

Most of our team is on holidays this week (Golden Week in China) so it may be a little while before a fix is released.

In the meantime, if you are not using the new libstdc++ features and you are also not using PSRAM, the easiest workaround is to roll back to the old toolchain until this is fixed. The build system will print a warning, but you shouldn't experience any problems unless you're relying on the aforementioned two items.

[mkonnov]

@projectgus thanks for your reply.

I think that this should be reasonable to remove this scary warning

WARNING: Toolchain version is not supported: 1.22.0-61-gab8375a
Expected to see version: 1.22.0-73-ge28a011
Please check ESP-IDF setup instructions and update the toolchain, or proceed at your own risk.

until Espressif guys roll out (AFTER TESTING !!!111) the new toolchain.

[urbanze]

I just upgraded to the new version, and before, a simple code had 300kB free. Now it's showing 280kB. This "unwanted problem" really did appear. I'll be following the updates on that.

[projectgus]

Turns out I was wrong, it's possible to fix this without updating the toolchain. I have a fix I'm testing here, if all goes well it should be merged next week after my colleagues have a chance to review.

until Espressif guys roll out (AFTER TESTING !!!111) the new toolchain.

I understand you're frustrated about the regression of RAM usage, that's understandable.

I want to clarify, before the master branch is pushed to github it is run through a bank of unit tests and a bank of integration tests (including WiFi & Bluetooth connectivity tests) with various configurations.

We don't have an automated test for memory use regressions, although due to this regression I'm going to look at ways to add this test.

Despite this automated testing, our master branch is not a stable release. Stable releases also receive substantial manual Q&A testing which is not feasible for us to run on every commit. Developers also test changes manually, but we're only human so mistakes sometimes happen.

Stable releases can be found here: https://github.com/espressif/esp-idf/releases

(The current master branch is a pre-V3.0.)

[mkonnov]

@projectgus I appreciate your reply.
Good luck.

[mkonnov]

@igrr is it fixed ?

[projectgus]

@mkonnov yes, this is fixed provided C++ Exceptions are not enabled in menuconfig.

You can click the commit link (9c7477e) to see some details of the fix.

[rojer]

the fix does not work. even with CONFIG_CXX_EXCEPTIONS= in sdkconfig,
_GLOBAL__sub_I___cxa_allocate_exception still ends up being called and allocates 20K of RAM during global constructor init.

[projectgus]

Hi @rojer,

I'm not able to see this building examples on the master branch, if I instrument do_global_ctors() then I see 16 bytes of free heap delta before/after constructors run.

In my tests __cxa_allocate_exception is linked, but it's the stub version in component/cxx/cxx_exception_stubs.cpp which doesn't pull in eh_alloc.cc.

It's possible there's a linker order where this doesn't happen as expected and you get the version from libstdc++ instead. Do you have an .elf file and .map file you can share?

[rojer]

i instrumented do_global_ctors as well and i see this:

[Nov 16 01:11:53.947] I (255) cpu_start: hf after 0x401b7d5c = 23492
[Nov 16 01:11:53.947] I (258) cpu_start: hf after 0x401b7574 = 4428

and yes, it comes from libstdc++'s eh_alloc:

(gdb) info line *0x401b7574
Line 307 of "/builds/idf/crosstool-NG/.build/src/gcc-5.2.0/libstdc++-v3/libsupc++/eh_alloc.cc" starts at address 0x401b7574 <_GLOBAL__sub_I___cxa_allocate_exception()> and ends at 0x401b7577 <_GLOBAL__sub_I___cxa_allocate_exception()+3>.

looking...

[projectgus]

So, for some reason when the linker has gone looking for __cxa_alloc_exception then it's pulled in the libstdc++ version instead of the stub, and the libstdc++ version also has that global constructor which allocates the emergency pool.

Some combination of the map file and the ld command line should help us work out what the difference is, here.

[rojer]

demo-js.map.txt

[rojer]

xtensa-esp32-elf-gcc -nostdlib -u call_user_start_cpu0 -Wl,--gc-sections -Wl,-static -Wl,--start-group -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/app_trace -lapp_trace -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/app_upd
ate -lapp_update -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/bootloader_support -lbootloader_support -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/driver -ldriver -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/obj
s/esp_adc_cal -lesp_adc_cal -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/esp32 -lesp32 /opt/Espressif/esp-idf/components/esp32/libhal.a -L/opt/Espressif/esp-idf/components/esp32/lib -lcore -lrtc -lnet80211 -lpp -lwpa -lsmartconfig -lcoexi
st -lwps -lwpa2 -lespnow -lphy -L /opt/Espressif/esp-idf/components/esp32/ld -T esp32_out.ld -u ld_include_panic_highint_hdl -T esp32.common.ld -T esp32.rom.ld -T esp32.peripherals.ld -T esp32.rom.spiram_incompatible_fns.ld -L/home/rojer/go/src/cesanta.c
om/mos_apps/demo-js/build/objs/ethernet -lethernet -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/expat -lexpat -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/freertos -lfreertos -Wl,--undefined=uxTopUsedPriority -L/home/rojer
/go/src/cesanta.com/mos_apps/demo-js/build/objs/heap -lheap -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/log -llog -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/lwip -llwip -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/
build/objs/micro-ecc -lmicro-ecc -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/newlib /opt/Espressif/esp-idf/components/newlib/lib/libc.a /opt/Espressif/esp-idf/components/newlib/lib/libm.a -lnewlib -L/home/rojer/go/src/cesanta.com/mos_app
s/demo-js/build/objs/nvs_flash -lnvs_flash -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/pthread -lpthread -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/soc -lsoc -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/
spi_flash -lspi_flash -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/tcpip_adapter -ltcpip_adapter -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/vfs -lvfs -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/wpa_suppl
icant -lwpa_supplicant -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/xtensa-debug-module -lxtensa-debug-module -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/mosapp -Wl,--whole-archive -lmosapp -Wl,--no-whole-archive -L/home/
rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/spiffs -lspiffs -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/cryptoauthlib -lcryptoauthlib -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/cs_mbedtls /opt/cs_mbedtls/libcs_
mbedtls_atca.a -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/bt -lbt -L /opt/Espressif/esp-idf/components/bt/lib -lbtdm_app -lgcc -lstdc++ -lgcov -Wl,--end-group -Wl,-EL -L/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/src -o /
home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/demo-js.elf -Wl,-Map=/home/rojer/go/src/cesanta.com/mos_apps/demo-js/build/objs/demo-js.map

[rojer]

to close the loop: i was missing the cxx component in my build, thanks @projectgus for helping me figure it out!