From 281ce584f3adc5058c0d2c00417cd283d7103407 Mon Sep 17 00:00:00 2001 From: Zhou Xiao Date: Wed, 2 Sep 2026 19:25:33 +0800 Subject: [PATCH] refactor(ble_log): remove the dead legacy LBM module and tidy the v7 switch ble_log_lbm.c/h were superseded by the v2 LBM (protocol v7) and are not part of the build; the two files only referenced each other. The deprecated Kconfig entries stay untouched - downstream test apps may still pin the old symbols (e.g. BLE_LOG_LL_HCI_LOG_PAYLOAD_LEN_LIMIT). Post-switch polish folded in: version info built in place inside lbm init, pool-internal tidying, simplified runtime submit/defer paths, per-snapshot clock sampling, shared waiter-count RMW in the acquire path, and dropped zero-value transport field inits. --- components/bt/common/ble_log/Kconfig.in | 10 +- components/bt/common/ble_log/README.md | 29 +- .../bt/common/ble_log/include/ble_log.h | 8 +- components/bt/common/ble_log/src/ble_log.c | 32 +- .../bt/common/ble_log/src/ble_log_lbm.c | 874 ------------------ .../bt/common/ble_log/src/ble_log_lbm_v2.c | 267 ++++-- .../bt/common/ble_log/src/ble_log_redir.c | 7 +- components/bt/common/ble_log/src/ble_log_rt.c | 159 ++-- .../bt/common/ble_log/src/ble_log_util.c | 15 +- .../src/internal_include/ble_log_lbm.h | 272 ------ .../src/internal_include/ble_log_lbm_v2.h | 25 +- .../src/internal_include/ble_log_prph.h | 3 + .../ble_log/src/internal_include/ble_log_rt.h | 9 + .../src/internal_include/ble_log_util.h | 5 + .../ble_log/src/prph/ble_log_prph_dummy.c | 1 - .../src/prph/ble_log_prph_spi_master_dma.c | 1 - .../src/prph/ble_log_prph_spi_master_hd.c | 2 - .../ble_log/src/prph/ble_log_prph_test.c | 4 - .../ble_log/src/prph/ble_log_prph_uart_dma.c | 7 +- .../ble_log_rt_test/main/test_ble_log_main.c | 4 +- .../main/test_ble_log_runtime.c | 138 ++- .../ble_log_test/main/test_ble_log_main.c | 4 +- .../ble_log_test/main/test_ble_log_rt.c | 146 ++- 23 files changed, 602 insertions(+), 1420 deletions(-) delete mode 100644 components/bt/common/ble_log/src/ble_log_lbm.c delete mode 100644 components/bt/common/ble_log/src/internal_include/ble_log_lbm.h diff --git a/components/bt/common/ble_log/Kconfig.in b/components/bt/common/ble_log/Kconfig.in index 85d6a2ad303..22d3ab6e7d0 100644 --- a/components/bt/common/ble_log/Kconfig.in +++ b/components/bt/common/ble_log/Kconfig.in @@ -96,11 +96,11 @@ if BLE_LOG_ENABLED bool "Toggle a GPIO on every BLE Log TS sync sample" default n help - BLE Log TS sync always runs: every periodic output tick samples - the link-layer, ESP and OS clocks into the internal snapshot. - Enable this option to additionally toggle a GPIO on every - sample so an external logic analyzer can align the device - clocks with the capture. + Every periodic Internal Snapshot samples the link-layer, ESP and + OS clocks regardless of this option. Enable this option to build + the GPIO toggle used by external logic analyzers. It starts + disabled and low; ble_log_ts_sync_io_toggle_enable controls its + edges without stopping periodic snapshots. if BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED config BLE_LOG_SYNC_IO_NUM diff --git a/components/bt/common/ble_log/README.md b/components/bt/common/ble_log/README.md index ae23c710aba..eb9c0802efe 100644 --- a/components/bt/common/ble_log/README.md +++ b/components/bt/common/ble_log/README.md @@ -74,9 +74,9 @@ redirection flush) is the alignment reference against the core timeline. ### Sources -The public `ble_log_src_t` ABI is frozen and its values are the on-wire -source IDs of protocol v7 frames — the frame source byte carries the enum -value directly, so existing decoders keep working: +The public `ble_log_src_t` ABI is frozen and its values are the base on-wire +source IDs of protocol v7 frames. Receivers must mask the `NON_YIELD` bit +before decoding the base source: ```text 0 INTERNAL @@ -96,7 +96,10 @@ equal-timestamp records from different sources — and every lost or rejected attempt leaves a gap in the sequence. Internal Snapshot frames carry their own separate sequence (a gap counts skipped snapshots), and the REDIR console stream keeps its own sequence as well (a gap counts a dropped -console batch). None of these sequences is reset. +console batch). `ble_log_init()` resets all three sequences, and its required +`INIT` snapshot starts a new receiver epoch. They remain continuous through +`FLUSH` within that epoch. Callers must not write until `ble_log_init()` +returns, so the `INIT` snapshot is submitted first. Actual ISR and critical-section records carry `NON_YIELD` in source bit 7. Controller-side HCI records are not emitted by BLE Log, and the controller no @@ -121,6 +124,8 @@ The snapshot contains: - compact statistics for `CUSTOM` through `ENCODE` (one slot per public source in that range, `HOST` included). +The periodic snapshot is an always-on system behavior from initialization +until deinitialization. It cannot be stopped by the TS sync IO control API. A skipped periodic snapshot burns one snapshot SN instead: the gap in the snapshot sequence is the loss signal, and it is visible directly in the frame header without a dedicated payload field. @@ -155,8 +160,21 @@ void ble_log_commit(uint32_t handle, size_t actual_len); void ble_log_write_hex_ll(uint32_t len, const uint8_t *data, uint32_t append_len, const uint8_t *append, uint32_t flags); +bool ble_log_ts_sync_io_toggle_enable(bool enable); +bool ble_log_sync_enable(bool enable); /* compatibility shim */ ``` +`ble_log_enable()` gates public producers only. Periodic system output remains +active while that gate is closed. + +`ble_log_ts_sync_io_toggle_enable()` controls only the optional external +analyzer GPIO, which starts disabled and low. Disabling it leaves the IO low +after a final falling edge; +periodic clock sampling, OPEN transport flushing, and Internal Snapshots +continue. When the GPIO feature is not built, the call remains a +lifecycle-checked no-op. `ble_log_sync_enable()` is the backward-compatible +name for the same behavior. + `ble_log_flush()` is an ordinary FreeRTOS task API. Do not call it from an ISR, critical section, or the shared ESP Timer task. @@ -197,7 +215,8 @@ canceled and counted as lost. | `CONFIG_BLE_LOG_POOL_TRANS_SIZE` | 640 | Bytes per shared transport; SPI builds require a multiple of four | | `CONFIG_BLE_LOG_LL_ENABLED` | target dependent | Controller LL logging | | `CONFIG_BLE_LOG_HCI_LOG_ENABLED` | target dependent | Host-side HCI capture | -| `CONFIG_BLE_LOG_TS_ENABLED` | n | GPIO/LC timestamp synchronization | +| `CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED` | n | Build the optional analyzer GPIO toggle | +| `CONFIG_BLE_LOG_TS_ENABLED` | n | Deprecated compatibility entry selecting the GPIO toggle | Old multi-LBM sizing options remain hidden only so existing sdkconfig files can be parsed; they no longer control allocation. diff --git a/components/bt/common/ble_log/include/ble_log.h b/components/bt/common/ble_log/include/ble_log.h index efa20298585..b62ace0ac2e 100644 --- a/components/bt/common/ble_log/include/ble_log.h +++ b/components/bt/common/ble_log/include/ble_log.h @@ -21,7 +21,7 @@ * memory requirements, keep it as less as possible; it's recommended to use subcode for more * log data structure decoding */ /* CRITICAL: this enum is a public ABI and must not be reordered or renamed. - * Its values are also the on-wire source IDs of protocol v7 frames. */ + * Its values are the base on-wire source IDs of protocol v7 frames. */ typedef enum { /* Internal */ BLE_LOG_SRC_INTERNAL = 0, @@ -63,6 +63,7 @@ typedef enum { /* INTERFACE */ bool ble_log_init(void); void ble_log_deinit(void); +/* Controls public producers only; periodic system output remains active. */ bool ble_log_enable(bool enable); /* Blocking; call only from a caller-owned task, not an ISR or system callback. */ void ble_log_flush(void); @@ -74,6 +75,11 @@ void ble_log_dump_to_console(void); void ble_log_write_hex_ll(uint32_t len, const uint8_t *addr, uint32_t len_append, const uint8_t *addr_append, uint32_t flag); #endif /* CONFIG_BLE_LOG_LL_ENABLED */ +/* Task-context only. Controls the optional TS sync IO toggle, which starts + * disabled and low; this is a lifecycle-checked no-op when the toggle is not + * built. Periodic Internal Snapshots remain active in either state. */ +bool ble_log_ts_sync_io_toggle_enable(bool enable); +/* Backward-compatible name for ble_log_ts_sync_io_toggle_enable(). */ bool ble_log_sync_enable(bool enable); #endif /* __BLE_LOG_H__ */ diff --git a/components/bt/common/ble_log/src/ble_log.c b/components/bt/common/ble_log/src/ble_log.c index 9be67605685..f74219ab8dc 100644 --- a/components/bt/common/ble_log/src/ble_log.c +++ b/components/bt/common/ble_log/src/ble_log.c @@ -49,8 +49,13 @@ bool ble_log_init(void) } ble_log_inited = true; - if (!ble_log_enable(true) || - !ble_log_internal_snapshot(BLE_LOG_SNAPSHOT_REASON_INIT, NULL, true)) { + /* Queue the required INIT snapshot before starting the periodic path or + * opening the public producer gate, so it starts the receiver epoch. + * INIT/FLUSH samples never toggle sync IO. */ + ble_log_ts_info_t ts_info; + ble_log_rt_ts_sample(&ts_info, false); + if (!ble_log_internal_snapshot(BLE_LOG_SNAPSHOT_REASON_INIT, &ts_info, true) || + !ble_log_rt_start_periodic() || !ble_log_enable(true)) { goto exit; } esp_err_t ret = esp_register_shutdown_handler(ble_log_shutdown_handler); @@ -80,23 +85,24 @@ void ble_log_deinit(void) ble_log_inited = false; ble_log_lbm_begin_deinit(); - /* Residual frames parked in OPEN transports would be discarded with - * the pool. Seal and dispatch them while the runtime queue is still - * alive; the peripheral deinit wait below completes the delivery. */ - ble_log_lbm_drain_open_transports(); + /* Seal and dispatch residual pool and UART0 REDIR data while the runtime + * queue is still alive. The peripheral waits below complete delivery. */ + ble_log_lbm_drain_open_trans(); +#if BLE_LOG_UART_REDIR_ENABLED + (void)ble_log_prph_flush(); +#endif /* CRITICAL - Deinit ordering rationale: * * 1. The LBM writer gate is closed before submodule teardown. Writers * already inside the gate keep a reference until they finish; later - * writers are rejected. With writers gone, the deinit drain seals - * the remaining OPEN transports and hands them to the runtime - * queue, so residual frames are not discarded with the pool. + * writers are rejected. With writers gone, the pool and REDIR drains + * seal and dispatch every residual frame while runtime is still live. * - * 2. Runtime dispatch must be stopped FIRST to prevent it from sending + * 2. Runtime dispatch is stopped FIRST to prevent it from sending * transports to an already-destroyed peripheral driver. Active - * submissions and callbacks finish before the timers are deleted; - * the queue is then drained and pending transports are discarded. + * submissions and callbacks finish before the timers and queue are + * deleted. * * 3. Peripheral interface is deinitialized SECOND. It waits for DMA * operations started before runtime dispatch stopped, then destroys @@ -104,7 +110,7 @@ void ble_log_deinit(void) * * 4. LBM is deinitialized LAST. At this point all DMA has completed * (ensured by step 3) and all queued transports have been drained - * (ensured by step 2), so freeing the buffers is safe. */ + * (ensured by steps 1 and 2), so freeing the buffers is safe. */ ble_log_rt_deinit(); ble_log_prph_deinit(); ble_log_lbm_deinit(); diff --git a/components/bt/common/ble_log/src/ble_log_lbm.c b/components/bt/common/ble_log/src/ble_log_lbm.c deleted file mode 100644 index 3e5d2566094..00000000000 --- a/components/bt/common/ble_log/src/ble_log_lbm.c +++ /dev/null @@ -1,874 +0,0 @@ -/* - * SPDX-FileCopyrightText: 2025-2026 Espressif Systems (Shanghai) CO LTD - * - * SPDX-License-Identifier: Apache-2.0 - */ -/* ------------------------------- */ -/* BLE Log - Log Buffer Management */ -/* ------------------------------- */ - -/* INCLUDE */ -#include "ble_log.h" -#include "ble_log_lbm.h" -#include "ble_log_rt.h" -#include "esp_log.h" - -#if CONFIG_BLE_LOG_LL_ENABLED && CONFIG_SOC_ESP_NIMBLE_CONTROLLER -#if CONFIG_BT_DUAL_MODE_ARCH -#include "ble_mbuf.h" -#define BLE_MBUF_COPY(buf, off, len, dst) ble_mbuf_copydata((struct ble_mbuf *)(buf), off, len, dst) -#else -#include "os/os_mbuf.h" -#define BLE_MBUF_COPY(buf, off, len, dst) os_mbuf_copydata((struct os_mbuf *)(buf), off, len, dst) -#endif // CONFIG_BT_DUAL_MODE_ARCH -#endif /* CONFIG_BLE_LOG_LL_ENABLED && CONFIG_SOC_ESP_NIMBLE_CONTROLLER */ - -/* VARIABLE */ -#define TAG "ble_log" -#define BLE_LOG_LBM_WAIT_TIMEOUT_MS (1000) - -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR volatile uint32_t lbm_ref_count = 0; -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t lbm_inited = 0; -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t lbm_enabled = 0; -BLE_LOG_STATIC volatile bool flush_in_progress = false; -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR ble_log_lbm_ctx_t *lbm_ctx = NULL; -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR ble_log_stat_mgr_t *stat_mgr_ctx[BLE_LOG_SRC_MAX] = {0}; - -/* PRIVATE FUNCTION DECLARATION */ -BLE_LOG_STATIC -bool ble_log_lbm_acquire_trans(size_t log_len, ble_log_lbm_t **out_lbm, - ble_log_prph_trans_t ***out_trans); -BLE_LOG_STATIC void ble_log_lbm_release(ble_log_lbm_t *lbm); -BLE_LOG_STATIC void ble_log_lbm_submit_trans(ble_log_prph_trans_t **trans); -BLE_LOG_STATIC -ble_log_prph_trans_t **ble_log_lbm_get_trans(ble_log_lbm_t *lbm, size_t log_len); -BLE_LOG_STATIC bool ble_log_lbm_flush_all_trans(void); -BLE_LOG_STATIC void ble_log_lbm_reset_stats(void); -BLE_LOG_STATIC -void ble_log_lbm_write_trans(ble_log_prph_trans_t **trans, ble_log_src_t src_code, - const uint8_t *addr, uint16_t len, - const uint8_t *addr_append, uint16_t len_append, bool omdata); -BLE_LOG_STATIC -bool ble_log_write_hex_core(ble_log_src_t src_code, const uint8_t *addr, size_t len); -#if BLE_LOG_UART_REDIR_ENABLED -BLE_LOG_STATIC -void ble_log_lbm_stream_seal(ble_log_prph_trans_t **trans, ble_log_src_t src_code); -#endif /* BLE_LOG_UART_REDIR_ENABLED */ -BLE_LOG_STATIC void ble_log_stat_mgr_update(ble_log_src_t src_code, uint32_t len, bool lost); - -/* ------------------------- */ -/* PRIVATE INTERFACE */ -/* ------------------------- */ -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -bool ble_log_lbm_ref_acquire(bool require_enabled) -{ - if (!ble_log_ref_count_try_acquire(&lbm_ref_count, &lbm_inited)) { - return false; - } - if (require_enabled && !BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_enabled)) { - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return false; - } - return true; -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -bool ble_log_lbm_acquire_trans(size_t log_len, ble_log_lbm_t **out_lbm, - ble_log_prph_trans_t ***out_trans) -{ - *out_lbm = NULL; - *out_trans = NULL; - - ble_log_lbm_t *lbm; - ble_log_prph_trans_t **trans; - ble_log_lbm_t *atomic_pool; - ble_log_lbm_t *spin_lbm; - int atomic_pool_size; - - if (BLE_LOG_IN_ISR()) { - atomic_pool = lbm_ctx->atomic_pool_isr; - spin_lbm = &(lbm_ctx->spin_isr); - atomic_pool_size = BLE_LOG_LBM_ATOMIC_ISR_CNT; - } else { - atomic_pool = lbm_ctx->atomic_pool_task; - spin_lbm = &(lbm_ctx->spin_task); - atomic_pool_size = BLE_LOG_LBM_ATOMIC_TASK_CNT; - } - - /* Try each atomic LBM: acquire lock, check buffer, fallback on failure */ - for (int i = 0; i < atomic_pool_size; i++) { - lbm = &atomic_pool[i]; - if (ble_log_cas_acquire(&(lbm->atomic_lock))) { - trans = ble_log_lbm_get_trans(lbm, log_len); - if (trans) { - *out_lbm = lbm; - *out_trans = trans; - return true; - } - ble_log_cas_release(&(lbm->atomic_lock)); - } - } - - /* Last resort: spinlock LBM */ - lbm = spin_lbm; - BLE_LOG_ACQUIRE_SPIN_LOCK(&(lbm->spin_lock)); - trans = ble_log_lbm_get_trans(lbm, log_len); - if (trans) { - *out_lbm = lbm; - *out_trans = trans; - return true; - } - BLE_LOG_RELEASE_SPIN_LOCK(&(lbm->spin_lock)); - - return false; -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -void ble_log_lbm_release(ble_log_lbm_t *lbm) -{ - switch (lbm->lock_type) { - case BLE_LOG_LBM_LOCK_ATOMIC: - ble_log_cas_release(&(lbm->atomic_lock)); - break; - case BLE_LOG_LBM_LOCK_SPIN: - BLE_LOG_RELEASE_SPIN_LOCK(&lbm->spin_lock); - break; - case BLE_LOG_LBM_LOCK_NONE: - default: - break; - } -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -void ble_log_lbm_submit_trans(ble_log_prph_trans_t **trans) -{ - ble_log_prph_trans_t *submitted = *trans; - BLE_LOG_ATOMIC_STORE_RELAXED(submitted->prph_owned, true); - - ble_log_lbm_t *lbm = (ble_log_lbm_t *)submitted->owner; - uint32_t inflight = __atomic_add_fetch(&lbm->trans_inflight, 1, __ATOMIC_RELAXED); - uint32_t peak = __atomic_load_n(&lbm->trans_inflight_peak, __ATOMIC_RELAXED); - while (inflight > peak && - !__atomic_compare_exchange_n(&lbm->trans_inflight_peak, &peak, inflight, - false, __ATOMIC_RELAXED, __ATOMIC_RELAXED)) { - } - - ble_log_rt_submit_trans(submitted); -} - -BLE_LOG_STATIC bool ble_log_lbm_flush_all_trans(void) -{ - ble_log_lbm_t *lbm; - ble_log_prph_trans_t **trans; - bool in_progress; - TickType_t start_tick = xTaskGetTickCount(); - - /* Queue transports with logs */ - for (int i = 0; i < BLE_LOG_LBM_CNT; i++) { - lbm = &(lbm_ctx->lbm_pool[i]); - int trans_idx = lbm->trans_idx; - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - trans = &(lbm->trans[trans_idx]); - if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE((*trans)->prph_owned) && (*trans)->pos) { - ble_log_lbm_submit_trans(trans); - } - trans_idx = (trans_idx + 1) & (BLE_LOG_TRANS_BUF_CNT - 1); - } - } - - /* Dispatch anything still waiting on the defer alarm, then - * wait for transportation to finish */ - if (!ble_log_rt_drain()) { - return false; - } - - do { - in_progress = false; - for (int i = 0; i < BLE_LOG_LBM_CNT; i++) { - lbm = &(lbm_ctx->lbm_pool[i]); - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - trans = &(lbm->trans[j]); - in_progress |= BLE_LOG_ATOMIC_LOAD_ACQUIRE((*trans)->prph_owned); - } - } - if (in_progress) { - if ((xTaskGetTickCount() - start_tick) >= - pdMS_TO_TICKS(BLE_LOG_LBM_WAIT_TIMEOUT_MS)) { - ESP_LOGE(TAG, "Timed out waiting for BLE Log transports"); - return false; - } - vTaskDelay(1); - } - } while (in_progress); - - return true; -} - -BLE_LOG_STATIC void ble_log_lbm_reset_stats(void) -{ - ble_log_lbm_t *lbm; - - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - BLE_LOG_MEMSET(stat_mgr_ctx[i], 0, sizeof(ble_log_stat_mgr_t)); - } - - for (int i = 0; i < BLE_LOG_LBM_CNT; i++) { - lbm = &(lbm_ctx->lbm_pool[i]); - __atomic_store_n(&lbm->trans_inflight, 0, __ATOMIC_RELAXED); - __atomic_store_n(&lbm->trans_inflight_peak, 0, __ATOMIC_RELAXED); - } -#if CONFIG_BLE_LOG_PRPH_UART_DMA - ble_log_prph_reset_util_counters(); -#endif -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -void ble_log_lbm_write_trans(ble_log_prph_trans_t **trans, ble_log_src_t src_code, - const uint8_t *addr, uint16_t len, - const uint8_t *addr_append, uint16_t len_append, bool omdata) -{ - /* Preparation before writing */ - uint8_t *buf = (*trans)->buf + (*trans)->pos; - uint16_t payload_len = len + len_append; - ble_log_stat_mgr_t *stat_mgr = stat_mgr_ctx[src_code]; - uint32_t frame_sn = BLE_LOG_GET_FRAME_SN(&(stat_mgr->frame_sn)); - ble_log_frame_head_t frame_head = { - .length = payload_len, - .frame_meta = BLE_LOG_MAKE_FRAME_META(src_code, frame_sn), - }; - - /* Memory operation */ - BLE_LOG_MEMCPY(buf, &frame_head, BLE_LOG_FRAME_HEAD_LEN); - if (len) { - BLE_LOG_MEMCPY(buf + BLE_LOG_FRAME_HEAD_LEN, addr, len); - } - if (len_append) { -#if CONFIG_BLE_LOG_LL_ENABLED && CONFIG_SOC_ESP_NIMBLE_CONTROLLER - if (omdata) { - BLE_MBUF_COPY(addr_append, 0, len_append, buf + BLE_LOG_FRAME_HEAD_LEN + len); - } - else -#endif /* CONFIG_BLE_LOG_LL_ENABLED && CONFIG_SOC_ESP_NIMBLE_CONTROLLER */ - { - BLE_LOG_MEMCPY(buf + BLE_LOG_FRAME_HEAD_LEN + len, addr_append, len_append); - } - } - - /* Data integrity check */ - uint32_t checksum = ble_log_fast_checksum((const uint8_t *)buf, BLE_LOG_FRAME_HEAD_LEN + payload_len); - BLE_LOG_MEMCPY(buf + BLE_LOG_FRAME_HEAD_LEN + payload_len, &checksum, BLE_LOG_FRAME_TAIL_LEN); - - /* Update peripheral transport */ - (*trans)->pos += payload_len + BLE_LOG_FRAME_OVERHEAD; - - ble_log_stat_mgr_update(src_code, payload_len, false); - - /* Queue trans if full */ - if (BLE_LOG_TRANS_FREE_SPACE((*trans)) <= BLE_LOG_FRAME_OVERHEAD) { - ble_log_lbm_submit_trans(trans); - } -} - -#if BLE_LOG_UART_REDIR_ENABLED -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -void ble_log_lbm_stream_seal(ble_log_prph_trans_t **trans, ble_log_src_t src_code) -{ - if ((*trans)->pos <= BLE_LOG_FRAME_HEAD_LEN) { - return; - } - - uint16_t payload_len = (*trans)->pos - BLE_LOG_FRAME_HEAD_LEN; - ble_log_stat_mgr_t *stat_mgr = stat_mgr_ctx[src_code]; - uint32_t frame_sn = BLE_LOG_GET_FRAME_SN(&(stat_mgr->frame_sn)); - ble_log_frame_head_t frame_head = { - .length = payload_len, - .frame_meta = BLE_LOG_MAKE_FRAME_META(src_code, frame_sn), - }; - BLE_LOG_MEMCPY((*trans)->buf, &frame_head, BLE_LOG_FRAME_HEAD_LEN); - - uint32_t checksum = ble_log_fast_checksum((*trans)->buf, (*trans)->pos); - BLE_LOG_MEMCPY((*trans)->buf + (*trans)->pos, &checksum, BLE_LOG_FRAME_TAIL_LEN); - (*trans)->pos += BLE_LOG_FRAME_TAIL_LEN; - - ble_log_stat_mgr_update(src_code, payload_len, false); - - ble_log_lbm_submit_trans(trans); -} -#endif /* BLE_LOG_UART_REDIR_ENABLED */ - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -void ble_log_stat_mgr_update(ble_log_src_t src_code, uint32_t len, bool lost) -{ - /* Get statistic manager by source code */ - ble_log_stat_mgr_t *stat_mgr = stat_mgr_ctx[src_code]; - - /* Update aligned counters */ - uint32_t bytes_cnt = len + BLE_LOG_FRAME_OVERHEAD; - if (lost) { - BLE_LOG_GET_FRAME_SN(&(stat_mgr->frame_sn)); /* consume SN for loss detection */ - __atomic_fetch_add(&stat_mgr->lost_frame_cnt, 1, __ATOMIC_RELAXED); - __atomic_fetch_add(&stat_mgr->lost_bytes_cnt, bytes_cnt, __ATOMIC_RELAXED); - } else { - __atomic_fetch_add(&stat_mgr->written_frame_cnt, 1, __ATOMIC_RELAXED); - __atomic_fetch_add(&stat_mgr->written_bytes_cnt, bytes_cnt, __ATOMIC_RELAXED); - } -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -bool ble_log_write_hex_core(ble_log_src_t src_code, const uint8_t *addr, size_t len) -{ - /* Get transport from the best available pool */ - size_t payload_len = len + sizeof(uint32_t); - ble_log_lbm_t *lbm; - ble_log_prph_trans_t **trans; - if (!ble_log_lbm_acquire_trans(payload_len, &lbm, &trans)) { - goto failed; - } - - /* Write transport */ - uint32_t os_ts = pdTICKS_TO_MS(BLE_LOG_IN_ISR()? - xTaskGetTickCountFromISR(): - xTaskGetTickCount()); - ble_log_lbm_write_trans(trans, src_code, (const uint8_t *)&os_ts, - sizeof(uint32_t), addr, len, false); - - /* Release */ - ble_log_lbm_release(lbm); - return true; - -failed: - if (BLE_LOG_ATOMIC_LOAD_RELAXED(lbm_inited)) { - ble_log_stat_mgr_update(src_code, payload_len, true); - } - return false; -} - -/* -------------------------- */ -/* INTERNAL INTERFACE */ -/* -------------------------- */ -/* CRITICAL: - * Recycle a transport back to its LBM pool after the send completes or fails. - * Leaves trans->pos untouched on purpose: a failed send keeps its buffered data - * so the next flush re-queues it (flush re-sends any trans with pos != 0) */ -BLE_LOG_IRAM_ATTR void ble_log_lbm_recycle_trans(ble_log_prph_trans_t *trans) -{ - ble_log_lbm_t *lbm = (ble_log_lbm_t *)trans->owner; - __atomic_fetch_sub(&lbm->trans_inflight, 1, __ATOMIC_RELAXED); - BLE_LOG_ATOMIC_STORE_RELEASE(trans->prph_owned, false); -} - -bool ble_log_lbm_init(void) -{ - /* Avoid double init */ - if (BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_inited)) { - return true; - } - - /* Initialize LBM context */ - lbm_ctx = (ble_log_lbm_ctx_t *)BLE_LOG_MALLOC(sizeof(ble_log_lbm_ctx_t)); - if (!lbm_ctx) { - goto exit; - } - BLE_LOG_MEMSET(lbm_ctx, 0, sizeof(ble_log_lbm_ctx_t)); - - /* Initialize peripheral transport for common LBMs */ - ble_log_lbm_t *lbm; - for (int i = 0; i < BLE_LOG_LBM_COMMON_CNT; i++) { - lbm = &(lbm_ctx->lbm_common_pool[i]); - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - if (!ble_log_prph_trans_init(&(lbm->trans[j]), - BLE_LOG_TRANS_SIZE)) { - goto exit; - } - lbm->trans[j]->owner = (void *)lbm; - } - } - - /* Initialize lock types for atomic pool */ - for (int i = 0; i < BLE_LOG_LBM_ATOMIC_CNT; i++) { - lbm_ctx->atomic_pool[i].lock_type = BLE_LOG_LBM_LOCK_ATOMIC; - } - - /* Initialize lock types for spin pool */ - for (int i = 0; i < BLE_LOG_LBM_SPIN_MAX; i++) { - lbm_ctx->spin_pool[i].lock_type = BLE_LOG_LBM_LOCK_SPIN; - portMUX_INITIALIZE(&(lbm_ctx->spin_pool[i].spin_lock)); - } - -#if CONFIG_BLE_LOG_LL_ENABLED - for (int i = 0; i < BLE_LOG_LBM_LL_MAX; i++) { - lbm = &(lbm_ctx->lbm_ll_pool[i]); - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - if (!ble_log_prph_trans_init(&(lbm->trans[j]), - BLE_LOG_TRANS_LL_SIZE)) { - goto exit; - } - lbm->trans[j]->owner = (void *)lbm; - } - } - - /* Initialize lock types for LL pool */ - for (int i = 0; i < BLE_LOG_LBM_LL_MAX; i++) { - lbm_ctx->lbm_ll_pool[i].lock_type = BLE_LOG_LBM_LOCK_NONE; - } -#endif /* CONFIG_BLE_LOG_LL_ENABLED */ - - /* Initialize statistic manager context */ - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - stat_mgr_ctx[i] = (ble_log_stat_mgr_t *)BLE_LOG_MALLOC(sizeof(ble_log_stat_mgr_t)); - if (!stat_mgr_ctx[i]) { - goto exit; - } - BLE_LOG_MEMSET(stat_mgr_ctx[i], 0, sizeof(ble_log_stat_mgr_t)); - } - - /* Initialization done */ - BLE_LOG_ATOMIC_STORE_RELAXED(lbm_enabled, false); - BLE_LOG_ATOMIC_STORE_RELEASE(lbm_inited, true); - return true; - -exit: - ble_log_lbm_deinit(); - return false; -} - -void ble_log_lbm_close(void) -{ - BLE_LOG_ATOMIC_STORE_SEQ_CST(lbm_inited, false); - BLE_LOG_ATOMIC_STORE_RELEASE(lbm_enabled, false); -} - -void ble_log_lbm_deinit(void) -{ - /* Close before waiting: every LBM entry increments the reference count - * before checking this seq_cst gate. */ - ble_log_lbm_close(); - - /* Disable module and wait for all references to be released */ - while (!ble_log_ref_count_wait(&lbm_ref_count, 0)) { - ESP_LOGE(TAG, "Timed out waiting for BLE Log references during deinit"); - BLE_LOG_ASSERT(false); - } - - /* Release statistic manager context */ - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - if (stat_mgr_ctx[i]) { - BLE_LOG_FREE(stat_mgr_ctx[i]); - stat_mgr_ctx[i] = NULL; - } - } - - /* Release LBM */ - if (lbm_ctx) { - /* Release peripheral transport for common pools */ - ble_log_lbm_t *lbm; - for (int i = 0; i < BLE_LOG_LBM_CNT; i++) { - lbm = &(lbm_ctx->lbm_pool[i]); - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - ble_log_prph_trans_deinit(&(lbm->trans[j])); - } - } - - /* Release LBM context */ - BLE_LOG_FREE(lbm_ctx); - lbm_ctx = NULL; - } -} - -BLE_LOG_IRAM_ATTR BLE_LOG_STATIC -ble_log_prph_trans_t **ble_log_lbm_get_trans(ble_log_lbm_t *lbm, size_t log_len) -{ - /* Check if available buffer can contain incoming log */ - ble_log_prph_trans_t **trans; - for (int i = 0; i < BLE_LOG_TRANS_BUF_CNT; i++) { - trans = &(lbm->trans[lbm->trans_idx]); - if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE((*trans)->prph_owned)) { - /* Return if there's enough free space in current transport */ - if (BLE_LOG_TRANS_FREE_SPACE((*trans)) >= (log_len + BLE_LOG_FRAME_OVERHEAD)) { - return trans; - } - - /* Queue transport if there's insufficient free space */ - if ((*trans)->pos) { - ble_log_lbm_submit_trans(trans); - } - } - - /* Current transport unavailable, switch to the other */ - lbm->trans_idx = (lbm->trans_idx + 1) & (BLE_LOG_TRANS_BUF_CNT - 1); - } - - /* All buffers are unavailable */ - return NULL; -} - -void ble_log_write_enh_stat(void) -{ - if (!ble_log_lbm_ref_acquire(true)) { - return; - } - - /* Snapshot all sources under one critical section so the set of - * counters is mutually consistent, then write outside the lock. */ - ble_log_enh_stat_t snapshots[BLE_LOG_SRC_MAX]; - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - snapshots[i].int_src_code = BLE_LOG_INT_SRC_ENH_STAT; - snapshots[i].src_code = i; - } - BLE_LOG_ENTER_CRITICAL(); - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - BLE_LOG_MEMCPY(&snapshots[i].written_frame_cnt, - &stat_mgr_ctx[i]->written_frame_cnt, - 4 * sizeof(uint32_t)); - } - BLE_LOG_EXIT_CRITICAL(); - - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - ble_log_write_hex(BLE_LOG_SRC_INTERNAL, (const uint8_t *)&snapshots[i], sizeof(ble_log_enh_stat_t)); - } - - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); -} - -#if BLE_LOG_UART_REDIR_ENABLED -/* ------------------------------------------------- */ -/* STREAM WRITE INTERFACE */ -/* */ -/* Stream mode appends raw data into a transport */ -/* buffer with deferred frame encapsulation: */ -/* - Header space is reserved on first write */ -/* - Data is memcpy'd after the reserved header */ -/* - Header and checksum are filled in at seal */ -/* */ -/* get_trans(lbm, 0) reuse safety: */ -/* */ -/* get_trans auto-queues a buffer raw (no seal) when */ -/* free_space < log_len + FRAME_OVERHEAD. With */ -/* log_len = 0, this triggers at free_space < 10. */ -/* */ -/* To prevent unsealed stream data from being sent */ -/* raw, stream_write auto-seals at free_space <= 10. */ -/* This guarantees that any unsealed stream buffer */ -/* seen by get_trans always has free_space > 10, */ -/* so get_trans returns it directly without queuing. */ -/* ------------------------------------------------- */ -BLE_LOG_IRAM_ATTR -void ble_log_lbm_stream_write(ble_log_lbm_t *lbm, ble_log_src_t src_code, - const uint8_t *data, size_t len) -{ - while (len > 0) { - ble_log_prph_trans_t **trans = ble_log_lbm_get_trans(lbm, 0); - if (!trans) { - ble_log_stat_mgr_update(src_code, len, true); - return; - } - - if ((*trans)->pos == 0) { - (*trans)->pos = BLE_LOG_FRAME_HEAD_LEN; - } - - uint16_t available = BLE_LOG_TRANS_FREE_SPACE((*trans)); - if (available <= BLE_LOG_FRAME_TAIL_LEN) { - ble_log_lbm_stream_seal(trans, src_code); - continue; - } - available -= BLE_LOG_FRAME_TAIL_LEN; - - size_t to_write = (len < available) ? len : available; - BLE_LOG_MEMCPY((*trans)->buf + (*trans)->pos, data, to_write); - (*trans)->pos += to_write; - data += to_write; - len -= to_write; - - if (BLE_LOG_TRANS_FREE_SPACE((*trans)) <= BLE_LOG_FRAME_OVERHEAD) { - ble_log_lbm_stream_seal(trans, src_code); - } - } -} - -BLE_LOG_IRAM_ATTR -void ble_log_lbm_stream_flush(ble_log_lbm_t *lbm, ble_log_src_t src_code) -{ - int trans_idx = lbm->trans_idx; - for (int i = 0; i < BLE_LOG_TRANS_BUF_CNT; i++) { - ble_log_prph_trans_t **trans = &(lbm->trans[trans_idx]); - if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE((*trans)->prph_owned) && - (*trans)->pos > BLE_LOG_FRAME_HEAD_LEN) { - ble_log_lbm_stream_seal(trans, src_code); - } - trans_idx = (trans_idx + 1) & (BLE_LOG_TRANS_BUF_CNT - 1); - } -} -#endif /* BLE_LOG_UART_REDIR_ENABLED */ - -BLE_LOG_STATIC void ble_log_emit_buf_util(ble_log_lbm_t *lbm, uint8_t lbm_id) -{ - ble_log_buf_util_t util = { - .int_src_code = BLE_LOG_INT_SRC_BUF_UTIL, - .lbm_id = lbm_id, - .trans_cnt = BLE_LOG_TRANS_BUF_CNT, - .inflight_peak = (uint8_t)__atomic_load_n(&lbm->trans_inflight_peak, - __ATOMIC_RELAXED), - }; - ble_log_write_hex(BLE_LOG_SRC_INTERNAL, - (const uint8_t *)&util, sizeof(ble_log_buf_util_t)); -} - -void ble_log_write_buf_util(void) -{ - if (!ble_log_lbm_ref_acquire(true)) { - return; - } - - ble_log_emit_buf_util(&lbm_ctx->spin_task, - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_COMMON_TASK, 0)); - for (int i = 0; i < BLE_LOG_LBM_ATOMIC_TASK_CNT; i++) { - ble_log_emit_buf_util(&lbm_ctx->atomic_pool_task[i], - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_COMMON_TASK, 1 + i)); - } - - ble_log_emit_buf_util(&lbm_ctx->spin_isr, - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_COMMON_ISR, 0)); - for (int i = 0; i < BLE_LOG_LBM_ATOMIC_ISR_CNT; i++) { - ble_log_emit_buf_util(&lbm_ctx->atomic_pool_isr[i], - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_COMMON_ISR, 1 + i)); - } - -#if CONFIG_BLE_LOG_LL_ENABLED - ble_log_emit_buf_util(&lbm_ctx->lbm_ll_task, - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_LL, 0)); - ble_log_emit_buf_util(&lbm_ctx->lbm_ll_hci, - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_LL, 1)); -#endif - -#if BLE_LOG_UART_REDIR_ENABLED - ble_log_lbm_t *redir_lbm = ble_log_prph_get_redir_lbm(); - if (redir_lbm) { - ble_log_emit_buf_util(redir_lbm, - BLE_LOG_BUF_UTIL_MAKE_ID(BLE_LOG_BUF_UTIL_POOL_REDIR, 0)); - } -#endif - - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); -} - -void ble_log_write_final_stat(void) -{ - if (!ble_log_lbm_ref_acquire(false)) { - return; - } - - ble_log_final_stat_t final_stat; - final_stat.int_src_code = BLE_LOG_INT_SRC_FINAL_STAT; - final_stat.src_cnt = BLE_LOG_SRC_MAX; - - BLE_LOG_ENTER_CRITICAL(); - for (int i = 0; i < BLE_LOG_SRC_MAX; i++) { - ble_log_final_stat_entry_t *entry = &final_stat.entries[i]; - entry->src_code = i; - BLE_LOG_MEMCPY(&entry->written_frame_cnt, - &stat_mgr_ctx[i]->written_frame_cnt, - 4 * sizeof(uint32_t)); - } - BLE_LOG_EXIT_CRITICAL(); - - ble_log_write_internal((const uint8_t *)&final_stat, sizeof(final_stat)); - - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); -} - -/* ------------------------ */ -/* PUBLIC INTERFACE */ -/* ------------------------ */ -bool ble_log_enable(bool enable) -{ - if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_inited)) { - return false; - } - BLE_LOG_ATOMIC_STORE_RELEASE(lbm_enabled, enable); - return true; -} - -void ble_log_flush(void) -{ - /* Prevent concurrent flush — two concurrent callers would deadlock on - * the ref_count spin-wait (both hold a ref, both wait for ref_count <= 1). - * Second caller returns immediately instead of deadlocking. */ - if (__atomic_test_and_set(&flush_in_progress, __ATOMIC_ACQUIRE)) { - return; - } - - if (!ble_log_lbm_ref_acquire(false)) { - goto clear; - } - ble_log_write_enh_stat(); - ble_log_write_buf_util(); - - /* Write BLE Log flush log */ - ble_log_info_t ble_log_info = { - .int_src_code = BLE_LOG_INT_SRC_FLUSH, - .version = BLE_LOG_VERSION, - }; - ble_log_write_hex(BLE_LOG_SRC_INTERNAL, (const uint8_t *)&ble_log_info, sizeof(ble_log_info_t)); - - /* Disable module and wait for all other references to release */ - bool lbm_enabled_copy = BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_enabled); - - BLE_LOG_ATOMIC_STORE_RELEASE(lbm_enabled, false); - if (!ble_log_ref_count_wait(&lbm_ref_count, 1)) { - ESP_LOGE(TAG, "Timed out waiting for BLE Log writers"); - goto fail; - } - - if (!ble_log_lbm_flush_all_trans()) { - goto fail; - } - - ble_log_write_final_stat(); - - if (!ble_log_lbm_flush_all_trans()) { - goto fail; - } - ble_log_lbm_reset_stats(); - -fail: - /* Resume enable status after a completed or failed flush. */ - BLE_LOG_ATOMIC_STORE_RELEASE(lbm_enabled, lbm_enabled_copy); - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); -clear: - __atomic_clear(&flush_in_progress, __ATOMIC_RELEASE); -} - -BLE_LOG_IRAM_ATTR -bool ble_log_write_hex(ble_log_src_t src_code, const uint8_t *addr, size_t len) -{ - bool ret = false; - - if (!ble_log_lbm_ref_acquire(true)) { - return false; - } - - ret = ble_log_write_hex_core(src_code, addr, len); - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return ret; -} - -BLE_LOG_IRAM_ATTR -bool ble_log_write_internal(const uint8_t *addr, size_t len) -{ - bool ret = false; - - if (!ble_log_lbm_ref_acquire(false)) { - return false; - } - - ret = ble_log_write_hex_core(BLE_LOG_SRC_INTERNAL, addr, len); - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return ret; -} - -#if CONFIG_BLE_LOG_LL_ENABLED -BLE_LOG_IRAM_ATTR -void ble_log_write_hex_ll(uint32_t len, const uint8_t *addr, - uint32_t len_append, const uint8_t *addr_append, uint32_t flag) -{ - if (!ble_log_lbm_ref_acquire(true)) { - return; - } - - /* Source code shall be determined before LBM determination */ - ble_log_src_t src_code = BLE_LOG_SRC_MAX; - bool use_ll_task = false; - if (flag & BIT(BLE_LOG_LL_FLAG_ISR)) { - src_code = BLE_LOG_SRC_LL_ISR; - } else if (flag & BIT(BLE_LOG_LL_FLAG_HCI)) { - src_code = BLE_LOG_SRC_LL_HCI; - } else if (flag & BIT(BLE_LOG_LL_FLAG_HCI_UPSTREAM)) { - src_code = BLE_LOG_SRC_HCI; - } else { - src_code = BLE_LOG_SRC_LL_TASK; - use_ll_task = true; - } - bool omdata = flag & BIT(BLE_LOG_LL_FLAG_OMDATA); - - /* Determine LBM and get transport */ - ble_log_lbm_t *lbm; - ble_log_prph_trans_t **trans; - size_t payload_len; - - if (BLE_LOG_IN_ISR()) { - /* os_mbuf_copydata is in flash and not safe to call from ISR */ - omdata = false; - - payload_len = len + len_append; - if (!ble_log_lbm_acquire_trans(payload_len, &lbm, &trans)) { - goto failed; - } - } else { - if (use_ll_task) { - lbm = &(lbm_ctx->lbm_ll_task); - } else { - lbm = &(lbm_ctx->lbm_ll_hci); -#if CONFIG_BLE_LOG_LL_HCI_LOG_PAYLOAD_LEN_LIMIT_ENABLED - if (len_append > CONFIG_BLE_LOG_LL_HCI_LOG_PAYLOAD_LEN_LIMIT) { - len_append = CONFIG_BLE_LOG_LL_HCI_LOG_PAYLOAD_LEN_LIMIT; - } -#endif /* CONFIG_BLE_LOG_LL_HCI_LOG_PAYLOAD_LEN_LIMIT_ENABLED */ - } - payload_len = len + len_append; - trans = ble_log_lbm_get_trans(lbm, payload_len); - if (!trans) { - /* LL pools use LOCK_NONE, release is no-op */ - goto failed; - } - } - - /* Write transport */ - ble_log_lbm_write_trans(trans, src_code, addr, len, addr_append, len_append, omdata); - - ble_log_lbm_release(lbm); - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return; - -failed: - if (BLE_LOG_ATOMIC_LOAD_RELAXED(lbm_inited)) { - ble_log_stat_mgr_update(src_code, payload_len, true); - } - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return; -} -#endif /* CONFIG_BLE_LOG_LL_ENABLED */ - -void ble_log_dump_to_console(void) -{ - if (!ble_log_lbm_ref_acquire(false)) { - return; - } - - int trans_idx; - ble_log_lbm_t *lbm; - ble_log_prph_trans_t *trans; - BLE_LOG_ENTER_CRITICAL(); - BLE_LOG_CONSOLE("[BLE_LOG_DUMP_START:\n"); - for (int i = 0; i < BLE_LOG_LBM_CNT; i++) { - lbm = &(lbm_ctx->lbm_pool[i]); - trans_idx = lbm->trans_idx; - for (int j = 0; j < BLE_LOG_TRANS_BUF_CNT; j++) { - trans = lbm->trans[trans_idx]; - BLE_LOG_FEED_WDT(); - - for (int k = 0; k < trans->size; k++) { - BLE_LOG_CONSOLE("%02x ", trans->buf[k]); - if (!(k & 0xFF)) { - BLE_LOG_FEED_WDT(); - } - } - trans_idx = (trans_idx + 1) & (BLE_LOG_TRANS_BUF_CNT - 1); - } - } - BLE_LOG_CONSOLE("\n:BLE_LOG_DUMP_END]\n\n"); - BLE_LOG_EXIT_CRITICAL(); - - BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); - return; -} diff --git a/components/bt/common/ble_log/src/ble_log_lbm_v2.c b/components/bt/common/ble_log/src/ble_log_lbm_v2.c index c17264de38d..092596489f4 100644 --- a/components/bt/common/ble_log/src/ble_log_lbm_v2.c +++ b/components/bt/common/ble_log/src/ble_log_lbm_v2.c @@ -13,6 +13,7 @@ #include "ble_log_rt.h" #include "esp_timer.h" +#include "esp_chip_info.h" #if CONFIG_BLE_LOG_LL_ENABLED && CONFIG_SOC_ESP_NIMBLE_CONTROLLER #if CONFIG_BT_DUAL_MODE_ARCH @@ -35,6 +36,34 @@ /* Single-instruction clock read; a function would add an IRAM call site. */ #define BLE_LOG_TIMESTAMP_NOW() ((uint32_t)esp_timer_get_time()) +#if CONFIG_BT_CONTROLLER_ENABLED +#if CONFIG_IDF_TARGET_ESP32 || CONFIG_IDF_TARGET_ESP32C3 || CONFIG_IDF_TARGET_ESP32S3 +extern const char *btdm_controller_get_compile_version(void); +#define BLE_LOG_CONTROLLER_GET_COMMIT() btdm_controller_get_compile_version() +#elif !CONFIG_BT_DUAL_MODE_ARCH || CONFIG_BT_CTRL_BLE_ENABLE +/* BR/EDR-only dual-mode builds do not link the BLE controller lib */ +extern char *ble_controller_get_compile_version(void); +#define BLE_LOG_CONTROLLER_GET_COMMIT() ble_controller_get_compile_version() +#endif +#if CONFIG_BT_DUAL_MODE_ARCH +/* BTDM common lib (dual-mode arch only) */ +extern const char *r_btdm_get_compile_version(void); +#define BLE_LOG_BTDM_COMMON_GET_COMMIT() r_btdm_get_compile_version() +#endif +#endif + +#if CONFIG_BLE_MESH && CONFIG_BLE_MESH_V11_SUPPORT +/* "Bluetooth Mesh v1.1 commit: " */ +extern const char bt_mesh_v11_commit_str[]; +#endif + +#if CONFIG_BT_AUDIO && CONFIG_SOC_BLE_AUDIO_SUPPORTED +extern const char *lib_audio_commit_get(void); +#endif + +_Static_assert(sizeof(ble_log_version_info_t) == 58, + "Unexpected BLE Log version info frame size"); + /* ------------------------------- */ /* Global Pool Context */ /* ------------------------------- */ @@ -77,6 +106,8 @@ typedef struct { } ble_log_pool_claim_t; /* VARIABLE */ +/* Process-lifetime count: a caller rejected by a closed gate may still owe + * its balancing release when the next LBM epoch starts. Never reset it. */ BLE_LOG_STATIC BLE_LOG_DRAM_ATTR volatile uint32_t lbm_ref_count = 0; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t lbm_inited = 0; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t lbm_enabled = 0; @@ -98,6 +129,7 @@ extern void ble_log_test_claim_pre_publish_hook(void) __attribute__((weak)); extern void ble_log_test_enable_before_lifecycle_lock_hook(void) __attribute__((weak)); extern void ble_log_test_disable_before_wake_hook(void) __attribute__((weak)); extern void ble_log_test_claim_locked_hook(void) __attribute__((weak)); +extern void ble_log_test_init_snapshot_before_acquire_hook(void) __attribute__((weak)); #endif BLE_LOG_IRAM_ATTR BLE_LOG_STATIC @@ -114,6 +146,7 @@ BLE_LOG_STATIC ble_log_prph_trans_t *ble_log_pool_acquire(size_t log_len, bool use_reserve, bool wait); BLE_LOG_STATIC void ble_log_pool_seal_and_send(ble_log_prph_trans_t *trans); +BLE_LOG_STATIC void ble_log_pool_seal_open_trans(void); BLE_LOG_STATIC void ble_log_pool_write_frame(ble_log_prph_trans_t *trans, uint32_t frame_sn, uint8_t source_meta, @@ -122,10 +155,14 @@ BLE_LOG_STATIC void ble_log_pool_write_frame(ble_log_prph_trans_t *trans, const uint8_t *addr, uint16_t len, const uint8_t *addr_append, uint16_t len_append, bool omdata); +BLE_LOG_STATIC void ble_log_pool_finish_frame(ble_log_prph_trans_t *trans, + uint16_t payload_len, + ble_log_stat_mgr_t *stat_mgr); BLE_LOG_STATIC void ble_log_stat_mgr_mark_lost(ble_log_src_t src_code); BLE_LOG_STATIC void ble_log_snapshot_stats(ble_log_source_stat_t *snapshots); BLE_LOG_STATIC bool ble_log_pool_flush_all_trans(void); BLE_LOG_STATIC void ble_log_pool_wake_all(void); +BLE_LOG_STATIC void ble_log_internal_version_info_init(void); /* ------------------------- */ /* BITMAP HELPERS */ @@ -151,11 +188,7 @@ ble_log_pool_update_peak(uint32_t free_bitmap) { uint32_t used = BLE_LOG_POOL_TRANS_CNT - __builtin_popcount(free_bitmap & BLE_LOG_POOL_ALL_MASK); - uint32_t peak = BLE_LOG_ATOMIC_LOAD_RELAXED(g_pool.inflight_peak); - while (used > peak && - !__atomic_compare_exchange_n(&g_pool.inflight_peak, &peak, used, true, - __ATOMIC_RELAXED, __ATOMIC_RELAXED)) { - } + ble_log_atomic_update_peak(&g_pool.inflight_peak, used); } /* A newly available shared transport satisfies one waiter. The SEQ_CST fence @@ -212,6 +245,19 @@ BLE_LOG_STATIC void ble_log_pool_wake_all(void) } } +/* Waiter registration is one atomic RMW with ACQ_REL on both sides of the + * park: the register must be visible to a concurrent gate close before the + * task blocks, and the unregister must pair with the wake that released + * it. The RMW is a CAS loop plus barrier on Xtensa (several instructions), + * so it lives here once instead of at the four call sites of the IRAM + * acquire path. delta is +1 or -1. */ +BLE_LOG_IRAM_ATTR BLE_LOG_STATIC void +ble_log_pool_waiter_adjust(int delta) +{ + __atomic_add_fetch(&g_pool.waiting_task_count, (uint32_t)delta, + __ATOMIC_ACQ_REL); +} + /* -------------------------------------- */ /* UNIFIED TRANSPORT RECYCLE */ /* -------------------------------------- */ @@ -264,6 +310,27 @@ BLE_LOG_IRAM_ATTR void ble_log_pool_seal_and_send(ble_log_prph_trans_t *trans) ble_log_rt_submit_trans(trans); } +/* Seals every OPEN transport in the pool. Caller contract: writers are + * gone (producer gate closed and drained), so each lock is uncontended + * and the acquire waits are bounded. */ +BLE_LOG_STATIC void ble_log_pool_seal_open_trans(void) +{ + for (int id = 0; id < BLE_LOG_POOL_TRANS_CNT; id++) { + if (!(BLE_LOG_ATOMIC_LOAD_ACQUIRE(g_pool.open_bitmap) & BIT(id))) { + continue; + } + ble_log_prph_trans_t *trans = g_pool.trans[id]; + while (!BLE_LOG_CAS_ACQUIRE(&trans->atomic_lock)) { + } + if (BLE_LOG_ATOMIC_LOAD_RELAXED(trans->state) == BLE_LOG_TRANS_STATE_OPEN && + trans->pos > 0) { + ble_log_pool_seal_and_send(trans); /* releases the lock */ + } else { + BLE_LOG_CAS_RELEASE(&trans->atomic_lock); + } + } +} + /* -------------------------------------- */ /* AVAILABLE BUFFER CLAIM */ /* -------------------------------------- */ @@ -399,16 +466,16 @@ ble_log_prph_trans_t *ble_log_pool_acquire(size_t log_len, return trans; } - __atomic_add_fetch(&g_pool.waiting_task_count, 1, __ATOMIC_ACQ_REL); + ble_log_pool_waiter_adjust(1); __atomic_thread_fence(__ATOMIC_SEQ_CST); trans = ble_log_pool_try_claim_available(frame_len, use_reserve); if (trans) { - __atomic_sub_fetch(&g_pool.waiting_task_count, 1, __ATOMIC_ACQ_REL); + ble_log_pool_waiter_adjust(-1); return trans; } if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_enabled)) { - __atomic_sub_fetch(&g_pool.waiting_task_count, 1, __ATOMIC_ACQ_REL); + ble_log_pool_waiter_adjust(-1); return NULL; } @@ -417,7 +484,7 @@ ble_log_prph_trans_t *ble_log_pool_acquire(size_t log_len, BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); xSemaphoreTake(g_pool.sem, portMAX_DELAY); BLE_LOG_REF_COUNT_ACQUIRE_SEQ_CST(&lbm_ref_count); - __atomic_sub_fetch(&g_pool.waiting_task_count, 1, __ATOMIC_ACQ_REL); + ble_log_pool_waiter_adjust(-1); if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_enabled)) { return NULL; @@ -466,11 +533,21 @@ void ble_log_pool_write_frame(ble_log_prph_trans_t *trans, uint32_t frame_sn, BLE_LOG_MEMCPY(payload, addr_append, len_append); } } - /* Data integrity check */ - uint32_t checksum = ble_log_fast_checksum((const uint8_t *)buf, BLE_LOG_FRAME_HEAD_LEN + payload_len); + /* Data integrity check, transport update and completion. */ + ble_log_pool_finish_frame(trans, payload_len, stat_mgr); +} + +/* Completes a frame whose head and payload are already in place at + * trans->pos: writes the checksum tail, advances pos, publishes the + * written-frame stat, then seals or publishes the transport. */ +BLE_LOG_IRAM_ATTR BLE_LOG_STATIC +void ble_log_pool_finish_frame(ble_log_prph_trans_t *trans, uint16_t payload_len, + ble_log_stat_mgr_t *stat_mgr) +{ + uint8_t *buf = trans->buf + trans->pos; + uint32_t checksum = ble_log_fast_checksum(buf, BLE_LOG_FRAME_HEAD_LEN + payload_len); BLE_LOG_MEMCPY(buf + BLE_LOG_FRAME_HEAD_LEN + payload_len, &checksum, BLE_LOG_FRAME_TAIL_LEN); - /* Update transport and publish the completed core-stat record. */ trans->pos += payload_len + BLE_LOG_FRAME_OVERHEAD; BLE_LOG_ATOMIC_ADD_RELAXED(stat_mgr->counters.written_frame_cnt, 1); @@ -556,13 +633,12 @@ void ble_log_commit(uint32_t handle, size_t actual_len) if (actual_len == 0 || actual_len > claim->max_len) { ble_log_stat_mgr_mark_lost(src_code); if (trans->pos == 0) { - /* Returning straight to FREE bypasses seal_and_send: also drop - * any pending-seal marker here. */ - BLE_LOG_ATOMIC_STORE_RELAXED(trans->pending_seal, false); - BLE_LOG_ATOMIC_STORE_RELEASE(trans->state, BLE_LOG_TRANS_STATE_FREE); - ble_log_pool_bitmap_set(&g_pool.free_bitmap, trans->id); + /* Returning straight to FREE: recycle covers pos, pending_seal, + * state, the free-bitmap hint and the waiter wake. The transport + * is in no bitmap while CLAIMED, so releasing the lock first + * keeps it invisible to scanners until recycle publishes it. */ BLE_LOG_CAS_RELEASE(&trans->atomic_lock); - ble_log_pool_notify_waiter(trans->id); + ble_log_lbm_recycle_trans(trans); } else { ble_log_pool_publish_open_and_unlock(trans); } @@ -571,7 +647,6 @@ void ble_log_commit(uint32_t handle, size_t actual_len) } uint16_t payload_len = (uint16_t)(sizeof(uint32_t) + actual_len); - uint8_t *buf = trans->buf + trans->pos; ble_log_stat_mgr_t *stat_mgr = &stat_mgr_ctx[src_code]; uint8_t source_meta = BLE_LOG_MAKE_SOURCE_META(src_code, claim->non_yield); @@ -579,21 +654,9 @@ void ble_log_commit(uint32_t handle, size_t actual_len) .length = payload_len, .frame_meta = BLE_LOG_MAKE_FRAME_META(source_meta, claim->frame_sn), }; - BLE_LOG_MEMCPY(buf, &frame_head, BLE_LOG_FRAME_HEAD_LEN); + BLE_LOG_MEMCPY(trans->buf + trans->pos, &frame_head, BLE_LOG_FRAME_HEAD_LEN); + ble_log_pool_finish_frame(trans, payload_len, stat_mgr); - uint32_t checksum = ble_log_fast_checksum(buf, - BLE_LOG_FRAME_HEAD_LEN + payload_len); - BLE_LOG_MEMCPY(buf + BLE_LOG_FRAME_HEAD_LEN + payload_len, - &checksum, BLE_LOG_FRAME_TAIL_LEN); - - trans->pos += payload_len + BLE_LOG_FRAME_OVERHEAD; - BLE_LOG_ATOMIC_ADD_RELAXED(stat_mgr->counters.written_frame_cnt, 1); - - if (BLE_LOG_TRANS_FREE_SPACE(trans) <= BLE_LOG_FRAME_OVERHEAD) { - ble_log_pool_seal_and_send(trans); - } else { - ble_log_pool_publish_open_and_unlock(trans); - } BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); } @@ -628,16 +691,13 @@ bool ble_log_lbm_init(void) goto exit; } - /* Allocate the transport buffers of the global pool. */ + /* Allocate the transport buffers of the global pool. trans_init zeroes + * the storage, so only the non-zero identity fields need setting. */ for (int id = 0; id < BLE_LOG_POOL_TRANS_CNT; id++) { if (!ble_log_prph_trans_init(&(g_pool.trans[id]), BLE_LOG_POOL_TRANS_SIZE)) { goto exit; } g_pool.trans[id]->id = (uint8_t)id; - g_pool.trans[id]->owner_kind = BLE_LOG_TRANS_OWNER_POOL; - g_pool.trans[id]->state = BLE_LOG_TRANS_STATE_FREE; - g_pool.trans[id]->atomic_lock = 0; - g_pool.trans[id]->pending_seal = 0; } if (!ble_log_prph_trans_init(&internal_trans, BLE_LOG_INTERNAL_TRANS_SIZE)) { @@ -645,8 +705,6 @@ bool ble_log_lbm_init(void) } internal_trans->id = BLE_LOG_TRANS_ID_NONE; internal_trans->owner_kind = BLE_LOG_TRANS_OWNER_INTERNAL; - internal_trans->state = BLE_LOG_TRANS_STATE_FREE; - internal_trans->atomic_lock = 0; g_pool.free_bitmap = BLE_LOG_POOL_ALL_MASK; g_pool.open_bitmap = 0; @@ -657,8 +715,8 @@ bool ble_log_lbm_init(void) internal_snapshot.int_src_code = BLE_LOG_INT_SRC_SNAPSHOT; internal_snapshot.pool.trans_cnt = BLE_LOG_POOL_TRANS_CNT; internal_snapshot.pool.non_yield_reserve_cnt = BLE_LOG_POOL_NON_YIELD_RESERVE_CNT; + ble_log_internal_version_info_init(); - lbm_ref_count = 0; BLE_LOG_ATOMIC_STORE_RELEASE(lbm_enabled, false); BLE_LOG_ATOMIC_STORE_RELEASE(lbm_inited, true); return true; @@ -692,7 +750,10 @@ void ble_log_lbm_begin_deinit(void) __attribute__((noinline)) BLE_LOG_STATIC void ble_log_snapshot_stats(ble_log_source_stat_t *snapshots) { - BLE_LOG_ENTER_CRITICAL(); + /* The counter writers (claim/commit/write_hex_ll, some in IRAM/ISR + * context) use relaxed atomics and never take the spinlock, so an + * exclusive section here would exclude nobody. The relaxed loads + * are the whole protection. */ for (int i = 0; i < BLE_LOG_SRC_CORE_COUNT; i++) { ble_log_stat_mgr_t *stat_mgr = &stat_mgr_ctx[BLE_LOG_SRC_CORE_FIRST + i]; @@ -701,7 +762,6 @@ void ble_log_snapshot_stats(ble_log_source_stat_t *snapshots) snapshots[i].lost_frame_cnt = BLE_LOG_ATOMIC_LOAD_RELAXED(stat_mgr->counters.lost_frame_cnt); } - BLE_LOG_EXIT_CRITICAL(); } void ble_log_lbm_deinit(void) @@ -724,30 +784,71 @@ bool ble_log_lbm_is_enabled(void) return BLE_LOG_ATOMIC_LOAD_ACQUIRE(lbm_enabled); } -void ble_log_internal_set_version_info(const ble_log_version_info_t *version_info) +/* Copies a NUL-terminated commit string into a fixed-width zero-padded field */ +BLE_LOG_STATIC void ble_log_commit_copy(uint8_t *dst, const char *src, size_t len) { - if (version_info) { - BLE_LOG_MEMCPY(&internal_snapshot.version_info, version_info, - sizeof(*version_info)); + BLE_LOG_MEMCPY(dst, src, strnlen(src, len)); +} + +/* Fills the version-info record carried by internal snapshots, in place: + * no intermediate copy. ble_log_lbm_init zeroes internal_snapshot first. */ +BLE_LOG_STATIC void ble_log_internal_version_info_init(void) +{ + ble_log_version_info_t *vi = &internal_snapshot.version_info; + vi->int_src_code = BLE_LOG_INT_SRC_VERSION_INFO; + vi->version = BLE_LOG_VERSION; +#ifdef BLE_LOG_IDF_COMMIT + BLE_LOG_MEMCPY(vi->idf_commit, BLE_LOG_IDF_COMMIT, + BLE_LOG_IDF_COMMIT_LEN); +#endif +#if CONFIG_BT_CONTROLLER_ENABLED && defined(BLE_LOG_CONTROLLER_GET_COMMIT) + ble_log_commit_copy(vi->controller_commit, + BLE_LOG_CONTROLLER_GET_COMMIT(), BLE_LOG_LIB_COMMIT_LEN); +#endif +#if CONFIG_BT_CONTROLLER_ENABLED && defined(BLE_LOG_BTDM_COMMON_GET_COMMIT) + ble_log_commit_copy(vi->btdm_common_commit, + BLE_LOG_BTDM_COMMON_GET_COMMIT(), BLE_LOG_LIB_COMMIT_LEN); +#endif +#if CONFIG_BLE_MESH && CONFIG_BLE_MESH_V11_SUPPORT + const char *mesh_commit = strrchr(bt_mesh_v11_commit_str, ' '); + if (mesh_commit) { + ble_log_commit_copy(vi->mesh_commit, mesh_commit + 1, + BLE_LOG_LIB_COMMIT_LEN); } +#endif +#if CONFIG_BT_AUDIO && CONFIG_SOC_BLE_AUDIO_SUPPORTED + ble_log_commit_copy(vi->audio_commit, lib_audio_commit_get(), + BLE_LOG_LIB_COMMIT_LEN); +#endif + esp_chip_info_t chip_info; + esp_chip_info(&chip_info); + vi->chip_model = (uint16_t)chip_info.model; + vi->chip_revision = chip_info.revision; } bool ble_log_internal_snapshot(uint16_t reason_flags, const ble_log_ts_info_t *ts_info, - bool required) + bool wait_for_transport) { - const uint32_t *gate = required ? &lbm_inited : &lbm_enabled; - if (!ble_log_ref_count_try_acquire(&lbm_ref_count, gate)) { +#if CONFIG_BLE_LOG_PRPH_TEST + if ((reason_flags & BLE_LOG_SNAPSHOT_REASON_INIT) && + ble_log_test_init_snapshot_before_acquire_hook) { + ble_log_test_init_snapshot_before_acquire_hook(); + } +#endif + /* Internal Snapshots are system output and outlive the public producer + * gate. Only LBM teardown stops new snapshots. */ + if (!ble_log_ref_count_try_acquire(&lbm_ref_count, &lbm_inited)) { return false; } if (!internal_trans) { goto failed; } - /* Capture the complete occurrence sample before any dedicated-buffer - * drain or wait. Without a TS sync sample, esp_ts comes from the frame - * timestamp and os_ts from the current tick. */ - uint32_t timestamp = ts_info ? ts_info->esp_ts : BLE_LOG_TIMESTAMP_NOW(); + /* The caller sampled the clocks (with or without a sync IO toggle) + * before any dedicated-buffer drain or wait; the frame timestamp is + * that sample's esp_ts. */ + uint32_t timestamp = ts_info->esp_ts; TickType_t start_tick = xTaskGetTickCount(); for (;;) { if (BLE_LOG_CAS_ACQUIRE(&internal_trans->atomic_lock)) { @@ -757,7 +858,7 @@ bool ble_log_internal_snapshot(uint16_t reason_flags, } BLE_LOG_CAS_RELEASE(&internal_trans->atomic_lock); } - if (!required || + if (!wait_for_transport || (xTaskGetTickCount() - start_tick) >= BLE_LOG_WAIT_TIMEOUT_TICKS) { goto lost; } @@ -766,11 +867,10 @@ bool ble_log_internal_snapshot(uint16_t reason_flags, } internal_snapshot.reason_flags = reason_flags; - internal_snapshot.ts.io_level = ts_info ? ts_info->io_level : 0; - internal_snapshot.ts.lc_ts = ts_info ? ts_info->lc_ts : 0; + internal_snapshot.ts.io_level = ts_info->io_level; + internal_snapshot.ts.lc_ts = ts_info->lc_ts; internal_snapshot.ts.esp_ts = timestamp; - internal_snapshot.ts.os_ts = ts_info ? ts_info->os_ts - : pdTICKS_TO_MS(xTaskGetTickCount()); + internal_snapshot.ts.os_ts = ts_info->os_ts; uint32_t free_bitmap = BLE_LOG_ATOMIC_LOAD_ACQUIRE(g_pool.free_bitmap) & BLE_LOG_POOL_ALL_MASK; internal_snapshot.pool.inflight = @@ -815,19 +915,7 @@ BLE_LOG_STATIC bool ble_log_pool_flush_all_trans(void) { /* New writes are disabled, so every held lock will be released after its * current frame copy. Seal every remaining OPEN transport. */ - for (int id = 0; id < BLE_LOG_POOL_TRANS_CNT; id++) { - ble_log_prph_trans_t *trans = g_pool.trans[id]; - while (!BLE_LOG_CAS_ACQUIRE(&trans->atomic_lock)) { - } - if (BLE_LOG_ATOMIC_LOAD_RELAXED(trans->state) == BLE_LOG_TRANS_STATE_OPEN && - trans->pos > 0) { - ble_log_pool_bitmap_clear(&g_pool.open_bitmap, id); - ble_log_pool_seal_and_send(trans); /* releases the lock */ - } else { - BLE_LOG_CAS_RELEASE(&trans->atomic_lock); - } - } - + ble_log_pool_seal_open_trans(); TickType_t start_tick = xTaskGetTickCount(); while ((BLE_LOG_ATOMIC_LOAD_ACQUIRE(g_pool.free_bitmap) & BLE_LOG_POOL_ALL_MASK) != BLE_LOG_POOL_ALL_MASK) { @@ -842,9 +930,11 @@ BLE_LOG_STATIC bool ble_log_pool_flush_all_trans(void) return true; } -void ble_log_lbm_flush_open_transports(void) +void ble_log_lbm_flush_open_trans(void) { - if (!ble_log_ref_count_try_acquire(&lbm_ref_count, &lbm_enabled)) { + /* Periodic OPEN flush is system output, independent from the public + * producer gate. LBM teardown remains the lifetime boundary. */ + if (!ble_log_ref_count_try_acquire(&lbm_ref_count, &lbm_inited)) { return; } @@ -873,26 +963,12 @@ void ble_log_lbm_flush_open_transports(void) BLE_LOG_REF_COUNT_RELEASE(&lbm_ref_count); } -void ble_log_lbm_drain_open_transports(void) +void ble_log_lbm_drain_open_trans(void) { /* Contract (see header): called after ble_log_lbm_begin_deinit() and * before ble_log_rt_deinit(). The producer gate is closed and writers * have drained, so no lock is held for longer than one frame copy. */ - for (int id = 0; id < BLE_LOG_POOL_TRANS_CNT; id++) { - if (!(BLE_LOG_ATOMIC_LOAD_ACQUIRE(g_pool.open_bitmap) & BIT(id))) { - continue; - } - ble_log_prph_trans_t *trans = g_pool.trans[id]; - while (!BLE_LOG_CAS_ACQUIRE(&trans->atomic_lock)) { - } - if (BLE_LOG_ATOMIC_LOAD_RELAXED(trans->state) == BLE_LOG_TRANS_STATE_OPEN && - trans->pos > 0) { - ble_log_pool_seal_and_send(trans); /* releases the lock */ - } else { - BLE_LOG_CAS_RELEASE(&trans->atomic_lock); - } - } - + ble_log_pool_seal_open_trans(); /* Hand the sealed buffers to the peripheral before the runtime queue * is destroyed; the peripheral deinit wait completes the delivery. */ (void)ble_log_rt_drain(); @@ -973,8 +1049,15 @@ void ble_log_flush(void) } #endif - if (!ble_log_pool_flush_all_trans() || - !ble_log_internal_snapshot(BLE_LOG_SNAPSHOT_REASON_FLUSH, NULL, true)) { + if (!ble_log_pool_flush_all_trans()) { + goto restore; + } + + /* One-shot FLUSH snapshot: sample after the pool drained so the clocks + * reflect the flush completion; no sync IO toggle (periodic flow only). */ + ble_log_ts_info_t ts_info; + ble_log_rt_ts_sample(&ts_info, false); + if (!ble_log_internal_snapshot(BLE_LOG_SNAPSHOT_REASON_FLUSH, &ts_info, true)) { goto restore; } diff --git a/components/bt/common/ble_log/src/ble_log_redir.c b/components/bt/common/ble_log/src/ble_log_redir.c index baad2794791..009fac42a30 100644 --- a/components/bt/common/ble_log/src/ble_log_redir.c +++ b/components/bt/common/ble_log/src/ble_log_redir.c @@ -50,7 +50,6 @@ void ble_log_redir_seal(ble_log_prph_trans_t *trans, ble_log_src_t src_code) uint16_t payload_len = trans->pos - BLE_LOG_FRAME_HEAD_LEN; ble_log_redir_t *redir = ble_log_prph_get_redir_lbm(); - BLE_LOG_ASSERT(redir); /* REDIR keeps its own stream sequence: a raw console stream is not a * log attempt, so it never eats Global SNs or fakes loss gaps. The * stream has no core-stat slot. */ @@ -66,11 +65,7 @@ void ble_log_redir_seal(ble_log_prph_trans_t *trans, ble_log_src_t src_code) trans->pos += BLE_LOG_FRAME_TAIL_LEN; uint32_t infl = __atomic_add_fetch(&redir->inflight, 1, __ATOMIC_RELAXED); - uint32_t peak = BLE_LOG_ATOMIC_LOAD_RELAXED(redir->inflight_peak); - while (infl > peak && - !__atomic_compare_exchange_n(&redir->inflight_peak, &peak, infl, true, - __ATOMIC_RELAXED, __ATOMIC_RELAXED)) { - } + ble_log_atomic_update_peak(&redir->inflight_peak, infl); BLE_LOG_ATOMIC_STORE_RELAXED(trans->state, BLE_LOG_TRANS_STATE_SENDING); ble_log_rt_submit_trans(trans); diff --git a/components/bt/common/ble_log/src/ble_log_rt.c b/components/bt/common/ble_log/src/ble_log_rt.c index 5482092d1e6..5c24513ccda 100644 --- a/components/bt/common/ble_log/src/ble_log_rt.c +++ b/components/bt/common/ble_log/src/ble_log_rt.c @@ -16,7 +16,6 @@ #include "esp_log.h" #include "esp_timer.h" -#include "esp_chip_info.h" #if CONFIG_BLE_LOG_LL_ENABLED #include "esp_bt.h" #endif @@ -29,10 +28,14 @@ /* Link-layer clock sample; 0 when the controller exports no accessor. */ #if CONFIG_BLE_LOG_LL_ENABLED #if CONFIG_BT_DUAL_MODE_ARCH -/* The dual-mode-arch controller (ESP32-H4, ESP32-S31) does not export its - * link-layer timer yet; its accessor is r_sched_timer_getCurrentTimeU32. - * Call it once the controller libraries export the symbol. */ -#define BLE_LOG_GET_LC_TS 0 +/* Temporary fallback until the dual-mode controller libraries export the + * link-layer timer accessor. A strong library definition overrides it. */ +uint32_t r_sched_timer_getCurrentTimeU32(void) __attribute__((weak)); +uint32_t r_sched_timer_getCurrentTimeU32(void) +{ + return 0; +} +#define BLE_LOG_GET_LC_TS r_sched_timer_getCurrentTimeU32() /* ESP BLE Controller Gen 2 */ #elif defined(CONFIG_IDF_TARGET_ESP32H2) || defined(CONFIG_IDF_TARGET_ESP32C6) || defined(CONFIG_IDF_TARGET_ESP32C5) ||\ defined(CONFIG_IDF_TARGET_ESP32C61) || defined(CONFIG_IDF_TARGET_ESP32H21) @@ -53,9 +56,6 @@ extern uint32_t lld_read_clock_us(void); #define BLE_LOG_GET_LC_TS 0 #endif /* CONFIG_BLE_LOG_LL_ENABLED */ -_Static_assert(sizeof(ble_log_version_info_t) == 58, - "Unexpected BLE Log version info frame size"); - BLE_LOG_STATIC uint32_t ble_log_rt_lc_ts_get(void) { #if CONFIG_BLE_LOG_LL_ENABLED @@ -74,72 +74,33 @@ BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t rt_inited = 0; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR volatile uint32_t rt_ref_count = 0; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR QueueHandle_t rt_queue_handle = NULL; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR esp_timer_handle_t rt_defer_timer = NULL; -BLE_LOG_STATIC ble_log_version_info_t rt_version_info; -BLE_LOG_STATIC BLE_LOG_DRAM_ATTR uint32_t rt_ts_enabled = 0; BLE_LOG_STATIC BLE_LOG_DRAM_ATTR esp_timer_handle_t rt_ts_timer = NULL; /* Toggle IO phase; stays false when the toggle IO is compiled out. */ BLE_LOG_STATIC BLE_LOG_DRAM_ATTR bool rt_ts_io_level = false; +#if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED +/* Runtime IO control is independent from the always-on periodic snapshot. */ +BLE_LOG_STATIC BLE_LOG_DRAM_ATTR bool rt_ts_io_toggle_enabled = false; +#endif /* PRIVATE FUNCTION DECLARATION */ BLE_LOG_STATIC void ble_log_rt_defer_cb(void *arg); BLE_LOG_STATIC void ble_log_rt_dispatch(QueueHandle_t queue, UBaseType_t pending); -BLE_LOG_STATIC void ble_log_rt_version_info_init(void); -BLE_LOG_STATIC void ble_log_rt_ts_sample(ble_log_ts_info_t *info); BLE_LOG_STATIC void ble_log_rt_ts_trigger(void *arg); /* PRIVATE FUNCTION */ -/* Copies a NUL-terminated commit string into a fixed-width zero-padded field */ -BLE_LOG_STATIC void ble_log_commit_copy(uint8_t *dst, const char *src, size_t len) -{ - BLE_LOG_MEMCPY(dst, src, strnlen(src, len)); -} - -BLE_LOG_STATIC void ble_log_rt_version_info_init(void) -{ - BLE_LOG_MEMSET(&rt_version_info, 0, sizeof(rt_version_info)); - rt_version_info.int_src_code = BLE_LOG_INT_SRC_VERSION_INFO; - rt_version_info.version = BLE_LOG_VERSION; -#ifdef BLE_LOG_IDF_COMMIT - BLE_LOG_MEMCPY(rt_version_info.idf_commit, BLE_LOG_IDF_COMMIT, - BLE_LOG_IDF_COMMIT_LEN); -#endif -#if CONFIG_BT_CONTROLLER_ENABLED && defined(BLE_LOG_CONTROLLER_GET_COMMIT) - ble_log_commit_copy(rt_version_info.controller_commit, - BLE_LOG_CONTROLLER_GET_COMMIT(), BLE_LOG_LIB_COMMIT_LEN); -#endif -#if CONFIG_BT_CONTROLLER_ENABLED && defined(BLE_LOG_BTDM_COMMON_GET_COMMIT) - ble_log_commit_copy(rt_version_info.btdm_common_commit, - BLE_LOG_BTDM_COMMON_GET_COMMIT(), BLE_LOG_LIB_COMMIT_LEN); -#endif -#if CONFIG_BLE_MESH && CONFIG_BLE_MESH_V11_SUPPORT - const char *mesh_commit = strrchr(bt_mesh_v11_commit_str, ' '); - if (mesh_commit) { - ble_log_commit_copy(rt_version_info.mesh_commit, mesh_commit + 1, - BLE_LOG_LIB_COMMIT_LEN); - } -#endif -#if CONFIG_BT_AUDIO && CONFIG_SOC_BLE_AUDIO_SUPPORTED - ble_log_commit_copy(rt_version_info.audio_commit, lib_audio_commit_get(), - BLE_LOG_LIB_COMMIT_LEN); -#endif - esp_chip_info_t chip_info; - esp_chip_info(&chip_info); - rt_version_info.chip_model = (uint16_t)chip_info.model; - rt_version_info.chip_revision = chip_info.revision; - ble_log_internal_set_version_info(&rt_version_info); -} - /* Captures the link-layer, ESP and OS clocks at one instant. */ -BLE_LOG_STATIC void ble_log_rt_ts_sample(ble_log_ts_info_t *info) +void ble_log_rt_ts_sample(ble_log_ts_info_t *info, bool toggle_io) { info->int_src_code = BLE_LOG_INT_SRC_TS; BLE_LOG_ENTER_CRITICAL(); #if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED - /* The critical section keeps the toggle IO edge and the clock samples - * adjacent, and excludes the phase write in ble_log_sync_enable. */ - rt_ts_io_level = !rt_ts_io_level; - gpio_set_level(CONFIG_BLE_LOG_SYNC_IO_NUM, rt_ts_io_level); + /* The critical section keeps the optional IO edge and clock samples + * adjacent, and serializes runtime IO control with the phase update. */ + if (toggle_io && rt_ts_io_toggle_enabled) { + rt_ts_io_level = !rt_ts_io_level; + gpio_set_level(CONFIG_BLE_LOG_SYNC_IO_NUM, rt_ts_io_level); + } #endif /* CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED */ info->io_level = rt_ts_io_level; info->lc_ts = ble_log_rt_lc_ts_get(); @@ -165,6 +126,8 @@ BLE_LOG_STATIC void ble_log_rt_defer_cb(void *arg) { (void)arg; + /* Deinit clears the queue only after stop_blocking has waited for this + * callback, so a live gate implies a live queue. */ if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(rt_inited)) { return; } @@ -186,18 +149,17 @@ BLE_LOG_STATIC void ble_log_rt_defer_cb(void *arg) BLE_LOG_STATIC void ble_log_rt_ts_trigger(void *arg) { (void)arg; - if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(rt_inited) || - !BLE_LOG_ATOMIC_LOAD_ACQUIRE(rt_ts_enabled)) { + if (!BLE_LOG_ATOMIC_LOAD_ACQUIRE(rt_inited)) { return; } ble_log_ts_info_t ts_info; - ble_log_rt_ts_sample(&ts_info); + ble_log_rt_ts_sample(&ts_info, true); /* Unified periodic output: best-effort flush of partially-filled OPEN * transports ahead of the periodic snapshot, so parked frames do not * wait for the next capacity seal. */ - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); (void)ble_log_internal_snapshot( BLE_LOG_SNAPSHOT_REASON_PERIODIC | @@ -212,8 +174,6 @@ bool ble_log_rt_init(void) return true; } - ble_log_rt_version_info_init(); - /* Configure the analyzer toggle IO */ #if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED gpio_config_t sync_io_conf = { @@ -221,7 +181,10 @@ bool ble_log_rt_init(void) .mode = GPIO_MODE_OUTPUT, .pin_bit_mask = BIT64(CONFIG_BLE_LOG_SYNC_IO_NUM), }; - if (gpio_config(&sync_io_conf) != ESP_OK) { + /* Program the output latch before enabling the driver to avoid a stale + * high level or a high glitch after deinit/reinit. */ + if (gpio_set_level(CONFIG_BLE_LOG_SYNC_IO_NUM, 0) != ESP_OK || + gpio_config(&sync_io_conf) != ESP_OK) { goto exit; } #endif /* CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED */ @@ -242,11 +205,13 @@ bool ble_log_rt_init(void) goto exit; } - /* TS sync is always on: the periodic tick drives the unified periodic - * output (TS sample, OPEN transport flush, snapshot). Test apps quiesce - * it with ble_log_sync_enable(false) for deterministic timing. */ + /* Create the system-periodic path here; the top-level init starts it only + * after queuing INIT, then it runs through deinit. Runtime sync control + * affects only the optional analyzer IO toggle. */ rt_ts_io_level = false; - BLE_LOG_ATOMIC_STORE_RELEASE(rt_ts_enabled, true); +#if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED + rt_ts_io_toggle_enabled = false; +#endif esp_timer_create_args_t ts_timer_args = { .callback = ble_log_rt_ts_trigger, .arg = NULL, @@ -255,8 +220,7 @@ bool ble_log_rt_init(void) /* Do not wake light sleep or replay every missed periodic callback. */ .skip_unhandled_events = true, }; - if (esp_timer_create(&ts_timer_args, &rt_ts_timer) != ESP_OK || - esp_timer_start_periodic(rt_ts_timer, BLE_LOG_TS_TRIGGER_TIMEOUT_US) != ESP_OK) { + if (esp_timer_create(&ts_timer_args, &rt_ts_timer) != ESP_OK) { goto exit; } @@ -268,6 +232,21 @@ exit: return false; } +bool ble_log_rt_start_periodic(void) +{ + bool started = false; + if (!ble_log_ref_count_try_acquire(&rt_ref_count, &rt_inited)) { + return false; + } + if (rt_ts_timer && + esp_timer_start_periodic(rt_ts_timer, + BLE_LOG_TS_TRIGGER_TIMEOUT_US) == ESP_OK) { + started = true; + } + BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); + return started; +} + void ble_log_rt_deinit(void) { /* Closing gate: seq_cst on both sides (see also submit/drain) so a @@ -278,7 +257,6 @@ void ble_log_rt_deinit(void) ESP_LOGE(TAG, "Timed out waiting for BLE Log runtime references"); BLE_LOG_ASSERT(false); } - BLE_LOG_ATOMIC_STORE_RELEASE(rt_ts_enabled, false); if (rt_ts_timer) { esp_timer_stop_blocking(rt_ts_timer, portMAX_DELAY); esp_timer_delete(rt_ts_timer); @@ -294,7 +272,6 @@ void ble_log_rt_deinit(void) if (rt_queue_handle) { ble_log_prph_trans_t *trans = NULL; while (xQueueReceive(rt_queue_handle, &trans, 0) == pdTRUE) { - trans->pos = 0; ble_log_lbm_recycle_trans(trans); } vQueueDelete(rt_queue_handle); @@ -304,6 +281,7 @@ void ble_log_rt_deinit(void) /* Release the toggle IO */ rt_ts_io_level = false; #if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED + rt_ts_io_toggle_enabled = false; gpio_reset_pin(CONFIG_BLE_LOG_SYNC_IO_NUM); #endif /* CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED */ } @@ -335,13 +313,13 @@ exit: BLE_LOG_IRAM_ATTR void ble_log_rt_submit_trans(ble_log_prph_trans_t *trans) { if (!ble_log_ref_count_try_acquire(&rt_ref_count, &rt_inited)) { + /* No reference was taken, so this path must not release; it stays + * separate from the held-reference failures below. */ ble_log_lbm_recycle_trans(trans); return; } if (!rt_queue_handle) { - BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); - ble_log_lbm_recycle_trans(trans); - return; + goto fail; } bool in_isr = BLE_LOG_IN_ISR(); @@ -349,35 +327,46 @@ BLE_LOG_IRAM_ATTR void ble_log_rt_submit_trans(ble_log_prph_trans_t *trans) ? xQueueSendFromISR(rt_queue_handle, &trans, NULL) : xQueueSend(rt_queue_handle, &trans, 0); if (queued != pdTRUE) { - BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); - ble_log_lbm_recycle_trans(trans); - return; + goto fail; } /* An active timer keeps the deadline anchored to the first submission. */ (void)esp_timer_start_once(rt_defer_timer, BLE_LOG_RT_DEFER_TIMEOUT_US); BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); + return; + +fail: + BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); + ble_log_lbm_recycle_trans(trans); } -bool ble_log_sync_enable(bool enable) +bool ble_log_ts_sync_io_toggle_enable(bool enable) { if (!ble_log_ref_count_try_acquire(&rt_ref_count, &rt_inited)) { return false; } - BLE_LOG_ATOMIC_STORE_RELEASE(rt_ts_enabled, enable); + #if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED - /* Leave the toggle IO at a defined low level: when sync is disabled - * while the IO idles low, drive a short high pulse first so the - * analyzer sees a final falling edge. The critical section excludes - * the phase toggle in ble_log_rt_ts_sample. */ + /* Restart the analyzer phase from low. When disabling an already-low IO, + * drive it high first so the external analyzer still sees a final + * falling edge. The periodic snapshot remains active in either state. */ BLE_LOG_ENTER_CRITICAL(); + rt_ts_io_toggle_enabled = enable; if (!enable && !rt_ts_io_level) { gpio_set_level(CONFIG_BLE_LOG_SYNC_IO_NUM, 1); } rt_ts_io_level = false; gpio_set_level(CONFIG_BLE_LOG_SYNC_IO_NUM, 0); BLE_LOG_EXIT_CRITICAL(); +#else + (void)enable; #endif /* CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED */ + BLE_LOG_REF_COUNT_RELEASE(&rt_ref_count); return true; } + +bool ble_log_sync_enable(bool enable) +{ + return ble_log_ts_sync_io_toggle_enable(enable); +} diff --git a/components/bt/common/ble_log/src/ble_log_util.c b/components/bt/common/ble_log/src/ble_log_util.c index e8ea3bd39bc..17a52df6ca6 100644 --- a/components/bt/common/ble_log/src/ble_log_util.c +++ b/components/bt/common/ble_log/src/ble_log_util.c @@ -25,9 +25,8 @@ BLE_LOG_DRAM_ATTR portMUX_TYPE ble_log_spin_lock = portMUX_INITIALIZER_UNLOCKED; BLE_LOG_IRAM_ATTR BLE_LOG_STATIC BLE_LOG_INLINE uint32_t ror32(uint32_t word, uint32_t shift) { - if (unlikely(shift == 0)) { - return word; - } + /* The mask folds shift == 0 into a zero left-shift amount, so the + * expression needs no shift == 0 guard. */ return (word >> shift) | (word << ((32 - shift) & 0x1F)); } @@ -98,3 +97,13 @@ bool ble_log_ref_count_wait(volatile uint32_t *ref_count, uint32_t max_ref_count } return true; } + +BLE_LOG_IRAM_ATTR +void ble_log_atomic_update_peak(volatile uint32_t *peak, uint32_t value) +{ + uint32_t current = BLE_LOG_ATOMIC_LOAD_RELAXED(*peak); + while (value > current && + !__atomic_compare_exchange_n(peak, ¤t, value, true, + __ATOMIC_RELAXED, __ATOMIC_RELAXED)) { + } +} diff --git a/components/bt/common/ble_log/src/internal_include/ble_log_lbm.h b/components/bt/common/ble_log/src/internal_include/ble_log_lbm.h deleted file mode 100644 index b9f2b9e32d9..00000000000 --- a/components/bt/common/ble_log/src/internal_include/ble_log_lbm.h +++ /dev/null @@ -1,272 +0,0 @@ -/* - * SPDX-FileCopyrightText: 2025-2026 Espressif Systems (Shanghai) CO LTD - * - * SPDX-License-Identifier: Apache-2.0 - */ -#ifndef __BLE_LOG_LBM_H__ -#define __BLE_LOG_LBM_H__ - -/* --------------------------------------- */ -/* BLE Log - Log Buffer Management */ -/* --------------------------------------- */ - -/* ---------------- */ -/* Includes */ -/* ---------------- */ -#include "ble_log.h" -#include "ble_log_prph.h" - -#include "freertos/FreeRTOS.h" - -#if defined(CONFIG_BLE_LOG_PRPH_UART_DMA) && (CONFIG_BLE_LOG_PRPH_UART_DMA_PORT == 0) -#define BLE_LOG_UART_REDIR_ENABLED (1) -#else -#define BLE_LOG_UART_REDIR_ENABLED (0) -#endif -#include "freertos/semphr.h" - -/* ------------------------- */ -/* Log Frame Defines */ -/* ------------------------- */ -typedef struct { - uint16_t length; - uint32_t frame_meta; -} __attribute__((packed)) ble_log_frame_head_t; - -#define BLE_LOG_FRAME_HEAD_LEN (sizeof(ble_log_frame_head_t)) -#define BLE_LOG_FRAME_TAIL_LEN (sizeof(uint32_t)) -#define BLE_LOG_FRAME_OVERHEAD (BLE_LOG_FRAME_HEAD_LEN + BLE_LOG_FRAME_TAIL_LEN) -#define BLE_LOG_MAKE_FRAME_META(src_code, sn) (((src_code) & 0xFF) | ((sn) << 8)) - -/* ---------------------------------- */ -/* Log Buffer Manager Defines */ -/* ---------------------------------- */ -typedef enum { - BLE_LOG_LBM_LOCK_NONE, - BLE_LOG_LBM_LOCK_SPIN, - BLE_LOG_LBM_LOCK_ATOMIC, - BLE_LOG_LBM_LOCK_MUTEX, -} ble_log_lbm_lock_t; - -typedef struct { - int trans_idx; - ble_log_prph_trans_t *trans[BLE_LOG_TRANS_BUF_CNT]; - ble_log_lbm_lock_t lock_type; - union { - /* BLE_LOG_LBM_LOCK_NONE */ - void *none; - /* BLE_LOG_LBM_LOCK_SPIN */ - portMUX_TYPE spin_lock; - /* BLE_LOG_LBM_LOCK_ATOMIC */ - volatile bool atomic_lock; - /* BLE_LOG_LBM_LOCK_MUTEX */ - SemaphoreHandle_t mutex; - }; - uint32_t trans_inflight; - uint32_t trans_inflight_peak; -} ble_log_lbm_t; - -/* --------------------------------------- */ -/* Log Buffer Manager Pool Defines */ -/* --------------------------------------- */ -enum { -#if CONFIG_BLE_LOG_LL_ENABLED - BLE_LOG_LBM_LL_TASK, - BLE_LOG_LBM_LL_HCI, -#endif /* CONFIG_BLE_LOG_LL_ENABLED */ - BLE_LOG_LBM_LL_MAX, -}; - -enum { - BLE_LOG_LBM_SPIN_TASK = 0, - BLE_LOG_LBM_SPIN_ISR, - BLE_LOG_LBM_SPIN_MAX, -}; - -#define BLE_LOG_LBM_ATOMIC_TASK_CNT CONFIG_BLE_LOG_LBM_ATOMIC_LOCK_TASK_CNT -#define BLE_LOG_LBM_ATOMIC_ISR_CNT CONFIG_BLE_LOG_LBM_ATOMIC_LOCK_ISR_CNT -#define BLE_LOG_LBM_ATOMIC_CNT (BLE_LOG_LBM_ATOMIC_TASK_CNT +\ - BLE_LOG_LBM_ATOMIC_ISR_CNT) -#define BLE_LOG_LBM_COMMON_CNT (BLE_LOG_LBM_ATOMIC_CNT + BLE_LOG_LBM_SPIN_MAX) -#define BLE_LOG_LBM_CNT (BLE_LOG_LBM_COMMON_CNT + BLE_LOG_LBM_LL_MAX) - -/* Derived per-buffer size from user-configured total-per-LBM budget */ -#define BLE_LOG_TRANS_SIZE (CONFIG_BLE_LOG_LBM_TRANS_BUF_SIZE / BLE_LOG_TRANS_BUF_CNT) -#define BLE_LOG_TRANS_LL_SIZE (CONFIG_BLE_LOG_LBM_LL_TRANS_BUF_SIZE / BLE_LOG_TRANS_BUF_CNT) - -/* Unified queue depth derivation */ -#define BLE_LOG_TRANS_POOL_CNT (BLE_LOG_LBM_CNT * BLE_LOG_TRANS_BUF_CNT) -#if BLE_LOG_UART_REDIR_ENABLED -#define BLE_LOG_TRANS_REDIR_CNT BLE_LOG_TRANS_BUF_CNT -#else -#define BLE_LOG_TRANS_REDIR_CNT (0) -#endif -#define BLE_LOG_TRANS_TOTAL_CNT (BLE_LOG_TRANS_POOL_CNT + BLE_LOG_TRANS_REDIR_CNT) - -/* ------------------------------------------ */ -/* Log Buffer Manager Context Defines */ -/* ------------------------------------------ */ -typedef struct { - union { - ble_log_lbm_t lbm_pool[BLE_LOG_LBM_CNT]; - struct { - union { - ble_log_lbm_t lbm_common_pool[BLE_LOG_LBM_COMMON_CNT]; - struct { - union { - ble_log_lbm_t spin_pool[BLE_LOG_LBM_SPIN_MAX]; - struct { - ble_log_lbm_t spin_task; - ble_log_lbm_t spin_isr; - }; - }; - union { - ble_log_lbm_t atomic_pool[BLE_LOG_LBM_ATOMIC_CNT]; - struct { - ble_log_lbm_t atomic_pool_task[BLE_LOG_LBM_ATOMIC_TASK_CNT]; - ble_log_lbm_t atomic_pool_isr[BLE_LOG_LBM_ATOMIC_ISR_CNT]; - }; - }; - }; - }; - union { - ble_log_lbm_t lbm_ll_pool[BLE_LOG_LBM_LL_MAX]; -#if CONFIG_BLE_LOG_LL_ENABLED - struct { - ble_log_lbm_t lbm_ll_task; - ble_log_lbm_t lbm_ll_hci; - }; -#endif /* CONFIG_BLE_LOG_LL_ENABLED */ - }; - }; - }; -} ble_log_lbm_ctx_t; - -/* -------------------------------------------- */ -/* Buffer Utilization Reporting Defines */ -/* -------------------------------------------- */ -typedef enum { - BLE_LOG_BUF_UTIL_POOL_COMMON_TASK = 0, - BLE_LOG_BUF_UTIL_POOL_COMMON_ISR = 1, - BLE_LOG_BUF_UTIL_POOL_LL = 2, - BLE_LOG_BUF_UTIL_POOL_REDIR = 3, -} ble_log_buf_util_pool_t; - -typedef struct { - uint8_t int_src_code; - uint8_t lbm_id; - uint8_t trans_cnt; - uint8_t inflight_peak; -} __attribute__((packed)) ble_log_buf_util_t; - -#define BLE_LOG_BUF_UTIL_MAKE_ID(pool, idx) (((pool) << 4) | ((idx) & 0x0F)) -#define BLE_LOG_BUF_UTIL_GET_POOL(id) (((id) >> 4) & 0x0F) -#define BLE_LOG_BUF_UTIL_GET_INDEX(id) ((id) & 0x0F) - -/* ---------------------------------------- */ -/* Enhanced Statistics Data Defines */ -/* ---------------------------------------- */ -typedef struct { - uint8_t int_src_code; - uint8_t src_code; - uint32_t written_frame_cnt; - uint32_t lost_frame_cnt; - uint32_t written_bytes_cnt; - uint32_t lost_bytes_cnt; -} __attribute__((packed)) ble_log_enh_stat_t; - -/* -------------------------------- */ -/* Final Statistics Defines */ -/* -------------------------------- */ -typedef struct { - uint8_t src_code; - uint32_t written_frame_cnt; - uint32_t lost_frame_cnt; - uint32_t written_bytes_cnt; - uint32_t lost_bytes_cnt; -} __attribute__((packed)) ble_log_final_stat_entry_t; - -typedef struct { - uint8_t int_src_code; - uint8_t src_cnt; - ble_log_final_stat_entry_t entries[BLE_LOG_SRC_MAX]; -} __attribute__((packed)) ble_log_final_stat_t; - -#define BLE_LOG_FINAL_STAT_LEN sizeof(ble_log_final_stat_t) - -/* -------------------------------------- */ -/* Log Statistics Manager Context */ -/* -------------------------------------- */ -typedef struct { - uint32_t frame_sn; - /* Aligned live counters — updated by ble_log_stat_mgr_update(), - * snapshot by ble_log_write_enh_stat(). Natural 4-byte alignment - * ensures each load/store compiles to a single l32i/s32i on - * Xtensa/RISC-V, so individual field access is atomic without locks. - * The packed ble_log_enh_stat_t wire format is built on the stack - * only when serializing to UART. */ - uint32_t written_frame_cnt; - uint32_t lost_frame_cnt; - uint32_t written_bytes_cnt; - uint32_t lost_bytes_cnt; -} ble_log_stat_mgr_t; - -#define BLE_LOG_GET_FRAME_SN(VAR) __atomic_fetch_add(VAR, 1, __ATOMIC_RELAXED) - -/* -------------------------- */ -/* Link Layer Defines */ -/* -------------------------- */ -#if CONFIG_BLE_LOG_LL_ENABLED -enum { - BLE_LOG_LL_FLAG_CONTINUE = 0, - BLE_LOG_LL_FLAG_END, - BLE_LOG_LL_FLAG_TASK, - BLE_LOG_LL_FLAG_ISR, - BLE_LOG_LL_FLAG_HCI, - BLE_LOG_LL_FLAG_RAW, - BLE_LOG_LL_FLAG_OMDATA, - BLE_LOG_LL_FLAG_HCI_UPSTREAM, -}; -#endif /* CONFIG_BLE_LOG_LL_ENABLED */ - -/* ------------------------------- */ -/* Compile-Time Guards */ -/* ------------------------------- */ -_Static_assert(CONFIG_BLE_LOG_LBM_TRANS_BUF_SIZE % BLE_LOG_TRANS_BUF_CNT == 0, - "Common LBM total buffer size must be a multiple of BLE_LOG_TRANS_BUF_CNT (4)"); -#if CONFIG_BLE_LOG_LL_ENABLED -_Static_assert(CONFIG_BLE_LOG_LBM_LL_TRANS_BUF_SIZE % BLE_LOG_TRANS_BUF_CNT == 0, - "LL LBM total buffer size must be a multiple of BLE_LOG_TRANS_BUF_CNT (4)"); -#endif -_Static_assert(CONFIG_BLE_LOG_LBM_TRANS_BUF_SIZE / BLE_LOG_TRANS_BUF_CNT >= BLE_LOG_FRAME_OVERHEAD, - "Common LBM per-buffer size too small for a single frame"); -_Static_assert(BLE_LOG_TRANS_SIZE >= BLE_LOG_FINAL_STAT_LEN + sizeof(uint32_t) + BLE_LOG_FRAME_OVERHEAD, - "Common LBM per-buffer size too small for final statistics frame"); -_Static_assert((BLE_LOG_TRANS_BUF_CNT & (BLE_LOG_TRANS_BUF_CNT - 1)) == 0, - "BLE_LOG_TRANS_BUF_CNT must be a power of 2"); -_Static_assert(1 + BLE_LOG_LBM_ATOMIC_TASK_CNT <= 16, - "Common task pool exceeds lbm_id 4-bit index limit (max 15)"); -_Static_assert(1 + BLE_LOG_LBM_ATOMIC_ISR_CNT <= 16, - "Common ISR pool exceeds lbm_id 4-bit index limit (max 15)"); -_Static_assert(BLE_LOG_TRANS_BUF_CNT <= 255, - "BLE_LOG_TRANS_BUF_CNT must fit in uint8_t for ble_log_buf_util_t"); - -/* --------------------------- */ -/* Internal Interfaces */ -/* --------------------------- */ -bool ble_log_lbm_init(void); -void ble_log_lbm_close(void); -void ble_log_lbm_deinit(void); -void ble_log_lbm_recycle_trans(ble_log_prph_trans_t *trans); -bool ble_log_write_internal(const uint8_t *addr, size_t len); -void ble_log_write_final_stat(void); -void ble_log_write_enh_stat(void); -void ble_log_write_buf_util(void); -#if BLE_LOG_UART_REDIR_ENABLED -void ble_log_lbm_stream_write(ble_log_lbm_t *lbm, ble_log_src_t src_code, - const uint8_t *data, size_t len); -void ble_log_lbm_stream_flush(ble_log_lbm_t *lbm, ble_log_src_t src_code); -ble_log_lbm_t *ble_log_prph_get_redir_lbm(void); -#endif - -#endif /* __BLE_LOG_LBM_H__ */ diff --git a/components/bt/common/ble_log/src/internal_include/ble_log_lbm_v2.h b/components/bt/common/ble_log/src/internal_include/ble_log_lbm_v2.h index f179d35ca37..f78f7e4c896 100644 --- a/components/bt/common/ble_log/src/internal_include/ble_log_lbm_v2.h +++ b/components/bt/common/ble_log/src/internal_include/ble_log_lbm_v2.h @@ -59,10 +59,9 @@ typedef struct { /* --------------------------------------- */ /* Protocol v7 Source ID Space */ /* --------------------------------------- */ -/* The frozen public ble_log_src_t values are the on-wire and statistic - * source IDs: the frame source byte carries the enum value directly and - * every source keeps its own wire sequence, matching the legacy wire - * identity so existing decoders keep working. */ +/* The frozen public ble_log_src_t values are the base on-wire and statistic + * source IDs. Bit 7 of the frame source byte carries NON_YIELD metadata, so + * receivers must mask it before decoding the base source. */ #define BLE_LOG_SRC_ID_MASK 0x7f #define BLE_LOG_SRC_FLAG_NON_YIELD 0x80 #define BLE_LOG_SRC_ID(source_meta) ((source_meta) & BLE_LOG_SRC_ID_MASK) @@ -115,9 +114,11 @@ typedef struct { * sources — and every lost or rejected attempt leaves a gap. INTERNAL * snapshot frames and the REDIR console stream keep their own separate * sequences (a gap counts a skipped snapshot or a dropped console batch). - * None of the sequences is ever reset. The per-counter macros live next - * to their counters in the owning translation units; the 24-bit wire - * field is enforced where the frame meta is packed. */ + * ble_log_init() resets all three sequences; its required INIT snapshot + * starts a new receiver epoch. They stay continuous through FLUSH within + * that epoch. The per-counter macros live next to their counters in the + * owning translation units; the 24-bit wire field is enforced where the + * frame meta is packed. */ /* -------------------------------- */ /* Internal Snapshot Frame */ @@ -226,18 +227,20 @@ bool ble_log_lbm_init(void); void ble_log_lbm_begin_deinit(void); void ble_log_lbm_deinit(void); bool ble_log_lbm_is_enabled(void); -void ble_log_lbm_flush_open_transports(void); +/* Best-effort system flush, gated by LBM lifetime rather than producers. */ +void ble_log_lbm_flush_open_trans(void); /* Deinit drain: seal every OPEN transport and dispatch it to the runtime * queue. Contract: called after ble_log_lbm_begin_deinit() (producer gate * closed, writers drained) and before ble_log_rt_deinit(); every transport * lock is then uncontended. The peripheral deinit wait completes the * delivery of the dispatched buffers. */ -void ble_log_lbm_drain_open_transports(void); +void ble_log_lbm_drain_open_trans(void); void ble_log_lbm_recycle_trans(ble_log_prph_trans_t *trans); -void ble_log_internal_set_version_info(const ble_log_version_info_t *version_info); +/* System output: gated by the LBM lifetime, not ble_log_enable(). A false + * wait_for_transport makes a busy dedicated transport a lossy fast path. */ bool ble_log_internal_snapshot(uint16_t reason_flags, const ble_log_ts_info_t *ts_info, - bool required); + bool wait_for_transport); /* Claim/commit: the public ble_log_src_t is accepted for API stability, but * only BLE_LOG_SRC_ENCODE is supported; its frames are stamped with the diff --git a/components/bt/common/ble_log/src/internal_include/ble_log_prph.h b/components/bt/common/ble_log/src/internal_include/ble_log_prph.h index 8d881ccd9d9..bc2ab9b0fd5 100644 --- a/components/bt/common/ble_log/src/internal_include/ble_log_prph.h +++ b/components/bt/common/ble_log/src/internal_include/ble_log_prph.h @@ -61,6 +61,9 @@ typedef struct { bool ble_log_prph_init(size_t trans_cnt); void ble_log_prph_deinit(void); +/* Allocates a transport whose storage is zeroed (every field except size + * starts at its zero value: state FREE, owner POOL, lock and pending_seal + * clear). Callers only need to set the non-zero identity fields. */ bool ble_log_prph_trans_init(ble_log_prph_trans_t **trans, size_t trans_size); void ble_log_prph_trans_deinit(ble_log_prph_trans_t **trans); void ble_log_prph_send_trans(ble_log_prph_trans_t *trans); diff --git a/components/bt/common/ble_log/src/internal_include/ble_log_rt.h b/components/bt/common/ble_log/src/internal_include/ble_log_rt.h index 89f51c7421b..86347fd05b4 100644 --- a/components/bt/common/ble_log/src/internal_include/ble_log_rt.h +++ b/components/bt/common/ble_log/src/internal_include/ble_log_rt.h @@ -12,6 +12,7 @@ /* INCLUDE */ #include "ble_log_prph.h" +#include "ble_log_lbm_v2.h" #include "freertos/FreeRTOS.h" #include "freertos/task.h" @@ -23,8 +24,16 @@ /* INTERFACE */ bool ble_log_rt_init(void); +/* Starts the always-on periodic path after the epoch INIT frame is queued. */ +bool ble_log_rt_start_periodic(void); void ble_log_rt_deinit(void); bool ble_log_rt_drain(void); void ble_log_rt_submit_trans(ble_log_prph_trans_t *trans); +/* Samples the link-layer, ESP and OS clocks at one instant. toggle_io allows + * the periodic path to toggle the sync IO when runtime IO toggling is enabled; + * one-shot snapshots (INIT/FLUSH) always pass false and leave the IO edge + * sequence untouched. io_level always reports the physical IO level. */ +void ble_log_rt_ts_sample(ble_log_ts_info_t *info, bool toggle_io); + #endif /* __BLE_LOG_RT_H__ */ diff --git a/components/bt/common/ble_log/src/internal_include/ble_log_util.h b/components/bt/common/ble_log/src/internal_include/ble_log_util.h index e12787523b5..bc631d48a8a 100644 --- a/components/bt/common/ble_log/src/internal_include/ble_log_util.h +++ b/components/bt/common/ble_log/src/internal_include/ble_log_util.h @@ -131,4 +131,9 @@ bool ble_log_ref_count_try_acquire(volatile uint32_t *ref_count, /* Task-context wait; returns false if the count stays above max for one second. */ bool ble_log_ref_count_wait(volatile uint32_t *ref_count, uint32_t max_ref_count); +/* Monotonic-peak publish: stores value into *peak only when it exceeds the + * current peak. Relaxed atomics are enough - a lost race can only leave the + * recorded peak below a transient maximum, and peaks are diagnostics. */ +void ble_log_atomic_update_peak(volatile uint32_t *peak, uint32_t value); + #endif /* __BLE_LOG_UTIL_H__ */ diff --git a/components/bt/common/ble_log/src/prph/ble_log_prph_dummy.c b/components/bt/common/ble_log/src/prph/ble_log_prph_dummy.c index 38d366d064c..0042581cc49 100644 --- a/components/bt/common/ble_log/src/prph/ble_log_prph_dummy.c +++ b/components/bt/common/ble_log/src/prph/ble_log_prph_dummy.c @@ -87,6 +87,5 @@ void ble_log_prph_trans_deinit(ble_log_prph_trans_t **trans) * SPI DMA) do the same work inside their asynchronous tx_done callbacks. */ void ble_log_prph_send_trans(ble_log_prph_trans_t *trans) { - trans->pos = 0; ble_log_lbm_recycle_trans(trans); } diff --git a/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_dma.c b/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_dma.c index 0b2c99043f0..eab253a8b2f 100644 --- a/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_dma.c +++ b/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_dma.c @@ -42,7 +42,6 @@ BLE_LOG_SPI_MASTER_DMA_CB_ATTR BLE_LOG_STATIC void spi_master_dma_tx_done_cb(spi /* Recycle transport */ ble_log_prph_trans_t *trans = (ble_log_prph_trans_t *)(spi_trans->user); - trans->pos = 0; ble_log_lbm_recycle_trans(trans); } diff --git a/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_hd.c b/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_hd.c index 9b202e56ed0..662be1ec579 100644 --- a/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_hd.c +++ b/components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_hd.c @@ -44,7 +44,6 @@ BLE_LOG_SPI_MASTER_HD_CB_ATTR BLE_LOG_STATIC void spi_master_hd_tx_done_cb(spi_t } } - ctx->trans->pos = 0; ble_log_lbm_recycle_trans(ctx->trans); } @@ -220,7 +219,6 @@ BLE_LOG_IRAM_ATTR void ble_log_prph_send_trans(ble_log_prph_trans_t *trans) uint8_t old_status = __atomic_fetch_or(&ctx->status, BLE_LOG_SPI_HD_END_QUEUE_FAILED, __ATOMIC_ACQ_REL); if (old_status & BLE_LOG_SPI_HD_DATA_DONE) { /* Data is already on the wire; recycle it without re-sending. */ - trans->pos = 0; ble_log_lbm_recycle_trans(trans); } } diff --git a/components/bt/common/ble_log/src/prph/ble_log_prph_test.c b/components/bt/common/ble_log/src/prph/ble_log_prph_test.c index 04f649419c8..9dc034c8bbd 100644 --- a/components/bt/common/ble_log/src/prph/ble_log_prph_test.c +++ b/components/bt/common/ble_log/src/prph/ble_log_prph_test.c @@ -155,7 +155,6 @@ void ble_log_prph_send_trans(ble_log_prph_trans_t *trans) uint32_t idx = __atomic_load_n(&s_auto_recycle_idx, __ATOMIC_ACQUIRE); ble_log_prph_test_hook_reg_t reg = s_auto_recycle_slots[idx & 1]; if (reg.hook) { - trans->pos = 0; ble_log_lbm_recycle_trans(trans); reg.hook(reg.ctx); __atomic_fetch_sub(&s_auto_recycle_busy, 1, __ATOMIC_RELEASE); @@ -164,7 +163,6 @@ void ble_log_prph_send_trans(ble_log_prph_trans_t *trans) __atomic_fetch_sub(&s_auto_recycle_busy, 1, __ATOMIC_RELEASE); if (xQueueSend(s_pending_trans, &trans, 0) != pdTRUE) { - trans->pos = 0; ble_log_lbm_recycle_trans(trans); BLE_LOG_ASSERT(false); } @@ -217,7 +215,6 @@ size_t ble_log_prph_test_read(uint8_t *data, size_t len, TickType_t timeout, if (delay_us > 0 && (esp_timer_start_once(s_tx_timer, (uint64_t)delay_us) != ESP_OK || xSemaphoreTake(s_tx_done, portMAX_DELAY) != pdTRUE)) { - trans->pos = 0; ble_log_lbm_recycle_trans(trans); BLE_LOG_ASSERT(false); return 0; @@ -233,7 +230,6 @@ size_t ble_log_prph_test_read(uint8_t *data, size_t len, TickType_t timeout, } size_t copied = len < trans->pos ? len : trans->pos; BLE_LOG_MEMCPY(data, trans->buf, copied); - trans->pos = 0; ble_log_lbm_recycle_trans(trans); if (uxQueueMessagesWaiting(s_pending_trans) == 0) { s_tx_deadline_us = 0; diff --git a/components/bt/common/ble_log/src/prph/ble_log_prph_uart_dma.c b/components/bt/common/ble_log/src/prph/ble_log_prph_uart_dma.c index ce0333e577b..7736178d04e 100644 --- a/components/bt/common/ble_log/src/prph/ble_log_prph_uart_dma.c +++ b/components/bt/common/ble_log/src/prph/ble_log_prph_uart_dma.c @@ -143,7 +143,6 @@ bool ble_log_prph_init(size_t trans_cnt) /* Redirection transports are not part of the global pool. */ redir_lbm->trans[i]->id = BLE_LOG_TRANS_ID_NONE; redir_lbm->trans[i]->owner_kind = BLE_LOG_TRANS_OWNER_REDIR; - redir_lbm->trans[i]->state = BLE_LOG_TRANS_STATE_FREE; } /* Mutex initialization */ @@ -306,7 +305,11 @@ void ble_log_prph_trans_deinit(ble_log_prph_trans_t **trans) BLE_LOG_IRAM_ATTR void ble_log_prph_send_trans(ble_log_prph_trans_t *trans) { if (uhci_transmit(dev_handle, trans->buf, trans->pos) != ESP_OK) { - /* No tx_done will fire on failure: recycle here to avoid leaking. */ + /* The UHCI queue depth matches the transport count and each transport + * occupies at most one slot, so a full queue cannot occur here: this + * is a driver fault. The assert compiles out with NDEBUG; the recycle + * below still covers that case (no tx_done will fire on failure). */ + BLE_LOG_ASSERT(false); ble_log_lbm_recycle_trans(trans); } } diff --git a/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_main.c b/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_main.c index 903cede8507..9db296dd963 100644 --- a/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_main.c +++ b/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_main.c @@ -53,8 +53,8 @@ bool test_ble_log_walk_frames(const uint8_t *data, size_t len, void setUp(void) { - /* The periodic TS tick is always on since TS sync became unconditional; - * quiesce it so timing-sensitive tests stay deterministic. */ + /* Preserve the external test-system contract: every test starts with the + * optional sync IO disabled and low. Periodic snapshots remain active. */ (void)ble_log_sync_enable(false); } diff --git a/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_runtime.c b/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_runtime.c index 2bd0e916224..d1067cf1e9e 100644 --- a/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_runtime.c +++ b/components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_runtime.c @@ -51,6 +51,13 @@ typedef struct { uint32_t ts_count; } rt_marker_observer_t; +#if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED +typedef struct { + bool found; + uint8_t io_level; +} rt_snapshot_observer_t; +#endif + typedef struct { SemaphoreHandle_t done; uint32_t remaining; @@ -122,6 +129,29 @@ static void observe_runtime_marker(const test_ble_log_frame_t *frame, void *ctx) } } +#if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED +static void observe_periodic_snapshot(const test_ble_log_frame_t *frame, + void *ctx) +{ + rt_snapshot_observer_t *observer = ctx; + if (observer->found || frame->src != BLE_LOG_SRC_INTERNAL || + frame->payload_len != sizeof(uint32_t) + + sizeof(ble_log_internal_snapshot_t)) { + return; + } + + ble_log_internal_snapshot_t snapshot; + memcpy(&snapshot, frame->payload + sizeof(uint32_t), sizeof(snapshot)); + uint16_t expected = BLE_LOG_SNAPSHOT_REASON_PERIODIC | + BLE_LOG_SNAPSHOT_REASON_TS_VALID; + if (snapshot.int_src_code == BLE_LOG_INT_SRC_SNAPSHOT && + (snapshot.reason_flags & expected) == expected) { + observer->found = true; + observer->io_level = snapshot.ts.io_level; + } +} +#endif + static TickType_t runtime_timeout_ticks(uint32_t timeout_ms) { uint64_t ticks = ((uint64_t)timeout_ms * configTICK_RATE_HZ + 999) / 1000; @@ -159,11 +189,12 @@ static bool write_runtime_marker(uint32_t seq, int64_t *enqueued_at_us) return true; } -static bool read_runtime_marker(uint32_t *seq, uint32_t *ts_count, - int64_t *received_at_us) +static bool read_runtime_marker_with_timeout(uint32_t *seq, uint32_t *ts_count, + int64_t *received_at_us, + uint32_t timeout_ms) { const int64_t deadline_us = esp_timer_get_time() + - (int64_t)RT_READ_TIMEOUT_MS * 1000; + (int64_t)timeout_ms * 1000; uint32_t observed_ts = 0; while (true) { @@ -197,6 +228,13 @@ static bool read_runtime_marker(uint32_t *seq, uint32_t *ts_count, } } +static bool read_runtime_marker(uint32_t *seq, uint32_t *ts_count, + int64_t *received_at_us) +{ + return read_runtime_marker_with_timeout(seq, ts_count, received_at_us, + RT_READ_TIMEOUT_MS); +} + static bool runtime_stream_is_quiet(void) { const int64_t drain_deadline_us = esp_timer_get_time() + @@ -229,6 +267,35 @@ static bool runtime_stream_is_quiet(void) return false; } +#if CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED +static bool read_periodic_snapshot(uint8_t *io_level) +{ + const int64_t deadline_us = esp_timer_get_time() + + (int64_t)BLE_LOG_TS_TRIGGER_TIMEOUT_US + 1000000; + while (true) { + TickType_t remaining; + if (!runtime_deadline_ticks(deadline_us, &remaining)) { + return false; + } + size_t len = ble_log_prph_test_read(s_capture, sizeof(s_capture), + remaining, 0, NULL); + if (!len) { + continue; + } + + rt_snapshot_observer_t observer = {0}; + if (!test_ble_log_walk_frames(s_capture, len, + observe_periodic_snapshot, &observer)) { + return false; + } + if (observer.found) { + *io_level = observer.io_level; + return true; + } + } +} +#endif + static void refill_runtime_queue(void *arg) { rt_starvation_ctx_t *ctx = arg; @@ -480,7 +547,7 @@ TEST_CASE("BLE Log periodic timestamp skips light sleep wakeups", TEST_ASSERT_TRUE(runtime_stream_is_quiet()); TEST_ASSERT_TRUE(ble_log_sync_enable(true)); for (int i = 0; i < 3; i++) { - vTaskDelay(runtime_timeout_ticks(CONFIG_BLE_LOG_TS_TRIGGER_TIMEOUT_MS)); + vTaskDelay(runtime_timeout_ticks(BLE_LOG_TS_TRIGGER_TIMEOUT_MS)); } TEST_ASSERT_TRUE(ble_log_sync_enable(false)); @@ -496,6 +563,65 @@ TEST_CASE("BLE Log periodic timestamp skips light sleep wakeups", "Periodic ESP timer did not emit a timestamp frame"); } +TEST_CASE("BLE Log sync IO control leaves periodic snapshots running", + "[ble_log][runtime][timestamp][ignore]") +{ +#if !CONFIG_BLE_LOG_TS_SYNC_TOGGLE_IO_ENABLED + TEST_IGNORE_MESSAGE("Requires BLE Log TS sync IO toggle support"); +#else + const uint32_t seq = UINT32_C(0x41000); + uint32_t received_seq; + uint8_t io_level; + TEST_ASSERT_TRUE(ble_log_enable(true)); + + TEST_ASSERT_TRUE(ble_log_ts_sync_io_toggle_enable(false)); + TEST_ASSERT_TRUE(runtime_stream_is_quiet()); + TEST_ASSERT_TRUE_MESSAGE(read_periodic_snapshot(&io_level), + "No periodic clock snapshot while sync IO was disabled"); + TEST_ASSERT_EQUAL_UINT8(0, io_level); + TEST_ASSERT_TRUE(runtime_stream_is_quiet()); + + /* Establish the timer phase above, then park a partial OPEN transport and + * close the public producer gate. The next periodic callback must still + * flush the transport and emit its Internal Snapshot. */ + prepare_payload(seq); + TEST_ASSERT_TRUE(ble_log_write_hex(BLE_LOG_SRC_CUSTOM, s_payload, + sizeof(rt_marker_t))); + TEST_ASSERT_TRUE(ble_log_enable(false)); + bool marker_received = read_runtime_marker_with_timeout( + &received_seq, NULL, NULL, + BLE_LOG_TS_TRIGGER_TIMEOUT_MS + 1000); + bool snapshot_received = read_periodic_snapshot(&io_level); + TEST_ASSERT_TRUE(ble_log_enable(true)); + + TEST_ASSERT_TRUE_MESSAGE( + marker_received, + "Producer disable stopped the periodic OPEN transport flush"); + TEST_ASSERT_EQUAL_UINT32(seq, received_seq); + TEST_ASSERT_TRUE_MESSAGE( + snapshot_received, + "Producer disable stopped periodic Internal Snapshots"); + TEST_ASSERT_EQUAL_UINT8(0, io_level); + + TEST_ASSERT_TRUE(runtime_stream_is_quiet()); + TEST_ASSERT_TRUE(ble_log_ts_sync_io_toggle_enable(true)); + bool high_seen = false; + for (int i = 0; i < 3 && !high_seen; i++) { + TEST_ASSERT_TRUE_MESSAGE(read_periodic_snapshot(&io_level), + "No periodic snapshot while sync IO was enabled"); + high_seen = io_level != 0; + } + TEST_ASSERT_TRUE_MESSAGE(high_seen, "Enabled sync IO never toggled high"); + + /* Exercise the compatibility shim on disable. */ + TEST_ASSERT_TRUE(ble_log_sync_enable(false)); + TEST_ASSERT_TRUE(runtime_stream_is_quiet()); + TEST_ASSERT_TRUE_MESSAGE(read_periodic_snapshot(&io_level), + "Sync IO disable stopped periodic snapshots"); + TEST_ASSERT_EQUAL_UINT8(0, io_level); +#endif +} + TEST_CASE("BLE Log runtime dispatch yields to other timer callbacks", "[ble_log][runtime][ignore]") { @@ -737,8 +863,10 @@ TEST_CASE("BLE Log LBM inflight peak stays bounded under bursts", } /* Snapshot the retained peak through the dedicated Internal transport. */ + ble_log_ts_info_t ts_info; + ble_log_rt_ts_sample(&ts_info, false); TEST_ASSERT_TRUE(ble_log_internal_snapshot( - BLE_LOG_SNAPSHOT_REASON_PERIODIC, NULL, true)); + BLE_LOG_SNAPSHOT_REASON_PERIODIC, &ts_info, true)); TEST_ASSERT_TRUE(ble_log_rt_drain()); const int64_t deadline_us = esp_timer_get_time() + diff --git a/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_main.c b/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_main.c index 20558a09e04..4048079c8cf 100644 --- a/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_main.c +++ b/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_main.c @@ -52,8 +52,8 @@ bool test_ble_log_walk_frames(const uint8_t *data, size_t len, void setUp(void) { - /* The periodic TS tick is always on since TS sync became unconditional; - * quiesce it so timing-sensitive tests stay deterministic. */ + /* Preserve the external test-system contract: every test starts with the + * optional sync IO disabled and low. Periodic snapshots remain active. */ (void)ble_log_sync_enable(false); } diff --git a/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_rt.c b/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_rt.c index 39b02135d1b..655b1cccdb5 100644 --- a/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_rt.c +++ b/components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_rt.c @@ -28,9 +28,8 @@ #error "BLE Log test app requires CONFIG_BLE_LOG_PRPH_TEST" #endif -/* The runtime dispatch hook is throttled to one pass per - * BLE_LOG_TS_TRIGGER_TIMEOUT_MS; let the window elapse between write bursts - * so a hook pass is guaranteed to run after the settle delay. */ +/* Internal Snapshots use the production periodic cadence; let one full + * window elapse when a test needs to observe the next periodic sample. */ #define TEST_HOOK_SETTLE_MS (BLE_LOG_TS_TRIGGER_TIMEOUT_MS + 100) #define TEST_READ_TIMEOUT_MS (50) #define TEST_MAX_ROUNDS (3) @@ -56,6 +55,7 @@ typedef struct { static uint8_t s_read_buf[TEST_READ_BUF_SIZE]; static bool s_claim_hook_armed; +static bool s_init_snapshot_hook_armed; static uint32_t s_stale_claim_handle; static volatile bool s_locked_hook_armed; static volatile bool s_enable_hook_armed; @@ -72,6 +72,7 @@ static SemaphoreHandle_t s_compression_hook_continue; void ble_log_test_claim_pre_publish_hook(void); void ble_log_test_claim_locked_hook(void); +void ble_log_test_init_snapshot_before_acquire_hook(void); void ble_log_test_enable_before_lifecycle_lock_hook(void); void ble_log_test_disable_before_wake_hook(void); #if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE @@ -97,7 +98,14 @@ void ble_log_test_claim_locked_hook(void) /* Runs while the claiming writer itself holds the OPEN transport * lock: the flush must skip the busy transport and leave the * pending-seal marker for the next claim. */ - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); + } +} + +void ble_log_test_init_snapshot_before_acquire_hook(void) +{ + if (s_init_snapshot_hook_armed) { + vTaskDelay(pdMS_TO_TICKS(TEST_HOOK_SETTLE_MS)); } } @@ -178,6 +186,28 @@ static void capture_version_info_frame(const test_ble_log_frame_t *frame, void * } } +typedef struct { + bool found; + uint16_t reason_flags; +} first_snapshot_capture_t; + +static void capture_first_snapshot(const test_ble_log_frame_t *frame, void *ctx) +{ + first_snapshot_capture_t *capture = ctx; + if (capture->found || frame->src != BLE_LOG_SRC_INTERNAL || + frame->payload_len != sizeof(uint32_t) + + sizeof(ble_log_internal_snapshot_t)) { + return; + } + + ble_log_internal_snapshot_t snapshot; + memcpy(&snapshot, frame->payload + sizeof(uint32_t), sizeof(snapshot)); + if (snapshot.int_src_code == BLE_LOG_INT_SRC_SNAPSHOT) { + capture->found = true; + capture->reason_flags = snapshot.reason_flags; + } +} + /* Consumes pending test transports concurrently with the writer: transports * are recycled only once read, and the LBM has a small pool of them. */ static void test_reader_task(void *arg) @@ -230,7 +260,7 @@ TEST_CASE("BLE Log v7 framing matches golden bytes", "[ble_log][wire]") TEST_ASSERT_EQUAL_size_t(8, sizeof(ble_log_source_stat_t)); TEST_ASSERT_EQUAL_size_t(134, sizeof(ble_log_internal_snapshot_t)); TEST_ASSERT_EQUAL_size_t( - 4, offsetof(ble_log_internal_snapshot_t, version_info)); + 3, offsetof(ble_log_internal_snapshot_t, version_info)); TEST_ASSERT_EQUAL_size_t( 62, offsetof(ble_log_internal_snapshot_t, ts.lc_ts)); TEST_ASSERT_EQUAL_size_t( @@ -335,6 +365,41 @@ TEST_CASE("BLE Log periodic tick reports build and chip versions", "[ble_log]") vSemaphoreDelete(ctx.done); } +TEST_CASE("BLE Log INIT snapshot starts each receiver epoch", "[ble_log][wire]") +{ + ble_log_deinit(); + s_init_snapshot_hook_armed = true; + bool initialized = ble_log_init(); + s_init_snapshot_hook_armed = false; + TEST_ASSERT_TRUE(initialized); + + size_t len = ble_log_prph_test_read( + s_read_buf, sizeof(s_read_buf), pdMS_TO_TICKS(1000), 0, NULL); + TEST_ASSERT_GREATER_THAN_size_t(0, len); + + first_snapshot_capture_t capture = {0}; + TEST_ASSERT_TRUE(test_ble_log_walk_frames( + s_read_buf, len, capture_first_snapshot, &capture)); + TEST_ASSERT_TRUE(capture.found); + TEST_ASSERT_EQUAL_HEX16(BLE_LOG_SNAPSHOT_REASON_INIT, + capture.reason_flags); +} + +TEST_CASE("BLE Log sync IO APIs retain runtime lifecycle checks", "[ble_log]") +{ + ble_log_deinit(); + TEST_ASSERT_FALSE(ble_log_ts_sync_io_toggle_enable(true)); + TEST_ASSERT_FALSE(ble_log_sync_enable(true)); + + TEST_ASSERT_TRUE(ble_log_init()); + TEST_ASSERT_TRUE(ble_log_ts_sync_io_toggle_enable(false)); + TEST_ASSERT_TRUE(ble_log_sync_enable(false)); + TEST_ASSERT_TRUE(ble_log_rt_drain()); + while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), + 0, 0, NULL) > 0) { + } +} + typedef struct { bool task_frame; bool non_yield_frame; @@ -429,7 +494,7 @@ TEST_CASE("BLE Log marks non-yield context and commits claimed payload", claimed[0] = 0x44; ble_log_commit(fresh_handle, 1); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); frame_meta_capture_t capture = {0}; @@ -535,7 +600,7 @@ TEST_CASE("BLE Log serializes task context per compression source", "[ble_log][compression]") { TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -583,7 +648,7 @@ TEST_CASE("BLE Log serializes task context per compression source", xSemaphoreGive(writer.exit); TEST_ASSERT_TRUE(xSemaphoreTake(writer.exited, pdMS_TO_TICKS(1000))); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); compression_capture_t capture = {0}; for (int i = 0; i < BLE_LOG_TRANS_TOTAL_CNT; i++) { @@ -729,7 +794,7 @@ TEST_CASE("BLE Log preserves LL payload and rejects oversized records", }; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -762,7 +827,7 @@ TEST_CASE("BLE Log preserves LL payload and rejects oversized records", BIT(BLE_LOG_LL_FLAG_TASK)); #endif - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); read_sequence_frames(captures, SEQUENCE_CAPTURE_COUNT); @@ -789,7 +854,7 @@ TEST_CASE("BLE Log flush preserves source-local sequence continuity", const uint8_t before_marker = 0x71; const uint8_t after_marker = 0x72; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -799,7 +864,7 @@ TEST_CASE("BLE Log flush preserves source-local sequence continuity", TEST_ASSERT_TRUE(ble_log_write_hex(BLE_LOG_SRC_CUSTOM, &before_marker, sizeof(before_marker))); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); sequence_capture_t before = { .src = BLE_LOG_SRC_CUSTOM, @@ -816,7 +881,7 @@ TEST_CASE("BLE Log flush preserves source-local sequence continuity", TEST_ASSERT_TRUE(ble_log_write_hex(BLE_LOG_SRC_CUSTOM, &after_marker, sizeof(after_marker))); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); sequence_capture_t after = { .src = BLE_LOG_SRC_CUSTOM, @@ -884,7 +949,7 @@ TEST_CASE("BLE Log pending-seal marker defers the busy transport flush", const uint8_t post_marker = 0xd4; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -919,7 +984,7 @@ TEST_CASE("BLE Log pending-seal marker defers the busy transport flush", TEST_ASSERT_TRUE(ble_log_write_hex(BLE_LOG_SRC_CUSTOM, &post_marker, sizeof(post_marker))); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); marker_chunk_capture_t chunks[2] = {0}; @@ -938,7 +1003,7 @@ TEST_CASE("BLE Log deinit drain delivers parked open transports", const uint8_t markers[TEST_MARKER_CHUNK_MAX] = {0xe1, 0xe2, 0xe3, 0xe4}; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -956,7 +1021,7 @@ TEST_CASE("BLE Log deinit drain delivers parked open transports", /* Exercise the exact deinit-drain contract: close the producer gate and * wait for writers before sealing every OPEN transport. */ ble_log_lbm_begin_deinit(); - ble_log_lbm_drain_open_transports(); + ble_log_lbm_drain_open_trans(); marker_chunk_capture_t chunks[1] = {0}; int chunk_count = read_marker_chunks(chunks, 1); @@ -980,7 +1045,7 @@ TEST_CASE("BLE Log deinit hands residual transports to the peripheral", int recycled = 0; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -1025,11 +1090,14 @@ static void capture_snapshot_loss(const test_ble_log_frame_t *frame, void *ctx) } } -TEST_CASE("BLE Log periodic snapshot fails fast while its transport is busy", +TEST_CASE("BLE Log periodic snapshot ignores producer gate and fails fast when busy", "[ble_log][lbm]") { + ble_log_ts_info_t ts_info; + ble_log_rt_ts_sample(&ts_info, false); + TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); for (int round = 0; round < 2; round++) { TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), @@ -1038,24 +1106,34 @@ TEST_CASE("BLE Log periodic snapshot fails fast while its transport is busy", } TEST_ASSERT_TRUE(ble_log_enable(false)); + bool submitted = false; + for (int attempt = 0; attempt < TEST_MAX_ROUNDS && !submitted; attempt++) { + TEST_ASSERT_TRUE(ble_log_rt_drain()); + while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), + 0, 0, NULL) > 0) { + } + submitted = ble_log_internal_snapshot( + BLE_LOG_SNAPSHOT_REASON_PERIODIC, &ts_info, false); + } + TEST_ASSERT_TRUE_MESSAGE(submitted, + "Periodic timer kept the Internal transport busy"); TEST_ASSERT_FALSE(ble_log_internal_snapshot( - BLE_LOG_SNAPSHOT_REASON_PERIODIC, NULL, false)); + BLE_LOG_SNAPSHOT_REASON_PERIODIC, &ts_info, false)); TEST_ASSERT_TRUE(ble_log_enable(true)); - - TEST_ASSERT_TRUE(ble_log_internal_snapshot( - BLE_LOG_SNAPSHOT_REASON_PERIODIC, NULL, false)); - TEST_ASSERT_FALSE(ble_log_internal_snapshot( - BLE_LOG_SNAPSHOT_REASON_PERIODIC, NULL, false)); - TEST_ASSERT_TRUE(ble_log_rt_drain()); - TEST_ASSERT_GREATER_THAN_size_t( - 0, ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), - pdMS_TO_TICKS(TEST_READ_TIMEOUT_MS), 0, NULL)); - - TEST_ASSERT_TRUE(ble_log_internal_snapshot( - BLE_LOG_SNAPSHOT_REASON_PERIODIC, NULL, false)); TEST_ASSERT_TRUE(ble_log_rt_drain()); snapshot_capture_t capture = {0}; + size_t first_len = ble_log_prph_test_read( + s_read_buf, sizeof(s_read_buf), pdMS_TO_TICKS(TEST_READ_TIMEOUT_MS), + 0, NULL); + TEST_ASSERT_GREATER_THAN_size_t(0, first_len); + TEST_ASSERT_TRUE(test_ble_log_walk_frames( + s_read_buf, first_len, capture_snapshot_loss, &capture)); + + TEST_ASSERT_TRUE(ble_log_internal_snapshot( + BLE_LOG_SNAPSHOT_REASON_PERIODIC, &ts_info, false)); + TEST_ASSERT_TRUE(ble_log_rt_drain()); + for (int i = 0; i < BLE_LOG_TRANS_TOTAL_CNT; i++) { size_t len = ble_log_prph_test_read( s_read_buf, sizeof(s_read_buf), pdMS_TO_TICKS(TEST_READ_TIMEOUT_MS), @@ -1137,7 +1215,7 @@ TEST_CASE("BLE Log deinit closes a parked LL writer before racing enable", BLE_LOG_MAX_PAYLOAD_LEN - sizeof(uint32_t)] = {0}; TEST_ASSERT_TRUE(ble_log_enable(true)); - ble_log_lbm_flush_open_transports(); + ble_log_lbm_flush_open_trans(); TEST_ASSERT_TRUE(ble_log_rt_drain()); while (ble_log_prph_test_read(s_read_buf, sizeof(s_read_buf), 0, 0, NULL) > 0) { }