From 03ec34e66112b2b583b54ff647d481c02efd37d7 Mon Sep 17 00:00:00 2001 From: Peter Harper Date: Fri, 30 May 2025 16:19:06 +0100 Subject: [PATCH 1/2] Tidy up bt logging Fixes #2253 --- .../cybt_shared_bus/BUILD.bazel | 2 +- .../cybt_shared_bus/cybt_logging.h | 49 +++++++++++++++++ .../cybt_shared_bus/cybt_shared_bus.c | 54 +++++++------------ .../cybt_shared_bus/cybt_shared_bus_driver.c | 44 +++++---------- 4 files changed, 84 insertions(+), 65 deletions(-) create mode 100644 src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h diff --git a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/BUILD.bazel b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/BUILD.bazel index 24e53b3f9..7ade7c787 100644 --- a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/BUILD.bazel +++ b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/BUILD.bazel @@ -6,7 +6,7 @@ cc_library( "cybt_shared_bus.c", "cybt_shared_bus_driver.c", ], - hdrs = ["cybt_shared_bus_driver.h"], + hdrs = ["cybt_shared_bus_driver.h", "cybt_logging.h"], includes = ["."], deps = [ "@cyw43-driver//:cyw43_driver", diff --git a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h new file mode 100644 index 000000000..849945f8e --- /dev/null +++ b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h @@ -0,0 +1,49 @@ +/* + * Copyright (c) 2025 Raspberry Pi (Trading) Ltd. + * + * SPDX-License-Identifier: BSD-3-Clause + */ + +#ifndef CYBT_LOGGING_H +#define CYBT_LOGGING_H + +// Error messages only enabled in debug by default +#ifndef NDEBUG +#define CYBT_ERROR_ENABLED 1 +#else +#define CYBT_ERROR_ENABLED 0 +#endif + +// Info messages only enabled in debug by default +#ifndef NDEBUG +#define CYBT_INFO_ENABLED 1 +#else +#define CYBT_INFO_ENABLED 0 +#endif + +// Debug messages disabled by default +#define CYBT_DEBUG_ENABLED 0 + +#if CYBT_DEBUG_ENABLED || CYBT_ERROR_ENABLED +#include +#endif + +#if CYBT_ERROR_ENABLED +#define cybt_error CYW43_WARN +#else +#define cybt_error(...) +#endif + +#if CYBT_INFO_ENABLED +#define cybt_info CYW43_PRINTF +#else +#define cybt_info(...) +#endif + +#if CYBT_DEBUG_ENABLED +#define cybt_debug CYW43_PRINTF +#else +#define cybt_debug(...) +#endif + +#endif // CYBT_LOGGING_H \ No newline at end of file diff --git a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus.c b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus.c index 9b454b6d5..f256f0e4c 100644 --- a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus.c +++ b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus.c @@ -15,6 +15,7 @@ #include "cybt_shared_bus_driver.h" #include "cyw43_btfw_43439.h" +#include "cybt_logging.h" #if CYW43_USE_HEX_BTFW extern const char brcm_patch_version[]; @@ -31,20 +32,6 @@ extern const int brcm_patch_ram_length; #define BTSDIO_FWBUF_OPER_DELAY_US (250) #define BTFW_WAIT_TIME_MS (150) -#define CYBT_DEBUG 0 -#define CYBT_VDEBUG 0 - -#if CYBT_DEBUG -#define cybt_debug(format,args...) printf("%d.%d: " format, (int)cyw43_hal_ticks_ms() / 1000, (int)cyw43_hal_ticks_ms() % 1000, ## args) -#else -#define cybt_debug(format, ...) ((void)0) -#endif -#ifndef NDEBUG -#define cybt_printf(format, args...) printf("%d.%d: " format, (int)cyw43_hal_ticks_ms() / 1000, (int)cyw43_hal_ticks_ms() % 1000, ## args) -#else -#define cybt_printf(...) -#endif - #define ROUNDUP(x, a) ((((x) + ((a) - 1)) / (a)) * (a)) #define ROUNDDN(x, a) ((x) & ~((a) - 1)) #define ISALIGNED(a, x) (((uint32_t)(a) & ((x) - 1)) == 0) @@ -123,7 +110,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) { ret = cybt_fw_download_prepare(&p_write_buf, &p_hex_buf); if (CYBT_SUCCESS != ret) { - cybt_printf("Could not allocate memory\n"); + cybt_error("Could not allocate memory\n"); return ret; } @@ -131,9 +118,9 @@ int cyw43_btbus_init(cyw43_ll_t *self) { const uint8_t *fw_data_buf; uint32_t fw_data_len; #if CYW43_USE_HEX_BTFW - cybt_printf("CYW43_USE_HEX_BTFW is true\n"); + cybt_error("CYW43_USE_HEX_BTFW is true\n"); #ifndef NDEBUG - cybt_printf("BT FW download, version = %s\n", brcm_patch_version); + cybt_info("BT FW download, version = %s\n", brcm_patch_version); #endif fw_data_len = brcm_patch_ram_length; fw_data_buf = brcm_patchram_buf; @@ -151,7 +138,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) { cybt_fw_download_finish(p_write_buf, p_hex_buf); if (CYBT_SUCCESS != ret) { - cybt_printf("hci_open(): FW download failed (0x%x)\n", ret); + cybt_error("hci_open(): FW download failed (0x%x)\n", ret); return CYBT_ERR_HCI_INIT_FAILED; } @@ -161,7 +148,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) { if (CYBT_SUCCESS == ret) { cybt_debug("hci_open(): FW download successfully\n"); } else { - cybt_printf("hci_open(): Failed to download FW\n"); + cybt_error("hci_open(): Failed to download FW\n"); return CYBT_ERR_HCI_INIT_FAILED; } @@ -182,7 +169,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) { return CYBT_SUCCESS; } -#if CYBT_VDEBUG +#if 0 static void dump_bytes(const uint8_t *bptr, uint32_t len) { unsigned int i = 0; @@ -198,6 +185,9 @@ static void dump_bytes(const uint8_t *bptr, uint32_t len) { } printf("\n"); } +#define DUMP_BYTES dump_bytes +#else +#define DUMP_BYTES(...) #endif static cybt_result_t cybt_hci_write_buf(const uint8_t *p_data, uint32_t length) { @@ -206,7 +196,7 @@ static cybt_result_t cybt_hci_write_buf(const uint8_t *p_data, uint32_t length) assert(ISALIGNED(p_data, 4)); if (!ISALIGNED(p_data, 4)) { - cybt_printf("cybt_hci_write_hdr: buffer not aligned\n"); + cybt_error("cybt_hci_write_hdr: buffer not aligned\n"); return CYBT_ERR_BADARG; } @@ -260,7 +250,7 @@ static cybt_result_t cybt_hci_read(uint8_t *p_data, uint32_t *p_length) { assert(ISALIGNED(p_data, 4)); if (!ISALIGNED(p_data, 4)) { assert(false); - cybt_printf("cybt_hci_read: buffer not aligned\n"); + cybt_error("cybt_hci_read: buffer not aligned\n"); return CYBT_ERR_BADARG; } @@ -272,9 +262,9 @@ static cybt_result_t cybt_hci_read(uint8_t *p_data, uint32_t *p_length) { cybt_debug("cybt_hci_read: bt2host_in_val=%lu bt2host_out_val=%lu fw_b2h_buf_count=%ld\n", fw_membuf_info.bt2host_in_val, fw_membuf_info.bt2host_out_val, fw_b2h_buf_count); if (fw_b2h_buf_count < available) { - cybt_printf("error: cybt_hci_read buffer overflow fw_b2h_buf_count=%ld available=%lu\n", fw_b2h_buf_count, + cybt_error("error: cybt_hci_read buffer overflow fw_b2h_buf_count=%ld available=%lu\n", fw_b2h_buf_count, available); - cybt_printf("error: cybt_hci_read bt2host_in_val=%lu bt2host_out_val=%lu\n", fw_membuf_info.bt2host_in_val, + cybt_error("error: cybt_hci_read bt2host_in_val=%lu bt2host_out_val=%lu\n", fw_membuf_info.bt2host_in_val, fw_membuf_info.bt2host_out_val); panic("cyw43 buffer overflow"); } @@ -355,9 +345,7 @@ int cyw43_btbus_write(uint8_t *buf, uint32_t size) { cybt_bus_request(); cybt_debug("cyw43_btbus_write: %d\n", cmd_len); -#if CYBT_VDEBUG - dump_bytes(buf, size); // dump header and data -#endif + DUMP_BYTES(buf, size); // dump header and data cybt_hci_write_buf(buf, size); cybt_bus_release(); @@ -376,7 +364,7 @@ static bool cybt_hci_read_packet(uint8_t *buf, uint32_t max_buf_size, uint32_t * if (bt_result != CYBT_SUCCESS) { *size = 0; - cybt_printf("cybt_hci_read_packet: error %d", bt_result); + cybt_error("cybt_hci_read_packet: error %d", bt_result); return true; } @@ -390,7 +378,7 @@ static bool cybt_hci_read_packet(uint8_t *buf, uint32_t max_buf_size, uint32_t * uint32_t hci_read_len = ((buf[2] << 16) & 0xFFFF00) | ((buf[1] << 8) & 0xFF00) | (buf[0] & 0xFF); if (hci_read_len > max_buf_size - 4) { *size = 0; - cybt_printf("cybt_hci_read_packet: too much data len %" PRId32"\n", hci_read_len); + cybt_error("cybt_hci_read_packet: too much data len %" PRId32"\n", hci_read_len); assert(false); return false; } @@ -401,7 +389,7 @@ static bool cybt_hci_read_packet(uint8_t *buf, uint32_t max_buf_size, uint32_t * bt_result = cybt_hci_read(buf + 4, &total_read_len); if (bt_result != CYBT_SUCCESS) { *size = 0; - cybt_printf("cybt_hci_read_packet: read failed\n"); + cybt_error("cybt_hci_read_packet: read failed\n"); assert(false); return false; } @@ -413,15 +401,13 @@ static bool cybt_hci_read_packet(uint8_t *buf, uint32_t max_buf_size, uint32_t * } else { assert(total_read_len > 0); *size = total_read_len + 4; - cybt_printf("cybt_hci_read_packet: failed to read all data %lu < %lu\n", total_read_len, hci_read_len); + cybt_error("cybt_hci_read_packet: failed to read all data %lu < %lu\n", total_read_len, hci_read_len); //assert(false); return true; } cybt_debug("cybt_hci_read_packet: %ld\n", *size); -#if CYBT_VDEBUG - dump_bytes(buf, *size); -#endif + DUMP_BYTES(buf, *size); return true; } diff --git a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus_driver.c b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus_driver.c index 452337f99..dcfca3a15 100644 --- a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus_driver.c +++ b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_shared_bus_driver.c @@ -11,6 +11,7 @@ #include "cyw43_ll.h" #include "cybt_shared_bus_driver.h" +#include "cybt_logging.h" // Bluetooth register corruption occurs if both wifi and bluetooth are fully utilised. #define CYBT_CORRUPTION_TEST 1 @@ -23,23 +24,6 @@ static uint32_t last_bt_ctrl_reg; #endif -#ifndef NDEBUG -#define cybt_printf(format, args ...) printf(format,##args) -#else -#define cybt_printf(...) -#endif - -#ifndef CYBT_DEBUG -#define CYBT_DEBUG 0 -#endif - -#if CYBT_DEBUG -#include -#define cybt_debug(format, args ...) printf(format,##args) -#else -#define cybt_debug(format, ...) ((void)0) -#endif - /****************************************************************************** * Constants @@ -319,7 +303,7 @@ cybt_result_t cybt_fw_download(const uint8_t *p_bt_firmware, uint8_t version_len = *p_bt_firmware; assert(*(p_bt_firmware + version_len) == 0); #ifndef NDEBUG - cybt_printf("BT FW download, version = %s\n", p_bt_firmware + 1); + cybt_info("BT FW download, version = %s\n", p_bt_firmware + 1); #endif p_bt_firmware += version_len + 1; // skip over version p_bt_firmware += 1; // skip over record count @@ -409,7 +393,7 @@ cybt_result_t cybt_toggle_bt_intr(void) { cybt_reg_read(HOST_CTRL_REG_ADDR, ®_val); #if CYBT_CORRUPTION_TEST if ((reg_val & ~(BTSDIO_REG_SW_RDY_BITMASK | BTSDIO_REG_WAKE_BT_BITMASK | BTSDIO_REG_DATA_VALID_BITMASK)) != 0) { - cybt_printf("cybt_toggle_bt_intr read HOST_CTRL_REG_ADDR as 0x%08lx\n", reg_val); + cybt_error("cybt_toggle_bt_intr read HOST_CTRL_REG_ADDR as 0x%08lx\n", reg_val); cybt_debug_dump(); panic("cyw43 btsdio register corruption"); } @@ -485,32 +469,32 @@ void cybt_debug_dump(void) { uint32_t reg_val = 0; cybt_fw_membuf_index_t buf_index; - cybt_printf("WLAN_RAM_BASE_ADDR: 0x%08lx\n", WLAN_RAM_BASE_ADDR); - cybt_printf("H2B_BUF_ADDR: 0x%08lx\n", H2B_BUF_ADDR); - cybt_printf("B2H_BUF_ADDR: 0x%08lx\n", B2H_BUF_ADDR); + cybt_debug("WLAN_RAM_BASE_ADDR: 0x%08lx\n", WLAN_RAM_BASE_ADDR); + cybt_debug("H2B_BUF_ADDR: 0x%08lx\n", H2B_BUF_ADDR); + cybt_debug("B2H_BUF_ADDR: 0x%08lx\n", B2H_BUF_ADDR); cybt_reg_read(H2B_BUF_IN_ADDR, &buf_index.host2bt_in_val); - cybt_printf("H2B_BUF_IN_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", H2B_BUF_IN_ADDR, buf_index.host2bt_in_val, + cybt_debug("H2B_BUF_IN_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", H2B_BUF_IN_ADDR, buf_index.host2bt_in_val, last_buf_index.host2bt_in_val); cybt_reg_read(H2B_BUF_OUT_ADDR, &buf_index.host2bt_out_val); - cybt_printf("H2B_BUF_OUT_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", H2B_BUF_OUT_ADDR, buf_index.host2bt_out_val, + cybt_debug("H2B_BUF_OUT_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", H2B_BUF_OUT_ADDR, buf_index.host2bt_out_val, last_buf_index.host2bt_out_val); cybt_reg_read(B2H_BUF_IN_ADDR, &buf_index.bt2host_in_val); - cybt_printf("B2H_BUF_IN_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", B2H_BUF_IN_ADDR, buf_index.bt2host_in_val, + cybt_debug("B2H_BUF_IN_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", B2H_BUF_IN_ADDR, buf_index.bt2host_in_val, last_buf_index.bt2host_in_val); cybt_reg_read(B2H_BUF_OUT_ADDR, &buf_index.bt2host_out_val); - cybt_printf("B2H_BUF_OUT_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", B2H_BUF_OUT_ADDR, buf_index.bt2host_out_val, + cybt_debug("B2H_BUF_OUT_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", B2H_BUF_OUT_ADDR, buf_index.bt2host_out_val, last_buf_index.bt2host_out_val); cybt_reg_read(HOST_CTRL_REG_ADDR, ®_val); - cybt_printf("HOST_CTRL_REG_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", HOST_CTRL_REG_ADDR, reg_val, + cybt_debug("HOST_CTRL_REG_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", HOST_CTRL_REG_ADDR, reg_val, last_host_ctrl_reg); cybt_reg_read(BT_CTRL_REG_ADDR, ®_val); - cybt_printf("BT_CTRL_REG_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", BT_CTRL_REG_ADDR, reg_val, last_bt_ctrl_reg); + cybt_debug("BT_CTRL_REG_ADDR: 0x%08lx = 0x%08lx (last 0x%08lx)\n", BT_CTRL_REG_ADDR, reg_val, last_bt_ctrl_reg); #endif } @@ -533,7 +517,7 @@ cybt_result_t cybt_get_bt_buf_index(cybt_fw_membuf_index_t *p_buf_index) { #if CYBT_CORRUPTION_TEST if (p_buf_index->host2bt_in_val >= BTSDIO_FWBUF_SIZE || p_buf_index->host2bt_out_val >= BTSDIO_FWBUF_SIZE || p_buf_index->bt2host_in_val >= BTSDIO_FWBUF_SIZE || p_buf_index->bt2host_out_val >= BTSDIO_FWBUF_SIZE) { - cybt_printf("cybt_get_bt_buf_index invalid buffer value\n"); + cybt_error("cybt_get_bt_buf_index invalid buffer value\n"); cybt_debug_dump(); } else { memcpy((uint8_t *) &last_buf_index, (uint8_t *) p_buf_index, sizeof(cybt_fw_membuf_index_t)); @@ -567,7 +551,7 @@ static cybt_result_t cybt_reg_read(uint32_t reg_addr, uint32_t *p_value) { return CYBT_SUCCESS; } -#if CYBT_DEBUG +#if 0 static void dump_bytes(const uint8_t *bptr, uint32_t len) { unsigned int i = 0; From 0a2fbb0e3a0eadea634c122dd46120dac6faa557 Mon Sep 17 00:00:00 2001 From: Peter Harper Date: Wed, 18 Jun 2025 18:34:40 +0100 Subject: [PATCH 2/2] Allow logging to be overridden --- .../cybt_shared_bus/cybt_logging.h | 14 +++++++++++--- 1 file changed, 11 insertions(+), 3 deletions(-) diff --git a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h index 849945f8e..aad2a1e6e 100644 --- a/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h +++ b/src/rp2_common/pico_cyw43_driver/cybt_shared_bus/cybt_logging.h @@ -8,42 +8,50 @@ #define CYBT_LOGGING_H // Error messages only enabled in debug by default +#ifndef CYBT_ERROR_ENABLED #ifndef NDEBUG #define CYBT_ERROR_ENABLED 1 #else #define CYBT_ERROR_ENABLED 0 #endif +#endif // Info messages only enabled in debug by default +#ifndef CYBT_INFO_ENABLED #ifndef NDEBUG #define CYBT_INFO_ENABLED 1 #else #define CYBT_INFO_ENABLED 0 #endif +#endif // Debug messages disabled by default +#ifndef CYBT_DEBUG_ENABLED #define CYBT_DEBUG_ENABLED 0 - -#if CYBT_DEBUG_ENABLED || CYBT_ERROR_ENABLED -#include #endif +#ifndef cybt_error #if CYBT_ERROR_ENABLED #define cybt_error CYW43_WARN #else #define cybt_error(...) #endif +#endif +#ifndef cybt_info #if CYBT_INFO_ENABLED #define cybt_info CYW43_PRINTF #else #define cybt_info(...) #endif +#endif +#ifndef cybt_debug #if CYBT_DEBUG_ENABLED #define cybt_debug CYW43_PRINTF #else #define cybt_debug(...) #endif +#endif #endif // CYBT_LOGGING_H \ No newline at end of file