From d2db2ef03c03a51b66c8c3c0a3ddb63f0b4bde7c Mon Sep 17 00:00:00 2001 From: Alexey Gerenkov Date: Wed, 12 Dec 2018 18:57:55 +0300 Subject: [PATCH] docs: Adds host-based heap tracing description --- docs/Doxyfile | 1 + docs/en/api-reference/system/app_trace.rst | 1 + docs/en/api-reference/system/heap_debug.rst | 175 +++++++++++++++++++- 3 files changed, 170 insertions(+), 7 deletions(-) diff --git a/docs/Doxyfile b/docs/Doxyfile index aa3096bad..17258901c 100644 --- a/docs/Doxyfile +++ b/docs/Doxyfile @@ -184,6 +184,7 @@ INPUT = \ ## Application Level Tracing - API Reference ## ../../components/app_trace/include/esp_app_trace.h \ + ../../components/app_trace/include/esp_sysview_trace.h \ ### Power management ../../components/esp_common/include/esp_pm.h \ ../../components/esp32/include/esp32/pm.h \ diff --git a/docs/en/api-reference/system/app_trace.rst b/docs/en/api-reference/system/app_trace.rst index 91860fb43..437d389e3 100644 --- a/docs/en/api-reference/system/app_trace.rst +++ b/docs/en/api-reference/system/app_trace.rst @@ -15,4 +15,5 @@ API Reference ------------- .. include:: /_build/inc/esp_app_trace.inc +.. include:: /_build/inc/esp_sysview_trace.inc diff --git a/docs/en/api-reference/system/heap_debug.rst b/docs/en/api-reference/system/heap_debug.rst index a6d4c2c50..2f0390706 100644 --- a/docs/en/api-reference/system/heap_debug.rst +++ b/docs/en/api-reference/system/heap_debug.rst @@ -122,11 +122,10 @@ Calls to :cpp:func:`heap_caps_check_integrity` may print errors relating to 0xFE Heap Tracing ------------ -Heap Tracing allows tracing of code which allocates/frees memory. +Heap Tracing allows tracing of code which allocates/frees memory. Two tracing modes are supported: -.. note:: - - Heap tracing "standalone" mode is currently implemented, meaning that tracing does not require any external hardware but uses internal memory to hold trace data. Heap tracing via JTAG trace port is also planned. +- Standalone. In this mode trace data are kept on-board, so the size of gathered information is limited by the buffer assigned for that purposes. Analysis is done by the on-board code. There are a couple of APIs available for accessing and dumping collected info. +- Host-based. This mode does not have the limitation of the standalone mode, because trace data are sent to the host over JTAG connection using app_trace library. Later on they can be analysed using special tools. Heap tracing can perform two functions: @@ -138,9 +137,13 @@ How To Diagnose Memory Leaks If you suspect a memory leak, the first step is to figure out which part of the program is leaking memory. Use the :cpp:func:`xPortGetFreeHeapSize`, :cpp:func:`heap_caps_get_free_size`, or :ref:`related functions ` to track memory use over the life of the application. Try to narrow the leak down to a single function or sequence of functions where free memory always decreases and never recovers. + +Standalone Mode ++++++++++++++++ + Once you've identified the code which you think is leaking: -- Under ``make menuconfig``, navigate to ``Component settings`` -> ``Heap Memory Debugging`` and set :ref:`CONFIG_HEAP_TRACING`. +- Under ``make menuconfig``, navigate to ``Component settings`` -> ``Heap Memory Debugging`` -> ``Heap tracing`` and select ``Standalone`` option (see :ref:`CONFIG_HEAP_TRACING_DEST`). - Call the function :cpp:func:`heap_trace_init_standalone` early in the program, to register a buffer which can be used to record the memory trace. - Call the function :cpp:func:`heap_trace_start` to begin recording all mallocs/frees in the system. Call this immediately before the piece of code which you suspect is leaking memory. - Call the function :cpp:func:`heap_trace_stop` to stop the trace once the suspect piece of code has finished executing. @@ -165,9 +168,9 @@ An example:: void some_function() { ESP_ERROR_CHECK( heap_trace_start(HEAP_TRACE_LEAKS) ); - + do_something_you_suspect_is_leaking(); - + ESP_ERROR_CHECK( heap_trace_stop() ); heap_trace_dump(); ... @@ -208,6 +211,164 @@ Finally, the total number of 'leaked' bytes (bytes allocated but not freed while A warning will be printed if the trace buffer was not large enough to hold all the allocations which happened. If you see this warning, consider either shortening the tracing period or increasing the number of records in the trace buffer. + +Host-Based Mode ++++++++++++++++ + +Once you've identified the code which you think is leaking: + +- Under ``make menuconfig``, navigate to ``Component settings`` -> ``Heap Memory Debugging`` -> ``Heap tracing`` and select ``Host-Based`` option (see :ref:`CONFIG_HEAP_TRACING_DEST`). +- Under ``make menuconfig``, navigate to ``Component settings`` -> ``Application Level Tracing`` -> ``Data Destination`` and select ``Trace memory``. +- Under ``make menuconfig``, navigate to ``Component settings`` -> ``Application Level Tracing`` -> ``FreeRTOS SystemView Tracing`` and check ``SystemView Tracing Enable``. +- Call the function :cpp:func:`heap_trace_init_tohost` early in the program, to initialize JTAG heap tracing module. +- Call the function :cpp:func:`heap_trace_start` to begin recording all mallocs/frees in the system. Call this immediately before the piece of code which you suspect is leaking memory. + In host-based mode argument to this function is ignored and heap tracing module behaves like ``HEAP_TRACE_ALL`` was passed: all allocations and deallocations are sent to the host. +- Call the function :cpp:func:`heap_trace_stop` to stop the trace once the suspect piece of code has finished executing. + +An example:: + + #include "esp_heap_trace.h" + + ... + + void app_main() + { + ... + ESP_ERROR_CHECK( heap_trace_init_tohost() ); + ... + } + + void some_function() + { + ESP_ERROR_CHECK( heap_trace_start(HEAP_TRACE_LEAKS) ); + + do_something_you_suspect_is_leaking(); + + ESP_ERROR_CHECK( heap_trace_stop() ); + ... + } + +To gather and analyse heap trace do the following on the host: + +1. Build the program and download it to the target as described in :doc:`Build and Flash `. + +2. Run OpenOCD (see :doc:`JTAG Debugging `). + +.. note:: + + In order to use this feature you need OpenOCD version `v0.10.0-esp32-20181105` or later. + +3. You can use GDB to start and/or stop tracing automatically. To do this you need to prepare special ``gdbinit`` file:: + + target remote :3333 + + mon reset halt + flushregs + + tb heap_trace_start + commands + mon esp32 sysview start file:///tmp/heap.svdat + c + end + + tb heap_trace_stop + commands + mon esp32 sysview stop + end + + c + +Using this file GDB will connect to the target, reset it, and start tracing when program hits breakpoint at :cpp:func:`heap_trace_start`. Trace data will be saved to ``/tmp/heap_log.svdat``. Tracing will be stopped when program hits breakpoint at :cpp:func:`heap_trace_stop`. + +4. Run GDB using the following command ``xtensa-esp32-elf-gdb -x gdbinit `` + +5. Quit GDB when program stops at :cpp:func:`heap_trace_stop`. Trace data are saved in ``/tmp/heap.svdat`` + +6. Run processing script ``$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py /tmp/heap_log.svdat `` + +The output from the heap trace will look something like this:: + + Parse trace from '/tmp/heap.svdat'... + Stop parsing trace. (Timeout 0.000000 sec while reading 1 bytes!) + Process events from '['/tmp/heap.svdat']'... + [0.002244575] HEAP: Allocated 1 bytes @ 0x3ffaffd8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.002258425] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.002563725] HEAP: Freed bytes @ 0x3ffaffe0 from task "free" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.002782950] HEAP: Freed bytes @ 0x3ffb40b8 from task "main" on core 0 by: + /home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 + /home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 + + [0.002798700] HEAP: Freed bytes @ 0x3ffb50bc from task "main" on core 0 by: + /home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 + /home/user/projects/esp/esp-idf/components/freertos/tasks.c:4590 + + [0.102436025] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.102449800] HEAP: Allocated 4 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.102666150] HEAP: Freed bytes @ 0x3ffaffe8 from task "free" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.202436200] HEAP: Allocated 3 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.202451725] HEAP: Allocated 6 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.202667075] HEAP: Freed bytes @ 0x3ffafff0 from task "free" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.302436000] HEAP: Allocated 4 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.302451475] HEAP: Allocated 8 bytes @ 0x3ffb40b8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:48 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.302667500] HEAP: Freed bytes @ 0x3ffb40b8 from task "free" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:31 (discriminator 9) + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + Processing completed. + Processed 1019 events + =============== HEAP TRACE REPORT =============== + Processed 14 heap events. + [0.002244575] HEAP: Allocated 1 bytes @ 0x3ffaffd8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.102436025] HEAP: Allocated 2 bytes @ 0x3ffaffe0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.202436200] HEAP: Allocated 3 bytes @ 0x3ffaffe8 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + [0.302436000] HEAP: Allocated 4 bytes @ 0x3ffafff0 from task "alloc" on core 0 by: + /home/user/projects/esp/esp-idf/examples/system/sysview_tracing_heap_log/main/sysview_heap_log.c:47 + /home/user/projects/esp/esp-idf/components/freertos/port.c:355 (discriminator 1) + + Found 10 leaked bytes in 4 blocks. + Heap Tracing To Find Heap Corruption ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^