Use cyw43 macros for bluetooth logging (#2490)

* Tidy up bt logging

Fixes #2253

* Allow logging to be overridden
This commit is contained in:
Peter Harper 2025-06-18 23:08:35 +01:00 committed by GitHub
parent c3c62675e8
commit 24af10a6a2
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
4 changed files with 92 additions and 65 deletions

View file

@ -6,7 +6,7 @@ cc_library(
"cybt_shared_bus.c", "cybt_shared_bus.c",
"cybt_shared_bus_driver.c", "cybt_shared_bus_driver.c",
], ],
hdrs = ["cybt_shared_bus_driver.h"], hdrs = ["cybt_shared_bus_driver.h", "cybt_logging.h"],
includes = ["."], includes = ["."],
deps = [ deps = [
"@cyw43-driver//:cyw43_driver", "@cyw43-driver//:cyw43_driver",

View file

@ -0,0 +1,57 @@
/*
* 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 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
#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

View file

@ -15,6 +15,7 @@
#include "cybt_shared_bus_driver.h" #include "cybt_shared_bus_driver.h"
#include "cyw43_btfw_43439.h" #include "cyw43_btfw_43439.h"
#include "cybt_logging.h"
#if CYW43_USE_HEX_BTFW #if CYW43_USE_HEX_BTFW
extern const char brcm_patch_version[]; 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 BTSDIO_FWBUF_OPER_DELAY_US (250)
#define BTFW_WAIT_TIME_MS (150) #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 ROUNDUP(x, a) ((((x) + ((a) - 1)) / (a)) * (a))
#define ROUNDDN(x, a) ((x) & ~((a) - 1)) #define ROUNDDN(x, a) ((x) & ~((a) - 1))
#define ISALIGNED(a, x) (((uint32_t)(a) & ((x) - 1)) == 0) #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); ret = cybt_fw_download_prepare(&p_write_buf, &p_hex_buf);
if (CYBT_SUCCESS != ret) { if (CYBT_SUCCESS != ret) {
cybt_printf("Could not allocate memory\n"); cybt_error("Could not allocate memory\n");
return ret; return ret;
} }
@ -131,9 +118,9 @@ int cyw43_btbus_init(cyw43_ll_t *self) {
const uint8_t *fw_data_buf; const uint8_t *fw_data_buf;
uint32_t fw_data_len; uint32_t fw_data_len;
#if CYW43_USE_HEX_BTFW #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 #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 #endif
fw_data_len = brcm_patch_ram_length; fw_data_len = brcm_patch_ram_length;
fw_data_buf = brcm_patchram_buf; 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); cybt_fw_download_finish(p_write_buf, p_hex_buf);
if (CYBT_SUCCESS != ret) { 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; return CYBT_ERR_HCI_INIT_FAILED;
} }
@ -161,7 +148,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) {
if (CYBT_SUCCESS == ret) { if (CYBT_SUCCESS == ret) {
cybt_debug("hci_open(): FW download successfully\n"); cybt_debug("hci_open(): FW download successfully\n");
} else { } 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; return CYBT_ERR_HCI_INIT_FAILED;
} }
@ -182,7 +169,7 @@ int cyw43_btbus_init(cyw43_ll_t *self) {
return CYBT_SUCCESS; return CYBT_SUCCESS;
} }
#if CYBT_VDEBUG #if 0
static void dump_bytes(const uint8_t *bptr, uint32_t len) { static void dump_bytes(const uint8_t *bptr, uint32_t len) {
unsigned int i = 0; unsigned int i = 0;
@ -198,6 +185,9 @@ static void dump_bytes(const uint8_t *bptr, uint32_t len) {
} }
printf("\n"); printf("\n");
} }
#define DUMP_BYTES dump_bytes
#else
#define DUMP_BYTES(...)
#endif #endif
static cybt_result_t cybt_hci_write_buf(const uint8_t *p_data, uint32_t length) { 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)); assert(ISALIGNED(p_data, 4));
if (!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; 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)); assert(ISALIGNED(p_data, 4));
if (!ISALIGNED(p_data, 4)) { if (!ISALIGNED(p_data, 4)) {
assert(false); assert(false);
cybt_printf("cybt_hci_read: buffer not aligned\n"); cybt_error("cybt_hci_read: buffer not aligned\n");
return CYBT_ERR_BADARG; 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", 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); fw_membuf_info.bt2host_in_val, fw_membuf_info.bt2host_out_val, fw_b2h_buf_count);
if (fw_b2h_buf_count < available) { 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); 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); fw_membuf_info.bt2host_out_val);
panic("cyw43 buffer overflow"); panic("cyw43 buffer overflow");
} }
@ -355,9 +345,7 @@ int cyw43_btbus_write(uint8_t *buf, uint32_t size) {
cybt_bus_request(); cybt_bus_request();
cybt_debug("cyw43_btbus_write: %d\n", cmd_len); cybt_debug("cyw43_btbus_write: %d\n", cmd_len);
#if CYBT_VDEBUG DUMP_BYTES(buf, size); // dump header and data
dump_bytes(buf, size); // dump header and data
#endif
cybt_hci_write_buf(buf, size); cybt_hci_write_buf(buf, size);
cybt_bus_release(); 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) { if (bt_result != CYBT_SUCCESS) {
*size = 0; *size = 0;
cybt_printf("cybt_hci_read_packet: error %d", bt_result); cybt_error("cybt_hci_read_packet: error %d", bt_result);
return true; 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); uint32_t hci_read_len = ((buf[2] << 16) & 0xFFFF00) | ((buf[1] << 8) & 0xFF00) | (buf[0] & 0xFF);
if (hci_read_len > max_buf_size - 4) { if (hci_read_len > max_buf_size - 4) {
*size = 0; *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); assert(false);
return 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); bt_result = cybt_hci_read(buf + 4, &total_read_len);
if (bt_result != CYBT_SUCCESS) { if (bt_result != CYBT_SUCCESS) {
*size = 0; *size = 0;
cybt_printf("cybt_hci_read_packet: read failed\n"); cybt_error("cybt_hci_read_packet: read failed\n");
assert(false); assert(false);
return false; return false;
} }
@ -413,15 +401,13 @@ static bool cybt_hci_read_packet(uint8_t *buf, uint32_t max_buf_size, uint32_t *
} else { } else {
assert(total_read_len > 0); assert(total_read_len > 0);
*size = total_read_len + 4; *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); //assert(false);
return true; return true;
} }
cybt_debug("cybt_hci_read_packet: %ld\n", *size); cybt_debug("cybt_hci_read_packet: %ld\n", *size);
#if CYBT_VDEBUG DUMP_BYTES(buf, *size);
dump_bytes(buf, *size);
#endif
return true; return true;
} }

View file

@ -11,6 +11,7 @@
#include "cyw43_ll.h" #include "cyw43_ll.h"
#include "cybt_shared_bus_driver.h" #include "cybt_shared_bus_driver.h"
#include "cybt_logging.h"
// Bluetooth register corruption occurs if both wifi and bluetooth are fully utilised. // Bluetooth register corruption occurs if both wifi and bluetooth are fully utilised.
#define CYBT_CORRUPTION_TEST 1 #define CYBT_CORRUPTION_TEST 1
@ -23,23 +24,6 @@ static uint32_t last_bt_ctrl_reg;
#endif #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 <stdio.h>
#define cybt_debug(format, args ...) printf(format,##args)
#else
#define cybt_debug(format, ...) ((void)0)
#endif
/****************************************************************************** /******************************************************************************
* Constants * Constants
@ -319,7 +303,7 @@ cybt_result_t cybt_fw_download(const uint8_t *p_bt_firmware,
uint8_t version_len = *p_bt_firmware; uint8_t version_len = *p_bt_firmware;
assert(*(p_bt_firmware + version_len) == 0); assert(*(p_bt_firmware + version_len) == 0);
#ifndef NDEBUG #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 #endif
p_bt_firmware += version_len + 1; // skip over version p_bt_firmware += version_len + 1; // skip over version
p_bt_firmware += 1; // skip over record count 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, &reg_val); cybt_reg_read(HOST_CTRL_REG_ADDR, &reg_val);
#if CYBT_CORRUPTION_TEST #if CYBT_CORRUPTION_TEST
if ((reg_val & ~(BTSDIO_REG_SW_RDY_BITMASK | BTSDIO_REG_WAKE_BT_BITMASK | BTSDIO_REG_DATA_VALID_BITMASK)) != 0) { 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(); cybt_debug_dump();
panic("cyw43 btsdio register corruption"); panic("cyw43 btsdio register corruption");
} }
@ -485,32 +469,32 @@ void cybt_debug_dump(void) {
uint32_t reg_val = 0; uint32_t reg_val = 0;
cybt_fw_membuf_index_t buf_index; cybt_fw_membuf_index_t buf_index;
cybt_printf("WLAN_RAM_BASE_ADDR: 0x%08lx\n", WLAN_RAM_BASE_ADDR); cybt_debug("WLAN_RAM_BASE_ADDR: 0x%08lx\n", WLAN_RAM_BASE_ADDR);
cybt_printf("H2B_BUF_ADDR: 0x%08lx\n", H2B_BUF_ADDR); cybt_debug("H2B_BUF_ADDR: 0x%08lx\n", H2B_BUF_ADDR);
cybt_printf("B2H_BUF_ADDR: 0x%08lx\n", B2H_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_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); last_buf_index.host2bt_in_val);
cybt_reg_read(H2B_BUF_OUT_ADDR, &buf_index.host2bt_out_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); last_buf_index.host2bt_out_val);
cybt_reg_read(B2H_BUF_IN_ADDR, &buf_index.bt2host_in_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); last_buf_index.bt2host_in_val);
cybt_reg_read(B2H_BUF_OUT_ADDR, &buf_index.bt2host_out_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); last_buf_index.bt2host_out_val);
cybt_reg_read(HOST_CTRL_REG_ADDR, &reg_val); cybt_reg_read(HOST_CTRL_REG_ADDR, &reg_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); last_host_ctrl_reg);
cybt_reg_read(BT_CTRL_REG_ADDR, &reg_val); cybt_reg_read(BT_CTRL_REG_ADDR, &reg_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 #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 CYBT_CORRUPTION_TEST
if (p_buf_index->host2bt_in_val >= BTSDIO_FWBUF_SIZE || p_buf_index->host2bt_out_val >= BTSDIO_FWBUF_SIZE || 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) { 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(); cybt_debug_dump();
} else { } else {
memcpy((uint8_t *) &last_buf_index, (uint8_t *) p_buf_index, sizeof(cybt_fw_membuf_index_t)); 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; return CYBT_SUCCESS;
} }
#if CYBT_DEBUG #if 0
static void dump_bytes(const uint8_t *bptr, uint32_t len) { static void dump_bytes(const uint8_t *bptr, uint32_t len) {
unsigned int i = 0; unsigned int i = 0;