Merge branch 'sysview_test_fixes_v6.0' into 'release/v6.0'

Sysview test fixes v6.0

See merge request espressif/esp-idf!50729
This commit is contained in:
Alexey Gerenkov
2026-07-20 18:45:30 +08:00
9 changed files with 114 additions and 48 deletions

View File

@@ -41,19 +41,40 @@
static const char *TAG = "usj_transport";
/*
* USB CDC IN transfers finish with a short packet. A 64-byte USJ packet fills
* the endpoint, so the host may keep the transfer open until it receives another
* packet shorter than 64 bytes. If no later short packet is sent, flush must send
* a ZLP (zero-length packet) to finish the transfer.
*
* See usb_serial_jtag_ll_txfifo_flush() for the USJ FIFO/full-packet behavior.
*/
typedef enum {
USJ_TX_IDLE,
USJ_TX_SHORT_PENDING,
USJ_TX_ZLP_PENDING,
} usj_tx_state_t;
/* Transport context */
typedef struct {
int inited; ///< Initialization flag (bitmask per core)
esp_trace_rb_t tx_ring; ///< TX ring buffer
esp_trace_rb_t rx_ring; ///< RX ring buffer
usj_tx_state_t tx_state; ///< Pending TX packet finalization state
/* Flush configuration */
uint32_t flush_tmo; ///< Flush timeout in microseconds
uint32_t flush_thresh; ///< Flush threshold in bytes
} usj_ctx_t;
#define USJ_FLUSH_TIMEOUT_US (1000000) // 1 second
#define USJ_FLUSH_THRESH_BYTES (0) // 0 bytes
/*
* flush_nolock() runs with interrupts masked, so normal flushes use a short
* fixed timeout even if an encoder requests a longer one.
*/
#define USJ_FLUSH_TIMEOUT_US (1000) // 1 ms
#define USJ_FLUSH_THRESH_BYTES (0) // 0 bytes
#define USJ_FLUSH_MAX_INTR_MASKED_US (2000) // 2 ms
#define USJ_FLUSH_POLL_STEP_US (100) // delay between no-progress polls
/* USB Serial JTAG hardware FIFO size (RX and TX) is 64 bytes (USB FS bulk endpoint max packet size) */
#define USJ_HW_FIFO_SIZE (64)
@@ -76,12 +97,32 @@ static uint32_t usj_write_fifo(usj_ctx_t *ctx, esp_trace_rb_t *rb)
uint32_t written = usb_serial_jtag_ll_write_txfifo(ptr, to_send);
esp_trace_rb_consume(rb, written);
/* Flush to send data or zero-byte packet to end USB transfer */
usb_serial_jtag_ll_txfifo_flush();
ctx->tx_state = usb_serial_jtag_ll_txfifo_writable() ? USJ_TX_SHORT_PENDING : USJ_TX_ZLP_PENDING;
return written;
}
static uint32_t usj_fill_txfifo(usj_ctx_t *ctx, bool commit_short)
{
esp_trace_rb_t *rb = &ctx->tx_ring;
uint32_t total_written = 0;
while (esp_trace_rb_data_len(rb) > 0 && usb_serial_jtag_ll_txfifo_writable()) {
uint32_t written = usj_write_fifo(ctx, rb);
if (written == 0) {
break;
}
total_written += written;
}
if (commit_short && ctx->tx_state == USJ_TX_SHORT_PENDING) {
usb_serial_jtag_ll_txfifo_flush();
ctx->tx_state = USJ_TX_IDLE;
}
return total_written;
}
static void usj_read_rx_fifo(usj_ctx_t *ctx)
{
uint8_t tmp[USJ_HW_FIFO_SIZE];
@@ -229,12 +270,8 @@ static esp_err_t usj_write(esp_trace_transport_t *tp, const void *data, size_t s
/* Add data to TX ring buffer */
esp_trace_rb_put(rb, (const uint8_t *)data, size);
/* Try to flush some data to HW FIFO immediately (non-blocking) */
while (esp_trace_rb_data_len(rb) > 0) {
if (usj_write_fifo(ctx, rb) == 0) {
break; /* FIFO full, will be drained on next write or flush */
}
}
/* Try to move data to HW FIFO immediately, without forcing a short packet. */
usj_fill_txfifo(ctx, false);
return ESP_OK;
}
@@ -250,31 +287,48 @@ static esp_err_t usj_down_buffer_config(esp_trace_transport_t *tp, uint8_t *buf,
return ESP_OK;
}
static esp_err_t usj_flush_nolock(esp_trace_transport_t *tp)
static esp_err_t usj_flush_with_timeout(usj_ctx_t *ctx, uint32_t tmo_us)
{
usj_ctx_t *ctx = (usj_ctx_t *)tp->ctx;
esp_trace_rb_t *rb = &ctx->tx_ring;
uint32_t pending = esp_trace_rb_data_len(rb);
if (pending < ctx->flush_thresh) {
if (pending < ctx->flush_thresh && ctx->tx_state == USJ_TX_IDLE) {
return ESP_OK;
}
esp_trace_tmo_t timeout;
esp_trace_tmo_init(&timeout, ctx->flush_tmo);
esp_trace_tmo_init(&timeout, tmo_us);
/* Drain ring buffer to HW FIFO */
while (esp_trace_rb_data_len(rb) > 0) {
usj_write_fifo(ctx, rb);
if (esp_trace_tmo_check(&timeout) != ESP_OK) {
return ESP_ERR_TIMEOUT;
while (esp_trace_rb_data_len(rb) > 0 || ctx->tx_state != USJ_TX_IDLE) {
uint32_t written = usj_fill_txfifo(ctx, true);
if (ctx->tx_state == USJ_TX_ZLP_PENDING && usb_serial_jtag_ll_txfifo_writable()) {
usb_serial_jtag_ll_txfifo_flush();
ctx->tx_state = USJ_TX_IDLE;
continue;
}
if (written == 0) {
if (esp_trace_tmo_check(&timeout) != ESP_OK) {
return ESP_ERR_TIMEOUT;
}
esp_rom_delay_us(USJ_FLUSH_POLL_STEP_US);
}
esp_rom_delay_us(100);
}
return ESP_OK;
}
static esp_err_t usj_flush_nolock(esp_trace_transport_t *tp)
{
usj_ctx_t *ctx = (usj_ctx_t *)tp->ctx;
/* Interrupts are masked here, so never spin longer than the int_wdt-safe limit. */
uint32_t tmo = (ctx->flush_tmo < USJ_FLUSH_MAX_INTR_MASKED_US)
? ctx->flush_tmo : USJ_FLUSH_MAX_INTR_MASKED_US;
return usj_flush_with_timeout(ctx, tmo);
}
static bool usj_is_host_connected(esp_trace_transport_t *tp)
{
(void)tp;
@@ -341,7 +395,8 @@ static esp_err_t usj_get_config(esp_trace_transport_t *tp, esp_trace_transport_c
static void usj_panic_handler(esp_trace_transport_t *tp, const void *info)
{
(void)info;
usj_flush_nolock(tp);
usj_ctx_t *ctx = (usj_ctx_t *)tp->ctx;
usj_flush_with_timeout(ctx, ctx->flush_tmo);
}
/* ----------------------- Transport Registration ----------------------- */

View File

@@ -57,6 +57,7 @@ def test_examples_app_trace_basic(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
@idf_parametrize(
'target', ['esp32s3', 'esp32c3', 'esp32c5', 'esp32c6', 'esp32c61', 'esp32h2', 'esp32p4'], indirect=['target']
)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_examples_app_trace_basic_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
_test_examples_app_trace_basic(openocd_dut, dut)

View File

@@ -102,6 +102,7 @@ def _capture_trace(ser: serial.Serial, trace_log_path: str, capture_s: float = 5
@pytest.mark.usb_serial_jtag
@idf_parametrize('target', soc_filtered_targets('SOC_USB_SERIAL_JTAG_SUPPORTED == 1'), indirect=['target'])
@pytest.mark.parametrize('config', [pytest.param('default')], indirect=True)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
@pytest.mark.temp_skip_ci(targets=['esp32h4'], reason='lack of runner # TODO: IDFCI-10703')
def test_esp_trace_ext_lib_usj(dut: IdfDut) -> None:
dut.expect('Start of trace session', timeout=5)

View File

@@ -83,5 +83,6 @@ def test_gcov(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
@idf_parametrize(
'target', ['esp32s3', 'esp32c3', 'esp32c5', 'esp32c6', 'esp32c61', 'esp32h2', 'esp32p4'], indirect=['target']
)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_gcov_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
_test_gcov(openocd_dut, dut)

View File

@@ -45,19 +45,11 @@ static const char *TAG = "example";
#define SYSVIEW_EXAMPLE_WAIT_EVENT_START() example_sysview_event_send(SYSVIEW_EXAMPLE_WAIT_EVENT_START_ID, 0)
#define SYSVIEW_EXAMPLE_WAIT_EVENT_END(_val_) example_sysview_event_send(SYSVIEW_EXAMPLE_WAIT_EVENT_END_ID, _val_)
static void example_sysview_module_send_desc(void);
static SEGGER_SYSVIEW_MODULE s_example_sysview_module = {
.sModule = "example_sysview_module",
.sModule = "M=Example SystemView User Module",
.NumEvents = SYSVIEW_EXAMPLE_EVENT_MAX,
.pfSendModuleDesc = example_sysview_module_send_desc,
};
static void example_sysview_module_send_desc(void)
{
SEGGER_SYSVIEW_RecordModuleDescription(&s_example_sysview_module, "Example SystemView User Module");
}
static void example_sysview_event_send(uint32_t id, uint32_t val)
{
U8 aPacket[SEGGER_SYSVIEW_INFO_SIZE + SEGGER_SYSVIEW_QUANTA_U32];

View File

@@ -31,13 +31,16 @@ def _validate_trace_data(trace_log: list[str], target: str, is_uart: bool = Fals
content = f.read()
search_str = f'N=FreeRTOS Application,D={target},C=core{idx},O=FreeRTOS'.encode()
assert search_str in content, f'SysView trace data not found in {log}'
# For UART transport, validate STOP record at end of file
# TODO: Adapt this to JTAG as well.
if is_uart:
size = len(content)
assert size >= 2, 'Trace file too small to contain STOP record'
assert content[-2] == STOP_EVENT_ID, 'STOP record does not start with STOP eventID'
# The file must end with a TRACE_STOP record: the STOP event ID
# followed by a variable-length timestamp delta. Walk back
# over the trailing continuation bytes (0x80 bit set)
# to find the event ID, since its offset is not fixed.
size = len(content)
assert size >= 2, 'Trace file too small to contain STOP record'
i = size - 2
while i >= 0 and (content[i] & 0x80):
i -= 1
assert i >= 0 and content[i] == STOP_EVENT_ID, 'STOP record does not start with STOP eventID'
def _capture_sysview_trace(ser: serial.Serial, trace_log_path: str) -> None:
@@ -64,13 +67,13 @@ def _capture_sysview_trace(ser: serial.Serial, trace_log_path: str) -> None:
except serial.SerialTimeoutException:
assert False, 'Timeout reached while reading from serial port, exiting...'
# Wait some time to let data accumulate in target's ring buffer
# Give pending trace data a short window to reach the host before requesting STOP.
time.sleep(0.2)
# Send Stop command
ser.write(STOP_CMD)
# Capture until target flushed data or timeout (3 seconds)
# Capture the final data produced by STOP and the transport flush.
end_time = time.time() + 3.0
last_data_time = time.time()
while time.time() < end_time and (time.time() - last_data_time) <= 1.0:
@@ -125,6 +128,7 @@ def _test_sysview_tracing_jtag(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
# Do a sleep while sysview samples are captured.
time.sleep(3)
openocd.write('esp sysview stop')
openocd.apptrace_wait_stop()
_validate_trace_data(trace_log, dut.target)
@@ -141,6 +145,7 @@ def test_sysview_tracing_jtag(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
@idf_parametrize(
'target', ['esp32s3', 'esp32c3', 'esp32c5', 'esp32c6', 'esp32c61', 'esp32h2', 'esp32p4'], indirect=['target']
)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_sysview_tracing_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
_test_sysview_tracing_jtag(openocd_dut, dut)
@@ -164,6 +169,7 @@ def test_sysview_tracing_uart(dut: IdfDut) -> None:
@pytest.mark.usb_serial_jtag
@idf_parametrize('target', soc_filtered_targets('SOC_USB_SERIAL_JTAG_SUPPORTED == 1'), indirect=['target'])
@pytest.mark.parametrize('config', [pytest.param('sysview_usj')], indirect=True)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_sysview_tracing_usj_serial(dut: IdfDut) -> None:
time.sleep(1) # wait for USJ port to be ready
usj_port = '/dev/serial_ports/ttyACM-esp32'

View File

@@ -77,5 +77,6 @@ def test_examples_sysview_tracing_heap_log(openocd_dut: 'OpenOCD', idf_path: str
@idf_parametrize(
'target', ['esp32s3', 'esp32c3', 'esp32c5', 'esp32c6', 'esp32c61', 'esp32h2', 'esp32p4'], indirect=['target']
)
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_examples_sysview_tracing_heap_log_usj(openocd_dut: 'OpenOCD', idf_path: str, dut: IdfDut) -> None:
_test_examples_sysview_tracing_heap_log(openocd_dut, idf_path, dut)

View File

@@ -13,8 +13,9 @@ if typing.TYPE_CHECKING:
from conftest import OpenOCD
@idf_parametrize('target', ['esp32c5', 'esp32c6', 'esp32p4'], indirect=['target'])
@pytest.mark.usb_serial_jtag
@idf_parametrize('target', ['esp32c5', 'esp32c6', 'esp32p4'], indirect=['target'])
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_lp_core_debugging(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
dut.expect('Do some work on HP core...')

View File

@@ -1,7 +1,8 @@
# SPDX-FileCopyrightText: 2022-2025 Espressif Systems (Shanghai) CO LTD
# SPDX-FileCopyrightText: 2022-2026 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Unlicense OR CC0-1.0
import os
import re
import time
import typing
import pexpect
@@ -21,13 +22,19 @@ def _test_idf_gdb(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
# Don't need to have output from UART anymore
dut.serial.stop_redirect_thread()
with openocd_dut.run(), open(os.path.join(dut.logdir, 'gdb.txt'), 'w') as gdb_log, pexpect.spawn(
f'idf.py -B {dut.app.binary_path} gdb --batch',
timeout=60,
logfile=gdb_log,
encoding='utf-8',
codec_errors='ignore',
) as p:
time.sleep(1) # Wait for the USJ port to be ready
with (
openocd_dut.run(),
open(os.path.join(dut.logdir, 'gdb.txt'), 'w') as gdb_log,
pexpect.spawn(
f'idf.py -B {dut.app.binary_path} gdb --batch',
timeout=60,
logfile=gdb_log,
encoding='utf-8',
codec_errors='ignore',
) as p,
):
p.expect(re.compile(r'add symbol table from file.*bootloader.elf'))
p.expect(
re.compile(r'add symbol table from file.*rom.elf')
@@ -43,5 +50,6 @@ def test_idf_gdb(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
@pytest.mark.usb_serial_jtag
@idf_parametrize('target', ['esp32s3', 'esp32c3', 'esp32c6', 'esp32h2'], indirect=['target'])
@idf_parametrize('port', ['/dev/serial_ports/ttyUSB-esp32'], indirect=['port'])
def test_idf_gdb_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
_test_idf_gdb(openocd_dut, dut)