Mirrors/esp-idf
1
0
Fork 0
mirror of https://github.com/espressif/esp-idf.git synced 2026-09-22 13:01:16 +03:00
Code Issues Packages Projects Releases Wiki Activity

refactor(ble_log): remove the dead legacy LBM module and tidy the v7 switch

Browse Source 
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.
This commit is contained in:
Zhou Xiao
2026-09-02 19:25:33 +08:00
committed by guozifan
parent 06478ec313
commit 281ce584f3
23 changed files with 602 additions and 1420 deletions
Download Patch File Download Diff File Expand all files Collapse all files

10
components/bt/common/ble_log/Kconfig.in
View File

@@ -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

29
components/bt/common/ble_log/README.md
View File

@@ -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.

8
components/bt/common/ble_log/include/ble_log.h
View File

@@ -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__ */

32
components/bt/common/ble_log/src/ble_log.c
View File

@@ -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();

874
components/bt/common/ble_log/src/ble_log_lbm.c
View File

@@ -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;
}

267
components/bt/common/ble_log/src/ble_log_lbm_v2.c
View File

@@ -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: <hash>" */
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;
}

7
components/bt/common/ble_log/src/ble_log_redir.c
View File

@@ -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);

159
components/bt/common/ble_log/src/ble_log_rt.c
View File

@@ -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);
}

15
components/bt/common/ble_log/src/ble_log_util.c
View File

@@ -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, &current, value, true,
__ATOMIC_RELAXED, __ATOMIC_RELAXED)) {
}
}

272
components/bt/common/ble_log/src/internal_include/ble_log_lbm.h
View File

@@ -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__ */

25
components/bt/common/ble_log/src/internal_include/ble_log_lbm_v2.h
View File

@@ -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

3
components/bt/common/ble_log/src/internal_include/ble_log_prph.h
View File

@@ -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);

9
components/bt/common/ble_log/src/internal_include/ble_log_rt.h
View File

@@ -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__ */

5
components/bt/common/ble_log/src/internal_include/ble_log_util.h
View File

@@ -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__ */

1
components/bt/common/ble_log/src/prph/ble_log_prph_dummy.c
View File

@@ -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);
}

1
components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_dma.c
View File

@@ -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);
}

2
components/bt/common/ble_log/src/prph/ble_log_prph_spi_master_hd.c
View File

@@ -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);
}
}

4
components/bt/common/ble_log/src/prph/ble_log_prph_test.c
View File

@@ -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;

7
components/bt/common/ble_log/src/prph/ble_log_prph_uart_dma.c
View File

@@ -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);
}
}

4
components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_main.c
View File

@@ -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);
}

138
components/bt/common/ble_log/test_apps/ble_log_rt_test/main/test_ble_log_runtime.c
View File

@@ -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() +

4
components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_main.c
View File

@@ -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);
}

146
components/bt/common/ble_log/test_apps/ble_log_test/main/test_ble_log_rt.c
View File

@@ -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) {
}