Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[ESP32S3] v5.1 consuming up to 30kB of internal RAM more than same example in v4.4 (IDFGH-12234) #13285

Closed
3 tasks done
KonssnoK opened this issue Feb 28, 2024 · 21 comments
Closed
3 tasks done
Assignees
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally

Comments

@KonssnoK
Copy link
Contributor

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.

General issue report

this was tested on esp32s3 devkit-C
using
https://github.com/espressif/esp-idf/tree/master/examples/mesh/ip_internal_network

Changes on v4.4

diff --git a/examples/mesh/ip_internal_network/main/mesh_main.c b/examples/mesh/ip_internal_network/main/mesh_main.c
index 72e4a82d4c..92bbb1d4ce 100644
--- a/examples/mesh/ip_internal_network/main/mesh_main.c
+++ b/examples/mesh/ip_internal_network/main/mesh_main.c
@@ -383,6 +383,8 @@ void ip_event_handler(void *arg, esp_event_base_t event_base,

 void app_main(void)
 {
+    heap_caps_malloc_extmem_enable(0);
+
     ESP_ERROR_CHECK(nvs_flash_init());
     /*  tcpip initialization */
     ESP_ERROR_CHECK(esp_netif_init());
@@ -422,6 +424,6 @@ void app_main(void)
     ESP_ERROR_CHECK(esp_mesh_set_config(&cfg));
     /* mesh start */
     ESP_ERROR_CHECK(esp_mesh_start());
-    ESP_LOGI(MESH_TAG, "mesh starts successfully, heap:%d, %s\n",  esp_get_free_heap_size(),
+    ESP_LOGI(MESH_TAG, "mesh starts successfully, internal heap:%" PRId32 ", %s\n", esp_get_free_internal_heap_size(),
              esp_mesh_is_root_fixed() ? "root fixed" : "root not fixed");
 }

sdkconfig

CONFIG_ESP32S3_SPIRAM_SUPPORT=y

#
# SPI RAM config
#
# CONFIG_SPIRAM_MODE_QUAD is not set
CONFIG_SPIRAM_MODE_OCT=y
CONFIG_SPIRAM_TYPE_AUTO=y
# CONFIG_SPIRAM_TYPE_ESPPSRAM64 is not set
CONFIG_SPIRAM_SIZE=-1
CONFIG_SPIRAM_CLK_IO=30
CONFIG_SPIRAM_CS_IO=26
# CONFIG_SPIRAM_FETCH_INSTRUCTIONS is not set
# CONFIG_SPIRAM_RODATA is not set
# CONFIG_SPIRAM_ALLOW_STACK_EXTERNAL_MEMORY is not set
CONFIG_SPIRAM_SPEED_80M=y
# CONFIG_SPIRAM_SPEED_40M is not set
CONFIG_SPIRAM=y
CONFIG_SPIRAM_BOOT_INIT=y
# CONFIG_SPIRAM_IGNORE_NOTFOUND is not set
# CONFIG_SPIRAM_USE_MEMMAP is not set
# CONFIG_SPIRAM_USE_CAPS_ALLOC is not set
CONFIG_SPIRAM_USE_MALLOC=y
CONFIG_SPIRAM_MEMTEST=y
CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL=2048
CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y
CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL=32768
# end of SPI RAM config

Log on v4.4

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x16dc
load:0x403c9700,len:0xbd4
load:0x403cc700,len:0x2fb0
entry 0x403c9954
I (24) boot: ESP-IDF v4.4.6-323-g979a56386d-dirty 2nd stage bootloader
I (25) boot: compile time 14:03:31
I (25) boot: Multicore bootloader
I (28) boot: chip revision: v0.1
I (32) boot.esp32s3: Boot SPI Speed : 80MHz
I (37) boot.esp32s3: SPI Mode       : DIO
I (42) boot.esp32s3: SPI Flash Size : 2MB
I (47) boot: Enabling RNG early entropy source...
I (52) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (70) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00124f80
I (85) boot: End of partition table
I (89) esp_image: segment 0: paddr=00010020 vaddr=3c0c0020 size=26598h (157080) map
I (126) esp_image: segment 1: paddr=000365c0 vaddr=3fc97970 size=04284h ( 17028) load
I (130) esp_image: segment 2: paddr=0003a84c vaddr=40374000 size=057cch ( 22476) load
I (137) esp_image: segment 3: paddr=00040020 vaddr=42000020 size=b7c50h (752720) map
I (275) esp_image: segment 4: paddr=000f7c78 vaddr=403797cc size=0e19ch ( 57756) load
I (296) boot: Loaded app from partition at offset 0x10000
I (296) boot: Disabling RNG early entropy source...
I (308) cpu_start: Multicore app
I (308) opi psram: vendor id : 0x0d (AP)
I (308) opi psram: dev id    : 0x02 (generation 3)
I (310) opi psram: density   : 0x03 (64 Mbit)
I (315) opi psram: good-die  : 0x01 (Pass)
I (320) opi psram: Latency   : 0x01 (Fixed)
I (325) opi psram: VCC       : 0x01 (3V)
I (330) opi psram: SRF       : 0x01 (Fast Refresh)
I (335) opi psram: BurstType : 0x01 (Hybrid Wrap)
I (340) opi psram: BurstLen  : 0x01 (32 Byte)
I (345) opi psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (351) opi psram: DriveStrength: 0x00 (1/1)
I (357) MSPI Timing: PSRAM timing tuning index: 5
I (362) spiram: Found 64MBit SPI RAM device
I (367) spiram: SPI RAM mode: sram 80m
I (371) spiram: PSRAM initialized, cache is in normal (1-core) mode.
I (378) cpu_start: Pro cpu up.
I (382) cpu_start: Starting app cpu, entry point is 0x403753fc
0x403753fc: call_start_cpu1 at C:/repos/v3/esp-idf/components/esp_system/port/cpu_start.c:151

I (0) cpu_start: App cpu up.
I (808) spiram: SPI SRAM memory test OK
I (817) cpu_start: Pro cpu start user code
I (817) cpu_start: cpu freq: 160000000
I (818) cpu_start: Application information:
I (820) cpu_start: Project name:     ip_internal_network
I (826) cpu_start: App version:      v4.4.6-323-g979a56386d-dirty
I (833) cpu_start: Compile time:     Feb 28 2024 14:01:55
I (839) cpu_start: ELF file SHA256:  c986ca6f4f535940...
I (845) cpu_start: ESP-IDF:          v4.4.6-323-g979a56386d-dirty
I (852) cpu_start: Min chip rev:     v0.0
I (856) cpu_start: Max chip rev:     v0.99
I (861) cpu_start: Chip rev:         v0.1
I (866) heap_init: Initializing. RAM available for dynamic allocation:
I (873) heap_init: At 3FCA1640 len 000480D0 (288 KiB): D/IRAM
I (880) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DIRAM
I (886) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (893) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (899) spiram: Adding pool of 8192K of external SPI memory to heap allocator
I (908) spi_flash: detected chip: generic
I (912) spi_flash: flash io: dio
W (915) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (929) sleep: Configure to isolate all GPIO pins in sleep state
I (935) sleep: Enable automatic switching of GPIO sleep configuration
I (943) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (963) spiram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (983) pp: pp rom version: e7ae62f
I (983) net80211: net80211 rom version: e7ae62f
I (1003) wifi:wifi driver task: 3fcedb1c, prio:23, stack:6656, core=0
I (1003) system_api: Base MAC address is not set
I (1003) system_api: read default base MAC address from EFUSE
I (1013) wifi:wifi firmware version: 4647edf
I (1013) wifi:wifi certification version: v7.0
I (1013) wifi:config NVS flash: enabled
I (1013) wifi:config nano formating: disabled
I (1023) wifi:Init data frame dynamic rx buffer num: 32
I (1023) wifi:Init static rx mgmt buffer num: 5
I (1033) wifi:Init management short buffer num: 32
I (1033) wifi:Init static tx buffer num: 16
I (1043) wifi:Init tx cache buffer num: 32
I (1043) wifi:Init static tx FG buffer num: 2
I (1043) wifi:Init static rx buffer size: 1600
I (1053) wifi:Init static rx buffer num: 10
I (1053) wifi:Init dynamic rx buffer num: 32
I (1063) wifi_init: rx ba win: 6
I (1063) wifi_init: tcpip mbox: 32
I (1063) wifi_init: udp mbox: 6
I (1073) wifi_init: tcp mbox: 6
I (1073) wifi_init: tcp tx win: 5760
I (1083) wifi_init: tcp rx win: 5760
I (1083) wifi_init: tcp mss: 624
I (1083) wifi_init: WiFi/LWIP prefer SPIRAM
I (1093) wifi_init: WiFi IRAM OP enabled
I (1093) wifi_init: WiFi RX IRAM OP enabled
I (1103) wifi:Set ps type: 0

I (1103) phy_init: phy_version 620,ec7ec30,Sep  5 2023,13:49:13
W (1113) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (1173) wifi:mode : softAP (7c:df:a1:e1:95:05)
I (1173) wifi:Total power save buffer number: 8
I (1173) wifi:Init max length of beacon: 752/752
I (1173) wifi:Init max length of beacon: 752/752
I (1183) wifi:mode : sta (7c:df:a1:e1:95:04) + softAP (7c:df:a1:e1:95:05)
I (1183) wifi:enable tsf
I (1193) mesh: <nvs>read layer:0, err:0x1102
I (1193) mesh: <nvs>read assoc:0, err:0x1102
I (1773) wifi:Total power save buffer number: 8
I (2333) wifi:mode : sta (7c:df:a1:e1:95:04)
I (2343) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:1
I (2343) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:76
I (2343) mesh_main: mesh starts successfully, internal heap:245207, root not fixed

Changes in 5.1

esp-idf release/v5.1


diff --git a/examples/mesh/ip_internal_network/main/mesh_main.c b/examples/mesh/ip_internal_network/main/mesh_main.c
index 9a56ed149d..982dcd106a 100644
--- a/examples/mesh/ip_internal_network/main/mesh_main.c
+++ b/examples/mesh/ip_internal_network/main/mesh_main.c
@@ -384,6 +384,8 @@ void ip_event_handler(void *arg, esp_event_base_t event_base,

 void app_main(void)
 {
+    heap_caps_malloc_extmem_enable(0);
+
     ESP_ERROR_CHECK(nvs_flash_init());
     /*  tcpip initialization */
     ESP_ERROR_CHECK(esp_netif_init());
@@ -423,6 +425,6 @@ void app_main(void)
     ESP_ERROR_CHECK(esp_mesh_set_config(&cfg));
     /* mesh start */
     ESP_ERROR_CHECK(esp_mesh_start());
-    ESP_LOGI(MESH_TAG, "mesh starts successfully, heap:%" PRId32 ", %s\n",  esp_get_free_heap_size(),
+    ESP_LOGI(MESH_TAG, "mesh starts successfully, internal heap:%" PRId32 ", %s\n", esp_get_free_internal_heap_size(),
              esp_mesh_is_root_fixed() ? "root fixed" : "root not fixed");
 }

sdkconfig


#
# ESP PSRAM
#
CONFIG_SPIRAM=y

#
# SPI RAM config
#
# CONFIG_SPIRAM_MODE_QUAD is not set
CONFIG_SPIRAM_MODE_OCT=y
CONFIG_SPIRAM_TYPE_AUTO=y
# CONFIG_SPIRAM_TYPE_ESPPSRAM64 is not set
CONFIG_SPIRAM_ALLOW_STACK_EXTERNAL_MEMORY=y
CONFIG_SPIRAM_CLK_IO=30
CONFIG_SPIRAM_CS_IO=26
# CONFIG_SPIRAM_FETCH_INSTRUCTIONS is not set
# CONFIG_SPIRAM_RODATA is not set
CONFIG_SPIRAM_SPEED_80M=y
# CONFIG_SPIRAM_SPEED_40M is not set
CONFIG_SPIRAM_SPEED=80
CONFIG_SPIRAM_BOOT_INIT=y
# CONFIG_SPIRAM_IGNORE_NOTFOUND is not set
# CONFIG_SPIRAM_USE_MEMMAP is not set
# CONFIG_SPIRAM_USE_CAPS_ALLOC is not set
CONFIG_SPIRAM_USE_MALLOC=y
CONFIG_SPIRAM_MEMTEST=y
CONFIG_SPIRAM_MALLOC_ALWAYSINTERNAL=2048
CONFIG_SPIRAM_TRY_ALLOCATE_WIFI_LWIP=y
CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL=32768
# CONFIG_SPIRAM_ALLOW_BSS_SEG_EXTERNAL_MEMORY is not set
# CONFIG_SPIRAM_ECC_ENABLE is not set
# end of SPI RAM config
# end of ESP PSRAM

Log

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3818,len:0x1764
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2e04
entry 0x403c9908
I (27) boot: ESP-IDF v5.1.3-1-gc361705ae7-dirty 2nd stage bootloader
I (27) boot: compile time Feb 28 2024 13:55:46
I (27) boot: Multicore bootloader
I (32) boot: chip revision: v0.1
I (35) boot.esp32s3: Boot SPI Speed : 80MHz
I (40) boot.esp32s3: SPI Mode       : DIO
I (45) boot.esp32s3: SPI Flash Size : 2MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (73) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (81) boot:  2 factory          factory app      00 00 00010000 00124f80
I (88) boot: End of partition table
I (93) esp_image: segment 0: paddr=00010020 vaddr=3c0d0020 size=30158h (196952) map
I (136) esp_image: segment 1: paddr=00040180 vaddr=3fc98900 size=04b78h ( 19320) load
I (141) esp_image: segment 2: paddr=00044d00 vaddr=40374000 size=0b318h ( 45848) load
I (152) esp_image: segment 3: paddr=00050020 vaddr=42000020 size=c308ch (798860) map
I (296) esp_image: segment 4: paddr=001130b4 vaddr=4037f318 size=095cch ( 38348) load
I (313) boot: Loaded app from partition at offset 0x10000
I (314) boot: Disabling RNG early entropy source...
I (325) cpu_start: Multicore app
I (325) octal_psram: vendor id    : 0x0d (AP)
I (326) octal_psram: dev id       : 0x02 (generation 3)
I (328) octal_psram: density      : 0x03 (64 Mbit)
I (334) octal_psram: good-die     : 0x01 (Pass)
I (339) octal_psram: Latency      : 0x01 (Fixed)
I (344) octal_psram: VCC          : 0x01 (3V)
I (349) octal_psram: SRF          : 0x01 (Fast Refresh)
I (355) octal_psram: BurstType    : 0x01 (Hybrid Wrap)
I (361) octal_psram: BurstLen     : 0x01 (32 Byte)
I (367) octal_psram: Readlatency  : 0x02 (10 cycles@Fixed)
I (373) octal_psram: DriveStrength: 0x00 (1/1)
I (379) MSPI Timing: PSRAM timing tuning index: 5
I (383) esp_psram: Found 8MB PSRAM device
I (388) esp_psram: Speed: 80MHz
I (392) cpu_start: Pro cpu up.
I (396) cpu_start: Starting app cpu, entry point is 0x40375624
0x40375624: call_start_cpu1 at C:/repos/v3-5.1/esp-idf/components/esp_system/port/cpu_start.c:159

I (0) cpu_start: App cpu up.
I (854) esp_psram: SPI SRAM memory test OK
I (864) cpu_start: Pro cpu start user code
I (864) cpu_start: cpu freq: 160000000 Hz
I (864) cpu_start: Application information:
I (867) cpu_start: Project name:     ip_internal_network
I (873) cpu_start: App version:      v5.1.3-1-gc361705ae7-dirty
I (880) cpu_start: Compile time:     Feb 28 2024 13:55:25
I (886) cpu_start: ELF file SHA256:  ca862259a18754bf...
I (892) cpu_start: ESP-IDF:          v5.1.3-1-gc361705ae7-dirty
I (898) cpu_start: Min chip rev:     v0.0
I (903) cpu_start: Max chip rev:     v0.99
I (908) cpu_start: Chip rev:         v0.1
I (913) heap_init: Initializing. RAM available for dynamic allocation:
I (920) heap_init: At 3FCA2E40 len 000468D0 (282 KiB): DRAM
I (926) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (933) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (939) heap_init: At 600FE010 len 00001FD8 (7 KiB): RTCRAM
I (945) esp_psram: Adding pool of 8192K of PSRAM memory to heap allocator
I (954) spi_flash: detected chip: generic
I (957) spi_flash: flash io: dio
W (961) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (975) sleep: Configure to isolate all GPIO pins in sleep state
I (981) sleep: Enable automatic switching of GPIO sleep configuration
I (989) app_start: Starting scheduler on CPU0
I (993) app_start: Starting scheduler on CPU1
I (993) main_task: Started on CPU0
I (1003) esp_psram: Reserving pool of 32K of internal memory for DMA/internal allocations
I (1013) main_task: Calling app_main()
I (1033) pp: pp rom version: e7ae62f
I (1033) net80211: net80211 rom version: e7ae62f
I (1053) wifi:wifi driver task: 3fcb43e0, prio:23, stack:6656, core=0
I (1053) wifi:wifi firmware version: 0016c4d
I (1053) wifi:wifi certification version: v7.0
I (1053) wifi:config NVS flash: enabled
I (1053) wifi:config nano formating: disabled
I (1063) wifi:Init data frame dynamic rx buffer num: 32
I (1063) wifi:Init static rx mgmt buffer num: 5
I (1073) wifi:Init management short buffer num: 32
I (1073) wifi:Init static tx buffer num: 16
I (1073) wifi:Init tx cache buffer num: 32
I (1083) wifi:Init static tx FG buffer num: 2
I (1083) wifi:Init static rx buffer size: 1600
I (1093) wifi:Init static rx buffer num: 10
I (1093) wifi:Init dynamic rx buffer num: 32
I (1093) wifi_init: rx ba win: 6
I (1103) wifi_init: tcpip mbox: 32
I (1103) wifi_init: udp mbox: 6
I (1113) wifi_init: tcp mbox: 6
I (1113) wifi_init: tcp tx win: 5760
I (1113) wifi_init: tcp rx win: 5760
I (1123) wifi_init: tcp mss: 624
I (1123) wifi_init: WiFi/LWIP prefer SPIRAM
I (1133) wifi_init: WiFi IRAM OP enabled
I (1133) wifi_init: WiFi RX IRAM OP enabled
I (1143) wifi:Set ps type: 0, coexist: 0

I (1143) phy_init: phy_version 640,cd64a1a,Jan 24 2024,17:28:12
W (1153) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (1203) wifi:mode : softAP (7c:df:a1:e1:95:05)
I (1213) wifi:Total power save buffer number: 8
I (1213) wifi:Init max length of beacon: 752/752
I (1213) wifi:Init max length of beacon: 752/752
I (1213) wifi:mode : sta (7c:df:a1:e1:95:04) + softAP (7c:df:a1:e1:95:05)
I (1223) wifi:enable tsf
I (1223) mesh: <nvs>read layer:0, err:0x1102
I (1223) mesh: <nvs>read assoc:0, err:0x1102
I (1783) wifi:Total power save buffer number: 8
I (2333) wifi:mode : sta (7c:df:a1:e1:95:04)
I (2343) mesh: <MESH_NWK_LOOK_FOR_NETWORK>need_scan:0x3, need_scan_router:0x0, look_for_nwk_count:1
I (2343) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:76
I (2343) mesh_main: mesh starts successfully, internal heap:214471, root not fixed

See last line of log:
v4.4: 245207 bytes free
v5.1: 214471 bytes free
-> delta ~ 30.7k

FYI @zhangyanjiaoesp

@espressif-bot espressif-bot added the Status: Opened Issue is new label Feb 28, 2024
@github-actions github-actions bot changed the title [ESP32S3] v5.1 consuming up to 30kB of internal memory more than same example in v4.4 [ESP32S3] v5.1 consuming up to 30kB of internal memory more than same example in v4.4 (IDFGH-12234) Feb 28, 2024
@dobairoland
Copy link
Collaborator

This is just a tip to narrow down the source of the difference: You can use esp-idf-size (https://github.com/espressif/esp-idf-size) (already available in ESP-IDF environments) and with the --diff argument to see the difference between the two projects.

python -m esp_idf_size.ng build/blink_v5.1.map --diff /tmp/blink_v4.4.map

You can add arguments to get more details. See python -m esp_idf_size.ng --help.

@KonssnoK
Copy link
Contributor Author

This is just a tip to narrow down the source of the difference: You can use esp-idf-size (https://github.com/espressif/esp-idf-size) (already available in ESP-IDF environments) and with the --diff argument to see the difference between the two projects.

python -m esp_idf_size.ng build/blink_v5.1.map --diff /tmp/blink_v4.4.map

You can add arguments to get more details. See python -m esp_idf_size.ng --help.

hello @dobairoland , we are talking about internal RAM usage, not file size. I'll update the name to reflect that

@KonssnoK KonssnoK changed the title [ESP32S3] v5.1 consuming up to 30kB of internal memory more than same example in v4.4 (IDFGH-12234) [ESP32S3] v5.1 consuming up to 30kB of internal RAM more than same example in v4.4 (IDFGH-12234) Feb 28, 2024
@espressif-bot espressif-bot added Status: In Progress Work is in progress and removed Status: Opened Issue is new labels Feb 29, 2024
@cbaechler
Copy link
Contributor

After quite some debugging I think I have found the difference between release/v4.4 and release/v5.1 that is causing the above mentioned behavior.

While in v4.4 the FreeRTOS malloc was simply defined as #define pvPortMalloc malloc, in v5.1 it is now defined as

#define portFREERTOS_HEAP_CAPS    ( MALLOC_CAP_INTERNAL | MALLOC_CAP_8BIT )

/*-----------------------------------------------------------*/

void * pvPortMalloc( size_t xWantedSize )
{
    void * pvReturn = NULL;

    /* All dynamic allocation done by FreeRTOS goes through this function. If
     * users need to allocate FreeRTOS objects into external RAM, they should
     * use the "static" equivalents of FreeRTOS API to create FreeRTOS objects
     * (e.g., queues). */
    pvReturn = heap_caps_malloc( xWantedSize, portFREERTOS_HEAP_CAPS );

    return pvReturn;
}

which forces the allocations to happen on the internal RAM.

By placing logs in esp_wifi/esp32s3/esp_adapter.c I can observe that calling esp_mesh_start() creates a queue of 96 elements with 184 bytes each (resulting in an allocation of 17664 bytes). By changing the code in queue_create_wrapper I managed to allocate the storage of the queue in SPIRAM:

- return (void *)xQueueCreate(queue_len, item_size);
+ return (void *)xQueueCreateWithCaps(queue_len, item_size, MALLOC_CAP_SPIRAM);

I tried to apply a similar modification to task_create_wrapper, however it fails on an assertion when creating a task with the name wifi:

assert failed: spi_flash_disable_interrupts_caches_and_other_cpu cache_utils.c:154 (esp_task_stack_is_sane_cache_disabled())

I assume this is related to the explanation in the code, but I am not sure I 100% understand the comment

/*
 * All dynamic allocation done by FreeRTOS should be placed in internal 8-bit
 * accessible RAM (i.e., using the MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT flags).
 * This is due to the fact that FreeRTOS objects (e.g., task stacks, TCBs,
 * queues etc) must be accessible even if the cache is disabled. Therefore, the
 * heap that is made available to FreeRTOS for dynamic allocation is a subset of
 * the ESP-IDF heap (where all MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT memory is
 * made available to FreeRTOS for dynamic allocation).
 * */

@KonssnoK
Copy link
Contributor Author

KonssnoK commented Mar 1, 2024

what is not clear is why we can write to spi_flash in v4.4 while having tasks allocated in the spi_ram and we cannot do the same in 5.1.

For sure there are no hardware limitations, or we would not have been abled in the first place to put our RTOS stuff on SPI_RAM.

@zhangyanjiaoesp
Copy link
Collaborator

@dobairoland @Dazza0 PTAL

@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 4, 2024

@KonssnoK Please take a look at the FreeRTOS section of the IDF v5.1 migration guide. All dynamic memory allocated by FreeRTOS will not default to be being internal memory. This change was intentional in to increase run time safety.

For library/user code that need to move memory allocations to external memory. This now needs to be done explicitly (see the CreateWithCaps() API mentioned in the migration guide).

@KonssnoK
Copy link
Contributor Author

KonssnoK commented Mar 4, 2024

@KonssnoK Please take a look at the FreeRTOS section of the IDF v5.1 migration guide. All dynamic memory allocated by FreeRTOS will not default to be being internal memory. This change was intentional in to increase run time safety.

For library/user code that need to move memory allocations to external memory. This now needs to be done explicitly (see the CreateWithCaps() API mentioned in the migration guide).

Hello @Dazza0 , could you please be more specific on what you mean with "increase runtime safety" ?

Does this mean that 4.4 is not runtime safe and the change needs to be backported?

What is the criticality?
Is it related to the HW design?

Thanks.

@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 5, 2024

@KonssnoK Previously, FreeRTOS would simply use malloc. Thus, if users enabled CONFIG_SPIRAM_USE_MALLOC, it is possible that malloc() will return memory in SPIRAM. Thus, it was possible that xQueueCreate() could allocate a queue in SPIRAM. Given that SPIRAM is inaccessible when the cache is disabled (e.g., during an SPI flash write), it was up to the users to ensure that FreeRTOS objects that were allocated in SPIRAM were not access while the cache was disabled. For example, if
xQueueCreate() allocates a queue in SPIRAM, users must ensure that the queue was not accessed while another task was executing an SPI flash write operation.

However, we encountered numerous users who ran into a Cache disabled but cached memory region accessed error as they were not aware of the restrictions of allocating memory from SPIRAM. Thus, the decision was made to make FreeRTOS to allocate all dynamic memory from internal memory by default (which is always accessible). FreeRTOS objects can still be allocated from SPIRAM (or other types of memory as well). However, this must now be done explicitly by the user (via the ...WithCaps() API) such that they are aware of exactly which type of memory the object is placed in, and the associated restrictions.

@KonssnoK
Copy link
Contributor Author

KonssnoK commented Mar 5, 2024

thanks @Dazza0 .

Am I correct saying that the only way to have such a scenario of Cache disabled but cached memory region accessed would be when the second core tries to do something on spi ram during spi flash operations?

Because from what I remember on flash operations you always have at least

  • scheduler is suspended on running CPU
  • interrupts are disabled

@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 5, 2024

@KonssnoK

Am I correct saying that the only way to have such a scenario of Cache disabled but cached memory region accessed would be when the second core tries to do something on spi ram during spi flash operations?

Yes, that's correct

Because from what I remember on flash operations you always have at least

scheduler is suspended on running CPU
interrupts are disabled

Interrupts created with the ESP_INTR_FLAG_IRAM will still run during flash operations. If that interrupt handler then calls xQueueSendFromISR() to an SPI RAM queue, we get the Cache disabled but cached memory region accessed error.

@KonssnoK
Copy link
Contributor Author

KonssnoK commented Mar 5, 2024

our main doubt is about some espressif closed source code (mesh) that we use extensively.

This means that to recover space we'll have to change the esp_adapter file to use withCaps but we have no visibility on what happens inside the mesh library.

@zhangyanjiaoesp could you make an evaluation of:

  • how many ESP_INTR_FLAG_IRAM interrupts there are in the mesh library.
  • if there are xQueueSendFromISR in the mesh library

If 1 is true (used) it means that we should not move mesh queues to spi ram (even if we currently do).

If 1 is false (not used) it means we can use the mesh library on the same core of spi flash operations independently from 2, which somehow invalidates #11023

If 1 is false and 2 false (not used) it means we can also move mesh to the second core.

@Dazza0 please confirm.

Thanks

@zhangyanjiaoesp
Copy link
Collaborator

@zhangyanjiaoesp could you make an evaluation of:

  • how many ESP_INTR_FLAG_IRAM interrupts there are in the mesh library.
  • if there are xQueueSendFromISR in the mesh library

@KonssnoK

  • there are no ESP_INTR_FLAG_IRAM interrupts in the mesh library
  • there are no xQueueSendFromISR in the mesh library

@KonssnoK
Copy link
Contributor Author

KonssnoK commented Mar 5, 2024

@zhangyanjiaoesp thanks!
so it means we should be able to change esp_adapter, add withCaps and move it to core1 without any issue.

@espressif-bot espressif-bot added Status: Reviewing Issue is being reviewed and removed Status: In Progress Work is in progress labels Mar 12, 2024
@romocitto88
Copy link

Hi, I'm facing the same issue: my project in v5.1 is consuming internal RAM more than same code in v4.4 and always the compilation return "out of region..."
Which are the steps to solve this issue?

@zhangyanjiaoesp
Copy link
Collaborator

@romocitto88 Please take a look at #13285 (comment) and #13285 (comment)

@romocitto88
Copy link

I read the comments and I changed the functions indicated with "...WithCaps() with MALLOC_CAP_SPIRAM" but nothing is changed. I missed something?

@espressif-bot espressif-bot added Status: Done Issue is done internally Resolution: NA Issue resolution is unavailable and removed Status: Reviewing Issue is being reviewed labels Mar 13, 2024
@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 13, 2024

@romocitto88 Could you post a copy of the error log you are encountering?

@romocitto88
Copy link

romocitto88 commented Mar 13, 2024

@Dazza0
Here the error:

c:/.platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld.exe: .pio/build/esp32dev/firmware.elf section .iram0.text' will not fit in region iram0_0_seg'
c:/.platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld.exe: IRAM0 segment data does not fit.
c:/.platformio/packages/toolchain-xtensa-esp32/bin/../lib/gcc/xtensa-esp32-elf/12.2.0/../../../../xtensa-esp32-elf/bin/ld.exe: region `iram0_0_seg' overflowed by 2528 bytes

@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 13, 2024

@romocitto88 You are running our of static memory (IRAM to be specific). It's completely unrelated to this issue.

Please refer to this guide regarding reducing binary size.

@romocitto88
Copy link

@Dazza0
The same project with ESP-IDF version 4.4.2 everything compiles without problems, and with ESP-IDF version 5.1.2 runs out the memory. I've attached a file merge of the two section compiled with the different IDF-VERSION
Merge.pdf

@Dazza0
Copy link
Collaborator

Dazza0 commented Mar 14, 2024

@romocitto88 Yes, more functions have been placed into IRAM between v4.4.2 and v5.1.2. Again, please refer to the reducing binary size guide to determine what is using up your IRAM and what can be moved to flash to reduce IRAM usage.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally
Projects
None yet
Development

No branches or pull requests

7 participants