PSRAM decreases in do_global_ctors

jumjum123
Posts: 180
Joined: Mon Oct 17, 2016 3:11 pm

Re: PSRAM decreases in do_global_ctors

Postby jumjum123 » Mon Feb 05, 2018 10:32 am

Forgot to answer to this:
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

esp_get_free_heap_size() is used in one place only, to log available heap
the number 1280kb is used in partitions table, but I already changed this to other values, that didn't change anything
The freakish way, yes, thats something, hmmmm, no idea how to find this. :?

ESP_Angus
Posts: 1155
Joined: Sun May 08, 2016 4:11 am

Re: PSRAM decreases in do_global_ctors

Postby ESP_Angus » Mon Feb 05, 2018 2:29 pm

That is all quite strange...

How about if you call heap_caps_dump(MALLOC_CAP_SPIRAM) after do_global_ctors?

Also, it'd be interesting to see output from heap_caps_get_free_size(MALLOC_CAP_SPIRAM), heap_caps_get_free_size(MALLOC_CAP_8BIT), and heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT).

jumjum123
Posts: 180
Joined: Mon Oct 17, 2016 3:11 pm

Re: PSRAM decreases in do_global_ctors

Postby jumjum123 » Mon Feb 05, 2018 3:52 pm

Code: Select all

ESP_ERROR_CHECK( heap_trace_init_standalone(trace_record, NUM_RECORDS) );
ESP_EARLY_LOGI(TAG, "trace initialised\n");
ESP_ERROR_CHECK( heap_trace_start(HEAP_TRACE_ALL));
ESP_EARLY_LOGI(TAG, "trace started\n");
    do_global_ctors();
ESP_ERROR_CHECK( heap_trace_stop());
ESP_EARLY_LOGI(TAG, "trace stopped\n");
heap_trace_dump();
heap_caps_dump(MALLOC_CAP_SPIRAM);
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_SPIRAM):%d\n",heap_caps_get_free_size(MALLOC_CAP_SPIRAM));
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_8BIT):%d\n",heap_caps_get_free_size(MALLOC_CAP_8BIT));
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT):%d\n",heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT));


I (1430) cpu_start: heap after reserving pool:4206140
I (105) cpu_start: trace initialised
I (105) cpu_start: trace started
I (106) cpu_start: do_global:1061313156(4011790c) = (4205388)
I (107) cpu_start: do_global:1061313152(40117114) = (2894568)
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
Heap start 0x3f800010 end 0x3fbffff4
First free block 0x3f94001c
Block 0x3f800010 data size 0x00000004 bytes next block 0x3f800018 FREE. Next free 0x3f94001c
Block 0x3f800018 data size 0x00140000 bytes next block 0x3f94001c
Block 0x3f94001c data size 0x002bffd4 bytes next block 0x3fbffff4 FREE. Next free 0x3fbffff4
Block 0x3fbffff4 data size 0x00000000 bytes next block 0x00000000 FREE. Next free 0x00000000
I (162) cpu_start: heap_caps_get_free_size(MALLOC_CAP_SPIRAM):2883540
I (169) cpu_start: heap_caps_get_free_size(MALLOC_CAP_8BIT):2906248
I (175) cpu_start: heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT):22708


jumjum123
Posts: 180
Joined: Mon Oct 17, 2016 3:11 pm

Re: PSRAM decreases in do_global_ctors

Postby jumjum123 » Mon Feb 05, 2018 3:56 pm

there is something wrong with heap tracing
I've added an malloc after starting trace, but it's not in heap_trace_dump

Code: Select all

ESP_ERROR_CHECK( heap_trace_init_standalone(trace_record, NUM_RECORDS) );
ESP_EARLY_LOGI(TAG, "trace initialised\n");
ESP_ERROR_CHECK( heap_trace_start(HEAP_TRACE_ALL));
ESP_EARLY_LOGI(TAG, "trace started\n");
      int x = malloc(131072);
ESP_EARLY_LOGI(TAG, "heap after malloc:%d(%d)\n",esp_get_free_heap_size(),x);
heap_caps_dump(MALLOC_CAP_SPIRAM);
    do_global_ctors();
ESP_ERROR_CHECK( heap_trace_stop());
ESP_EARLY_LOGI(TAG, "trace stopped\n");
heap_trace_dump();
heap_caps_dump(MALLOC_CAP_SPIRAM);
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_SPIRAM):%d\n",heap_caps_get_free_size(MALLOC_CAP_SPIRAM));
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_8BIT):%d\n",heap_caps_get_free_size(MALLOC_CAP_8BIT));
ESP_EARLY_LOGI(TAG,"heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT):%d\n",heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT));


jumjum123
Posts: 180
Joined: Mon Oct 17, 2016 3:11 pm

Re: PSRAM decreases in do_global_ctors

Postby jumjum123 » Mon Feb 05, 2018 6:24 pm

ok, found the reason, why heap dump is empty.
I had to add some flags to my linker file.
WRAP_FUNCTIONS = calloc malloc free realloc heap_caps_malloc heap_caps_free heap_caps_realloc
WRAP_ARGUMENT := -Wl,--wrap=

LDFLAGS+= -lheap $(addprefix $(WRAP_ARGUMENT),$(WRAP_FUNCTIONS))


Now I get this:
4 allocations trace (100 entry buffer)
12 bytes (@ 0x3ffddd38) allocated CPU 0 ccount 0x032267c8 caller 0x40114f50:0x40117805:0x400d0af2:0x40081213
8 bytes (@ 0x3ffddd54) allocated CPU 0 ccount 0x0322a8c4 caller 0x40114e14:0x40117008:0x400d0af2:0x40081213
80 bytes (@ 0x3ffddd6c) allocated CPU 0 ccount 0x0322b684 caller 0x4008aca6:0x4008aee7:0x40114e33:0x40117008
1310720 bytes (@ 0x3f800024) allocated CPU 0 ccount 0x0322d350 caller 0x4011701e:0x400d0af2:0x40081213:0x4008144a
1310820 bytes alive in trace (4/4 allocations)
total allocations 4 total frees 0
Heap start 0x3f800010 end 0x3fbffff4
First free block 0x3f940028
Block 0x3f800010 data size 0x00000004 bytes next block 0x3f800018 FREE. Next free 0x3f940028
Block 0x3f800018 data size 0x0014000c bytes next block 0x3f940028
Block 0x3f940028 data size 0x002bffc8 bytes next block 0x3fbffff4 FREE. Next free 0x3fbffff4
Block 0x3fbffff4 data size 0x00000000 bytes next block 0x00000000 FREE. Next free 0x00000000
I (492) cpu_start: heap_caps_get_free_size(MALLOC_CAP_SPIRAM):2883516
I (498) cpu_start: heap_caps_get_free_size(MALLOC_CAP_8BIT):2903844
I (504) cpu_start: heap_caps_get_free_size(MALLOC_CAP_INTERNAL|MALLOC_CAP_8BIT):20328

In lst file I find this for caller of last alloc (0x4011701e)

Code: Select all

40116ff8 <_GLOBAL__sub_I___cxa_allocate_exception>:
40116ff8:   004136           entry   a1, 32
40116ffb:   c71b41           l32r   a4, 40108c68 <lwip_listen+0x9ac>
40116ffe:   0b0c         movi.n   a11, 0
40117000:   04ad         mov.n   a10, a4
40117002:   201110           or   a1, a1, a1
40117005:   fdde65           call8   40114dec <pthread_mutex_init>
40117008:   020c         movi.n   a2, 0
4011700a:   2429         s32i.n   a2, a4, 8
4011700c:   201110           or   a1, a1, a1
4011700f:   fff5e5           call8   40116f6c <__cxx_eh_arena_size_get>
40117012:   34a9         s32i.n   a10, a4, 12
40117014:   0a2d         mov.n   a2, a10
40117016:   6a8c         beqz.n   a10, 40117020 <_GLOBAL__sub_I___cxa_allocate_exception+0x28>
40117018:   c4e581           l32r   a8, 401083ac <lwip_listen+0xf0>
4011701b:   0008e0           callx8   a8
4011701e:   24a9         s32i.n   a10, a4, 8
40117020:   2488         l32i.n   a8, a4, 8
40117022:   48cc         bnez.n   a8, 4011702a <_GLOBAL__sub_I___cxa_allocate_exception+0x32>
40117024:   3489         s32i.n   a8, a4, 12
40117026:   1489         s32i.n   a8, a4, 4
40117028:   f01d         retw.n
4011702a:   1489         s32i.n   a8, a4, 4
4011702c:   0829         s32i.n   a2, a8, 0
4011702e:   020c         movi.n   a2, 0
40117030:   1829         s32i.n   a2, a8, 4
40117032:   f01d         retw.n
40117034:   04ad         mov.n   a10, a4
40117036:   201110           or   a1, a1, a1
40117039:   fde625           call8   40114e9c <pthread_mutex_destroy>
4011703c:   02ad         mov.n   a10, a2
4011703e:   201110           or   a1, a1, a1
40117041:   012165           call8   40118258 <_Unwind_Resume>

ESP_Angus
Posts: 1155
Joined: Sun May 08, 2016 4:11 am

Re: PSRAM decreases in do_global_ctors

Postby ESP_Angus » Tue Feb 06, 2018 2:40 am

jumjum123 wrote:ok, found the reason, why heap dump is empty.
I had to add some flags to my linker file.
WRAP_FUNCTIONS = calloc malloc free realloc heap_caps_malloc heap_caps_free heap_caps_realloc
WRAP_ARGUMENT := -Wl,--wrap=

LDFLAGS+= -lheap $(addprefix $(WRAP_ARGUMENT),$(WRAP_FUNCTIONS))



I see. When using an external build system, making sure you have the same linker flags as the ESP-IDF build system is very important.

We have some ideas to make this easier in the future.

In lst file I find this for caller of last alloc (0x4011701e)

Code: Select all

40116ff8 <_GLOBAL__sub_I___cxa_allocate_exception>:
40116ff8:   004136           entry   a1, 32
40116ffb:   c71b41           l32r   a4, 40108c68 <lwip_listen+0x9ac>
40116ffe:   0b0c         movi.n   a11, 0
40117000:   04ad         mov.n   a10, a4
40117002:   201110           or   a1, a1, a1
40117005:   fdde65           call8   40114dec <pthread_mutex_init>
40117008:   020c         movi.n   a2, 0
4011700a:   2429         s32i.n   a2, a4, 8
4011700c:   201110           or   a1, a1, a1
4011700f:   fff5e5           call8   40116f6c <__cxx_eh_arena_size_get>
40117012:   34a9         s32i.n   a10, a4, 12
40117014:   0a2d         mov.n   a2, a10
40117016:   6a8c         beqz.n   a10, 40117020 <_GLOBAL__sub_I___cxa_allocate_exception+0x28>
40117018:   c4e581           l32r   a8, 401083ac <lwip_listen+0xf0>
4011701b:   0008e0           callx8   a8
4011701e:   24a9         s32i.n   a10, a4, 8
40117020:   2488         l32i.n   a8, a4, 8
40117022:   48cc         bnez.n   a8, 4011702a <_GLOBAL__sub_I___cxa_allocate_exception+0x32>
40117024:   3489         s32i.n   a8, a4, 12
40117026:   1489         s32i.n   a8, a4, 4
40117028:   f01d         retw.n
4011702a:   1489         s32i.n   a8, a4, 4
4011702c:   0829         s32i.n   a2, a8, 0
4011702e:   020c         movi.n   a2, 0
40117030:   1829         s32i.n   a2, a8, 4
40117032:   f01d         retw.n
40117034:   04ad         mov.n   a10, a4
40117036:   201110           or   a1, a1, a1
40117039:   fde625           call8   40114e9c <pthread_mutex_destroy>
4011703c:   02ad         mov.n   a10, a2
4011703e:   201110           or   a1, a1, a1
40117041:   012165           call8   40118258 <_Unwind_Resume>


Make sure you're linking -lcxx and passing the linker flags mentioned here:
https://github.com/espressif/esp-idf/bl ... mponent.mk

jumjum123
Posts: 180
Joined: Mon Oct 17, 2016 3:11 pm

Re: PSRAM decreases in do_global_ctors

Postby jumjum123 » Tue Feb 06, 2018 7:55 am

hip hip hooray !!!
That made it, ESP_ANGUS, thanks a lot.
I see. When using an external build system, making sure you have the same linker flags as the ESP-IDF build system is very important.
We have some ideas to make this easier in the future.

Please do this. Its always :o :shock: :?: to figure out, how to get it running with "last minor changes"
Working with ESP-IDF by its own works like a charm.
But this is not the case for porting projects, running on multiple platforms.

Who is online

Users browsing this forum: No registered users and 2 guests