Way of dynamic memory allocation detections

User avatar
Gfast2
Posts: 182
Joined: Fri Aug 11, 2017 1:52 am

Way of dynamic memory allocation detections

Postby Gfast2 » Tue Mar 20, 2018 1:32 pm

Hi ESP-IDF,

After a long trip in my home town (Da Lian, China), I started my job here (Berlin, Germany) again. ;)

Today I'd like to know how to track memory allocation (in real time)?

I know there is a API call that track the free stack space:

Code: Select all

uxTaskGetStackHighWaterMark
And other three command for static memory usage statistic:
  • make size
    make size-components
    make size-files
---

But how to detect if I'm out of memory indeed?
Some weeks ago I've ported open62541(OPC UA) successfully. But my OPC UA Server ran only on WIFI connection but not with Ethernet (With my Ethernet connection, I made a Webserver up & running without any issue). For the OPC UA with WIFI, I didn't add too many logic for the test. But with the Ethernet, I did add many peripheral (Ethernet, SD Card, Serial Communication...) and a little bit more code for them. So I'm blind to tell if the single problem is only because I've used up all memories from our half Mega Byte static RAM.

P.s:
the gdb got triggered & stopped pointing at a function I never called.

User avatar
Gfast2
Posts: 182
Joined: Fri Aug 11, 2017 1:52 am

Re: Way of dynamic memory allocation detections

Postby Gfast2 » Tue Mar 20, 2018 1:55 pm

static memory usage by make size:

Code: Select all

Total sizes:
 DRAM .data size:   14728 bytes
 DRAM .bss  size:   42488 bytes
Used static DRAM:   57216 bytes ( 123520 available, 31.7% used)
Used static IRAM:   43771 bytes (  87301 available, 33.4% used)
      Flash code:  525519 bytes
    Flash rodata:  178052 bytes
Total image size:~ 762070 bytes (.bin may be padded larger)

Code: Select all

Per-file contributions to ELF file:
             Object File DRAM .data & .bss   IRAM Flash code & rodata   Total
             open62541.o       5820     54      0     175085    69425  250384
                xmltok.o          0      0      0      34221    18516   52737
             emac_main.o          8  32819    344       4367     1366   38904
              xmlparse.o          0      0      0      19022     3023   22045
        lib_a-vfprintf.o          0      0      0      14161      756   14917
                  uart.o         36     13      0       7498     7290   14837
       lib_a-svfprintf.o          0      0      0      13774      756   14530
            spi_common.o         19     21    231       3116     9381   12768
                    ff.o          0     10      0      12413      253   12676
               sockets.o          0    729      0       9528      925   11182
                   nd6.o          8   1027      0       9766      136   10937
      lib_a-svfiprintf.o          0      0      0       9642     1210   10852
       lib_a-vfiprintf.o          0      0      0       9933      738   10671
        spiffs_nucleus.o          0      0      0      10296        0   10296
                tcp_in.o          0     54      0       8071      916    9041
               api_msg.o          0      0      0       5847     1464    7311
                  dhcp.o          0     64      0       5445     1758    7267
                  gpio.o          0      0      0       3096     4015    7111
             sdmmc_cmd.o          0      0      0       4684     2340    7024
                   tcp.o          4     23      0       5289     1447    6763
                 tasks.o         20    700   5395          0      515    6630
        lib_a-svfscanf.o          0      0      0       6363       39    6402
               tcp_out.o          0      0      0       5027     1124    6151
            sdmmc_host.o          8      8      0       5030     1079    6125
            spi_master.o          0     12   2396       2747      960    6115
                   dns.o          0   1294      0       4588      206    6088
                 cJSON.o         12      8      0       5014      641    5675
            rtc_module.o         16      8      0       1204     4377    5605
                   rmt.o          8     49    776       3262     1444    5539
            esp_spiffs.o          0     12      0       3667     1603    5282
               sd_card.o          0   1361      0       2492     1284    5137
       lib_a-svfiscanf.o          0      0      0       4963       34    4997
              spiflash.o          0    328      0       2963     1512    4803
               xmlrole.o          0      0      0       3789      947    4736
                etharp.o          0    241      0       3176      699    4116
       spiffs_hydrogen.o          0      0      0       4037        0    4037
                 panic.o       1955      5   1930          0        0    3890
        unwind-dw2-fde.o          4     20      0       3344      404    3772
                  pbuf.o          0      1      0       2414     1161    3576
               portasm.o       3084      0    480          0        0    3564
          lib_a-strtod.o          0      0      0       3422      125    3547
    tcpip_adapter_lwip.o          0    124      0       3033      309    3466
                minmea.o          0      0      0       3120      340    3460
            intr_alloc.o          8     22    730       1952      728    3440
            lib_a-dtoa.o          0      0      0       3334       13    3347
                   udp.o          2      4      0       3083      216    3305
                   ip6.o          0      0      0       3178      124    3302
               rtc_clk.o       1272      8   1998          0        0    3278
   spi_flash_rom_patch.o          0      0   2369          0      770    3139
               vfs_fat.o          0     12      0       2766      346    3124
        lib_a-strerror.o          0      0      0        802     2258    3060
            multi_heap.o        800      0   2178          0        0    2978
                 queue.o          0      0   2407          0      392    2799
             spiffs_gc.o          0      0      0       2721        0    2721
               api_lib.o          0      0      0       1675      955    2630
            dhcpserver.o          5     42      0       2486       68    2601
               ringbuf.o          0      0   2212          0      375    2587
     unwind-dw2-xtensa.o          0      0      0       2208      324    2532
           lib_a-mprec.o          0      0      0       2134      296    2430
              ip6_frag.o          0      6      0       1905      442    2353
                  igmp.o          0     12      0       1572      707    2291
       esp_timer_esp32.o          8     26   1479        254      474    2241
               gdbstub.o          0    933      0       1257       39    2229
             cpu_start.o          0     41   1024        413      604    2082
            flash_mmap.o          0    296   1228        148      367    2039
             flash_ops.o         32      5   1894         70        0    2001
                WS2812.o          7      0      0        926     1022    1955
        eh_personality.o          0      0      0       1565      384    1949
     sdmmc_transaction.o          0     85      0       1435      419    1939
                 netif.o          0    241      0       1369      287    1897
                   ip4.o          0      6      0       1622      139    1767
             heap_caps.o          4      0   1093         52      593    1742
        xtensa_vectors.o          8      0   1697          0       36    1741
           ws2812_task.o          0      4      0        936      751    1691
            system_api.o          0     14    597        426      652    1689
                   vfs.o          0     32      0       1519      131    1682
            phy_common.o          0      0      0        499     1136    1635
              task_wdt.o         58      4      0       1105      408    1575
                   raw.o          0      4      0       1235      223    1462
               nvs_api.o          0      0      0          0     1456    1456
           cache_utils.o          4     14    936         92      394    1440
        heap_caps_init.o          0      4      0       1038      387    1429
               ethinit.o          0    328      0        552      546    1426
              sys_arch.o          0      8      0       1193      222    1423
                timers.o          8     56   1102          0      247    1413
                  mld6.o          0      4      0       1407        0    1411
                   clk.o          0      0     67        538      801    1406
             ffunicode.o          0      0      0        368      978    1346
    lib_a-gdtoa-gethex.o          0      0      0       1293        0    1293
             gps_clock.o        160      0   1109          0        0    1269
             partition.o          0      8      0       1009      223    1240
     soc_memory_layout.o          0      0      0          0     1239    1239
              eh_alloc.o          0     16      0        616      601    1233
              vfs_uart.o         40     31      0        882      275    1228
event_default_handlers.o          0     96      0        517      560    1173
          spiffs_cache.o          0      0      0       1124        0    1124
                  icmp.o          0      0      0        732      371    1103
       xtensa_intr_asm.o       1024      0     51          0        0    1075
               pthread.o          8      4    178        330      512    1032
             esp_timer.o          8     12    517        353      126    1016
...
and make size-components

Code: Select all

Per-archive contributions to ELF file:
            Archive File DRAM .data & .bss   IRAM Flash code & rodata   Total
          libopen62541.a       5820     54      0     175085    69425  250384
               liblwip.a         19   3852      0      86451    15271  105593
                  libc.a          0      4     12      75599     6357   81972
              libexpat.a          0      0      0      57032    22486   79518
             libdriver.a        111    244   3403      28827    29450   62035
           libethernet.a          8  32819    344       5730     2637   41538
              libesp32.a       2069   1383   7694       8574     5252   24972
             libspiffs.a          0     12      0      21845     1603   23460
           libfreertos.a       4148    776  14569          0     1977   21470
              libfatfs.a          4     47      0      17000     2161   19212
               libmain.a        160   2079   1109       8238     4479   16065
                libgcc.a          4     20    104      10931      888   11947
          libspi_flash.a         36    323   6427       1319     1754    9859
              libsdmmc.a          0      0      0       4684     2340    7024
                libsoc.a       1272      8   4000          0     1239    6519
               libheap.a        804      4   3271       1090      980    6149
             libstdc++.a          8     36      0       3853     2170    6067
               libjson.a         12      8      0       5014      641    5675
      libtcpip_adapter.a          0    124      0       3033      309    3466
             libminmea.a          0      0      0       3120      340    3460
                libvfs.a         40     63      0       2401      406    2910
          libnvs_flash.a          0      0      0          0     2544    2544
             libws2812.a          7      0      0        926     1022    1955
             libnewlib.a        152    252    744        532      230    1910
            libpthread.a         16      8    178        828      640    1670
         libapp_update.a          0      0      0        124      717     841
                liblog.a          8    268    432         82        0     790
                libhal.a          0      0    515          0       32     547
                libcxx.a          0      0      0          5      160     165
                  libm.a          0      0     84          0        0      84
     libwpa_supplicant.a          0      0      0          0        0       0
               libcore.a          0      0      0          0        0       0
            libcoexist.a          0      0      0          0        0       0
                libwps.a          0      0      0          0        0       0
                 libpp.a          0      0      0          0        0       0
            libmbedtls.a          0      0      0          0        0       0
           libnet80211.a          0      0      0          0        0       0
               libwpa2.a          0      0      0          0        0       0
 libbootloader_support.a          0      0      0          0        0       0
                librtc.a          0      0      0          0        0       0
                libwpa.a          0      0      0          0        0       0
                libphy.a          0      0      0          0        0       0


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

Re: Way of dynamic memory allocation detections

Postby ESP_Angus » Tue Mar 20, 2018 10:00 pm

It looks like your static memory (data RAM) use is OK (judging from the "Used static DRAM" line in "make size"). Maybe you're running out of heap memory (dynamic memory) at runtime? Heap is the memory allocated by malloc(), calloc(), and similar functions.

As this memory is dynamic (as then name suggests), you have to trace it at runtime. There are a number of built-in tools for this. I suggest starting here to read about them:
https://esp-idf.readthedocs.io/en/lates ... nformation

User avatar
Gfast2
Posts: 182
Joined: Fri Aug 11, 2017 1:52 am

Re: Way of dynamic memory allocation detections

Postby Gfast2 » Thu Mar 22, 2018 9:33 am

Hi ESP_Angus,

Thank you very much for the Link about Heap Memory Debugging.

---

I've followed the instructions as the docu said: Turned on "Assertion level" to "Enable" & make sure "Optimization Level" to "-Og", but didn't change my code. After manually clean and recompile the code base, I still get crashed in the same place but without

Code: Select all

CORRUPT HEAP: multi_heap.c:225 detected at 0x3ffbb71c
Because the crash happened in the API call of a opensourced library (op62541.org), I've tried to add one line above the place where the crash get triggered, the statement I added:

Code: Select all

ESP_LOGW(TAG,"freeheap before crash: %d",esp_get_free_heap_size());
And this log I've never get logged till the whole programm get crashed.

And this part of code looks like this:

Code: Select all

35234     ESP_LOGW(TAG,"freeheap before crash: %d",esp_get_free_heap_size());
35235 
35236     /* Add to the list of pending acks */
35237     UA_Client_NotificationsAckNumber *tmpAck =
35238         (UA_Client_NotificationsAckNumber*)UA_malloc(sizeof(UA_Client_NotificationsAckNumber));
35239     ORRUPT HEAP: multi_heap.c:225 detected at 0x3ffbb71c
35240         UA_LOG_WARNING(client->config.logger, UA_LOGCATEGORY_CLIENT,
35241                        "Not enough memory to store the acknowledgement for a publish "
35242                        "message on subscription %u", sub->subscriptionID);
35243         return;
35244     }
35245     tmpAck->subAck.sequenceNumber = msg->sequenceNumber;
35246     tmpAck->subAck.subscriptionId = sub->subscriptionID;
35247     LIST_INSERT_HEAD(&client->pendingNotificationsAcks, tmpAck, listEntry);
35248 }
And my crash log:

Code: Select all

Guru Meditation Error: Core  1 panic'ed (StoreProhibited)
. Exception was unhandled.
Core 1 register dump:
PC      : 0x4000c2ff  PS      : 0x00060730  A0      : 0x800e8a5c  A1      : 0x3ffe2290  
A2      : 0x00000000  A3      : 0x3ffe2590  A4      : 0x00000008  A5      : 0x00000000  
A6      : 0x00000001  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x3ffe2290  
A10     : 0x00000000  A11     : 0x00001800  A12     : 0x00000000  A13     : 0x00000003  
A14     : 0x00000000  A15     : 0x00000000  SAR     : 0x0000000c  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff  

Backtrace: 0x4000c2ff:0x3ffe2290 0x400e8a59:0x3ffe22a0 0x400e9309:0x3ffe22c0 0x400ec82d:0x3ffe2300 0x40102a68:0x3ffe2330 0x401120d3:0x3ffe2930 0x401123e2:0x3ffe2960 0x40114cda:0x3ffe2b30 0x400d500d:0x3ffe2b50
0x400e8a59: UInt64_encodeBinary at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x400e9309: UA_encodeBinaryInternal at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x400ec82d: UA_encodeBinary at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x40102a68: function_ua_namespace0_53 at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x401120d3: ua_namespace0 at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x401123e2: UA_Server_initNS0 at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x40114cda: UA_Server_new at /home/gfast2/workspace/ioc-110-ethernet/components/open62541/./open62541.c:35242 (discriminator 3)

0x400d500d: opcua_task at /home/gfast2/workspace/ioc-110-ethernet/main/./opcua_task.c:31

CPU halted.
I know very possibly is this crash not related to heap out-of-usage (From the Assertion level detection result), and if the crash really happend on line 35242, the main reason is from the "return;" on line 35243. But please look at line 35240: "Not enough memory to store the acknowledgement for a plublish message on subscription %d".

This whole open62541 library takes about 102kB memory as a freeRTOS task (Tested in other project), and in this project, before the initialization of the same open62541 task, "esp_get_free_heap_size()" return me 126156Byte free heap. This let me thinking, how to tell out of memory. Is that means about 26kB free Heap should also OK on theory?

User avatar
Gfast2
Posts: 182
Joined: Fri Aug 11, 2017 1:52 am

Re: Way of dynamic memory allocation detections

Postby Gfast2 » Thu Mar 22, 2018 10:04 am

BTW, with this library, I've two separate projects. One works with WIFI and the other works with ETH. The WIFI one is smaller, and works well with this open62541 library & WIFI, but the ETH one is bigger. The integration of this library happens much later. And still now do not works at all (But a Webserver through ETH works well here).

So can this crash caused by the difference between WIFI & ETH?

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

Re: Way of dynamic memory allocation detections

Postby ESP_Angus » Thu Mar 22, 2018 11:48 pm

Gfast2 wrote:After manually clean and recompile the code base, I still get crashed in the same place but without

Code: Select all

CORRUPT HEAP: multi_heap.c:225 detected at 0x3ffbb71c
Ah, now you mention this error message it changes the likely cause of this problem.

You're probably not running out of memory, something in the firmware has corrupted memory - ie it's written to heap memory that it doesn't own (by writing past the end of an allocated buffer, or by writing to memory after it's been freed, or something like that.)

You can learn about debugging this in the heap docs as well, here:
https://esp-idf.readthedocs.io/en/lates ... corruption
One works with WIFI and the other works with ETH. The WIFI one is smaller, and works well with this open62541 library & WIFI, but the ETH one is bigger. The integration of this library happens much later. And still now do not works at all (But a Webserver through ETH works well here).

So can this crash caused by the difference between WIFI & ETH?
This could be anything - maybe using WIFI vs Ethernet changes the timing of some events, or changes the size of some buffers, causing things to not fail which would otherwise fail.

You can try setting heap checking to Comprehensive in menuconfig and see if the behaviour changes at all.

Angus

User avatar
Gfast2
Posts: 182
Joined: Fri Aug 11, 2017 1:52 am

Re: Way of dynamic memory allocation detections

Postby Gfast2 » Fri Mar 23, 2018 8:46 am

Hi Angust,

Thanks again for your suggestions. Because of the code size of my ethernet project, I still believe this Problem is some how caused by the massive usage of heap memory.

Perhapse I was out of IRAM, but not DRAM (I've asked here yesterday what are theyLINK. After really a long while digging into detail of the old code base. I made a barebone demo Project copied from stock ethernet example from ESP. And tried to start a OPC UA Server by starting its task when I got system event "SYSTEM_EVENT_ETH_GOT_IP" (Just as my old code did). This minimal version project allowed my to starting that OPC UA Server, but get crash on something else about initialize a resuable socket

Code: Select all

setsockopt(newsock, SOL_SOCKET, SO_REUSEADDR,(const char *)&optval, sizeof(optval))
Since this specified problem is really something else. I've open another question here

I'll invest more time later on. Thanks again for your advices & hope you have a nice weekend

Cheers

Gfast2

Who is online

Users browsing this forum: Majestic-12 [Bot] and 89 guests