Merge branch 'change/sysview_test_config_v5.4' into 'release/v5.4'

change(sysview): run heap_log tracing tests on existing cores (v5.4)

See merge request espressif/esp-idf!35195

components/app_trace/sys_view/ext/heap_trace_module.c

@@ -21,7 +21,7 @@ const static char *TAG = "sysview_heap_trace";
 #endif
 
 static SEGGER_SYSVIEW_MODULE s_esp_sysview_heap_module = {
-    .sModule = "ESP32 SystemView Heap Tracing Module",
+    .sModule = "M=ESP32 SystemView Heap Tracing Module",
     .NumEvents = 2,
 };
 

examples/system/sysview_tracing_heap_log/README.md

@@ -18,7 +18,15 @@ This example requires the following tools:
 NOTE: In order to run this example you need OpenOCD version `v0.10.0-esp32-20190313` or later.
 
 2. [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.
-when 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`.
+
+    The gdbinit file includes commands to start tracing:
+    ```
+    mon esp sysview start file:///tmp/heap_log.svdat
+    # For dual-core mode uncomment the line below and comment the line above
+    # mon esp sysview start file:///tmp/heap_log0.svdat file:///tmp/heap_log1.svdat
+    ```
+    When program hits breakpoint at `heap_trace_start`, in single core mode, trace data will be saved to `/tmp/heap_log.svdat`. In dual core mode, there will be two trace data files, one for each core. `/tmp/heap_log0.svdat` and `/tmp/heap_log1.svdat`
+    Tracing will be stopped when program hits breakpoint at `heap_trace_stop`.
 
 3. [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.
 
@@ -59,6 +67,10 @@ Since SystemView tool is mostly intended for OS level analysis. It allows just t
 ```
 $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p -b build/sysview_tracing_heap_log.elf /tmp/heap_log.svdat
 ```
+And in dual core mode
+```
+$IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -p -b build/sysview_tracing_heap_log.elf /tmp/heap_log0.svdat /tmp/heap_log1.svdat
+```
 
 Below is the sample scripts output.
 

examples/system/sysview_tracing_heap_log/gdbinit

@@ -7,6 +7,8 @@ maintenance flush register-cache
 tb heap_trace_start
 commands
 mon esp sysview start file:///tmp/heap_log.svdat
+# For dual-core mode uncomment the line below and comment the line above
+# mon esp sysview start file:///tmp/heap_log0.svdat file:///tmp/heap_log1.svdat
 c
 end
 

examples/system/sysview_tracing_heap_log/pytest_sysview_tracing_heap_log.py

@@ -1,4 +1,4 @@
-# SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
+# SPDX-FileCopyrightText: 2022-2024 Espressif Systems (Shanghai) CO LTD
 # SPDX-License-Identifier: Unlicense OR CC0-1.0
 import os.path
 import time
@@ -13,33 +13,42 @@ from pytest_embedded_idf import IdfDut
 @pytest.mark.parametrize('config', ['app_trace_jtag'], indirect=True)
 @pytest.mark.parametrize('embedded_services', ['esp,idf,jtag'], indirect=True)
 def test_examples_sysview_tracing_heap_log(idf_path: str, dut: IdfDut) -> None:
-    trace_log = os.path.join(os.path.dirname(dut.gdb._logfile), 'heap_log.svdat')  # pylint: disable=protected-access
+    # Construct trace log paths
+    trace_log = [
+        os.path.join(os.path.dirname(dut.gdb._logfile), 'heap_log0.svdat')  # pylint: disable=protected-access
+    ]
+    if dut.target in ['esp32', 'esp32s3', 'esp32p4']:
+        trace_log.append(os.path.join(os.path.dirname(dut.gdb._logfile), 'heap_log1.svdat'))  # pylint: disable=protected-access
 
+    # Set up GDB
     dut.gdb.write('set width unlimited')  # Don't split output lines for easy parsing
     dut.gdb.write('mon reset halt')
     dut.gdb.write('maintenance flush register-cache')
 
+    # Start sysview tracing
     dut.gdb.write('tb heap_trace_start')
     dut.gdb.write('commands', non_blocking=True)
-    dut.gdb.write(f'mon esp sysview start file://{trace_log}', non_blocking=True)
+    trace_files = ' '.join([f'file://{log}' for log in trace_log])
+    dut.gdb.write(f'mon esp sysview start {trace_files}', non_blocking=True)
     dut.gdb.write('c', non_blocking=True)
     dut.gdb.write('end')
 
+    # Stop sysview tracing
     dut.gdb.write('tb heap_trace_stop')
     dut.gdb.write('commands', non_blocking=True)
     dut.gdb.write('mon esp sysview stop', non_blocking=True)
     dut.gdb.write('end')
-
     dut.gdb.write('c', non_blocking=True)
-    dut.expect('esp_apptrace: Initialized TRAX on CPU0')
 
-    time.sleep(1)  # make sure that the sysview file has been generated
-    with pexpect.spawn(' '.join([os.path.join(idf_path, 'tools', 'esp_app_trace', 'sysviewtrace_proc.py'),
-                                 '-p',
-                                 '-b', dut.app.elf_file,
-                                 trace_log])) as sysviewtrace:
+    # Wait for sysview files to be generated
+    time.sleep(1)
+
+    # Process sysview trace logs
+    command = [os.path.join(idf_path, 'tools', 'esp_app_trace', 'sysviewtrace_proc.py'), '-p'] + trace_log
+    with pexpect.spawn(' '.join(command)) as sysviewtrace:
         sysviewtrace.expect(r'Found \d+ leaked bytes in \d+ blocks.', timeout=120)
 
+    # Validate GDB logs
     with open(dut.gdb._logfile) as fr:  # pylint: disable=protected-access
         gdb_pexpect_proc = pexpect.fdpexpect.fdspawn(fr.fileno())
         gdb_pexpect_proc.expect_exact(

examples/system/sysview_tracing_heap_log/sdkconfig.defaults

@@ -1,5 +1,3 @@
-# Enable single core mode by default
-CONFIG_FREERTOS_UNICORE=y
 # 1ms tick period
 CONFIG_FREERTOS_HZ=1000
 # Enable application tracing by default

tools/esp_app_trace/espytrace/sysview.py

@@ -1,4 +1,4 @@
-# SPDX-FileCopyrightText: 2022-2023 Espressif Systems (Shanghai) CO LTD
+# SPDX-FileCopyrightText: 2022-2024 Espressif Systems (Shanghai) CO LTD
 # SPDX-License-Identifier: Apache-2.0
 import copy
 import json
@@ -87,7 +87,7 @@ def parse_trace(reader, parser, os_evt_map_file=''):
     parser : SysViewTraceDataParser
         Top level parser object.
     os_evt_map_file : string
-        Path to file containg events format description.
+        Path to file containing events format description.
     """
     global _os_events_map
     # parse OS events formats file
@@ -106,12 +106,12 @@ def _read_events_map(os_evt_map_file):
     Parameters
     ----------
     os_evt_map_file : string
-        Path to file containg events format description.
+        Path to file containing events format description.
 
     Returns
     -------
     dict
-        a dict with event IDs as keys and values as tuples containg event name and a list of parameters.
+        a dict with event IDs as keys and values as tuples containing event name and a list of parameters.
     """
     os_evt_map = {}
     with open(os_evt_map_file) as f:
@@ -130,7 +130,7 @@ def _read_events_map(os_evt_map_file):
                     elif sp[1] == 's':
                         params.append(SysViewEventParamSimple(sp[0], _decode_str))
                     elif sp[1] == 't' or sp[1] == 'T' or sp[1] == 'I' or sp[1] == 'p':
-                        # TODO: handle shrinked task/queue ID and addresses
+                        # TODO: handle shrunk task/queue ID and addresses
                         params.append(SysViewEventParamSimple(sp[0], _decode_u32))
             os_evt_map[int(comps[0])] = (comps[1], params)
     return os_evt_map
@@ -177,7 +177,7 @@ def _read_init_seq(reader):
     sync_bytes = struct.unpack(SYNC_SEQ_FMT, reader.read(struct.calcsize(SYNC_SEQ_FMT)))
     for b in sync_bytes:
         if b != 0:
-            raise SysViewTraceParseError('Invalid sync sequense!')
+            raise SysViewTraceParseError('Invalid sync sequence!')
 
 
 def _decode_u32(reader):
@@ -192,7 +192,7 @@ def _decode_u32(reader):
     Returns
     -------
     tuple
-        a tuple containg number of read bytes and decoded value.
+        a tuple containing number of read bytes and decoded value.
     """
     sz = 0
     val = 0
@@ -219,7 +219,7 @@ def _decode_id(reader):
     Returns
     -------
     tuple
-        a tuple containg number of read bytes and decoded value.
+        a tuple containing number of read bytes and decoded value.
     """
     return _decode_u32(reader)
 
@@ -236,7 +236,7 @@ def _decode_u64(reader):
     Returns
     -------
     tuple
-        a tuple containg number of read bytes and decoded value.
+        a tuple containing number of read bytes and decoded value.
     """
     sz,val = _decode_u32(reader)
     sz2,high = _decode_u32(reader)
@@ -256,7 +256,7 @@ def _decode_str(reader):
     Returns
     -------
     tuple
-        a tuple containg number of read bytes and decoded value.
+        a tuple containing number of read bytes and decoded value.
     """
     sz = 0
     val = ''
@@ -411,7 +411,7 @@ class SysViewEventParam:
             Returns
             -------
             tuple
-                a tuple containg number of read bytes and decoded value.
+                a tuple containing number of read bytes and decoded value.
         """
         pass
 
@@ -900,7 +900,7 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
             # empty list means IDLE context or self.start_ctx
             self.ctx_stack[t.core_id] = []
             # context is undefined, we do not know have we started the tracing in task/IDLE or IRQ context
-            # in general there are three scenarious when we can start tracing: when core is in task, IDLE task or IRQ context
+            # in general there are three scenarios when we can start tracing: when core is in task, IDLE task or IRQ context
             self.prev_ctx[t.core_id] = None
 
     def _get_curr_context(self, core_id):
@@ -963,13 +963,13 @@ class SysViewTraceDataProcessor(apptrace.TraceDataProcessor):
 
     def event_supported(self, e):
         """
-            Should be overriden in child class.
+            Should be overridden in child class.
         """
         return False
 
     def handle_event(self, e):
         """
-            Should be overriden in child class.
+            Should be overridden in child class.
         """
         pass
 
@@ -1263,7 +1263,7 @@ class SysViewHeapTraceDataParser(SysViewTraceDataExtEventParser):
         """
         if self.root_proc == self:
             SysViewTraceDataParser.on_new_event(self, event)
-        if event.id == SYSVIEW_EVTID_MODULEDESC and event.params['desc'].value == 'ESP32 SystemView Heap Tracing Module':
+        if event.id == SYSVIEW_EVTID_MODULEDESC and event.params['desc'].value == 'M=ESP32 SystemView Heap Tracing Module':
             self.events_off = event.params['evt_off'].value
 
 

tools/esp_app_trace/test/sysview/README.md

@@ -0,0 +1,66 @@
+# Steps to Generate Test Input Files
+
+1. `sysview_tracing_heap_log.elf`
+
+    Build example `sysview_tracing_heap_log` project.
+
+    ```
+    cd $IDF_PATH/examples/system/sysview_tracing_heap_log
+    idf.py set target esp32
+    idf.py build
+    cp build/sysview_tracing_heap_log.elf $IDF_PATH/tools/esp_app_trace/test/sysview/
+    cd $IDF_PATH/tools/esp_app_trace/test/sysview/
+    chmod -x sysview_tracing_heap_log.elf
+    ```
+
+2. `heap_log0.svdat` and `heap_log1.svdat`
+
+    Flash the example and run OpenOCD and GDB using the following command in a separate console
+
+    ```
+    cd $IDF_PATH/examples/system/sysview_tracing_heap_log
+    idf.py openocd
+    ```
+
+    ```
+    cd $IDF_PATH/examples/system/sysview_tracing_heap_log
+    xtensa-esp32-elf-gdb -x gdbinit build/sysview_tracing_heap_log.elf
+    ```
+    When program stops at `heap_trace_stop`  quit GDB and OpenOCD
+
+    Copy generated svdat files
+    ```
+    cp heap_log0.svdat $IDF_PATH/tools/esp_app_trace/test/sysview/
+    cp heap_log1.svdat $IDF_PATH/tools/esp_app_trace/test/sysview/
+    ```
+
+3. `heap_log_mcore.svdat`
+
+    Flash the example and run OpenOCD and GDB using the following command in a separate console
+
+    ```
+    cd $IDF_PATH/examples/system/sysview_tracing_heap_log
+    idf.py openocd
+    ```
+
+    ```
+    cd $IDF_PATH/examples/system/sysview_tracing_heap_log
+    xtensa-esp32-elf-gdb -x gdbinit-mcore build/sysview_tracing_heap_log.elf
+    ```
+    When program stops at `heap_trace_stop`  quit GDB and OpenOCD
+
+    Copy generated svdat file
+    ```
+    cp heap_log_mcore.svdat $IDF_PATH/tools/esp_app_trace/test/sysview/
+    ```
+
+4. `expected_output` and `expected_output_json` files
+
+    You can use the commands from the `test.sh` to generate expected result files
+
+    ```
+    $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p -b sysview_tracing_heap_log.elf heap_log0.svdat heap_log1.svdat &> expected_output
+    $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -j -b sysview_tracing_heap_log.elf heap_log0.svdat heap_log1.svdat &> expected_output.json
+    $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p -b sysview_tracing_heap_log.elf heap_log_mcore.svdat &> expected_output_mcore
+    $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -j -b sysview_tracing_heap_log.elf heap_log_mcore.svdat &> expected_output_mcore.json
+    ```

tools/esp_app_trace/test/sysview/blink.c

@@ -1,88 +0,0 @@
-/* Blink Example
-
-   This example code is in the Public Domain (or CC0 licensed, at your option.)
-
-   Unless required by applicable law or agreed to in writing, this
-   software is distributed on an "AS IS" BASIS, WITHOUT WARRANTIES OR
-   CONDITIONS OF ANY KIND, either express or implied.
-*/
-#include <stdio.h>
-#include "freertos/FreeRTOS.h"
-#include "freertos/task.h"
-#include "driver/gpio.h"
-#include "sdkconfig.h"
-#include "esp_heap_trace.h"
-
-/* Can use project configuration menu (idf.py menuconfig) to choose the GPIO
-   to blink or you can edit the following line and set a number here.
-*/
-#define BLINK_GPIO CONFIG_BLINK_GPIO
-
-void blink_task2(void *pvParameter)
-{
-    TaskHandle_t task = (TaskHandle_t)pvParameter;
-
-    while(1) {
-        if (xTaskNotifyWait(0, 0, NULL, portMAX_DELAY) != pdPASS) {
-            printf("Failed to wait for main task!\n");
-            return;
-        }
-        void *a = malloc(65);
-        printf("Alloced 65 bytes @ %p\n", a);
-        void *b = malloc(97);
-        printf("Alloced 97 bytes @ %p\n", b);
-        free(a);
-        printf("Freed @ %p\n", a);
-        b = malloc(11);
-        printf("Alloced 11 bytes @ %p\n", b);
-        b = malloc(24);
-        printf("Alloced 24 bytes @ %p\n", b);
-        free(b);
-        printf("Freed @ %p\n", b);
-        if (xTaskNotify(task, 0, eNoAction) != pdPASS) {
-            printf("Failed to notify main task!\n");
-            return;
-        }
-    }
-}
-
-void blink_task(void *pvParameter)
-{
-    TaskHandle_t task = 0;
-
-    if(heap_trace_init_tohost() != ESP_OK) {
-        printf("Failed to init heap trace!\n");
-        return;
-    }
-    xTaskCreatePinnedToCore(&blink_task2, "blink_task2", 2048, xTaskGetCurrentTaskHandle(), 5, &task, 1);
-
-    while(1) {
-        heap_trace_start(HEAP_TRACE_ALL);
-        if (xTaskNotify(task, 0, eNoAction) != pdPASS) {
-            printf("Failed to notify slave task!\n");
-            return;
-        }
-        void *a = malloc(64);
-        printf("Alloced 64 bytes @ %p\n", a);
-        void *b = malloc(96);
-        printf("Alloced 96 bytes @ %p\n", b);
-        free(a);
-        printf("Freed @ %p\n", a);
-        b = malloc(10);
-        printf("Alloced 10 bytes @ %p\n", b);
-        b = malloc(23);
-        printf("Alloced 23 bytes @ %p\n", b);
-        free(b);
-        printf("Freed @ %p\n", b);
-        if (xTaskNotifyWait(0, 0, NULL, portMAX_DELAY) != pdPASS) {
-            printf("Failed to wait for slave task!\n");
-            return;
-        }
-        heap_trace_stop();
-    }
-}
-
-void app_main(void)
-{
-    xTaskCreatePinnedToCore(&blink_task, "blink_task", 2048, NULL, 5, NULL, 0);
-}

tools/esp_app_trace/test/sysview/gdbinit

@@ -6,14 +6,14 @@ maintenance flush register-cache
 b heap_trace_start
 commands
 clear heap_trace_start
-mon esp32 sysview start file://cpu0.svdat file://cpu1.svdat
+mon esp sysview start file://heap_log0.svdat file://heap_log1.svdat
 c
 end
 
 b heap_trace_stop
 commands
 clear heap_trace_stop
-mon esp32 sysview stop
+mon esp sysview stop
 end
 
 c

tools/esp_app_trace/test/sysview/gdbinit-mcore

@@ -0,0 +1,19 @@
+target remote :3333
+
+mon reset halt
+maintenance flush register-cache
+
+b heap_trace_start
+commands
+clear heap_trace_start
+mon esp sysview_mcore start file://heap_log_mcore.svdat
+c
+end
+
+b heap_trace_stop
+commands
+clear heap_trace_stop
+mon esp sysview_mcore stop
+end
+
+c

tools/esp_app_trace/test/sysview/test.sh

@@ -2,14 +2,14 @@
 
 { python -m coverage debug sys \
     && python -m coverage erase &> output \
-    && python -m coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p -b test.elf cpu0.svdat cpu1.svdat &>> output \
+    && python -m coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -d -p -b sysview_tracing_heap_log.elf heap_log0.svdat heap_log1.svdat &>> output \
     && diff output expected_output \
     && python -m coverage report \
 ; } || { echo 'The test for sysviewtrace_proc has failed. Please examine the artifacts.' ; exit 1; }
 
 { python -m coverage debug sys \
     && python -m coverage erase &> output.json \
-    && python -m coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -j -b test.elf cpu0.svdat cpu1.svdat &>> output.json \
+    && python -m coverage run -a $IDF_PATH/tools/esp_app_trace/sysviewtrace_proc.py -j -b sysview_tracing_heap_log.elf heap_log0.svdat heap_log1.svdat &>> output.json \
     && diff output.json expected_output.json \
     && python -m coverage report \
 ; } || { echo 'The test for sysviewtrace_proc JSON functionality has failed. Please examine the artifacts.' ; exit 1; }