Skip to content

Commit

Permalink
Merge branch 'change/sysview_test_config_v5.4' into 'release/v5.4'
Browse files Browse the repository at this point in the history
change(sysview): run heap_log tracing tests on existing cores (v5.4)

See merge request espressif/esp-idf!35195
  • Loading branch information
gerekon committed Nov 27, 2024
2 parents 315b1ec + e5d377b commit c2ae806
Show file tree
Hide file tree
Showing 22 changed files with 37,521 additions and 256,337 deletions.
2 changes: 1 addition & 1 deletion components/app_trace/sys_view/ext/heap_trace_module.c
Original file line number Diff line number Diff line change
Expand Up @@ -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,
};

Expand Down
14 changes: 13 additions & 1 deletion examples/system/sysview_tracing_heap_log/README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down Expand Up @@ -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.
Expand Down
2 changes: 2 additions & 0 deletions examples/system/sysview_tracing_heap_log/gdbinit
Original file line number Diff line number Diff line change
Expand Up @@ -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

Expand Down
Original file line number Diff line number Diff line change
@@ -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
Expand All @@ -13,33 +13,42 @@
@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(
Expand Down
2 changes: 0 additions & 2 deletions examples/system/sysview_tracing_heap_log/sdkconfig.defaults
Original file line number Diff line number Diff line change
@@ -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
Expand Down
30 changes: 15 additions & 15 deletions tools/esp_app_trace/espytrace/sysview.py
Original file line number Diff line number Diff line change
@@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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:
Expand All @@ -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
Expand Down Expand Up @@ -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):
Expand All @@ -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
Expand All @@ -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)

Expand All @@ -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)
Expand All @@ -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 = ''
Expand Down Expand Up @@ -411,7 +411,7 @@ def decode(self, reader, max_sz):
Returns
-------
tuple
a tuple containg number of read bytes and decoded value.
a tuple containing number of read bytes and decoded value.
"""
pass

Expand Down Expand Up @@ -900,7 +900,7 @@ def __init__(self, traces, root_proc=None, print_events=False, keep_all_events=F
# 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):
Expand Down Expand Up @@ -963,13 +963,13 @@ def get_trace_stream(self, core_id, stream_id):

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

Expand Down Expand Up @@ -1263,7 +1263,7 @@ def on_new_event(self, event):
"""
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


Expand Down
66 changes: 66 additions & 0 deletions tools/esp_app_trace/test/sysview/README.md
Original file line number Diff line number Diff line change
@@ -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
```
88 changes: 0 additions & 88 deletions tools/esp_app_trace/test/sysview/blink.c

This file was deleted.

Binary file removed tools/esp_app_trace/test/sysview/cpu0.svdat
Binary file not shown.
Binary file removed tools/esp_app_trace/test/sysview/cpu1.svdat
Binary file not shown.
Loading

0 comments on commit c2ae806

Please sign in to comment.