1| Supported Targets | ESP32 | ESP32-S2 | ESP32-C3 | 2| ----------------- | ----- | -------- | -------- | 3 4# SystemView Heap and Log Tracing Example 5 6Heap memory leaking is quite widespread software bug. IDF provides [heap tracing feature](https://docs.espressif.com/projects/esp-idf/en/latest/api-reference/system/heap_debug.html#heap-tracing) which allows to collect information related to heap operations (allocations/deallocations) and detect potential memory leaks. This feature can be used in two modes: standalone and host-based. In standalone mode collected data are kept on-board, so this mode is limited by avaialable memory in the system. Host-based mode does not have such limitation because collected data are sent to the host and can be analysed there using special tools. One of such tool is SEGGER SystemView. For description of [SystemView tracing feature](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/app_trace.html#system-behaviour-analysis-with-segger-systemview) please refer to **ESP32 Programming Guide**, section **Application Level Tracing library**. SystemView is also can be useful to show log message sent from the target. 7This example shows how to use this tool and IDF's scripts for host-based heap and log tracing analysis. 8 9Consider the following situation. User program have two tasks. One task allocates memory and puts obtained addresses into the queue. Another task waits on that queue, reads sent pointers and frees memory. The first task queues only part of the pointers so some of the allocated blocks are not freed and become leaked. Both tasks uses IDF's logging API to report their actions. This example uses IDF's heap tracing module to record allocations and deallocations to detect memory leaks. Both heap tracing records and log mesages are redirected to the host. 10 11## How to use example 12 13### Hardware and tools required 14 15This example does not require any special hardware, and can be run on any common development board. 16This example requires the following tools: 171. [OpenOCD](https://docs.espressif.com/projects/esp-idf/en/latest/api-guides/jtag-debugging/index.html#run-openocd). 18NOTE: In order to run this example you need OpenOCD version `v0.10.0-esp32-20190313` or later. 19 202. [GDB](https://docs.espressif.com/projects/esp-idf/en/latest/get-started/index.html#setup-toolchain) can be used to start and/or stop tracing automatically. To do this you need to prepare special GDB command file. Having provided with `gdbinit` file from the example project directory GDB will connect to the target, reset it, start and stop tracing automatically. 21when program hits breakpoint at `heap_trace_start`. Trace data will be saved to `/tmp/hesp_log.svdat`. Tracing will be stopped when program hits breakpoint at `heap_trace_stop`. 22 233. [SEGGER SystemView tool](https://www.segger.com/products/development-tools/systemview/). By default SystemView shows only numeric values of IDs and parameters for IDF's heap messages in `Events` view. To make them pretty-looking you need to copy `SYSVIEW_FreeRTOS.txt` from the project's root directory to SystemView installation one. 24 25### Build and flash 26 27``` 28idf.py -p PORT flash monitor 29``` 30 31(Replace PORT with serial port name.) 32 33(To exit the serial monitor, type ``Ctrl-]``.) 34 35See the Getting Started Guide for full steps to configure and use ESP-IDF to build projects. 36 37### Collect And View Trace Data 38 39To run the example and collect trace data: 40 411. Run GDB using the following command from the project root directory: 42 43 ``` 44 xtensa-esp32-elf-gdb -x gdbinit build/sysview_tracing_heap_log.elf 45 ``` 46 472. When program stops at `heap_trace_stop` quit GDB. 48 493. Open trace data file in SystemView tool. 50 514. Now you can inspect all collected events. Log messages are shown in `Terminal` view. 52 535. You can filter out API related and heap events by right-clicking on any item in `Events` view and select `Show APIs only`. 54 55### Auto-detect Heap Leaks 56 57Since SystemView tool is mostly intended for OS level analysis. It allows just to inspect custom events' timestamps and parameters. So it can require some efforts to analyse heap operations flow. IDF provides special script to make the life a bit more easy. This script parses SystemView trace file sand reports detected memory leaks. The script also prints found log messages. To run it type the following from the project root directory: 58 59``` 60$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p -b build/sysview_tracing_heap_log.elf /tmp/heap_log.svdat 61``` 62 63Below is the sample scripts output. 64 65``` 66[0.002272225] HEAP: Allocated 8 bytes @ 0x3ffaff6c from task "main" on core 0 by: 67/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 68/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 69 70[0.002307300] HEAP: Allocated 2500 bytes @ 0x3ffb580c from task "main" on core 0 by: 71/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 72/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) 73 74[0.002323775] HEAP: Allocated 356 bytes @ 0x3ffb61d4 from task "main" on core 0 by: 75/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 76/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) 77 78[0.002427700] HEAP: Allocated 120 bytes @ 0x3ffaff78 from task "alloc0" on core 0 by: 79/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 80/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 81 82[0.002471225] HEAP: Allocated 2500 bytes @ 0x3ffb633c from task "alloc0" on core 0 by: 83/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 84/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 85 86[0.002487725] HEAP: Allocated 356 bytes @ 0x3ffb6d04 from task "alloc0" on core 0 by: 87/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 88/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 89 90[0.002569725] HEAP: Allocated 2 bytes @ 0x3ffafff4 from task "alloc0" on core 0 by: 91/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:59 92/home/user/projects/esp/esp-idf/components/freertos/port.c:145 93 94[0.002835275] LOG: I (298) example: Task[0x3ffb61d4]: allocated 2 bytes @ 0x3ffafff4 95[0.002974600] LOG: I (299) example: Task[0x3ffb6d04]: free memory @ 0x3ffafff4 96 97.... 98 99[2.942891550] LOG: I (3239) example: Task[0x3ffb7840]: allocated 396 bytes @ 0x3ffb9d08 100[2.943024150] LOG: I (3239) example: Task[0x3ffb6d04]: free memory @ 0x3ffb9c3c 101[2.943035600] HEAP: Freed bytes @ 0x3ffb9c3c from task "free0" on core 0 by: 102/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) 103/home/user/projects/esp/esp-idf/components/freertos/port.c:145 104 105[2.943212125] LOG: I (3239) example: Task[0x3ffb83ec]: free memory @ 0x3ffb9d08 106[2.943223500] HEAP: Freed bytes @ 0x3ffb9d08 from task "free1" on core 0 by: 107/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) 108/home/user/projects/esp/esp-idf/components/freertos/port.c:145 109 110[2.943649025] HEAP: Allocated 594 bytes @ 0x3ffb9c3c from task "alloc2" on core 0 by: 111/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:59 112/home/user/projects/esp/esp-idf/components/freertos/port.c:145 113 114[2.943734250] LOG: I (3240) example: Task[0x3ffb8f28]: allocated 594 bytes @ 0x3ffb9c3c 115[2.943867850] LOG: I (3240) example: Task[0x3ffb9ad4]: free memory @ 0x3ffb9c3c 116[2.943879200] HEAP: Freed bytes @ 0x3ffb9c3c from task "free2" on core 0 by: 117/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:24 (discriminator 9) 118/home/user/projects/esp/esp-idf/components/freertos/port.c:145 119 120[2.972813425] LOG: I (3269) example: Got notify val 2 121[2.972870400] LOG: I (3269) example: Wait notify 1 122[2.972932800] LOG: I (3269) example: Got notify val 1 123[2.972989825] LOG: I (3269) example: Wait notify 2 124[2.973756125] LOG: I (3270) example: Got notify val 1 125Processed 13467 events 126=============== LOG TRACE REPORT =============== 127Processed 600 log messages. 128=============== HEAP TRACE REPORT =============== 129Processed 612 heap events. 130[0.002272225] HEAP: Allocated 8 bytes @ 0x3ffaff6c from task "main" on core 0 by: 131/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 132/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 133 134[0.002307300] HEAP: Allocated 2500 bytes @ 0x3ffb580c from task "main" on core 0 by: 135/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 136/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) 137 138[0.002323775] HEAP: Allocated 356 bytes @ 0x3ffb61d4 from task "main" on core 0 by: 139/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 140/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) 141 142[0.002427700] HEAP: Allocated 120 bytes @ 0x3ffaff78 from task "alloc0" on core 0 by: 143/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 144/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 145 146[0.002471225] HEAP: Allocated 2500 bytes @ 0x3ffb633c from task "alloc0" on core 0 by: 147/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 148/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 149 150[0.002487725] HEAP: Allocated 356 bytes @ 0x3ffb6d04 from task "alloc0" on core 0 by: 151/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 152/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 153 154[0.003102175] HEAP: Allocated 8 bytes @ 0x3ffb6e6c from task "main" on core 0 by: 155/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:85 156/home/user/projects/esp/esp-idf/components/esp32/cpu_start.c:570 157 158.... 159 160[0.003713175] HEAP: Allocated 356 bytes @ 0x3ffb8f28 from task "main" on core 0 by: 161/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 162/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:84 (discriminator 2) 163 164[0.003814375] HEAP: Allocated 120 bytes @ 0x3ffb9090 from task "alloc2" on core 0 by: 165/home/user/projects/esp/esp-idf/components/freertos/queue.c:391 166/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:46 167 168[0.003845875] HEAP: Allocated 2500 bytes @ 0x3ffb910c from task "alloc2" on core 0 by: 169/home/user/projects/esp/esp-idf/components/freertos/tasks.c:804 170/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 171 172[0.003862350] HEAP: Allocated 356 bytes @ 0x3ffb9ad4 from task "alloc2" on core 0 by: 173/home/user/projects/esp/esp-idf/components/freertos/tasks.c:809 174/home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/build/../main/sysview_heap_log.c:55 175 176Found 17520 leaked bytes in 18 blocks. 177``` 178
