fix(app_trace): implement uart TX without using ISR

This commit is contained in:
Erhan Kurubas
2026-02-02 13:37:52 +01:00
parent 12fdd20da1
commit 5cea09fbdc
7 changed files with 111 additions and 82 deletions

View File

@@ -1,5 +1,5 @@
/*
* SPDX-FileCopyrightText: 2017-2025 Espressif Systems (Shanghai) CO LTD
* SPDX-FileCopyrightText: 2017-2026 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Apache-2.0
*/
@@ -19,7 +19,6 @@
#include "soc/gpio_periph.h"
#include "esp_rom_gpio.h"
#include "hal/uart_ll.h"
#include "esp_intr_alloc.h"
#include "esp_heap_caps.h"
#include "esp_private/esp_clk_tree_common.h"
#include "esp_private/esp_gpio_reserve.h"
@@ -45,10 +44,8 @@ typedef struct {
typedef struct {
int inited;
volatile bool tx_busy; ///< TX busy flag
uart_hal_context_t hal_ctx; ///< UART HAL context
esp_apptrace_uart_rb_t tx_ring; ///< TX ring buffer
intr_handle_t intr_handle; ///< Interrupt handle
/* TX message buffer */
uint8_t *tx_msg_buff; ///< TX message buffer to provide with get_up_buffer
@@ -178,31 +175,6 @@ static esp_err_t ring_buffer_init(esp_apptrace_uart_rb_t *rb, uint32_t size)
return ESP_OK;
}
static void IRAM_ATTR esp_apptrace_uart_isr_handler(void *arg)
{
esp_apptrace_uart_data_t *uart_data = arg;
esp_apptrace_uart_rb_t *rb = &uart_data->tx_ring;
uint32_t intr_status = uart_hal_get_intsts_mask(&uart_data->hal_ctx);
if (intr_status & UART_INTR_TXFIFO_EMPTY) {
uart_hal_clr_intsts_mask(&uart_data->hal_ctx, UART_INTR_TXFIFO_EMPTY);
uint32_t to_send = ring_buffer_calc_to_send(rb, uart_data->tx_msg_buff_size);
if (to_send > 0) {
uint32_t written = 0;
uart_hal_write_txfifo(&uart_data->hal_ctx, &rb->buffer[rb->tail], to_send, &written);
ring_buffer_advance_tail(rb, written);
}
/* If ring buffer is empty, disable TX interrupt */
if (ring_buffer_data_len(rb) == 0) {
uart_ll_disable_intr_mask(uart_data->hal_ctx.dev, UART_INTR_TXFIFO_EMPTY);
uart_data->tx_busy = false;
}
}
}
static esp_err_t esp_apptrace_uart_init(void *hw_data, const esp_apptrace_config_t *config)
{
esp_err_t ret = ESP_ERR_INVALID_ARG;
@@ -294,15 +266,6 @@ static esp_err_t esp_apptrace_uart_init(void *hw_data, const esp_apptrace_config
uart_ll_disable_intr_mask(uart_data->hal_ctx.dev, UART_LL_INTR_MASK);
uart_ll_clr_intsts_mask(uart_data->hal_ctx.dev, UART_LL_INTR_MASK);
/* Install interrupt handler */
int intr_alloc_flags = 0;
ret = esp_intr_alloc(uart_periph_signal[uart_config->uart_num].irq, intr_alloc_flags,
esp_apptrace_uart_isr_handler, uart_data, &uart_data->intr_handle);
if (ret != ESP_OK) {
ESP_APPTRACE_LOGE("Failed to allocate interrupt: %s", esp_err_to_name(ret));
goto err_alloc_intr;
}
/* Reset FIFOs */
uart_hal_rxfifo_rst(&uart_data->hal_ctx);
uart_hal_txfifo_rst(&uart_data->hal_ctx);
@@ -328,12 +291,9 @@ static esp_err_t esp_apptrace_uart_init(void *hw_data, const esp_apptrace_config
}
uart_data->inited |= 1 << core_id;
uart_data->tx_busy = false;
return ESP_OK;
err_alloc_intr:
heap_caps_free(uart_data->tx_msg_buff);
err_alloc_msg_buff:
heap_caps_free(uart_data->tx_ring.buffer);
err_init_ring_buff:
@@ -373,6 +333,22 @@ static uint8_t *esp_apptrace_uart_up_buffer_get(void *hw_data, uint32_t size, es
return uart_data->tx_msg_buff;
}
static uint32_t esp_apptrace_uart_write_fifo(esp_apptrace_uart_data_t *uart_data, esp_apptrace_uart_rb_t *rb)
{
if (uart_ll_get_txfifo_len(uart_data->hal_ctx.dev) == 0) {
/* FIFO is full. No blocking. */
return 0;
}
uint32_t to_send = ring_buffer_calc_to_send(rb, 0);
if (to_send == 0) {
return 0;
}
uint32_t written = 0;
uart_hal_write_txfifo(&uart_data->hal_ctx, &rb->buffer[rb->tail], to_send, &written);
ring_buffer_advance_tail(rb, written);
return written;
}
static esp_err_t esp_apptrace_uart_up_buffer_put(void *hw_data, uint8_t *ptr, esp_apptrace_tmo_t *tmo)
{
esp_apptrace_uart_data_t *uart_data = hw_data;
@@ -387,16 +363,13 @@ static esp_err_t esp_apptrace_uart_up_buffer_put(void *hw_data, uint8_t *ptr, es
ring_buffer_put(rb, ptr, uart_data->tx_pending_msg_size);
uart_data->tx_pending_msg_size = 0;
esp_apptrace_uart_unlock(uart_data);
// Trigger transmission if not already in progress
if (!uart_data->tx_busy) {
uart_data->tx_busy = true;
/* Enable TX interrupt */
uart_ll_clr_intsts_mask(uart_data->hal_ctx.dev, UART_INTR_TXFIFO_EMPTY);
uart_ll_ena_intr_mask(uart_data->hal_ctx.dev, UART_INTR_TXFIFO_EMPTY);
/* Flush ring buffer to UART FIFO */
while (ring_buffer_data_len(rb) > 0 && esp_apptrace_uart_write_fifo(uart_data, rb) > 0) {
esp_rom_delay_us(100);
}
esp_apptrace_uart_unlock(uart_data);
return ESP_OK;
}
@@ -479,20 +452,22 @@ static esp_err_t esp_apptrace_uart_flush_nolock(void *hw_data, uint32_t min_sz,
return ESP_OK;
}
/* Trigger transmission if there's data but not busy */
if (pending > 0 && !uart_data->tx_busy) {
uart_data->tx_busy = true;
uart_ll_clr_intsts_mask(uart_data->hal_ctx.dev, UART_INTR_TXFIFO_EMPTY);
uart_ll_ena_intr_mask(uart_data->hal_ctx.dev, UART_INTR_TXFIFO_EMPTY);
}
while (uart_data->tx_busy || ring_buffer_data_len(rb) > 0) {
/* Flush ring buffer to HW FIFO */
while (ring_buffer_data_len(rb) > 0) {
esp_apptrace_uart_write_fifo(uart_data, rb);
if (esp_apptrace_tmo_check(tmo) != ESP_OK) {
return ESP_ERR_TIMEOUT;
}
esp_rom_delay_us(100);
}
/* Wait until all data is flushed */
while (uart_ll_get_txfifo_len(uart_data->hal_ctx.dev) < SOC_UART_FIFO_LEN) {
if (esp_apptrace_tmo_check(tmo) != ESP_OK) {
return ESP_ERR_TIMEOUT;
}
esp_rom_delay_us(100);
}
return ESP_OK;
}

View File

@@ -8,6 +8,9 @@ examples/system/app_trace_basic:
- if: IDF_TARGET == "esp32h4"
temporary: true
reason: not supported yet #TODO: OCD-1137
depends_components:
- esp_trace
- app_trace
examples/system/base_mac_address:
depends_components:
@@ -79,6 +82,9 @@ examples/system/gcov:
- if: IDF_TARGET == "esp32h4"
temporary: true
reason: not supported yet #TODO: OCD-1138
depends_components:
- esp_trace
- app_trace
examples/system/heap_task_tracking:
disable:
@@ -264,6 +270,9 @@ examples/system/sysview_tracing:
- if: IDF_TARGET == "esp32h4"
temporary: true
reason: not supported yet #TODO: OCD-1136
depends_components:
- esp_trace
- app_trace
examples/system/sysview_tracing_heap_log:
disable:
@@ -275,6 +284,9 @@ examples/system/sysview_tracing_heap_log:
- if: IDF_TARGET == "esp32h4"
temporary: true
reason: not supported yet #TODO: OCD-1136
depends_components:
- esp_trace
- app_trace
examples/system/task_watchdog:
disable:

View File

@@ -1,4 +1,4 @@
# 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.path
import time
@@ -14,6 +14,7 @@ if typing.TYPE_CHECKING:
def _test_examples_app_trace_basic(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
time.sleep(1) # Wait for the USJ port to be ready
dut.expect_exact('example: Waiting for OpenOCD connection', timeout=5)
with openocd_dut.run() as openocd:
openocd.write('reset run')
@@ -65,15 +66,14 @@ def test_examples_app_trace_basic_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> No
@idf_parametrize('target', ['supported_targets'], indirect=['target'])
def test_examples_app_trace_basic_uart(dut: IdfDut) -> None:
dut.serial.close()
with serial.Serial(dut.serial.port, baudrate=1000000, timeout=10) as ser:
with serial.Serial(dut.serial.port, baudrate=1000000, timeout=3) as ser:
apptrace_log = os.path.join(dut.logdir, 'apptrace_log_uart.txt') # pylint: disable=protected-access
with open(apptrace_log, 'w+b') as f:
start_time = time.time()
while True:
try:
if ser.in_waiting:
data = ser.read(100)
f.write(data)
f.write(ser.read(ser.in_waiting))
if time.time() - start_time > 5:
break
except serial.SerialTimeoutException:

View File

@@ -108,6 +108,7 @@ def _test_gcov(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
assert os.path.isfile(gcda_path), f'Expected .gcda file not found: {gcda_path}'
print('Basic verification passed (all .gcda files exist)')
time.sleep(1) # Wait for the USJ port to be ready
dut.expect_exact('example: Ready for OpenOCD connection', timeout=5)
with openocd_dut.run() as openocd:
openocd.write('reset run')

View File

@@ -1,4 +1,4 @@
# 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.path
import re
@@ -15,19 +15,71 @@ if typing.TYPE_CHECKING:
from conftest import OpenOCD
def _validate_trace_data(trace_log: list[str], target: str) -> None:
def _validate_trace_data(trace_log: list[str], target: str, is_uart: bool = False) -> None:
"""Validate SysView trace data in log file(s).
Args:
trace_log: List of trace log paths
target: Target chip name (e.g., 'esp32', 'esp32s3')
is_uart: If True, also validate STOP record at end of file
"""
STOP_EVENT_ID = 0x0B # SYSVIEW_EVTID_TRACE_STOP
for idx, log in enumerate(trace_log):
with open(log, 'rb') as f:
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'
def _capture_sysview_trace(ser: serial.Serial, trace_log_path: str) -> None:
"""Capture SysView trace data from serial port.
Args:
ser: Serial port instance
trace_log_path: Path to save the trace log
"""
START_CMD = b'\x01'
STOP_CMD = b'\x02'
ser.reset_input_buffer()
# Send Start command to start SysView tracing
ser.write(START_CMD)
with open(trace_log_path, 'w+b') as f:
# Capture for 3 seconds
end_time = time.time() + 3.0
while time.time() < end_time:
try:
if ser.in_waiting:
f.write(ser.read(ser.in_waiting))
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
time.sleep(0.2)
# Send Stop command
ser.write(STOP_CMD)
# Capture until target flushed data or timeout (3 seconds)
end_time = time.time() + 3.0
last_data_time = time.time()
while time.time() < end_time and (time.time() - last_data_time) <= 1.0:
try:
if ser.in_waiting:
f.write(ser.read(ser.in_waiting))
last_data_time = time.time()
except serial.SerialTimeoutException:
assert False, 'Timeout reached while reading from serial port, exiting...'
def _test_sysview_tracing_jtag(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
# Construct trace log paths
@@ -52,6 +104,7 @@ def _test_sysview_tracing_jtag(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
def dut_expect_task_event() -> None:
dut.expect(re.compile(rb'example: Task\[0x[0-9A-Fa-f]+\]: received event \d+'), timeout=30)
time.sleep(1) # Wait for the USJ port to be ready
dut.expect_exact('example: Hello from sysview_tracing example!', timeout=5)
with (
openocd_dut.run() as openocd,
@@ -94,26 +147,10 @@ def test_sysview_tracing_usj(openocd_dut: 'OpenOCD', dut: IdfDut) -> None:
def _test_sysview_tracing_uart(dut: IdfDut) -> None:
dut.serial.close()
time.sleep(2) # Wait for the DUT to reboot
with serial.Serial(dut.serial.port, baudrate=dut.app.sdkconfig.get('APPTRACE_UART_BAUDRATE'), timeout=10) as ser:
with serial.Serial(dut.serial.port, baudrate=dut.app.sdkconfig.get('APPTRACE_UART_BAUDRATE'), timeout=3) as ser:
trace_log = [os.path.join(dut.logdir, 'sys_log_uart.svdat')] # pylint: disable=protected-access
# Send Start command to start SysView tracing
ser.write(b'\x01')
with open(trace_log[0], 'w+b') as f:
start_time = time.time()
while True:
try:
if ser.in_waiting:
data = ser.read(1024)
f.write(data)
if time.time() - start_time > 3:
break
except serial.SerialTimeoutException:
assert False, 'Timeout reached while reading from serial port, exiting...'
# Send Stop command
ser.write(b'\x02')
_validate_trace_data(trace_log, dut.target)
_capture_sysview_trace(ser, trace_log[0])
_validate_trace_data(trace_log, dut.target, is_uart=True)
@pytest.mark.generic

View File

@@ -1,3 +1,5 @@
CONFIG_ESP_CONSOLE_NONE=y
CONFIG_APPTRACE_DEST_UART=y
CONFIG_APPTRACE_DEST_UART_NUM=0
CONFIG_APPTRACE_UART_BAUDRATE=1000000
CONFIG_USE_CUSTOM_EVENT_ID=y

View File

@@ -1,6 +1,7 @@
# SPDX-FileCopyrightText: 2022-2025 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Unlicense OR CC0-1.0
import os.path
import time
import typing
import pexpect.fdpexpect
@@ -32,6 +33,7 @@ def _test_examples_sysview_tracing_heap_log(openocd_dut: 'OpenOCD', idf_path: st
else:
f_w.write(line)
time.sleep(1) # Wait for the USJ port to be ready
dut.expect_exact('example: Ready for OpenOCD connection', timeout=5)
with openocd_dut.run() as oocd:
if dut.target == 'esp32p4':