(VFS) recent fix of malloc to heap_caps_malloc causes a LoadStoreError (IDFGH-11654)

[kohait00]

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.

master

Espressif SoC revision.

ESP32 30.

Operating System used.

Linux

How did you build your project?

Eclipse IDE

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

None

Development Kit.

ESP32 DevkitC v4

Power Supply used.

USB

What is the expected behavior?

A private application with several function blocks like

wifi, http, provisioning, vfs, uart, etc

used startup properly until recently, updating to master causes a LoadStoreError in

esp_vfs_register_common at /mnt/work/esp-idf-v5.1.1/components/vfs/vfs.c:109

, so very early in startup.

What is the actual behavior?

crashes suppsedly with a memory corruption due to mem allocation returning NULL, cause IRAM heap might be exhausted.
introduced in my personal application by upstream master branch commit
7409f41

changing the
#define VFS_MALLOC_FLAGS MALLOC_CAP_INTERNAL
back to #define VFS_MALLOC_FLAGS MALLOC_CAP_DEFAULT
lets my application boot again.

I am not quite sure what the root of the problem is hence my intent to report it here.

Steps to reproduce.

1. Step
2. Step
3. Step
   ...

private application with quite some suff in it :)
I provide the

• map file and
• the sdkconfig,
• the trace dump

it might already be enough to judge what happened

Debug Logs.

ets Jul 29 2019 12:21:46

rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff01b0,len:10900
load:0x40078000,len:21520
ho 0 tail 12 room 4
load:0x40080400,len:4
0x40080400: _init at ??:?

load:0x40080404,len:13552
entry 0x4008079c
W (94) boot.esp32: eFuse virtual mode is enabled. If Secure boot or Flash encryption is enabled then it does not provide any security. FOR TESTING ONLY!
I (47) boot: ESP-IDF v5.3-dev-915-g566b4111bb-dirty 2nd stage bootloader
I (47) boot: compile time Dec 11 2023 00:56:32
I (50) boot: Multicore bootloader
I (54) boot: chip revision: v3.0
I (58) boot.esp32: SPI Speed      : 40MHz
I (63) boot.esp32: SPI Mode       : DIO
I (67) boot.esp32: SPI Flash Size : 4MB
I (72) boot: Enabling RNG early entropy source...
I (77) boot: Partition Table:
I (81) boot: ## Label            Usage          Type ST Offset   Length
I (88) boot:  0 bootloader       Unknown data     01 b0 00001000 0000c000
I (95) boot:  1 nvs              WiFi data        01 02 0000d000 00003000
I (103) boot:  2 part_table       Unknown data     01 ee 00010000 00001000
I (110) boot:  3 phy_init         RF data          01 01 00011000 00001000
I (118) boot:  4 otadata          OTA data         01 00 00012000 00002000
W (126) efuse: [Virtual] try loading efuses from flash: 0x14000 (offset)
W (133) efuse: [Virtual] Loading virtual efuse blocks from flash
EFUSE_BLKx:
0) 0x00000000 0x1f32b3c4 0x00bd08b6 0x0000a200 0x00000934 0x00100000 0x00000004 
1) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 
2) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 
3) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 

I (172) boot:  5 emul_efuse       efuse            01 05 00014000 00002000
I (180) boot:  6 nvs_keys         NVS keys         01 04 00016000 00001000
I (187) boot:  7 nvs_sys          WiFi data        01 02 00017000 00009000
I (195) boot:  8 ota_0            OTA app          00 10 00020000 00140000
I (202) boot:  9 ota_1            OTA app          00 11 00160000 00140000
I (210) boot: 10 usr              WiFi data        01 02 002a0000 00020000
I (218) boot: 11 www              Unknown data     01 82 002c0000 00140000
I (225) boot: End of partition table
I (229) boot: Enabled a check secure version of app for anti rollback
I (236) boot: Secure version (from eFuse) = 0
W (242) boot: Use GPIO 0 for more than 6 s to perform Factory Feset!
I (1249) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=3de70h (253552) map
I (1336) esp_image: segment 1: paddr=0005de98 vaddr=3ffb0000 size=02180h (  8576) load
I (1340) esp_image: segment 2: paddr=00060020 vaddr=400d0020 size=bd400h (775168) map
I (1608) esp_image: segment 3: paddr=0011d428 vaddr=3ffb2180 size=01cbch (  7356) load
I (1611) esp_image: segment 4: paddr=0011f0ec vaddr=40080000 size=16190h ( 90512) load
I (1649) esp_image: segment 5: paddr=00135284 vaddr=50000000 size=00004h (     4) load
I (1660) boot: Loaded app from partition at offset 0x20000
I (1661) boot: Disabling RNG early entropy source...
I (1673) cpu_start: Multicore app
I (1682) cpu_start: Pro cpu start user code
I (1682) cpu_start: cpu freq: 240000000 Hz
I (1682) cpu_start: Application information:
I (1685) cpu_start: Project name:     gen_app
I (1690) cpu_start: App version:      0.3.2.66
I (1695) cpu_start: Secure version:   0
I (1700) cpu_start: Compile time:     Dec 11 2023 00:56:27
I (1706) cpu_start: ELF file SHA256:  7b5a0d1c2759d373...
I (1712) cpu_start: ESP-IDF:          v5.3-dev-915-g566b4111bb-dirty
I (1719) cpu_start: Min chip rev:     v0.0
I (1724) cpu_start: Max chip rev:     v3.99 
I (1729) cpu_start: Chip rev:         v3.0
I (1734) heap_init: Initializing. RAM available for dynamic allocation:
I (1741) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1747) heap_init: At 3FFBBDB8 len 00024248 (144 KiB): DRAM
I (1753) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1760) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1766) heap_init: At 40096190 len 00009E70 (39 KiB): IRAM
Guru Meditation Error: Core  0 panic'ed (LoadStoreError). Exception was unhandled.

Core  0 register dump:
PC      : 0x400013d2  PS      : 0x00060f30  A0      : 0x8018bc94  A1      : 0x3ffe3b40  
0x400013d2: strcpy in ROM

A2      : 0x40096574  A3      : 0x3f402ba6  A4      : 0x000000ff  A5      : 0x0000ff00  
A6      : 0x00ff0000  A7      : 0xff000000  A8      : 0x0000002f  A9      : 0x3ffe3b00  
A10     : 0x40096574  A11     : 0x00000000  A12     : 0x3ffae8f0  A13     : 0x00000800  
A14     : 0x00000000  A15     : 0x000000c0  SAR     : 0x0000001d  EXCCAUSE: 0x00000003  
EXCVADDR: 0x40096574  LBEG    : 0x40082bf5  LEND    : 0x40082bfd  LCOUNT  : 0x00000027  
0x40082bf5: esp_timer_impl_get_counter_reg at /mnt/work/esp-idf-v5.1.1/components/esp_timer/src/esp_timer_impl_lac.c:118

0x40082bfd: esp_timer_impl_get_counter_reg at /mnt/work/esp-idf-v5.1.1/components/esp_timer/src/esp_timer_impl_lac.c:128



Backtrace: 0x400013cf:0x3ffe3b40 0x4018bc91:0x3ffe3b50 0x400d67b8:0x3ffe3b80 0x400d3c7f:0x3ffe3ba0 0x400d45a7:0x3ffe3bc0 0x400d45f2:0x3ffe3bf0 0x400d775e:0x3ffe3c20 0x4008154a:0x3ffe3c40 0x40079a60:0x3ffe3c80 |<-CORRUPTED
0x400013cf: strcpy in ROM

0x4018bc91: esp_vfs_register_common at /mnt/work/esp-idf-v5.1.1/components/vfs/vfs.c:109

0x400d67b8: esp_vfs_console_register at /mnt/work/esp-idf-v5.1.1/components/vfs/vfs_console.c:200 (discriminator 1)

0x400d3c7f: __esp_system_init_fn_init_vfs_console at /mnt/work/esp-idf-v5.1.1/components/esp_system/startup_funcs.c:181

0x400d45a7: do_system_init_fn at /mnt/work/esp-idf-v5.1.1/components/esp_system/startup.c:126

0x400d45f2: do_core_init at /mnt/work/esp-idf-v5.1.1/components/esp_system/startup.c:164
 (inlined by) start_cpu0_default at /mnt/work/esp-idf-v5.1.1/components/esp_system/startup.c:197

0x400d775e: start_cpu0 at /mnt/work/gen_app/main/main.c:44

0x4008154a: call_start_cpu0 at /mnt/work/esp-idf-v5.1.1/components/esp_system/port/cpu_start.c:779 (discriminator 1)

More Information.

sdkconfig.txt
gen_app.map.txt

[zwx1995esp]

Hi, @kohait00 Thanks for finding this issue. This might be a known issue, you can try with adding the heap config flag: MALLOC_CAP_8BIT for this line to fix it.

#define VFS_MALLOC_FLAGS (MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT)

The fix PR is under the merging flow.

[kohait00]

Hi, @kohait00 Thanks for finding this issue. This might be a known issue, you can try with adding the heap config flag: MALLOC_CAP_8BIT for this line to fix it.

#define VFS_MALLOC_FLAGS (MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT)

The fix PR is under the merging flow.

Thanks, that worked for me...
it appears MALLOC_CAP_8BIT simply has been forgotten here, as it is used in all the other relevant places, am I right?

[zwx1995esp]

Hi, @kohait00 Thanks for finding this issue. This might be a known issue, you can try with adding the heap config flag: MALLOC_CAP_8BIT for this line to fix it.

#define VFS_MALLOC_FLAGS (MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT)

The fix PR is under the merging flow.

Thanks, that worked for me... it appears MALLOC_CAP_8BIT simply has been forgotten here, as it is used in all the other relevant places, am I right?

Yeah, the flag MALLOC_CAP_INTERNAL should be used together with MALLOC_CAP_8BIT. I believe the other places should be used(If not, then will be a bug, and need to be fixed).

[havrak]

Hello this bug is also present in v5.2 release, which as of today is the latest version. Would it be possible to patch it there, as v5.2 includes small changes to ULP on ESP32C6 and such staying on v5.1 is not preferred.

[igrr]

This issue was fixed with:

• commit bdce46f on release/v5.2, will be part of v5.2.0
• commit 0e759c6 on master