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.

Sign up for GitHub

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

Jump to bottom

Less memory available for dev since v4.3.x (IDFGH-6233) #7906

Closed
AlpinProgrammer opened this issue Nov 15, 2021 · 10 comments
Closed

Less memory available for dev since v4.3.x (IDFGH-6233) #7906

AlpinProgrammer opened this issue Nov 15, 2021 · 10 comments
Assignees
@SoucheSouche
Labels
Status: Reviewing Issue is being reviewed

Comments

@AlpinProgrammer
Copy link

Environment

  • Development Kit: ESP32-DevKit
  • Kit version (for WroverKit/PicoKit/DevKitC): v?
  • Module or chip used: ESP32-WROOM-32
  • IDF version: v4.3.1
  • Build System: Make
  • Compiler version: xtensa-esp32-elf-gcc (crosstool-NG esp-2021r1) 8.4.0
  • Operating System: Linux
  • Using an IDE?: No
  • Power Supply: USB

Problem Description

Hello,
I am posting an issue here because we noticed a significant memory loss when going from using esp-idf-v4.2.2 to using esp-idf-v4.3.1.

Since the v4.3.x seems to add support for the new ESP32-C3, can this explain the loss ?

In order to illustrate the problem, I used the hello world example, adding log to show the memory available.

As you can observe from the logs, there is a 12552 byte loss from heap_caps_get_free_size(MALLOC_CAP_INTERNAL) information and a 8580 byte loss from the esp_get_minimum_free_heap_size() information.

Thank you for your help !

Code to reproduce this issue

Using examples/get-started/hello_world, replace

void app_main(void)
{

by

#include "esp_log.h"

void app_main(void)
{
    ESP_LOGI("MAIN", "Free internal Heap memory: %d",heap_caps_get_free_size(MALLOC_CAP_INTERNAL));

Debug Logs

v4.2.2

--- idf_monitor on /dev/ttyUSB1 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_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:0x3fff0030,len:7124
load:0x40078000,len:13852
load:0x40080400,len:4548
entry 0x400806ec
I (27) boot: ESP-IDF v4.2.2 2nd stage bootloader
I (27) boot: compile time 16:53:29
I (27) boot: chip revision: 1
I (29) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (36) boot.esp32: SPI Speed      : 40MHz
I (41) boot.esp32: SPI Mode       : DIO
I (46) boot.esp32: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (56) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (74) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (81) boot:  2 factory          factory app      00 00 00010000 00100000
I (89) boot: End of partition table
I (93) boot_comm: chip revision: 1, min. application chip revision: 0
I (100) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x06554 ( 25940) map
I (119) esp_image: segment 1: paddr=0x0001657c vaddr=0x3ffb0000 size=0x02040 (  8256) load
I (123) esp_image: segment 2: paddr=0x000185c4 vaddr=0x40080000 size=0x07a54 ( 31316) load
0x40080000: _WindowOverflow4 at /home/vincent/Work/esp32-linkio-mesh/esp-idf-v4.2.2/components/freertos/xtensa/xtensa_vectors.S:1730

I (141) esp_image: segment 3: paddr=0x00020020 vaddr=0x400d0020 size=0x13a5c ( 80476) map
0x400d0020: _stext at ??:?

I (171) esp_image: segment 4: paddr=0x00033a84 vaddr=0x40087a54 size=0x02490 (  9360) load
0x40087a54: esp_log_timestamp at /home/vincent/Work/esp32-linkio-mesh/esp-idf-v4.2.2/components/log/log_freertos.c:94

I (181) boot: Loaded app from partition at offset 0x10000
I (181) boot: Disabling RNG early entropy source...
I (183) cpu_start: Pro cpu up.
I (187) cpu_start: Application information:
I (192) cpu_start: Project name:     hello-world
I (197) cpu_start: App version:      v4.2.2-dirty
I (202) cpu_start: Compile time:     Nov 12 2021 16:57:39
I (208) cpu_start: ELF file SHA256:  5da50d86e80f17a0...
I (214) cpu_start: ESP-IDF:          v4.2.2-dirty
I (220) cpu_start: Starting app cpu, entry point is 0x4008107c
0x4008107c: call_start_cpu1 at /home/vincent/Work/esp32-linkio-mesh/esp-idf-v4.2.2/components/esp32/cpu_start.c:287

I (0) cpu_start: App cpu up.
I (230) heap_init: Initializing. RAM available for dynamic allocation:
I (237) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (243) heap_init: At 3FFB2880 len 0002D780 (181 KiB): DRAM
I (249) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (256) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (262) heap_init: At 40089EE4 len 0001611C (88 KiB): IRAM
I (268) cpu_start: Pro cpu start user code
I (286) spi_flash: detected chip: gd
I (287) spi_flash: flash io: dio
I (287) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (295) MAIN: Free internal Heap memory: 390584
Hello world!
This is esp32 chip with 2 CPU cores, WiFi/BT/BLE, silicon revision 1, 4MB external flash
Free heap: 299972
Restarting in 10 seconds...
Restarting in 9 seconds...
Restarting in 8 seconds...
Restarting in 7 seconds...
Restarting in 6 seconds...
Restarting in 5 seconds...
Restarting in 4 seconds...

v4.3.1

--- idf_monitor on /dev/ttyUSB1 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
20 �ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_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:0x3fff0030,len:7040
load:0x40078000,len:14276
ho 0 tail 12 room 4
load:0x40080400,len:3712
entry 0x4008067c
I (28) boot: ESP-IDF v4.3.1-dirty 2nd stage bootloader
I (29) boot: compile time 17:12:35
I (29) boot: chip revision: 1
I (32) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed      : 40MHz
I (44) boot.esp32: SPI Mode       : DIO
I (48) boot.esp32: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (95) boot_comm: chip revision: 1, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=07554h ( 30036) map
I (122) esp_image: segment 1: paddr=0001757c vaddr=3ffb0000 size=028ech ( 10476) load
I (126) esp_image: segment 2: paddr=00019e70 vaddr=40080000 size=061a8h ( 25000) load
I (138) esp_image: segment 3: paddr=00020020 vaddr=400d0020 size=144f8h ( 83192) map
I (169) esp_image: segment 4: paddr=00034520 vaddr=400861a8 size=04a3ch ( 19004) load
I (177) esp_image: segment 5: paddr=00038f64 vaddr=50000000 size=00010h (    16) load
I (183) boot: Loaded app from partition at offset 0x10000
I (183) boot: Disabling RNG early entropy source...
I (197) cpu_start: Pro cpu up.
I (197) cpu_start: Starting app cpu, entry point is 0x40080fdc
0x40080fdc: call_start_cpu1 at /home/vincent/Work/esp32-linkio-mesh/esp-idf-v4.3.1/components/esp_system/port/cpu_start.c:141

I (0) cpu_start: App cpu up.
I (212) cpu_start: Pro cpu start user code
I (212) cpu_start: cpu freq: 160000000
I (212) cpu_start: Application information:
I (216) cpu_start: Project name:     hello-world
I (221) cpu_start: App version:      v4.3.1-dirty
I (227) cpu_start: Compile time:     Nov 12 2021 17:13:44
I (233) cpu_start: ELF file SHA256:  db7566436e938924...
I (239) cpu_start: ESP-IDF:          v4.3.1-dirty
I (245) heap_init: Initializing. RAM available for dynamic allocation:
I (252) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (258) heap_init: At 3FFB31C0 len 0002CE40 (179 KiB): DRAM
I (264) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (270) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (277) heap_init: At 4008ABE4 len 0001541C (85 KiB): IRAM
I (284) spi_flash: detected chip: gd
I (287) spi_flash: flash io: dio
I (292) sleep: Configure to isolate all GPIO pins in sleep state
I (298) sleep: Enable automatic switching of GPIO sleep configuration
I (305) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (316) MAIN: Free internal Heap memory: 378032
Hello world!
This is esp32 chip with 2 CPU core(s), WiFi/BT/BLE, silicon revision 1, 4MB external flash
Minimum free heap size: 291392 bytes
Restarting in 10 seconds...
Restarting in 9 seconds...
Restarting in 8 seconds...
Restarting in 7 seconds...
Restarting in 6 seconds...
Restarting in 5 seconds...
Restarting in 4 seconds...
Restarting in 3 seconds...
Restarting in 2 seconds...
Restarting in 1 seconds...
Restarting in 0 seconds...
Restarting now.
@espressif-bot espressif-bot added the Status: Opened Issue is new label Nov 15, 2021
@github-actions github-actions bot changed the title Less memory available for dev since v4.3.x Less memory available for dev since v4.3.x (IDFGH-6233) Nov 15, 2021
@AxelLin
Copy link
Contributor

AxelLin commented Nov 15, 2021

#7822

@philippe44
Copy link

philippe44 commented Nov 18, 2021 •
edited
Loading

Here are the changes I get with my PR. The "ctrl_size" is the memory used for the allocator control block. Previously, it was the same size for all, so when you had SPIRAM, there was almost 2kB overhead for each. You see below that now each"ctrl_size" is adjusted to the minimum required.

So you have 416*3+736+872*2+804=4532 instead of 2168*7=10644 bytes improvement (again if you have SPIRAM, otherwise the largest block would require, I think 872 for control, so 872*7=6104)

I (1487) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
W (1477) NEW POOL of 7268 bytes, ctrl_size: 416 sli_c:8 fli_c:10 small_b 32 max_b:16384

I (1502) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
W (1493) NEW POOL of 16628 bytes, ctrl_size: 736 sli_c:16 fli_c:10 small_b 64 max_b:32768

I (1518) heap_init: At 3FFC7A78 len 00018588 (97 KiB): DRAM
W (1509) NEW POOL of 99700 bytes, ctrl_size: 872 sli_c:16 fli_c:12 small_b 64 max_b:131072

I (1525) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
W (1591) NEW POOL of 15052 bytes, ctrl_size: 416 sli_c:8 fli_c:10 small_b 32 max_b:16384

I (1531) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
W (1601) NEW POOL of 113820 bytes, ctrl_size: 872 sli_c:16 fli_c:12 small_b 64 max_b:131072

I (1547) heap_init: At 4009CF6C len 00003094 (12 KiB): IRAM
W (1537) NEW POOL of 12416 bytes, ctrl_size: 416 sli_c:8 fli_c:10 small_b 32 max_b:16384

I (1553) spiram: Adding pool of 4050K of external SPI memory to heap allocator
W (1561) NEW POOL of 4147491 bytes, ctrl_size: 2168 sli_c:32 fli_c:16 small_b 128 max_b:4194304

I (1611) spiram: Reserving pool of 64K of internal memory for DMA/internal allocations
W (1621) NEW POOL of 65515 bytes, ctrl_size: 804 sli_c:16 fli_c:11 small_b 64 max_b:65536

@espressif-bot espressif-bot added Status: Selected for Development Issue is selected for development and removed Status: Opened Issue is new labels Aug 22, 2022
@espressif-bot espressif-bot added Status: In Progress Work is in progress Resolution: Done Issue is done internally Status: Done Issue is done internally and removed Status: Selected for Development Issue is selected for development Status: In Progress Work is in progress labels Nov 25, 2022
@AxelLin
Copy link
Contributor

AxelLin commented Dec 16, 2022

@SoucheSouche Any update?
This is marked as "Resolution: Done", is this fixed?

@SoucheSouche
Copy link
Collaborator

SoucheSouche commented Dec 16, 2022 •
edited
Loading

Hi @AxelLin,

Yes, the resolution of this issue was merged in the master branch and v4.4. The backports to v5.0 is waiting to be merged as well.

@AxelLin
Copy link
Contributor

AxelLin commented Dec 16, 2022

@SoucheSouche

v4.3 also needs fix.

I'm aware v4.3 is in maintenance period, but this bug report clearly says it's impacted since v4.3.x.
In additional, the PR was created on Nov 4, 2021. (It took almost 1 year to merge the PR.)
So please fix v4.3 as well.

@espressif-bot espressif-bot added Status: In Progress Work is in progress and removed Resolution: Done Issue is done internally Status: Done Issue is done internally labels Dec 23, 2022
@SoucheSouche
Copy link
Collaborator

SoucheSouche commented Dec 28, 2022 •
edited
Loading

@AlpinProgrammer, @AxelLin, I created a backport to v4.3 including several changes on the heap component affecting the available heap memory. This allows the recovery of ~65% of the loss between v4.2 and v4.3.

@AxelLin
Copy link
Contributor

AxelLin commented Dec 28, 2022

@SoucheSouche

Thanks.
Just curious what's the recovery ratio for v4.4 and v5.0 with the fix?

@SoucheSouche
Copy link
Collaborator

SoucheSouche commented Dec 29, 2022 •
edited
Loading

@AxelLin

when running the hello_world example on esp32, we get the following results for available heap memory:

release v5.0:

  • before fixes → 295868 bytes
  • after fixes → 301716 bytes

release v4.4:

  • before fixes → 296120 bytes
  • after fixes → 301944 bytes

@espressif-bot espressif-bot added Status: Reviewing Issue is being reviewed and removed Status: In Progress Work is in progress labels Jan 31, 2023
@AxelLin
Copy link
Contributor

AxelLin commented Feb 28, 2023

@AlpinProgrammer, @AxelLin, I created a backport to v4.3 including several changes on the heap component affecting the available heap memory. This allows the recovery of ~65% of the loss between v4.2 and v4.3.

@SoucheSouche
I still cannot find the fix in v4.3 branch after waiting for 2 Months.
It has been marked as Reviewing for a Month, how is the status now?

@SoucheSouche
Copy link
Collaborator

The fix was merged on our GitLab repo several of days ago. It should be available on Github with the next sync.

@AxelLin AxelLin mentioned this issue Mar 1, 2023
Open
3 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@SoucheSouche SoucheSouche

Labels
Status: Reviewing Issue is being reviewed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@AxelLin @philippe44 @zikalino @AlpinProgrammer @SoucheSouche @espressif-bot