From da26095bd1ee8575d3dd32e41509fe9aec2cd8cc Mon Sep 17 00:00:00 2001 From: Erhan Kurubas Date: Thu, 6 Aug 2026 09:51:33 +0200 Subject: [PATCH] fix(esp_trace): send trace data over usb-serial-jtag reliably --- .../app_trace/app_trace_membufs_proto.c | 24 +++---- .../adapter_transport_usb_serial_jtag.c | 71 +++++++++++-------- components/esp_trace/include/esp_trace_util.h | 14 +++- components/esp_trace/src/ports/port_utils.c | 8 +-- .../ext_trace_lib/include/trace_FreeRTOS.h | 3 + .../src/adapter_encoder_ext_trace_lib.c | 42 ++++++++--- .../ext_trace_lib/src/trace_FreeRTOS.c | 18 ++++- .../esp_trace_custom_library/main/app_main.c | 13 +++- .../pytest_esp_trace_custom_library.py | 10 +-- .../sysview_tracing/pytest_sysview_tracing.py | 6 +- 10 files changed, 142 insertions(+), 67 deletions(-) diff --git a/components/app_trace/app_trace_membufs_proto.c b/components/app_trace/app_trace_membufs_proto.c index b535624ec6d..1ad237a898a 100644 --- a/components/app_trace/app_trace_membufs_proto.c +++ b/components/app_trace/app_trace_membufs_proto.c @@ -1,5 +1,5 @@ /* - * SPDX-FileCopyrightText: 2021-2025 Espressif Systems (Shanghai) CO LTD + * SPDX-FileCopyrightText: 2021-2026 Espressif Systems (Shanghai) CO LTD * * SPDX-License-Identifier: Apache-2.0 OR MIT */ @@ -75,7 +75,7 @@ static esp_err_t esp_apptrace_membufs_swap(esp_apptrace_membufs_proto_data_t *pr esp_err_t res = proto->hw->swap_start(proto->state.in_block); if (res != ESP_OK) { - ESP_APPTRACE_LOGE("Failed to swap to new block: %d", res); + ESP_APPTRACE_LOGV("Failed to swap to new block: %s", esp_err_to_name(res)); return res; } @@ -100,7 +100,7 @@ static esp_err_t esp_apptrace_membufs_swap(esp_apptrace_membufs_proto_data_t *pr *(p - 8), *(p - 7), *(p - 6), *(p - 5), *(p - 4), *(p - 3), *(p - 2), *(p - 1)); uint32_t sz = esp_apptrace_membufs_down_buffer_write_nolock(proto, (uint8_t *)(hdr + 1), hdr->block_sz); if (sz != hdr->block_sz) { - ESP_APPTRACE_LOGE("Failed to write %" PRIu32 " bytes to down buffer (%" PRIu16 " %" PRIu32 ")!", + ESP_APPTRACE_LOGE("Failed to write %" PRIu32 " bytes to down buffer (%" PRIu32 " %" PRIu32 ")!", hdr->block_sz - sz, hdr->block_sz, sz); } hdr->block_sz = 0; @@ -149,20 +149,18 @@ uint8_t *esp_apptrace_membufs_down_buffer_get(esp_apptrace_membufs_proto_data_t } break; } - // may need to flush + // may need to flush to expose host down-channel data if (proto->hw->host_data_pending()) { ESP_APPTRACE_LOGD("force flush"); int res = esp_apptrace_membufs_swap_waitus(proto, tmo); - if (res != ESP_OK) { - ESP_APPTRACE_LOGE("Failed to switch to another block to recv data from host!"); - /*do not return error because data can be in down buffer already*/ - } - } else { - // check tmo only if there is no data from host - int res = esp_apptrace_tmo_check(tmo); - if (res != ESP_OK) { - return NULL; + if (res == ESP_OK) { + continue; /* re-check rb_down */ } + ESP_APPTRACE_LOGE("Failed to switch to another block to recv data from host!"); + } + /* Check the timeout even while host data is pending so a zero timeout returns immediately instead of spinning. */ + if (esp_apptrace_tmo_check(tmo) != ESP_OK) { + return NULL; } } return ptr; diff --git a/components/esp_trace/adapters/transport/adapter_transport_usb_serial_jtag.c b/components/esp_trace/adapters/transport/adapter_transport_usb_serial_jtag.c index da3e366bfe5..fd724f84f15 100644 --- a/components/esp_trace/adapters/transport/adapter_transport_usb_serial_jtag.c +++ b/components/esp_trace/adapters/transport/adapter_transport_usb_serial_jtag.c @@ -15,6 +15,8 @@ * is responsible for serializing access using esp_trace_lock_init(), esp_trace_lock_take(), * and esp_trace_lock_give(). All transport operations (read, write, flush_nolock) are * invoked while the encoder holds the lock, so no transport-level locking is required. + * + * Logging: use ESP_EARLY_LOGx only, ESP_LOGx is not safe in ISR context. */ #include @@ -29,6 +31,7 @@ #include "esp_cpu.h" #include "esp_attr.h" #include "esp_rom_caps.h" +#include "esp_rom_sys.h" #include "esp_heap_caps.h" #include "esp_private/periph_ctrl.h" #include "hal/usb_serial_jtag_ll.h" @@ -51,7 +54,6 @@ static const char *TAG = "usj_transport"; */ typedef enum { USJ_TX_IDLE, - USJ_TX_SHORT_PENDING, USJ_TX_ZLP_PENDING, } usj_tx_state_t; @@ -67,11 +69,8 @@ typedef struct { uint32_t flush_thresh; ///< Flush threshold in bytes } usj_ctx_t; -/* - * 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 +/* Default flush timeout, used on non-masked paths (e.g. panic handler). */ +#define USJ_FLUSH_TIMEOUT_US (1000000) // 1 s #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 @@ -84,7 +83,7 @@ typedef struct { static uint32_t usj_write_fifo(usj_ctx_t *ctx, esp_trace_rb_t *rb) { if (!usb_serial_jtag_ll_txfifo_writable()) { - /* FIFO is full, no blocking */ + /* Previous packet is not sent yet */ return 0; } @@ -97,17 +96,21 @@ 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); - ctx->tx_state = usb_serial_jtag_ll_txfifo_writable() ? USJ_TX_SHORT_PENDING : USJ_TX_ZLP_PENDING; + /* Checked before wr_done, which also clears the writable flag */ + ctx->tx_state = usb_serial_jtag_ll_txfifo_writable() ? USJ_TX_IDLE : USJ_TX_ZLP_PENDING; + + /* Send the packet. A no-op if the HW already flushed a full FIFO. */ + usb_serial_jtag_ll_txfifo_flush(); return written; } -static uint32_t usj_fill_txfifo(usj_ctx_t *ctx, bool commit_short) +static uint32_t usj_fill_txfifo(usj_ctx_t *ctx) { 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()) { + while (esp_trace_rb_data_len(rb) > 0) { uint32_t written = usj_write_fifo(ctx, rb); if (written == 0) { break; @@ -115,11 +118,6 @@ static uint32_t usj_fill_txfifo(usj_ctx_t *ctx, bool commit_short) 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; } @@ -127,7 +125,15 @@ static void usj_read_rx_fifo(usj_ctx_t *ctx) { uint8_t tmp[USJ_HW_FIFO_SIZE]; while (usb_serial_jtag_ll_rxfifo_data_available()) { - uint32_t n = usb_serial_jtag_ll_read_rxfifo(tmp, sizeof(tmp)); + /* Read only what fits, the rest stays in the HW FIFO */ + uint32_t space = esp_trace_rb_free_len(&ctx->rx_ring); + if (space == 0) { + break; + } + if (space > sizeof(tmp)) { + space = sizeof(tmp); + } + uint32_t n = usb_serial_jtag_ll_read_rxfifo(tmp, space); if (n == 0) { break; } @@ -185,22 +191,23 @@ static esp_err_t usj_init(esp_trace_transport_t *tp, const void *tp_cfg) /* Initialize TX ring buffer */ esp_err_t ret = esp_trace_rb_init(&ctx->tx_ring, CONFIG_ESP_TRACE_USJ_TX_BUFFER_SIZE); if (ret != ESP_OK) { - ESP_LOGE(TAG, "Failed to initialize TX ring buffer"); + ESP_EARLY_LOGE(TAG, "Failed to initialize TX ring buffer"); goto err_ctx; } /* Initialize RX ring buffer to capture host commands */ ret = esp_trace_rb_init(&ctx->rx_ring, USJ_RX_BUFFER_SIZE); if (ret != ESP_OK) { - ESP_LOGE(TAG, "Failed to initialize RX ring buffer"); + ESP_EARLY_LOGE(TAG, "Failed to initialize RX ring buffer"); goto err_tx_ring; } -#if ESP_ROM_HAS_ETS_PRINTF_BUG /* Make sure no printf output is sent to USB-Serial-JTAG */ +#if ESP_ROM_HAS_ETS_PRINTF_BUG extern bool g_usb_print; g_usb_print = false; #endif + esp_rom_install_channel_putc(2, NULL); } @@ -267,13 +274,15 @@ static esp_err_t usj_write(esp_trace_transport_t *tp, const void *data, size_t s /* Read any new RX data into the RX ring buffer to avoid losing host commands in case of heavy trace output */ usj_read_rx_fifo(ctx); - /* Add data to TX ring buffer */ - esp_trace_rb_put(rb, (const uint8_t *)data, size); + esp_err_t ret = esp_trace_rb_put(rb, (const uint8_t *)data, size); + if (ret != ESP_OK) { + /* Free what the HW can take, then retry before dropping the record */ + usj_fill_txfifo(ctx); + ret = esp_trace_rb_put(rb, (const uint8_t *)data, size); + } + usj_fill_txfifo(ctx); - /* Try to move data to HW FIFO immediately, without forcing a short packet. */ - usj_fill_txfifo(ctx, false); - - return ESP_OK; + return ret; } static esp_err_t usj_down_buffer_config(esp_trace_transport_t *tp, uint8_t *buf, uint32_t size) @@ -292,7 +301,7 @@ static esp_err_t usj_flush_with_timeout(usj_ctx_t *ctx, uint32_t tmo_us) esp_trace_rb_t *rb = &ctx->tx_ring; uint32_t pending = esp_trace_rb_data_len(rb); - if (pending < ctx->flush_thresh && ctx->tx_state == USJ_TX_IDLE) { + if ((pending == 0 || pending < ctx->flush_thresh) && ctx->tx_state == USJ_TX_IDLE) { return ESP_OK; } @@ -300,9 +309,11 @@ static esp_err_t usj_flush_with_timeout(usj_ctx_t *ctx, uint32_t tmo_us) esp_trace_tmo_init(&timeout, tmo_us); while (esp_trace_rb_data_len(rb) > 0 || ctx->tx_state != USJ_TX_IDLE) { - uint32_t written = usj_fill_txfifo(ctx, true); + uint32_t written = usj_fill_txfifo(ctx); - if (ctx->tx_state == USJ_TX_ZLP_PENDING && usb_serial_jtag_ll_txfifo_writable()) { + /* Ring is empty: send a ZLP if the last packet filled the endpoint */ + if (esp_trace_rb_data_len(rb) == 0 && 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; @@ -363,7 +374,7 @@ static esp_err_t usj_set_config(esp_trace_transport_t *tp, esp_trace_transport_c ctx->flush_thresh = *(const uint32_t *)value; return ESP_OK; default: - ESP_LOGE(TAG, "Key %d is not supported", key); + ESP_EARLY_LOGE(TAG, "Key %d is not supported", key); return ESP_ERR_NOT_SUPPORTED; } } @@ -387,7 +398,7 @@ static esp_err_t usj_get_config(esp_trace_transport_t *tp, esp_trace_transport_c *(uint32_t *)value = ctx->flush_thresh; return ESP_OK; default: - ESP_LOGE(TAG, "Key %d is not supported", key); + ESP_EARLY_LOGE(TAG, "Key %d is not supported", key); return ESP_ERR_NOT_SUPPORTED; } } diff --git a/components/esp_trace/include/esp_trace_util.h b/components/esp_trace/include/esp_trace_util.h index e95d5ceea37..5e814731363 100644 --- a/components/esp_trace/include/esp_trace_util.h +++ b/components/esp_trace/include/esp_trace_util.h @@ -157,12 +157,22 @@ static inline uint32_t esp_trace_rb_data_len(const esp_trace_rb_t *rb) } /** - * @brief Write data into the ring buffer (overwrites oldest data if full) + * @brief Get number of bytes that can still be written to the ring buffer + */ +static inline uint32_t esp_trace_rb_free_len(const esp_trace_rb_t *rb) +{ + return rb->max_size - rb->count; +} + +/** + * @brief Write data into the ring buffer, all of it or none + * + * Data already in the buffer is never overwritten. * * @param rb Ring buffer * @param data Source data * @param len Number of bytes to write - * @return ESP_OK always (data is always accepted; oldest data may be dropped) + * @return ESP_OK on success, ESP_ERR_NO_MEM if the data does not fit */ esp_err_t esp_trace_rb_put(esp_trace_rb_t *rb, const uint8_t *data, uint32_t len); diff --git a/components/esp_trace/src/ports/port_utils.c b/components/esp_trace/src/ports/port_utils.c index f2cc592c681..4870016b95c 100644 --- a/components/esp_trace/src/ports/port_utils.c +++ b/components/esp_trace/src/ports/port_utils.c @@ -195,10 +195,10 @@ esp_err_t esp_trace_rb_init(esp_trace_rb_t *rb, uint32_t size) esp_err_t esp_trace_rb_put(esp_trace_rb_t *rb, const uint8_t *data, uint32_t len) { - /* Drop oldest data if needed to make room */ - uint32_t free_len = rb->max_size - rb->count; - if (len > free_len) { - rb_advance_tail(rb, len - free_len); + /* Drop the new record instead of overwriting old ones, so that the records + * in the buffer stay complete */ + if (len > rb->max_size - rb->count) { + return ESP_ERR_NO_MEM; } uint32_t head = rb->head; diff --git a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/include/trace_FreeRTOS.h b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/include/trace_FreeRTOS.h index c49ca59bf49..3dc5381597a 100644 --- a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/include/trace_FreeRTOS.h +++ b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/include/trace_FreeRTOS.h @@ -36,6 +36,9 @@ void init_trace_lib(esp_trace_encoder_t *enc); void trace_lib_start(void); void trace_lib_stop(void); +/* @brief Get the number of trace lines written to and dropped by the transport */ +void trace_lib_get_stats(uint32_t *written, uint32_t *dropped); + /* Hook implementations — defined in trace_FreeRTOS.c. * Kept void*-typed to avoid depending on FreeRTOS types in this header. */ void trace_lib_task_switched_in(void); diff --git a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/adapter_encoder_ext_trace_lib.c b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/adapter_encoder_ext_trace_lib.c index 976704b44e4..cc227ba465e 100644 --- a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/adapter_encoder_ext_trace_lib.c +++ b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/adapter_encoder_ext_trace_lib.c @@ -85,14 +85,6 @@ static esp_err_t stop(esp_trace_encoder_t *enc) return ESP_OK; } -static esp_err_t flush(esp_trace_encoder_t *enc) -{ - if (!enc || !enc->tp || !enc->tp->vt->flush_nolock) { - return ESP_ERR_NOT_SUPPORTED; - } - return enc->tp->vt->flush_nolock(enc->tp); -} - /** * @brief Panic handler * @@ -104,7 +96,11 @@ static esp_err_t flush(esp_trace_encoder_t *enc) static void panic_handler(esp_trace_encoder_t *enc, const void *info) { (void)info; - flush(enc); + + /* No lock here, the panicking core may already hold it */ + if (enc && enc->tp && enc->tp->vt->flush_nolock) { + enc->tp->vt->flush_nolock(enc->tp); + } } static unsigned int take_lock(esp_trace_encoder_t *enc, uint32_t tmo_us) @@ -127,6 +123,34 @@ static void give_lock(esp_trace_encoder_t *enc, unsigned int int_state) esp_trace_lock_give(&ctx->lock); } +/* Total time for the flush, split over several flush_nolock() calls */ +#define EXT_TRACE_LIB_FLUSH_TMO_US (1000000) + +static esp_err_t flush(esp_trace_encoder_t *enc) +{ + if (!enc || !enc->tp || !enc->tp->vt->flush_nolock) { + return ESP_ERR_NOT_SUPPORTED; + } + + /* One call may be too short to send all the data, so repeat it and release + * the lock in between to keep interrupts enabled */ + esp_trace_tmo_t tmo; + esp_trace_tmo_init(&tmo, EXT_TRACE_LIB_FLUSH_TMO_US); + + esp_err_t err; + do { + unsigned int int_state = take_lock(enc, ESP_TRACE_TMO_INFINITE); + err = enc->tp->vt->flush_nolock(enc->tp); + give_lock(enc, int_state); + + if (err != ESP_ERR_TIMEOUT) { + break; /* done, or an error that repeating cannot fix */ + } + } while (esp_trace_tmo_check(&tmo) == ESP_OK); + + return err; +} + static const esp_trace_encoder_vtable_t s_ext_trace_lib_vt = { .init = init, .write = write, diff --git a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/trace_FreeRTOS.c b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/trace_FreeRTOS.c index 5e88bf6df37..d8f12035a9a 100644 --- a/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/trace_FreeRTOS.c +++ b/examples/system/tracing/esp_trace_custom_library/components/ext_trace_lib/src/trace_FreeRTOS.c @@ -35,6 +35,8 @@ static esp_trace_encoder_t *s_enc = NULL; static uint32_t s_ts_freq_hz = 1000000; /* default assume 1 MHz */ static uint32_t s_last_ts = 0; static volatile bool s_enabled = false; +static uint32_t s_written = 0; +static uint32_t s_dropped = 0; void init_trace_lib(esp_trace_encoder_t *enc) { @@ -87,12 +89,26 @@ static void encode(const char *type, const char *detail) if (n >= (int)sizeof(line)) { n = (int)sizeof(line) - 1; } - esp_trace_write(s_esp_trace_handle, line, (size_t)n, 0); + if (esp_trace_write(s_esp_trace_handle, line, (size_t)n, 0) == ESP_OK) { + s_written++; + } else { + s_dropped++; /* transport buffer was full, line dropped */ + } } s_enc->vt->give_lock(s_enc, int_state); } +void trace_lib_get_stats(uint32_t *written, uint32_t *dropped) +{ + if (written) { + *written = s_written; + } + if (dropped) { + *dropped = s_dropped; + } +} + void trace_lib_task_switched_in(void) { TaskHandle_t h = xTaskGetCurrentTaskHandle(); diff --git a/examples/system/tracing/esp_trace_custom_library/main/app_main.c b/examples/system/tracing/esp_trace_custom_library/main/app_main.c index 28d7c07aa27..265bb4b6e9b 100644 --- a/examples/system/tracing/esp_trace_custom_library/main/app_main.c +++ b/examples/system/tracing/esp_trace_custom_library/main/app_main.c @@ -5,6 +5,7 @@ */ #include "sdkconfig.h" +#include #include #include @@ -13,6 +14,7 @@ #include "freertos/queue.h" #include "esp_log.h" #include "esp_trace.h" +#include "trace_FreeRTOS.h" static const char *TAG = "main"; @@ -70,7 +72,16 @@ void app_main(void) vTaskDelay(1000 / portTICK_PERIOD_MS); esp_trace_stop(); - esp_trace_flush(); + esp_err_t err = esp_trace_flush(); + + /* Logged from task context, so it goes to the console UART and not to the + * trace port. Shows whether the device sent the trace data or not. */ + uint32_t written = 0; + uint32_t dropped = 0; + trace_lib_get_stats(&written, &dropped); + ESP_LOGI(TAG, "Trace flush: %s, host connected: %d, lines written: %" PRIu32 ", dropped: %" PRIu32, + esp_err_to_name(err), (int)esp_trace_is_host_connected(esp_trace_get_active_handle()), + written, dropped); ESP_LOGI(TAG, "End of trace session"); } diff --git a/examples/system/tracing/esp_trace_custom_library/pytest_esp_trace_custom_library.py b/examples/system/tracing/esp_trace_custom_library/pytest_esp_trace_custom_library.py index 304464015ec..1d424804aea 100644 --- a/examples/system/tracing/esp_trace_custom_library/pytest_esp_trace_custom_library.py +++ b/examples/system/tracing/esp_trace_custom_library/pytest_esp_trace_custom_library.py @@ -76,7 +76,6 @@ def _validate_trace_data(trace_log_path: str) -> None: def _capture_trace(ser: serial.Serial, trace_log_path: str, capture_s: float = 5.0) -> None: """Capture trace output from the USB-Serial-JTAG endpoint.""" - ser.reset_input_buffer() with open(trace_log_path, 'w+b') as f: end_time = time.time() + capture_s while time.time() < end_time: @@ -107,10 +106,13 @@ def _capture_trace(ser: serial.Serial, trace_log_path: str, capture_s: float = 5 def test_esp_trace_ext_lib_usj(dut: IdfDut) -> None: dut.expect('Start of trace session', timeout=5) - time.sleep(1) # wait for USJ port to be ready + # Open the port before the DUT starts tracing usj_port = '/dev/serial_ports/ttyACM-esp32' - ser = serial.Serial(usj_port, baudrate=1000000, timeout=10) trace_log_path = os.path.join(dut.logdir, 'ext_trace.log') + time.sleep(1) # Wait for the USJ port to be ready + with serial.Serial(usj_port, baudrate=1000000, timeout=10) as ser: + # Discard data from before this test, the DUT is not tracing yet + ser.reset_input_buffer() + _capture_trace(ser, trace_log_path) - _capture_trace(ser, trace_log_path) _validate_trace_data(trace_log_path) diff --git a/examples/system/tracing/sysview_tracing/pytest_sysview_tracing.py b/examples/system/tracing/sysview_tracing/pytest_sysview_tracing.py index a08169fa690..0d9f2096ed6 100644 --- a/examples/system/tracing/sysview_tracing/pytest_sysview_tracing.py +++ b/examples/system/tracing/sysview_tracing/pytest_sysview_tracing.py @@ -183,7 +183,7 @@ def test_sysview_tracing_uart(dut: IdfDut) -> None: 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' - ser = serial.Serial(usj_port, baudrate=1000000, timeout=10) trace_log = [os.path.join(dut.logdir, 'sys_log_usj.svdat')] # pylint: disable=protected-access - _capture_sysview_trace(ser, trace_log[0]) - _validate_trace_data(trace_log, dut.target, is_uart=True) + with serial.Serial(usj_port, baudrate=1000000, timeout=10) as ser: + _capture_sysview_trace(ser, trace_log[0]) + _validate_trace_data(trace_log, dut.target, is_uart=True)