Merge branch 'feat/nimble_logs_compression' into 'master'

feat(nimble): Support NimBLE log compression and decompression over SPI

See merge request espressif/esp-idf!46967
This commit is contained in:
Rahul Tank
2026-04-22 08:02:05 +05:30
19 changed files with 2132 additions and 51 deletions
+1 -3
View File
@@ -1181,8 +1181,6 @@ set(bt_priv_requires
esp_driver_uart esp_driver_uart
vfs vfs
esp_ringbuf esp_ringbuf
esp_driver_spi
esp_driver_gpio
esp_gdbstub esp_gdbstub
esp_security esp_security
) )
@@ -1217,7 +1215,7 @@ endif()
idf_component_register(SRCS "${srcs}" idf_component_register(SRCS "${srcs}"
INCLUDE_DIRS "${include_dirs}" INCLUDE_DIRS "${include_dirs}"
PRIV_INCLUDE_DIRS "${priv_include_dirs}" PRIV_INCLUDE_DIRS "${priv_include_dirs}"
REQUIRES esp_timer esp_wifi REQUIRES esp_timer esp_wifi esp_driver_spi esp_driver_gpio
PRIV_REQUIRES "${bt_priv_requires}" PRIV_REQUIRES "${bt_priv_requires}"
LDFRAGMENTS "${ldscripts}") LDFRAGMENTS "${ldscripts}")
+2 -1
View File
@@ -15,7 +15,8 @@ if BLE_LOG_ENABLED
config BLE_LOG_LBM_TRANS_BUF_SIZE config BLE_LOG_LBM_TRANS_BUF_SIZE
int "Total buffer memory per common LBM (bytes)" int "Total buffer memory per common LBM (bytes)"
default 2048 default 2048 if BT_BLUEDROID_ENABLED
default 4096 if BT_NIMBLE_ENABLED
help help
Total buffer memory allocated for each common pool log buffer Total buffer memory allocated for each common pool log buffer
manager (LBM). This memory is divided equally among internal manager (LBM). This memory is divided equally among internal
@@ -9,7 +9,7 @@ set(BLE_MESH_LOG_INDEX_HEADER "\"\"")
set(BLE_MESH_TAGS "") set(BLE_MESH_TAGS "")
set(BLE_MESH_TAGS_PRESERVE "") set(BLE_MESH_TAGS_PRESERVE "")
# default config value for host module # default config value for host module (Bluedroid or NimBLE)
set(HOST_CODE_PATH "") set(HOST_CODE_PATH "")
set(HOST_LOG_INDEX_HEADER "\"\"") set(HOST_LOG_INDEX_HEADER "\"\"")
set(BLE_HOST_TAGS "") set(BLE_HOST_TAGS "")
@@ -41,6 +41,20 @@ if(CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE AND CONFIG_BT_BLUEDROID_ENABLED)
"${CMAKE_CURRENT_LIST_DIR}/scripts/module_scripts/bluedroid/make_bluedroid_log_macro.py") "${CMAKE_CURRENT_LIST_DIR}/scripts/module_scripts/bluedroid/make_bluedroid_log_macro.py")
include(${CMAKE_CURRENT_LIST_DIR}/cmake/ble_host_bluedroid_tags.cmake) include(${CMAKE_CURRENT_LIST_DIR}/cmake/ble_host_bluedroid_tags.cmake)
if(NOT EXISTS "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}")
file(WRITE "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}" "")
endif()
list(APPEND LOG_COMPRESSED_MODULE_CODE_PATH ${HOST_CODE_PATH})
elseif(CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE AND CONFIG_BT_NIMBLE_ENABLED)
list(APPEND LOG_COMPRESSED_MODULE "BLE_HOST")
set(HOST_CODE_PATH "host/nimble/nimble/nimble/host")
set(HOST_LOG_INDEX_HEADER "nimble_log_index.h")
set(BLE_HOST_LOG_SCRIPT_PATH
"${CMAKE_CURRENT_LIST_DIR}/scripts/module_scripts/nimble/make_nimble_log_macro.py")
set(BLE_HOST_TAGS "MODLOG_DFLT, BLE_HS_LOG")
set(BLE_HOST_TAGS_PRESERVE "")
if(NOT EXISTS "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}") if(NOT EXISTS "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}")
file(WRITE "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}" "") file(WRITE "${CMAKE_BINARY_DIR}/ble_log/include/${HOST_LOG_INDEX_HEADER}" "")
endif() endif()
@@ -160,9 +160,9 @@ if BLE_COMPRESSED_LOG_ENABLE
endif endif
menuconfig BLE_HOST_COMPRESSED_LOG_ENABLE menuconfig BLE_HOST_COMPRESSED_LOG_ENABLE
bool "Enable BLE Host log compression(Preview, only Bluedroid Host for now)" bool "Enable BLE Host log compression(Preview)"
depends on BLE_COMPRESSED_LOG_ENABLE depends on BLE_COMPRESSED_LOG_ENABLE
depends on BT_BLUEDROID_ENABLED depends on BT_BLUEDROID_ENABLED || BT_NIMBLE_ENABLED
default n default n
help help
Apply compression to host logs. Requires Apply compression to host logs. Requires
@@ -182,7 +182,7 @@ if BLE_COMPRESSED_LOG_ENABLE
help help
Maximum output length for a single log Maximum output length for a single log
if BLE_HOST_COMPRESSED_LOG_ENABLE if BLE_HOST_COMPRESSED_LOG_ENABLE && BT_BLUEDROID_ENABLED
menu "Select the BTM layer log tag to be compressed" menu "Select the BTM layer log tag to be compressed"
config BLE_BLUEDROID_BTM_ERROR_LOG_COMPRESSION config BLE_BLUEDROID_BTM_ERROR_LOG_COMPRESSION
bool "Compress error log of Bluedroid host" bool "Compress error log of Bluedroid host"
@@ -16,6 +16,14 @@
#if CONFIG_BLE_COMPRESSED_LOG_ENABLE #if CONFIG_BLE_COMPRESSED_LOG_ENABLE
#define BLE_CP_DROP_LOG_PERIOD 256U
#define BLE_CP_TRY_PUSH(expr) do { \
if ((expr) != 0) { \
return -1; \
} \
} while (0)
#define BUF_NAME(name, idx) name##_buffer##idx #define BUF_NAME(name, idx) name##_buffer##idx
#define BUF_MGMT_NAME(name) name##_log_buffer_mgmt #define BUF_MGMT_NAME(name) name##_log_buffer_mgmt
@@ -42,12 +50,18 @@ INIT_BUFFER_MGMT(mesh, LOG_CP_MAX_LOG_BUFFER_USED_SIMU);
char * mesh_last_task_handle = NULL; char * mesh_last_task_handle = NULL;
#endif #endif
#if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE #if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE && CONFIG_BT_BLUEDROID_ENABLED
DECLARE_BUFFERS(host, CONFIG_BLE_HOST_COMPRESSED_LOG_BUFFER_LEN, LOG_CP_MAX_LOG_BUFFER_USED_SIMU); DECLARE_BUFFERS(host, CONFIG_BLE_HOST_COMPRESSED_LOG_BUFFER_LEN, LOG_CP_MAX_LOG_BUFFER_USED_SIMU);
INIT_BUFFER_MGMT(host, LOG_CP_MAX_LOG_BUFFER_USED_SIMU); INIT_BUFFER_MGMT(host, LOG_CP_MAX_LOG_BUFFER_USED_SIMU);
char * host_last_task_handle = NULL; char * host_last_task_handle = NULL;
#endif #endif
#if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE && CONFIG_BT_NIMBLE_ENABLED
DECLARE_BUFFERS(nimble, CONFIG_BLE_HOST_COMPRESSED_LOG_BUFFER_LEN, LOG_CP_MAX_LOG_BUFFER_USED_SIMU);
INIT_BUFFER_MGMT(nimble, LOG_CP_MAX_LOG_BUFFER_USED_SIMU);
char * nimble_last_task_handle = NULL;
#endif
/* The maximum number of supported parameters is 64 */ /* The maximum number of supported parameters is 64 */
#define LOG_HEADER(log_type, info) ((log_type << 6) | (info & 0x3f)) #define LOG_HEADER(log_type, info) ((log_type << 6) | (info & 0x3f))
@@ -66,10 +80,15 @@ int ble_compressed_log_cb_get(uint8_t source, ble_cp_log_buffer_mgmt_t **mgmt)
last_handle = &mesh_last_task_handle; last_handle = &mesh_last_task_handle;
break; break;
#endif #endif
#if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE #if CONFIG_BLE_HOST_COMPRESSED_LOG_ENABLE && (CONFIG_BT_BLUEDROID_ENABLED || CONFIG_BT_NIMBLE_ENABLED)
case BLE_COMPRESSED_LOG_OUT_SOURCE_HOST: case BLE_COMPRESSED_LOG_OUT_SOURCE_HOST:
#if CONFIG_BT_BLUEDROID_ENABLED
buffer_mgmt = BUF_MGMT_NAME(host); buffer_mgmt = BUF_MGMT_NAME(host);
last_handle = &host_last_task_handle; last_handle = &host_last_task_handle;
#elif CONFIG_BT_NIMBLE_ENABLED
buffer_mgmt = BUF_MGMT_NAME(nimble);
last_handle = &nimble_last_task_handle;
#endif
break; break;
#endif #endif
default: default:
@@ -80,10 +99,18 @@ int ble_compressed_log_cb_get(uint8_t source, ble_cp_log_buffer_mgmt_t **mgmt)
for (int i = 0; i < LOG_CP_MAX_LOG_BUFFER_USED_SIMU; i++) { for (int i = 0; i < LOG_CP_MAX_LOG_BUFFER_USED_SIMU; i++) {
if (ble_log_cas_acquire(&(buffer_mgmt[i].busy))) { if (ble_log_cas_acquire(&(buffer_mgmt[i].busy))) {
*mgmt = &buffer_mgmt[i]; *mgmt = &buffer_mgmt[i];
ble_log_cp_push_u8(*mgmt, source); if (ble_log_cp_push_u8(*mgmt, source) != 0) {
(*mgmt)->idx = 0;
ble_log_cas_release(&((*mgmt)->busy));
return -1;
}
if (*last_handle == NULL || if (*last_handle == NULL ||
*last_handle != cur_handle) { *last_handle != cur_handle) {
ble_log_cp_push_u8(*mgmt, LOG_HEADER(LOG_TYPE_INFO, LOG_TYPE_INFO_TASK_SWITCH)); if (ble_log_cp_push_u8(*mgmt, LOG_HEADER(LOG_TYPE_INFO, LOG_TYPE_INFO_TASK_SWITCH)) != 0) {
(*mgmt)->idx = 0;
ble_log_cas_release(&((*mgmt)->busy));
return -1;
}
*last_handle = cur_handle; *last_handle = cur_handle;
} }
return 0; return 0;
@@ -108,8 +135,8 @@ int ble_log_compressed_hex_print_internal(ble_cp_log_buffer_mgmt_t *mgmt, uint32
{ {
uint8_t arg_type = 0; uint8_t arg_type = 0;
ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_ARGS, args_cnt)); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_ARGS, args_cnt)));
ble_log_cp_push_u16(mgmt, log_index); BLE_CP_TRY_PUSH(ble_log_cp_push_u16(mgmt, log_index));
uint8_t size_info_idx = mgmt->idx; uint8_t size_info_idx = mgmt->idx;
uint8_t *cur = &(mgmt->buffer)[mgmt->idx]; uint8_t *cur = &(mgmt->buffer)[mgmt->idx];
uint8_t size_info = 0; uint8_t size_info = 0;
@@ -117,20 +144,20 @@ int ble_log_compressed_hex_print_internal(ble_cp_log_buffer_mgmt_t *mgmt, uint32
for (size_t i = 0; i < args_cnt; i++) { for (size_t i = 0; i < args_cnt; i++) {
if (i % 2) { if (i % 2) {
arg_type = va_arg(args, size_t); arg_type = va_arg(args, size_t);
ble_log_cp_push_u8(mgmt, size_info|arg_type); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, size_info|arg_type));
size_info = 0; size_info = 0;
cur++; cur++;
} else { } else {
arg_type = va_arg(args, size_t); arg_type = va_arg(args, size_t);
if (i == args_cnt - 1) { if (i == args_cnt - 1) {
ble_log_cp_push_u8(mgmt, arg_type); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, arg_type));
} else { } else {
size_info = arg_type << 4; size_info = arg_type << 4;
} }
} }
if (arg_type >= ARG_SIZE_TYPE_MAX) { if (arg_type >= ARG_SIZE_TYPE_MAX) {
printf("Found invalid arg type %08lx type %d", log_index, arg_type); printf("Found invalid arg type %08lx type %d", log_index, arg_type);
return 0; return -1;
} }
} }
@@ -148,27 +175,31 @@ int ble_log_compressed_hex_print_internal(ble_cp_log_buffer_mgmt_t *mgmt, uint32
uint32_t u32v = va_arg(args, size_t); uint32_t u32v = va_arg(args, size_t);
if (likely(u32v)) { if (likely(u32v)) {
if (u32v <= 0xff) { if (u32v <= 0xff) {
ble_log_cp_push_u8(mgmt, 3); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, 3));
ble_log_cp_push_u8(mgmt, u32v); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, u32v));
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU32, !(i%2)); BLE_CP_TRY_PUSH(
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU32, !(i%2))
);
break; break;
} else if (u32v <= 0xffff) { } else if (u32v <= 0xffff) {
ble_log_cp_push_u8(mgmt, 2); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, 2));
ble_log_cp_push_u16(mgmt, u32v); BLE_CP_TRY_PUSH(ble_log_cp_push_u16(mgmt, u32v));
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU32, !(i%2)); BLE_CP_TRY_PUSH(
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU32, !(i%2))
);
break; break;
} else { } else {
ble_log_cp_push_u32(mgmt, u32v); BLE_CP_TRY_PUSH(ble_log_cp_push_u32(mgmt, u32v));
} }
} else { } else {
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_AZU32, !(i%2)); BLE_CP_TRY_PUSH(ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_AZU32, !(i%2)));
} }
break; break;
case ARG_SIZE_TYPE_U64: case ARG_SIZE_TYPE_U64:
uint64_t u64v = va_arg(args, uint64_t); uint64_t u64v = va_arg(args, uint64_t);
if (likely(u64v)) { if (likely(u64v)) {
if (unlikely(u64v >> 48)) { if (unlikely(u64v >> 48)) {
ble_log_cp_push_u64(mgmt, u64v); BLE_CP_TRY_PUSH(ble_log_cp_push_u64(mgmt, u64v));
} else { } else {
uint32_t tmpv = 0; uint32_t tmpv = 0;
uint8_t lz = 0; uint8_t lz = 0;
@@ -179,45 +210,46 @@ int ble_log_compressed_hex_print_internal(ble_cp_log_buffer_mgmt_t *mgmt, uint32
tmpv = u64v >> 32; tmpv = u64v >> 32;
} }
lz += __builtin_clz(tmpv) / 8; lz += __builtin_clz(tmpv) / 8;
ble_log_cp_push_u8(mgmt, lz); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, lz));
switch (8-lz) { switch (8-lz) {
case 5: case 5:
ble_log_cp_push_u32(mgmt, (uint32_t)u64v); BLE_CP_TRY_PUSH(ble_log_cp_push_u32(mgmt, (uint32_t)u64v));
[[fallthrough]]; [[fallthrough]];
case 1: case 1:
ble_log_cp_push_u8(mgmt, (uint8_t)tmpv); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, (uint8_t)tmpv));
break; break;
case 6: case 6:
ble_log_cp_push_u32(mgmt, (uint32_t)u64v); BLE_CP_TRY_PUSH(ble_log_cp_push_u32(mgmt, (uint32_t)u64v));
[[fallthrough]]; [[fallthrough]];
case 2: case 2:
ble_log_cp_push_u16(mgmt, (uint16_t)tmpv); BLE_CP_TRY_PUSH(ble_log_cp_push_u16(mgmt, (uint16_t)tmpv));
break; break;
case 7: case 7:
ble_log_cp_push_u32(mgmt, (uint32_t)u64v); BLE_CP_TRY_PUSH(ble_log_cp_push_u32(mgmt, (uint32_t)u64v));
[[fallthrough]]; [[fallthrough]];
case 3: case 3:
ble_log_cp_push_u8(mgmt, (uint8_t)tmpv); BLE_CP_TRY_PUSH(ble_log_cp_push_u8(mgmt, (uint8_t)tmpv));
ble_log_cp_push_u16(mgmt, (uint16_t)(tmpv >> 8)); BLE_CP_TRY_PUSH(ble_log_cp_push_u16(mgmt, (uint16_t)(tmpv >> 8)));
break; break;
default: default:
assert(0); assert(0);
break; break;
} }
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU64, !(i%2)); BLE_CP_TRY_PUSH(
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_LZU64, !(i%2))
);
} }
} else { } else {
ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_AZU64, !(i%2)); BLE_CP_TRY_PUSH(ble_log_cp_update_half_byte(mgmt, size_info_idx + i/2, ARG_SIZE_TYPE_AZU64, !(i%2)));
} }
break; break;
case ARG_SIZE_TYPE_STR: case ARG_SIZE_TYPE_STR:
char *str_p = (char *)va_arg(args, char *); char *str_p = (char *)va_arg(args, char *);
ble_log_cp_push_buf(mgmt, (const uint8_t *)str_p, strlen(str_p) + 1); BLE_CP_TRY_PUSH(ble_log_cp_push_buf(mgmt, (const uint8_t *)str_p, strlen(str_p) + 1));
break; break;
default: default:
printf("Invalid size %d\n", arg_type); printf("Invalid size %d\n", arg_type);
assert(0); return -1;
break;
} }
} }
return 0; return 0;
@@ -231,7 +263,10 @@ int ble_log_compressed_hex_printv(uint8_t source, uint32_t log_index, size_t arg
return 0; return 0;
} }
ble_log_compressed_hex_print_internal(mgmt, log_index, args_cnt, args); if (ble_log_compressed_hex_print_internal(mgmt, log_index, args_cnt, args) != 0) {
ble_compressed_log_buffer_free(mgmt);
return 0;
}
ble_compressed_log_output(source, mgmt->buffer, mgmt->idx); ble_compressed_log_output(source, mgmt->buffer, mgmt->idx);
ble_compressed_log_buffer_free(mgmt); ble_compressed_log_buffer_free(mgmt);
return 0; return 0;
@@ -246,12 +281,19 @@ int ble_log_compressed_hex_print(uint8_t source, uint32_t log_index, size_t args
} }
if (args_cnt == 0) { if (args_cnt == 0) {
ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_ARGS, 0)); if (ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_ARGS, 0)) != 0 ||
ble_log_cp_push_u16(mgmt, log_index); ble_log_cp_push_u16(mgmt, log_index) != 0) {
ble_compressed_log_buffer_free(mgmt);
return 0;
}
} else { } else {
va_list args; va_list args;
va_start(args, args_cnt); va_start(args, args_cnt);
ble_log_compressed_hex_print_internal(mgmt, log_index, args_cnt, args); if (ble_log_compressed_hex_print_internal(mgmt, log_index, args_cnt, args) != 0) {
va_end(args);
ble_compressed_log_buffer_free(mgmt);
return 0;
}
va_end(args); va_end(args);
} }
@@ -269,16 +311,23 @@ int ble_log_compressed_hex_print_buf(uint8_t source, uint32_t log_index, uint8_t
} }
if (buf == NULL && len != 0) { if (buf == NULL && len != 0) {
ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_INFO, LOG_TYPE_INFO_NULL_BUF)); if (ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_INFO, LOG_TYPE_INFO_NULL_BUF)) != 0 ||
ble_log_cp_push_u16(mgmt, log_index); ble_log_cp_push_u16(mgmt, log_index) != 0) {
ble_compressed_log_buffer_free(mgmt);
return 0;
}
ble_compressed_log_output(source, mgmt->buffer, mgmt->idx); ble_compressed_log_output(source, mgmt->buffer, mgmt->idx);
ble_compressed_log_buffer_free(mgmt); ble_compressed_log_buffer_free(mgmt);
return 0; return 0;
} }
ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_BUF, buf_idx)); if (ble_log_cp_push_u8(mgmt, LOG_HEADER(LOG_TYPE_HEX_BUF, buf_idx)) != 0 ||
ble_log_cp_push_u16(mgmt, log_index); ble_log_cp_push_u16(mgmt, log_index) != 0 ||
ble_log_cp_push_buf(mgmt, buf, len); ble_log_cp_push_u16(mgmt, (uint16_t)len) != 0 ||
ble_log_cp_push_buf(mgmt, buf, (uint16_t)len) != 0) {
ble_compressed_log_buffer_free(mgmt);
return 0;
}
ble_compressed_log_output(source, mgmt->buffer, mgmt->idx); ble_compressed_log_output(source, mgmt->buffer, mgmt->idx);
ble_compressed_log_buffer_free(mgmt); ble_compressed_log_buffer_free(mgmt);
return 0; return 0;
@@ -327,10 +327,23 @@ class LogCompressor:
if not fmt_node: if not fmt_node:
return None return None
nimble_nodes = False
if fmt_node.type == 'concatenated_string': if fmt_node.type == 'concatenated_string':
log_fmt = self._process_concatenated_string(fmt_node) log_fmt = self._process_concatenated_string(fmt_node)
elif fmt_node.type == 'string_literal': elif fmt_node.type == 'string_literal':
log_fmt = fmt_node.text.decode('utf-8')[1:-1] # Remove quotes log_fmt = fmt_node.text.decode('utf-8')[1:-1] # Remove quotes
elif fmt_node.type == 'identifier':
# NimBLE style: BLE_HS_LOG(level, "fmt", ...)
nimble_nodes = True
fmt_node = valid_arg_childrn[1] if len(valid_arg_childrn) > 1 else None
if not fmt_node:
return None
if fmt_node.type == 'concatenated_string':
log_fmt = self._process_concatenated_string(fmt_node)
elif fmt_node.type == 'string_literal':
log_fmt = fmt_node.text.decode('utf-8')[1:-1]
else:
return None
else: else:
return None return None
@@ -353,7 +366,11 @@ class LogCompressor:
log_info['hexify'] = False log_info['hexify'] = False
return log_info return log_info
arguments: list[Node] = valid_arg_childrn[1:] arguments: list[Node] = []
if nimble_nodes:
arguments = valid_arg_childrn[2:]
else:
arguments = valid_arg_childrn[1:]
if len(arguments) != need_args: if len(arguments) != need_args:
raise SyntaxError(f'LogSyntaxError:{node.text.decode("utf-8")}') raise SyntaxError(f'LogSyntaxError:{node.text.decode("utf-8")}')
@@ -564,6 +581,30 @@ class LogCompressor:
with open(file_path, 'rb') as f: with open(file_path, 'rb') as f:
content = f.read() content = f.read()
# NimBLE host macros are emitted to nimble_log_index.h (module BLE_HOST when NimBLE is enabled).
# Ensure each compressed NimBLE source includes that header.
if (
module == 'BLE_HOST'
and self.module_info[module].get('log_index_file') == 'nimble_log_index.h'
and b'#include "nimble_log_index.h"' not in content
):
lines = content.splitlines(keepends=True)
first_include = None
last_include = None
for idx, line in enumerate(lines):
if line.lstrip().startswith(b'#include'):
if first_include is None:
first_include = idx
last_include = idx
elif first_include is not None and line.strip() and not line.lstrip().startswith(b'//'):
break
if last_include is not None:
lines.insert(last_include + 1, b'#include "nimble_log_index.h"\n')
content = b''.join(lines)
else:
content = b'#include "nimble_log_index.h"\n' + content
new_content = bytearray(content) new_content = bytearray(content)
logs = self.extract_log_calls(content, self.module_info[module]['tags']) logs = self.extract_log_calls(content, self.module_info[module]['tags'])
LOGGER.info(f'Processing {file_path} - found {len(logs)} logs') LOGGER.info(f'Processing {file_path} - found {len(logs)} logs')
@@ -788,6 +829,10 @@ class LogCompressor:
for module in module_names: for module in module_names:
if module in modules: if module in modules:
self.module_info[module] = modules[module] self.module_info[module] = modules[module]
if module == 'BLE_HOST' and modules[module].get('log_index_file') == 'nimble_log_index.h':
# Force a one-time DB/config refresh for NimBLE compression
# when generator behavior changes (e.g. header injection).
self.module_info[module]['generator_rev'] = 'nimble_include_fix_v1'
module_script_path = self.module_info[module]['script'] module_script_path = self.module_info[module]['script']
spec = self.module_mod[module] = importlib.util.spec_from_file_location(module, module_script_path) spec = self.module_mod[module] = importlib.util.spec_from_file_location(module, module_script_path)
if spec and spec.loader: if spec and spec.loader:
@@ -0,0 +1,168 @@
# BLE Log Decompression Tool
`ble_log_decompress.py` converts BLE Log compressed binary frames into readable log messages.
It supports:
- **Real-time decoding** from a serial port
- **Offline decoding** from captured hex text (`stdin`)
## Why this tool exists
In BLE Log mode, firmware does not transmit full printf-style strings over the logging transport. Instead, it sends compact binary records (log IDs + encoded arguments). This reduces runtime overhead and transport bandwidth on target.
The decompression tool runs on the host side and reconstructs the original log message text by combining:
- incoming frame bytes, and
- a generated dictionary file (`*_logs.json`) that maps log IDs to format strings.
## What the tool does
Firmware sends compact BLE Log frames instead of full text strings. The tool:
1. Parses each frame (`header + payload + checksum tail`)
2. Validates frame integrity (checksum and size guards)
3. Resolves log IDs using a generated dictionary (`*_logs.json`)
4. Prints reconstructed text output
## End-to-end data flow
1. **Input acquisition**
- Serial mode: reads one line at a time from UART.
- Stdin mode: reads captured hex lines from a file/pipe.
2. **Hex line parsing**
- Converts space-separated hex tokens into raw bytes.
- Tolerates optional line labels like `RX:`.
- Malformed tokens are skipped to improve robustness.
3. **Rolling frame assembly**
- Bytes are appended to a rolling buffer.
- Frames are extracted only when a complete frame is present.
- This allows recovery when a frame spans multiple lines.
4. **Frame validation and resynchronization**
- Validates checksum using selected mode (`off`, `head`, `head_payload`, `auto`).
- Applies sanity checks (for example `--max-payload-len`) to avoid “ghost frames” caused by padding/noise.
- On mismatch, parser shifts forward and attempts resync.
5. **Compressed payload decode**
- Decodes compressed record types and argument encodings.
- Rebuilds formatted messages using the dictionary.
- Prints a normalized line with timestamp, sequence, source, log ID, and message.
## Current scope
The current decoder path accepts **host compressed logs only** (on-wire source id **0**), using the dictionary `BLE_HOST_logs.json` (Bluedroid or NimBLE — only one host is active per build).
If the payload source is not **host (0)** (for example mesh sources 1 or 2), that record path is ignored by this script.
## Requirements
- Python 3.8+
- `pyserial` (required only for serial mode)
Install:
```bash
pip install pyserial
```
## Quick start
### Real-time serial mode
```bash
python ble_log_decompress.py \
--port /dev/ttyUSB0 \
--baud 115200 \
--dict path/to/BLE_HOST_logs.json
```
### Offline mode (from file)
```bash
cat captured_dump.txt | python ble_log_decompress.py \
--stdin \
--dict path/to/BLE_HOST_logs.json
```
If `--dict` is not provided, the tool attempts best-effort auto-discovery of a suitable JSON dictionary under `build/`.
## Input format
Each line should be space-separated hex bytes, for example:
```text
08 00 07 4F 01 00 CC CA 18 00 ...
```
An optional leading label token ending with `:` is accepted.
Example accepted lines:
```text
08 00 07 4F 01 00 CC CA 18 00 ...
RX: 08 00 07 4F 01 00 CC CA 18 00 ...
```
For best results, keep input as raw hex bytes from the BLE Log transport path.
## Command-line options
| Option | Default | Purpose |
|---|---|---|
| `--port` | `/dev/ttyUSB0` | Serial port path |
| `--baud` | `115200` | Serial baud rate |
| `--stdin` | off | Read from stdin instead of serial |
| `--dict` | auto-discover if omitted | Path to dictionary JSON |
| `--checksum` | `auto` | `off`, `head`, `head_payload`, `auto` |
| `--hex-buf` | `summary` | HEX buffer output: `skip`, `summary`, `full` |
| `--max-payload-len` | `1014` | Payload sanity guard |
Notes:
- `--checksum auto` learns checksum coverage mode from the stream and then locks to the dominant mode.
- Validation supports both checksum algorithms used by firmware:
- additive sum
- XOR (32-bit little-endian chunk XOR)
- If `--dict` points to a JSON file, sibling known dictionaries in the same directory are also checked.
## Output format
Example:
```text
[12.345s] [Seq 123] [Src 3] [Log 44] GAP procedure initiated: advertise;
```
Field meaning:
- `Timestamp`: target-side tick timestamp (ms) converted to seconds
- `Seq`: frame sequence number from frame metadata
- `Src`: compressed source ID found in payload
- `Log`: dictionary log ID used for format lookup
- trailing text: reconstructed message after argument decoding/formatting
Depending on record type and options, the tool may also print:
- unknown/no-format records,
- HEX buffer summaries (`--hex-buf summary`), or
- full HEX buffer dumps (`--hex-buf full`).
## Common issues
- **No decoded output**
- Ensure the dictionary matches the running firmware build.
- Ensure the input is BLE Log frame hex, not plain UART text logs.
- Confirm logs are Host compressed logs for this decoder path.
- **Frequent drops/resync**
- Use `--checksum auto`.
- Confirm serial port/baud and wiring.
- Adjust `--max-payload-len` only if your transport framing differs.
- **Messages decode but text is wrong**
- Dictionary likely does not match the firmware binary.
- Rebuild and use the dictionary generated from the same build output.
@@ -0,0 +1,51 @@
# SPDX-FileCopyrightText: 2026 Espressif Systems (Shanghai) CO LTD
# SPDX-License-Identifier: Apache-2.0
import textwrap
def generate_nimble_log_prefix(print_statm: str) -> str:
return f'{{if (MYNEWT_VAL(BLE_HS_LOG_LVL) <= LOG_LEVEL_ ##fmt) {print_statm};}}\\\n'
def gen_header_head() -> str:
head = textwrap.dedent("""
// Compression function declarations
extern int ble_log_compressed_hex_print
(uint8_t source, uint32_t log_index, size_t args_size_cnt, ...);
extern int ble_log_compressed_hex_print_buf
(uint8_t source, uint32_t log_index, uint8_t buf_idx, const uint8_t *buf, size_t len);
""")
return head
def gen_compressed_stmt(
log_index: int,
module_id: int,
func_name: str,
fmt: str,
args: list[dict],
buffer_args: list[dict],
) -> str:
if len(args) == 0:
stmt = f' ble_log_compressed_hex_print({module_id}, {log_index}, 0);'
for idx, buffer_arg in enumerate(buffer_args):
stmt += '\\\n'
stmt += (
f' ble_log_compressed_hex_print_buf('
f'{module_id}, {log_index}, {idx}, '
f'(const uint8_t *){buffer_arg["buffer"]}, {buffer_arg["length"]});'
)
stmt += '\\\n'
return ' ' + generate_nimble_log_prefix(stmt)
size_str = ', '.join([arg['size_type'] for arg in args])
args_str = ', '.join([arg['name'] for arg in args]).replace('\\\n', '').replace('\n', '')
stmt = f' ble_log_compressed_hex_print({module_id}, {log_index}, {len(args)}, {size_str}, {args_str});'
for idx, buffer_arg in enumerate(buffer_args):
stmt += '\\\n'
stmt += (
f' ble_log_compressed_hex_print_buf('
f'{module_id}, {log_index}, {idx}, '
f'(const uint8_t *){buffer_arg["buffer"]}, {buffer_arg["length"]});'
)
stmt += '\\\n'
return ' ' + generate_nimble_log_prefix(stmt)
@@ -4,3 +4,4 @@ tree_sitter>=0.23,<=0.23.2; python_version == "3.9"
tree_sitter_c>=0.23,<0.23.5; python_version == "3.9" tree_sitter_c>=0.23,<0.23.5; python_version == "3.9"
tree-sitter~=0.25; python_version >= "3.10" tree-sitter~=0.25; python_version >= "3.10"
tree-sitter-c~=0.24; python_version >= "3.10" tree-sitter-c~=0.24; python_version >= "3.10"
pyserial>=3.5
@@ -17,6 +17,8 @@
#define BLE_LOG_SPI_BUS SPI2_HOST #define BLE_LOG_SPI_BUS SPI2_HOST
#define BLE_LOG_SPI_MAX_TRANSFER_SIZE (10240) #define BLE_LOG_SPI_MAX_TRANSFER_SIZE (10240)
#define BLE_LOG_SPI_TRANS_ITVL_MIN_US (30) #define BLE_LOG_SPI_TRANS_ITVL_MIN_US (30)
#define BLE_LOG_SPI_DMA_ALIGN_BYTES (4U)
#define BLE_LOG_SPI_ALIGN_LOG_PERIOD (256U)
/* VARIABLE */ /* VARIABLE */
BLE_LOG_STATIC bool prph_inited = false; BLE_LOG_STATIC bool prph_inited = false;
@@ -174,11 +176,26 @@ 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) BLE_LOG_IRAM_ATTR void ble_log_prph_send_trans(ble_log_prph_trans_t *trans)
{ {
spi_transaction_t *spi_trans = (spi_transaction_t *)trans->ctx; spi_transaction_t *spi_trans = (spi_transaction_t *)trans->ctx;
uint16_t tx_len = trans->pos;
/*
* SPI slave DMA requires transaction length to be 4-byte aligned.
* Pad trailing bytes with zero to reduce transport loss on slave side.
*/
uint16_t aligned_len = (uint16_t)((tx_len + (BLE_LOG_SPI_DMA_ALIGN_BYTES - 1U)) &
~(BLE_LOG_SPI_DMA_ALIGN_BYTES - 1U));
if (aligned_len != tx_len) {
uint16_t pad_len = (uint16_t)(aligned_len - tx_len);
if (aligned_len <= trans->size) {
BLE_LOG_MEMSET(trans->buf + tx_len, 0, pad_len);
tx_len = aligned_len;
}
}
/* CRITICAL: /* CRITICAL:
* Bytes to bits length conversion is required for tx, and rxlength must be * Bytes to bits length conversion is required for tx, and rxlength must be
* cleared regardless of whether it is used for rx as per SPI master driver */ * cleared regardless of whether it is used for rx as per SPI master driver */
spi_trans->length = (trans->pos << 3); spi_trans->length = (tx_len << 3);
spi_trans->rxlength = 0; spi_trans->rxlength = 0;
if (spi_device_queue_trans(dev_handle, spi_trans, 0) != ESP_OK) { if (spi_device_queue_trans(dev_handle, spi_trans, 0) != ESP_OK) {
ble_log_lbm_t *lbm = (ble_log_lbm_t *)trans->owner; ble_log_lbm_t *lbm = (ble_log_lbm_t *)trans->owner;
@@ -0,0 +1,9 @@
# The following lines of boilerplate have to be in your project's CMakeLists
# in this exact order for cmake to work correctly
cmake_minimum_required(VERSION 3.22)
# list(APPEND sdkconfig_defaults)
include($ENV{IDF_PATH}/tools/cmake/project.cmake)
# "Trim" the build. Include the minimal set of components, main, and anything it depends on.
# idf_build_set_property(MINIMAL_BUILD ON)
project(ble_spi_slave)
@@ -0,0 +1,111 @@
| Supported Targets | ESP32 | ESP32-C2 | ESP32-C3 | ESP32-C5 | ESP32-C6 | ESP32-C61 | ESP32-H2 | ESP32-H4 | ESP32-S3 |
| ----------------- | ----- | -------- | -------- | -------- | -------- | --------- | -------- | -------- | -------- |
# NimBLE SPI Slave Receiver Example
(See the README.md file in the upper level 'examples' directory for more information about examples.)
## Overview
This example configures the device as an **SPI slave receiver** and prints received data to UART in hexadecimal format.
It is intended to work with a peer device acting as an SPI master (for example, a NimBLE BLE Log sender). Data is received on SPI and projected to the serial monitor, which makes this example useful for bring-up and transport validation.
### What this example does
- Initializes SPI slave mode (`SPI2_HOST`)
- Uses MOSI/SCLK/CS lines to receive data in half-duplex style
- Keeps MISO disabled (`-1`)
- Receives transactions in 1024-byte DMA buffers
- Prints received bytes to UART in 32-byte lines (`%02X` format)
## Hardware behavior
The receive pins are configured from Kconfig symbols used by this example:
- `CONFIG_BT_BLE_LOG_SPI_OUT_MOSI_IO_NUM`
- `CONFIG_BT_BLE_LOG_SPI_OUT_SCLK_IO_NUM`
- `CONFIG_BT_BLE_LOG_SPI_OUT_CS_IO_NUM`
Defined in [main/ble_spi_slave.h](main/ble_spi_slave.h).
The example enables pull-ups on MOSI/SCLK/CS to reduce false activity when no master is connected.
## Hardware connection
Connect your SPI master device to the example target:
- Master MOSI -> Slave MOSI
- Master SCLK -> Slave SCLK
- Master CS -> Slave CS
- GND <-> GND
Notes:
- MISO is not used by this example.
- SPI mode is fixed to mode 0 in current code.
- Ensure both devices share a common ground.
## How to Use Example
Before project configuration and build, set the target:
```bash
idf.py set-target <chip_name>
```
### Configure the project
Open configuration menu:
```bash
idf.py menuconfig
```
Configure SPI pin assignments used by this example via Bluetooth/BLE Log SPI output configuration (MOSI/SCLK/CS), so they match your wiring.
### Build and flash
```bash
idf.py -p PORT flash monitor
```
(To exit the serial monitor, type `Ctrl-]`.)
## Expected output
When the SPI master sends data, this example prints the received bytes as hexadecimal text, for example:
```text
08 00 07 4F 01 00 CC CA 18 00 ...
```
Output is line-broken every 32 bytes for readability in the monitor.
## Typical use with BLE Log pipelines
This receiver can be used as the SPI-side capture endpoint in BLE Log transport testing:
1. Master device sends BLE Log frame bytes over SPI.
2. This example receives and prints them on UART.
3. Host tools can capture UART hex and decode with BLE log decompression scripts.
## Limitations
- This example does not decode BLE payloads; it only receives and prints raw bytes.
- Transaction buffer size is fixed at 1024 bytes in current source.
## Troubleshooting
- **No data printed**
- Verify wiring and shared ground.
- Verify pin configuration in menuconfig matches your board wiring.
- Verify SPI master is actively transmitting and uses mode 0.
- **Corrupted or unstable output**
- Check signal integrity and clock speed.
- Confirm pull-ups and board-level electrical compatibility.
- **Build errors related to drivers**
- Ensure SPI/GPIO driver components are enabled (already declared in this example component dependencies).
@@ -0,0 +1,3 @@
idf_component_register(SRCS "main.c"
REQUIRES esp_driver_spi esp_driver_gpio
INCLUDE_DIRS ".")
@@ -0,0 +1,12 @@
/*
* SPDX-FileCopyrightText: 2026 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Unlicense OR CC0-1.0
*/
// Please update the following configuration according to your HardWare spec
#define RCV_HOST SPI2_HOST
#define GPIO_MOSI CONFIG_BT_BLE_LOG_SPI_OUT_MOSI_IO_NUM
#define GPIO_MISO -1
#define GPIO_SCLK CONFIG_BT_BLE_LOG_SPI_OUT_SCLK_IO_NUM
#define GPIO_CS CONFIG_BT_BLE_LOG_SPI_OUT_CS_IO_NUM
@@ -0,0 +1,131 @@
/*
* SPDX-FileCopyrightText: 2026 Espressif Systems (Shanghai) CO LTD
*
* SPDX-License-Identifier: Unlicense OR CC0-1.0
*/
#include <stdio.h>
#include <stdint.h>
#include <stddef.h>
#include <string.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_log.h"
#include "driver/spi_slave.h"
#include "driver/gpio.h"
#include "ble_spi_slave.h"
/*
SPI receiver (slave) example.
This example is supposed to work together with a NimBLE module acting as SPI master.
It uses the standard SPI pins (MISO, MOSI, SCLK, CS) to transmit logs over in a
half-duplex fashion, that is, the master puts data on the MOSI pin, while the MISO pins
remain inactive.
*/
//Dummy callback called after a transaction is queued and ready for pickup by master.
static void my_post_setup_cb(spi_slave_transaction_t *trans)
{
return;
}
//Dummy callback called after transaction is sent/received.
static void my_post_trans_cb(spi_slave_transaction_t *trans)
{
return;
}
//Main application
void app_main(void)
{
int n = 0;
esp_err_t ret;
spi_slave_transaction_t t = {0};
//Configuration for the SPI bus
spi_bus_config_t buscfg = {
.mosi_io_num = GPIO_MOSI,
.miso_io_num = -1,
.sclk_io_num = GPIO_SCLK,
.quadwp_io_num = -1,
.quadhd_io_num = -1,
};
//Configuration for the SPI slave interface
spi_slave_interface_config_t slvcfg = {
.mode = 0,
.spics_io_num = GPIO_CS,
.queue_size = 3,
.flags = 0,
.post_setup_cb = my_post_setup_cb,
.post_trans_cb = my_post_trans_cb
};
//Enable pull-ups on SPI lines so we don't detect rogue pulses when no master is connected.
gpio_set_pull_mode(GPIO_MOSI, GPIO_PULLUP_ONLY);
gpio_set_pull_mode(GPIO_SCLK, GPIO_PULLUP_ONLY);
gpio_set_pull_mode(GPIO_CS, GPIO_PULLUP_ONLY);
/**
* The default drive capability on esp32 is GPIO_DRIVE_CAP_2 (~20 mA).
* When connecting master devices that uses a source/sink current lower or higher than GPIO_DRIVER_CAP_DEFAULT.
* Using a drive strength that does not match the requirements of the connected device can cause issues
* such as unreliable switching, or damage to the GPIO pin or external device.
*
* - GPIO_DRIVE_CAP_0: ~5 mA
* - GPIO_DRIVE_CAP_1: ~10 mA
* - GPIO_DRIVE_CAP_2: ~20 mA
* - GPIO_DRIVE_CAP_3: ~40 mA
gpio_set_drive_capability(GPIO_MOSI, GPIO_DRIVE_CAP_3);
gpio_set_drive_capability(GPIO_SCLK, GPIO_DRIVE_CAP_3);
gpio_set_drive_capability(GPIO_CS, GPIO_DRIVE_CAP_3);
**/
//Initialize SPI slave interface
ret = spi_slave_initialize(RCV_HOST, &buscfg, &slvcfg, SPI_DMA_CH_AUTO);
assert(ret == ESP_OK);
// For SPI DMA, buffers should be word-aligned.
WORD_ALIGNED_ATTR uint8_t recvbuf[1024];
while (1) {
//Clear receive buffer, set send buffer to something sane
memset(recvbuf, 0x00, 1024);
//Set up a transaction of 1024 bytes to receive
t.length = 1024 * 8;
t.tx_buffer = NULL;
t.rx_buffer = recvbuf;
/* This call enables the SPI slave interface to receive to the recvbuf. The transaction is
* initialized by the SPI master, however, so it will not actually happen until the master starts a hardware transaction
* by pulling CS low and pulsing the clock etc.
*/
ret = spi_slave_transmit(RCV_HOST, &t, portMAX_DELAY);
/* Get the actual number of bytes received */
int rcv_bytes = t.trans_len / 8;
if (rcv_bytes == 0) {
rcv_bytes = 1024; // Fallback if hardware didn't report exact length
}
/* Print the binary buffer in safe 32-byte chunks */
for (int i = 0; i < rcv_bytes; i++) {
// Print the raw byte (ignoring null-terminators)
printf("%02X ", recvbuf[i]);
// Break the line to prevent ESP-IDF terminal truncation
if ((i + 1) % 32 == 0 || i == rcv_bytes - 1) {
printf("\n");
}
}
n++;
}
}
@@ -0,0 +1,7 @@
CONFIG_BT_ENABLED=y
CONFIG_BTDM_CTRL_MODE_BLE_ONLY=y
CONFIG_BTDM_CTRL_MODE_BR_EDR_ONLY=n
CONFIG_BTDM_CTRL_MODE_BTDM=n
CONFIG_BT_BLUEDROID_ENABLED=n
CONFIG_BT_NIMBLE_ENABLED=y
CONFIG_BT_BLE_LOG_SPI_OUT_ENABLED=y
+1
View File
@@ -92,6 +92,7 @@ KNOWN_MISSING = {
'bluetooth/nimble/ble_phy/phy_prph', 'bluetooth/nimble/ble_phy/phy_prph',
'bluetooth/nimble/ble_proximity_sensor/proximity_sensor_cent', 'bluetooth/nimble/ble_proximity_sensor/proximity_sensor_cent',
'bluetooth/nimble/ble_proximity_sensor/proximity_sensor_prph', 'bluetooth/nimble/ble_proximity_sensor/proximity_sensor_prph',
'bluetooth/nimble/ble_spi_slave',
'bluetooth/nimble/ble_spp/spp_client', 'bluetooth/nimble/ble_spp/spp_client',
'bluetooth/nimble/ble_spp/spp_server', 'bluetooth/nimble/ble_spp/spp_server',
'bluetooth/nimble/blecent', 'bluetooth/nimble/blecent',