diff --git a/components/bt/common/include/bt_common.h b/components/bt/common/include/bt_common.h index f687e3afe7..098082f647 100644 --- a/components/bt/common/include/bt_common.h +++ b/components/bt/common/include/bt_common.h @@ -61,6 +61,16 @@ #define HEAP_MEMORY_DEBUG FALSE #endif +#if UC_BT_BLUEDROID_THREAD_DEBUG +#define OSI_THREAD_DEBUG TRUE +#else +#define OSI_THREAD_DEBUG FALSE +#endif + +#define OSI_THREAD_BLOCK_TIME UC_BT_BLUEDROID_THREAD_BLOCK_TIME + +#define OSI_THREAD_BLOCK_MSG UC_BT_BLUEDROID_THREAD_BLOCK_MSG + #ifndef BT_BLE_DYNAMIC_ENV_MEMORY #define BT_BLE_DYNAMIC_ENV_MEMORY FALSE #endif diff --git a/components/bt/common/include/bt_user_config.h b/components/bt/common/include/bt_user_config.h index 5632b5fe22..2d695fa1c3 100644 --- a/components/bt/common/include/bt_user_config.h +++ b/components/bt/common/include/bt_user_config.h @@ -107,6 +107,24 @@ #define UC_BT_BLUEDROID_MEM_DEBUG FALSE #endif +#ifdef CONFIG_BT_BLUEDROID_THREAD_DEBUG +#define UC_BT_BLUEDROID_THREAD_DEBUG TRUE +#else +#define UC_BT_BLUEDROID_THREAD_DEBUG FALSE +#endif + +#ifdef CONFIG_BT_BLUEDROID_THREAD_BLOCK_TIME +#define UC_BT_BLUEDROID_THREAD_BLOCK_TIME CONFIG_BT_BLUEDROID_THREAD_BLOCK_TIME +#else +#define UC_BT_BLUEDROID_THREAD_BLOCK_TIME 1000 +#endif + +#ifdef CONFIG_BT_BLUEDROID_THREAD_BLOCK_MSG +#define UC_BT_BLUEDROID_THREAD_BLOCK_MSG CONFIG_BT_BLUEDROID_THREAD_BLOCK_MSG +#else +#define UC_BT_BLUEDROID_THREAD_BLOCK_MSG 50 +#endif + #ifdef CONFIG_BT_ALLOCATION_FROM_SPIRAM_FIRST #define UC_HEAP_ALLOCATION_FROM_SPIRAM_FIRST CONFIG_BT_ALLOCATION_FROM_SPIRAM_FIRST #else diff --git a/components/bt/common/osi/allocator.c b/components/bt/common/osi/allocator.c index 0293daa8c4..91ec942eb5 100644 --- a/components/bt/common/osi/allocator.c +++ b/components/bt/common/osi/allocator.c @@ -216,7 +216,9 @@ void *osi_malloc_func(size_t size) void *p = osi_malloc_base(size); if (size != 0 && p == NULL) { - OSI_TRACE_ERROR("malloc failed (caller=%p size=%u)\n", __builtin_return_address(0), size); + OSI_TRACE_ERROR("malloc failed (caller=%p size=%u)", __builtin_return_address(0), size); + OSI_TRACE_ERROR("heap info: free=%d, largest_block=%d", + heap_caps_get_free_size(MALLOC_CAP_DEFAULT), heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT)); #if HEAP_ALLOCATION_FAILS_ABORT assert(0); #endif @@ -230,7 +232,9 @@ void *osi_calloc_func(size_t size) void *p = osi_calloc_base(size); if (size != 0 && p == NULL) { - OSI_TRACE_ERROR("calloc failed (caller=%p size=%u)\n", __builtin_return_address(0), size); + OSI_TRACE_ERROR("calloc failed (caller=%p size=%u)", __builtin_return_address(0), size); + OSI_TRACE_ERROR("heap info: free=%d, largest_block=%d", + heap_caps_get_free_size(MALLOC_CAP_DEFAULT), heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT)); #if HEAP_ALLOCATION_FAILS_ABORT assert(0); #endif diff --git a/components/bt/common/osi/include/osi/allocator.h b/components/bt/common/osi/include/osi/allocator.h index d95040538d..071892ffaf 100644 --- a/components/bt/common/osi/include/osi/allocator.h +++ b/components/bt/common/osi/include/osi/allocator.h @@ -21,6 +21,7 @@ #include #include +#include "bt_common.h" #include "esp_heap_caps.h" char *osi_strdup(const char *str); diff --git a/components/bt/common/osi/thread.c b/components/bt/common/osi/thread.c index 91bc7906ce..95475670be 100644 --- a/components/bt/common/osi/thread.c +++ b/components/bt/common/osi/thread.c @@ -61,6 +61,10 @@ struct osi_event { static const size_t DEFAULT_WORK_QUEUE_CAPACITY = 100; +#if OSI_THREAD_DEBUG +static void osi_thread_run_item(osi_thread_t *thread, int wq_idx, struct work_item *item); +#endif + static struct work_queue *osi_work_queue_create(size_t capacity) { if (capacity == 0) { @@ -162,7 +166,11 @@ static void osi_thread_run(void *arg) struct work_item item; while (!thread->stop && idx < thread->work_queue_num) { if (osi_thead_work_queue_get(thread->work_queues[idx], &item) == true) { + #if OSI_THREAD_DEBUG + osi_thread_run_item(thread, idx, &item); + #else item.func(item.context); + #endif idx = 0; continue; } else { @@ -451,3 +459,45 @@ bool osi_thread_post_event(struct osi_event *event, uint32_t timeout) return ret; } + +#if OSI_THREAD_DEBUG +static void osi_thread_run_item(osi_thread_t *thread, int wq_idx, struct work_item *item) +{ + uint32_t pre_time; + uint32_t pre_msg_cnt; + uint32_t cur_time; + uint32_t cur_msg_cnt; + + pre_time = esp_log_timestamp(); + pre_msg_cnt = uxQueueMessagesWaiting(thread->work_queues[wq_idx]->queue); + item->func(item->context); + cur_time = esp_log_timestamp(); + cur_msg_cnt = uxQueueMessagesWaiting(thread->work_queues[wq_idx]->queue); + if ((cur_time - pre_time) >= OSI_THREAD_BLOCK_TIME || + (cur_msg_cnt > pre_msg_cnt && (cur_msg_cnt - pre_msg_cnt) >= OSI_THREAD_BLOCK_MSG)) { + OSI_TRACE_ERROR("%s was blocked while running item: %p exec_time=[%u %u] msg_inc=[%u %u]", + pcTaskGetName(thread->thread_handle), item->func, cur_time, pre_time, cur_msg_cnt, pre_msg_cnt); + assert(0); + } +} + +void osi_thread_workqueue_dump(osi_thread_t *thread) +{ + int idx = 0; + struct work_item item; + + vTaskSuspendAll(); + + while (idx < thread->work_queue_num) { + if (osi_thead_work_queue_get(thread->work_queues[idx], &item) == true) { + esp_rom_printf("[%u] %p %p\n", idx, item.func, item.context); + idx = 0; + continue; + } else { + idx++; + } + } + + xTaskResumeAll(); +} +#endif // OSI_THREAD_DEBUG diff --git a/components/bt/host/bluedroid/Kconfig.in b/components/bt/host/bluedroid/Kconfig.in index 929e539919..2bd78f05f1 100644 --- a/components/bt/host/bluedroid/Kconfig.in +++ b/components/bt/host/bluedroid/Kconfig.in @@ -33,13 +33,6 @@ config BT_BTU_TASK_STACK_SIZE help This select btu task stack size -config BT_BLUEDROID_MEM_DEBUG - bool "Bluedroid memory debug" - depends on BT_BLUEDROID_ENABLED - default n - help - Bluedroid memory debug - config BT_BLUEDROID_ESP_COEX_VSC bool "Enable Espressif Vendor-specific HCI commands for coexist status configuration" depends on BT_BLUEDROID_ENABLED @@ -481,6 +474,40 @@ config BT_BLE_RPA_SUPPORTED For other BLE chips, devices support network privacy mode and device privacy mode, users can switch the two modes according to their own needs. So this option is enabled by default. +menu "Bluedroid debug option" + config BT_BLUEDROID_MEM_DEBUG + bool "Bluedroid memory debug" + depends on BT_BLUEDROID_ENABLED + default n + help + Bluedroid memory debug + + config BT_BLUEDROID_THREAD_DEBUG + bool "Bluedroid thread debug" + depends on BT_BLUEDROID_ENABLED + default n + help + Enable Bluedroid thread debug mode. + Used to debug whether the thread is blocked and + dump information about the thread’s related work queue. + + config BT_BLUEDROID_THREAD_BLOCK_TIME + int "OSI thread block time (in ms)" + depends on BT_BLUEDROID_THREAD_DEBUG + default 1000 + help + Indicates how long it takes for the thread to execute an item + before it is considered blocked. + + config BT_BLUEDROID_THREAD_BLOCK_MSG + int "OSI thread block message count" + depends on BT_BLUEDROID_THREAD_DEBUG + default 50 + help + Indicates how many messages are added to the queue + while the threadis executing an item before it is considered blocked. +endmenu #BT debug option + config BT_STACK_NO_LOG bool "Disable BT debug logs (minimize bin size)" depends on BT_BLUEDROID_ENABLED diff --git a/components/bt/host/bluedroid/bta/gatt/bta_gattc_act.c b/components/bt/host/bluedroid/bta/gatt/bta_gattc_act.c index bbbc1ba09f..07ebff2877 100644 --- a/components/bt/host/bluedroid/bta/gatt/bta_gattc_act.c +++ b/components/bt/host/bluedroid/bta/gatt/bta_gattc_act.c @@ -736,6 +736,7 @@ void bta_gattc_conn(tBTA_GATTC_CLCB *p_clcb, tBTA_GATTC_DATA *p_data) #if (GATTC_CACHE_NVS == TRUE) p_clcb->p_srcb->state = BTA_GATTC_SERV_LOAD; if (bta_gattc_cache_load(p_clcb)) { + APPL_TRACE_DEBUG("%s found gattc cache", __func__); p_clcb->p_srcb->state = BTA_GATTC_SERV_IDLE; bta_gattc_reset_discover_st(p_clcb->p_srcb, BTA_GATT_OK); //register service change @@ -743,6 +744,7 @@ void bta_gattc_conn(tBTA_GATTC_CLCB *p_clcb, tBTA_GATTC_DATA *p_data) } else #endif { /* cache is building */ + APPL_TRACE_DEBUG("%s cache not found, start discovery %u", __func__, bta_gattc_cb.auto_disc); if (bta_gattc_cb.auto_disc) { p_clcb->p_srcb->state = BTA_GATTC_SERV_DISC; /* cache load failure, start discovery */ @@ -1856,6 +1858,8 @@ void bta_gattc_process_api_refresh(tBTA_GATTC_CB *p_cb, tBTA_GATTC_DATA *p_msg) UINT8 i; UNUSED(p_cb); + APPL_TRACE_DEBUG("%s", __func__); + if (p_srvc_cb != NULL) { /* try to find a CLCB */ if (p_srvc_cb->connected && p_srvc_cb->num_clcb != 0) { @@ -1974,6 +1978,8 @@ void bta_gattc_process_api_cache_clean(tBTA_GATTC_CB *p_cb, tBTA_GATTC_DATA *p_m tBTA_GATTC_SERV *p_srvc_cb = bta_gattc_find_srvr_cache(p_msg->api_clean.remote_bda); UNUSED(p_cb); + APPL_TRACE_DEBUG("%s", __func__); + if (p_srvc_cb != NULL && p_srvc_cb->p_srvc_cache != NULL) { //mark it and delete the cache */ list_free(p_srvc_cb->p_srvc_cache); diff --git a/components/bt/host/bluedroid/bta/gatt/bta_gattc_co.c b/components/bt/host/bluedroid/bta/gatt/bta_gattc_co.c index 8ec3a55dff..d6ca7bca47 100644 --- a/components/bt/host/bluedroid/bta/gatt/bta_gattc_co.c +++ b/components/bt/host/bluedroid/bta/gatt/bta_gattc_co.c @@ -444,6 +444,8 @@ void bta_gattc_co_cache_addr_init(void) void bta_gattc_co_cache_addr_deinit(void) { + APPL_TRACE_DEBUG("%s is_open=%d", __func__, cache_env->is_open); + if(!cache_env->is_open) { return; } @@ -553,7 +555,7 @@ void bta_gattc_co_cache_addr_save(BD_ADDR bd_addr, hash_key_t hash_key) memcpy(cache_env->cache_addr[new_index].addr, bd_addr, sizeof(BD_ADDR)); memcpy(cache_env->cache_addr[new_index].hash_key, hash_key, sizeof(hash_key_t)); cache_env->num_addr++; - APPL_TRACE_DEBUG("%s(), num = %d", __func__, cache_env->num_addr); + APPL_TRACE_DEBUG("%s bd_addr="MACSTR" num=%d", __func__, MAC2STR(bd_addr), cache_env->num_addr); } nvs_handle_t *fp = &cache_env->addr_fp; diff --git a/components/bt/host/bluedroid/bta/gatt/bta_gattc_utils.c b/components/bt/host/bluedroid/bta/gatt/bta_gattc_utils.c index 18632d2dfa..4b2d019252 100644 --- a/components/bt/host/bluedroid/bta/gatt/bta_gattc_utils.c +++ b/components/bt/host/bluedroid/bta/gatt/bta_gattc_utils.c @@ -327,6 +327,8 @@ void bta_gattc_clcb_dealloc_by_conn_id(UINT16 conn_id) { tBTA_GATTC_CLCB *p_clcb = bta_gattc_find_clcb_by_conn_id(conn_id); + APPL_TRACE_DEBUG("%s conn_id=%u p_clcb=%p", __func__, conn_id, p_clcb); + if (p_clcb) { tBTA_GATTC_RCB *p_clreg = p_clcb->p_rcb; bta_gattc_clcb_dealloc(p_clcb); @@ -523,8 +525,7 @@ BOOLEAN bta_gattc_enqueue(tBTA_GATTC_CLCB *p_clcb, tBTA_GATTC_DATA *p_data) cmd_data->api_write.p_value = (UINT8 *)(cmd_data + 1); memcpy(cmd_data->api_write.p_value, p_data->api_write.p_value, len); } else { - APPL_TRACE_ERROR("%s(), line = %d, alloc fail, size %d, no memory. free=%d, largest_block=%d", __func__, __LINE__, - sizeof(tBTA_GATTC_DATA) + len, heap_caps_get_free_size(MALLOC_CAP_DEFAULT), heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT)); + APPL_TRACE_ERROR("%s(), line = %d, alloc fail, no memory.", __func__, __LINE__); return FALSE; } } else { diff --git a/components/bt/host/bluedroid/bta/include/bta/bta_gatt_api.h b/components/bt/host/bluedroid/bta/include/bta/bta_gatt_api.h index 7819b8a718..7c2a4c154c 100644 --- a/components/bt/host/bluedroid/bta/include/bta/bta_gatt_api.h +++ b/components/bt/host/bluedroid/bta/include/bta/bta_gatt_api.h @@ -39,9 +39,11 @@ #endif +#if (APPL_INITIAL_TRACE_LEVEL >= BT_TRACE_LEVEL_DEBUG) #ifndef BTA_GATT_DEBUG #define BTA_GATT_DEBUG FALSE #endif +#endif typedef enum { BTGATT_DB_PRIMARY_SERVICE, diff --git a/components/bt/host/bluedroid/common/include/common/bt_trace.h b/components/bt/host/bluedroid/common/include/common/bt_trace.h index bd3b1ed8fc..85ddbe58d4 100644 --- a/components/bt/host/bluedroid/common/include/common/bt_trace.h +++ b/components/bt/host/bluedroid/common/include/common/bt_trace.h @@ -57,6 +57,14 @@ static inline void trc_dump_buffer(const char *prefix, uint8_t *data, uint16_t l #define BTTRC_DUMP_BUFFER(_prefix, _data, _len) #endif +#ifndef MAC2STR +#define MAC2STR(a) (a)[0], (a)[1], (a)[2], (a)[3], (a)[4], (a)[5] +#define MACSTR "%02x:%02x:%02x:%02x:%02x:%02x" +#endif + +/* Support up to 64 bytes of buffer */ +const char *bt_hex2str(const void *buf, size_t len); + //static const char BTE_LOGMSG_MODULE[] = "bte_logmsg_module"; /* BTrgs);E tracing IDs for debug purposes */ diff --git a/components/bt/host/bluedroid/hci/hci_layer.c b/components/bt/host/bluedroid/hci/hci_layer.c index f87b7f7c8f..c6a6efa4ee 100644 --- a/components/bt/host/bluedroid/hci/hci_layer.c +++ b/components/bt/host/bluedroid/hci/hci_layer.c @@ -51,6 +51,10 @@ #define HCI_DOWNSTREAM_DATA_QUEUE_IDX (0) +#ifndef MIN +#define MIN(a,b) (((a)<(b))?(a):(b)) +#endif + typedef struct { bool timer_is_set; osi_alarm_t *command_response_timer; @@ -711,3 +715,27 @@ const char *hci_status_code_to_string(uint8_t status) } } #endif + +const char *bt_hex2str(const void *buf, size_t len) +{ + static const char hex[] = "0123456789abcdef"; + static char str[129]; + const uint8_t *b = buf; + size_t i; + + len = MIN(len, (sizeof(str) - 1) / 2); + + for (i = 0; i < len; i++) { + str[i * 2] = hex[b[i] >> 4]; + str[i * 2 + 1] = hex[b[i] & 0xf]; + } + + str[i * 2] = '\0'; + + return str; +} + +int get_hci_work_queue_size(int wq_idx) +{ + return osi_thread_queue_wait_size(hci_host_thread, wq_idx); +} diff --git a/components/bt/host/bluedroid/hci/packet_fragmenter.c b/components/bt/host/bluedroid/hci/packet_fragmenter.c index f0ee531433..ccc220fbf1 100644 --- a/components/bt/host/bluedroid/hci/packet_fragmenter.c +++ b/components/bt/host/bluedroid/hci/packet_fragmenter.c @@ -180,8 +180,7 @@ static void reassemble_and_dispatch(BT_HDR *packet) partial_packet = (BT_HDR *)osi_calloc(full_length + sizeof(BT_HDR)); if (partial_packet == NULL) { - HCI_TRACE_WARNING("%s full_length %d no memory, free=%d, largest_block=%d", __func__, full_length, - heap_caps_get_free_size(MALLOC_CAP_DEFAULT), heap_caps_get_largest_free_block(MALLOC_CAP_DEFAULT)); + HCI_TRACE_WARNING("%s full_length %d no memory.", __func__, full_length); assert(0); } diff --git a/components/bt/host/bluedroid/stack/btm/btm_acl.c b/components/bt/host/bluedroid/stack/btm/btm_acl.c index 6350f4ba26..fc4b44a277 100644 --- a/components/bt/host/bluedroid/stack/btm/btm_acl.c +++ b/components/bt/host/bluedroid/stack/btm/btm_acl.c @@ -786,7 +786,7 @@ void btm_acl_encrypt_change (UINT16 handle, UINT8 status, UINT8 encr_enable) tBTM_SEC_DEV_REC *p_dev_rec; tBTM_BL_ROLE_CHG_DATA evt; - BTM_TRACE_DEBUG ("btm_acl_encrypt_change handle=%d status=%d encr_enabl=%d\n", + BTM_TRACE_DEBUG ("btm_acl_encrypt_change handle=%d status=%d encr_enable=%d\n", handle, status, encr_enable); p = btm_handle_to_acl(handle); if (p == NULL) { diff --git a/components/bt/host/bluedroid/stack/btm/btm_ble.c b/components/bt/host/bluedroid/stack/btm/btm_ble.c index d65e632931..a99614e93c 100644 --- a/components/bt/host/bluedroid/stack/btm/btm_ble.c +++ b/components/bt/host/bluedroid/stack/btm/btm_ble.c @@ -77,18 +77,16 @@ BOOLEAN BTM_SecAddBleDevice (BD_ADDR bd_addr, BD_NAME bd_name, tBT_DEVICE_TYPE d tBTM_SEC_DEV_REC *p_dev_rec; tBTM_INQ_INFO *p_info = NULL; - BTM_TRACE_DEBUG ("BTM_SecAddBleDevice dev_type=0x%x", dev_type); + BTM_TRACE_DEBUG ("%s dev_type=0x%x bd_addr="MACSTR"", __func__, dev_type, MAC2STR(bd_addr)); p_dev_rec = btm_find_dev (bd_addr); if (!p_dev_rec) { - BTM_TRACE_DEBUG("Add a new device"); - /* There is no device record, allocate one. * If we can not find an empty spot for this one, let it fail. */ if (list_length(btm_cb.p_sec_dev_rec_list) < BTM_SEC_MAX_DEVICE_RECORDS) { - p_dev_rec = (tBTM_SEC_DEV_REC *)osi_malloc(sizeof(tBTM_SEC_DEV_REC)); - if(p_dev_rec) { - list_append(btm_cb.p_sec_dev_rec_list, p_dev_rec); + p_dev_rec = (tBTM_SEC_DEV_REC *)osi_malloc(sizeof(tBTM_SEC_DEV_REC)); + if (p_dev_rec) { + list_append(btm_cb.p_sec_dev_rec_list, p_dev_rec); BTM_TRACE_DEBUG ("allocate a new dev rec idx=0x%x\n", list_length(btm_cb.p_sec_dev_rec_list)); /* Mark this record as in use and initialize */ @@ -158,22 +156,20 @@ BOOLEAN BTM_SecAddBleDevice (BD_ADDR bd_addr, BD_NAME bd_name, tBT_DEVICE_TYPE d BOOLEAN BTM_SecAddBleKey (BD_ADDR bd_addr, tBTM_LE_KEY_VALUE *p_le_key, tBTM_LE_KEY_TYPE key_type) { tBTM_SEC_DEV_REC *p_dev_rec; - BTM_TRACE_DEBUG ("BTM_SecAddBleKey"); p_dev_rec = btm_find_dev (bd_addr); + if (!p_dev_rec || !p_le_key || (key_type != BTM_LE_KEY_PENC && key_type != BTM_LE_KEY_PID && key_type != BTM_LE_KEY_PCSRK && key_type != BTM_LE_KEY_LENC && key_type != BTM_LE_KEY_LCSRK && key_type != BTM_LE_KEY_LID)) { - BTM_TRACE_WARNING ("BTM_SecAddBleKey() Wrong Type, or No Device record \ - for bdaddr: %08x%04x, Type: %d", - (bd_addr[0] << 24) + (bd_addr[1] << 16) + (bd_addr[2] << 8) + bd_addr[3], - (bd_addr[4] << 8) + bd_addr[5], key_type); + BTM_TRACE_WARNING ("BTM_SecAddBleKey() Wrong Type, or No Device record \ + for bdaddr: "MACSTR", key_type: %02x", + MAC2STR(bd_addr), key_type); return (FALSE); } - BTM_TRACE_DEBUG ("BTM_SecAddLeKey() BDA: %08x%04x, Type: 0x%02x", - (bd_addr[0] << 24) + (bd_addr[1] << 16) + (bd_addr[2] << 8) + bd_addr[3], - (bd_addr[4] << 8) + bd_addr[5], key_type); + BTM_TRACE_DEBUG ("BTM_SecAddLeKey() BDA: "MACSTR", key_type: 0x%02x", + MAC2STR(bd_addr), key_type); btm_sec_save_le_key (bd_addr, key_type, p_le_key, FALSE); @@ -1759,15 +1755,14 @@ void btm_ble_ltk_request_reply(BD_ADDR bda, BOOLEAN use_stk, BT_OCTET16 stk) tBTM_CB *p_cb = &btm_cb; if (p_rec == NULL) { - BTM_TRACE_ERROR("btm_ble_ltk_request_reply received for unknown device"); + BTM_TRACE_ERROR("%s received for unknown device "MACSTR"", __func__, MAC2STR(bda)); return; } - BTM_TRACE_DEBUG ("btm_ble_ltk_request_reply"); + BTM_TRACE_DEBUG ("%s key_type=%x key_size=%d", __func__, p_rec->ble.key_type, p_rec->ble.keys.key_size); p_cb->enc_handle = p_rec->ble_hci_handle; p_cb->key_size = p_rec->ble.keys.key_size; - BTM_TRACE_DEBUG("key size = %d", p_rec->ble.keys.key_size); if (use_stk) { btsnd_hcic_ble_ltk_req_reply(btm_cb.enc_handle, stk); } else { /* calculate LTK using peer device */ @@ -2047,7 +2042,8 @@ void btm_ble_conn_complete(UINT8 *p, UINT16 evt_len, BOOLEAN enhanced) STREAM_TO_UINT8 (role, p); STREAM_TO_UINT8 (bda_type, p); STREAM_TO_BDADDR (bda, p); - BTM_TRACE_DEBUG("status = %d, handle = %d, role = %d, bda_type = %d",status,handle,role,bda_type); + BTM_TRACE_DEBUG("status=%d handle=%d role=%d bda_type=%d bda="MACSTR"", + status, handle, role, bda_type, MAC2STR(bda)); if (status == 0) { if (enhanced) { STREAM_TO_BDADDR (local_rpa, p); diff --git a/components/bt/host/bluedroid/stack/btm/btm_ble_bgconn.c b/components/bt/host/bluedroid/stack/btm/btm_ble_bgconn.c index 1eb67844f1..b418bd70f7 100644 --- a/components/bt/host/bluedroid/stack/btm/btm_ble_bgconn.c +++ b/components/bt/host/bluedroid/stack/btm/btm_ble_bgconn.c @@ -821,6 +821,7 @@ tBTM_BLE_CONN_ST btm_ble_get_conn_st(void) *******************************************************************************/ void btm_ble_set_conn_st(tBTM_BLE_CONN_ST new_st) { + BTM_TRACE_DEBUG("%s old=%u new=%u", __func__, btm_cb.ble_ctr_cb.conn_state, new_st); btm_cb.ble_ctr_cb.conn_state = new_st; if (new_st == BLE_BG_CONN || new_st == BLE_DIR_CONN) { diff --git a/components/bt/host/bluedroid/stack/btm/btm_ble_gap.c b/components/bt/host/bluedroid/stack/btm/btm_ble_gap.c index e43185e72d..61580de047 100644 --- a/components/bt/host/bluedroid/stack/btm/btm_ble_gap.c +++ b/components/bt/host/bluedroid/stack/btm/btm_ble_gap.c @@ -2136,6 +2136,7 @@ void BTM_Recovery_Pre_State(void) { #if ((BLE_42_ADV_EN == TRUE) || (BLE_42_SCAN_EN == TRUE)) tBTM_BLE_INQ_CB *ble_inq_cb = &btm_cb.ble_ctr_cb.inq_var; + BTM_TRACE_DEBUG("%s state=0x%x", __func__, ble_inq_cb->state); #endif // #if ((BLE_42_ADV_EN == TRUE) || (BLE_42_SCAN_EN == TRUE)) #if (BLE_42_ADV_EN == TRUE) if (ble_inq_cb->state & BTM_BLE_ADVERTISING) { diff --git a/components/bt/host/bluedroid/stack/btm/btm_dev.c b/components/bt/host/bluedroid/stack/btm/btm_dev.c index 1784d4a353..cc5ad3358b 100644 --- a/components/bt/host/bluedroid/stack/btm/btm_dev.c +++ b/components/bt/host/bluedroid/stack/btm/btm_dev.c @@ -73,9 +73,11 @@ BOOLEAN BTM_SecAddDevice (BD_ADDR bd_addr, DEV_CLASS dev_class, BD_NAME bd_name, /* There is no device record, allocate one. * If we can not find an empty spot for this one, let it fail. */ if (list_length(btm_cb.p_sec_dev_rec_list) < BTM_SEC_MAX_DEVICE_RECORDS) { - p_dev_rec = (tBTM_SEC_DEV_REC *)osi_malloc(sizeof(tBTM_SEC_DEV_REC)); - if(p_dev_rec) { - list_append(btm_cb.p_sec_dev_rec_list, p_dev_rec); + p_dev_rec = (tBTM_SEC_DEV_REC *)osi_malloc(sizeof(tBTM_SEC_DEV_REC)); + if(p_dev_rec) { + BTM_TRACE_DEBUG("%s alloc a new dev rec %p bd_addr="MACSTR"", + __func__, p_dev_rec, MAC2STR(bd_addr)); + list_append(btm_cb.p_sec_dev_rec_list, p_dev_rec); /* Mark this record as in use and initialize */ memset (p_dev_rec, 0, sizeof (tBTM_SEC_DEV_REC)); p_dev_rec->sec_flags = BTM_SEC_IN_USE; @@ -360,6 +362,8 @@ tBTM_SEC_DEV_REC *btm_sec_alloc_dev (BD_ADDR bd_addr) if (list_length(btm_cb.p_sec_dev_rec_list) < BTM_SEC_MAX_DEVICE_RECORDS){ p_dev_new_rec = (tBTM_SEC_DEV_REC *)osi_malloc(sizeof(tBTM_SEC_DEV_REC)); if (p_dev_new_rec) { + BTM_TRACE_DEBUG("%s alloc a new dev rec %p bd_addr="MACSTR"", + __func__, p_dev_new_rec, MAC2STR(bd_addr)); new_entry_found = TRUE; malloc_new_entry = TRUE; } else { diff --git a/components/bt/host/bluedroid/stack/gatt/att_protocol.c b/components/bt/host/bluedroid/stack/gatt/att_protocol.c index ea7776e4c7..c16967c6ef 100644 --- a/components/bt/host/bluedroid/stack/gatt/att_protocol.c +++ b/components/bt/host/bluedroid/stack/gatt/att_protocol.c @@ -495,7 +495,7 @@ BT_HDR *attp_build_sr_msg(tGATT_TCB *p_tcb, UINT8 op_code, tGATT_SR_MSG *p_msg) ** Description This function sends the server response or indication message ** to client. ** -** Parameter p_tcb: pointer to the connection control block. +** Parameter p_tcb: pointer to the connection control block. ** p_msg: pointer to message parameters structure. ** ** Returns GATT_SUCCESS if successfully sent; otherwise error code. @@ -661,7 +661,7 @@ tGATT_STATUS attp_send_cl_msg (tGATT_TCB *p_tcb, UINT16 clcb_idx, UINT8 op_code, if (p_cmd != NULL) { status = attp_cl_send_cmd(p_tcb, clcb_idx, op_code, p_cmd); } - + GATT_TRACE_DEBUG("%s opcode=%x status=%x", __func__, op_code, status); } else { GATT_TRACE_ERROR("Peer device not connected"); } diff --git a/components/bt/host/bluedroid/stack/gatt/gatt_main.c b/components/bt/host/bluedroid/stack/gatt/gatt_main.c index 4eaae0d302..f92a2c392b 100644 --- a/components/bt/host/bluedroid/stack/gatt/gatt_main.c +++ b/components/bt/host/bluedroid/stack/gatt/gatt_main.c @@ -997,6 +997,7 @@ void gatt_data_process (tGATT_TCB *p_tcb, BT_HDR *p_buf) pseudo_op_code = op_code & (~GATT_WRITE_CMD_MASK); if (pseudo_op_code < GATT_OP_CODE_MAX) { + GATT_TRACE_DEBUG("%s opcode=%x msg_len=%u", __func__, op_code, msg_len); if (op_code == GATT_SIGN_CMD_WRITE) { #if (SMP_INCLUDED == TRUE) gatt_verify_signature(p_tcb, p_buf); @@ -1222,7 +1223,6 @@ tGATT_CH_STATE gatt_get_ch_state(tGATT_TCB *p_tcb) { tGATT_CH_STATE ch_state = GATT_CH_CLOSE; if (p_tcb) { - GATT_TRACE_DEBUG ("gatt_get_ch_state: ch_state=%d", p_tcb->ch_state); ch_state = p_tcb->ch_state; } return ch_state; @@ -1235,6 +1235,7 @@ uint16_t gatt_get_local_mtu(void) void gatt_set_local_mtu(uint16_t mtu) { + GATT_TRACE_DEBUG("%s mtu=%u", __func__, mtu); gatt_default.local_mtu = mtu; } diff --git a/components/bt/host/bluedroid/stack/gatt/gatt_sr.c b/components/bt/host/bluedroid/stack/gatt/gatt_sr.c index 5947239cf1..585a4c921a 100644 --- a/components/bt/host/bluedroid/stack/gatt/gatt_sr.c +++ b/components/bt/host/bluedroid/stack/gatt/gatt_sr.c @@ -405,7 +405,7 @@ tGATT_STATUS gatt_sr_process_app_rsp (tGATT_TCB *p_tcb, tGATT_IF gatt_if, tGATT_STATUS ret_code = GATT_SUCCESS; UNUSED(trans_id); - GATT_TRACE_DEBUG("gatt_sr_process_app_rsp gatt_if=%d\n", gatt_if); + GATT_TRACE_DEBUG("gatt_sr_process_app_rsp gatt_if=%d opcode=%x\n", gatt_if, op_code); gatt_sr_update_cback_cnt(p_tcb, gatt_if, FALSE, FALSE); @@ -1827,6 +1827,7 @@ void gatt_server_handle_client_req (tGATT_TCB *p_tcb, UINT8 op_code, { /* there is pending command, discard this one */ if (!gatt_sr_cmd_empty(p_tcb) && op_code != GATT_HANDLE_VALUE_CONF) { + GATT_TRACE_WARNING("%s discard command opcode=%02x", __func__, op_code); return; } @@ -1891,6 +1892,7 @@ void gatt_server_handle_client_req (tGATT_TCB *p_tcb, UINT8 op_code, break; default: + GATT_TRACE_ERROR("%s unknown command opcode=%02x", __func__, op_code); break; } } diff --git a/components/bt/host/bluedroid/stack/gatt/gatt_utils.c b/components/bt/host/bluedroid/stack/gatt/gatt_utils.c index 5565169a78..ae99c39a9f 100644 --- a/components/bt/host/bluedroid/stack/gatt/gatt_utils.c +++ b/components/bt/host/bluedroid/stack/gatt/gatt_utils.c @@ -1296,14 +1296,9 @@ BOOLEAN gatt_parse_uuid_from_cmd(tBT_UUID *p_uuid_rec, UINT16 uuid_size, UINT8 * void gatt_start_rsp_timer(UINT16 clcb_idx) { tGATT_CLCB *p_clcb = gatt_clcb_find_by_idx(clcb_idx); - UINT32 timeout = GATT_WAIT_FOR_RSP_TOUT; p_clcb->rsp_timer_ent.param = (TIMER_PARAM_TYPE)p_clcb; - if (p_clcb->operation == GATTC_OPTYPE_DISCOVERY && - p_clcb->op_subtype == GATT_DISC_SRVC_ALL) { - timeout = GATT_WAIT_FOR_DISC_RSP_TOUT; - } btu_start_timer (&p_clcb->rsp_timer_ent, BTU_TTYPE_ATT_WAIT_FOR_RSP, - timeout); + GATT_WAIT_FOR_RSP_TOUT); } /******************************************************************************* ** @@ -1369,7 +1364,8 @@ void gatt_rsp_timeout(TIMER_LIST_ENT *p_tle) } } - GATT_TRACE_WARNING("gatt_rsp_timeout disconnecting..."); + GATT_TRACE_WARNING("gatt_rsp_timeout conn_id=%x op=%u op_sub=%u retry_count=%u disconnecting...", + p_clcb->conn_id, p_clcb->operation, p_clcb->op_subtype, p_clcb->retry_count); gatt_disconnect (p_clcb->p_tcb); } @@ -1811,7 +1807,7 @@ void gatt_clcb_dealloc (tGATT_CLCB *p_clcb) btu_free_timer(&p_clcb->rsp_timer_ent); memset(p_clcb, 0, sizeof(tGATT_CLCB)); list_remove(gatt_cb.p_clcb_list, p_clcb); - p_clcb = NULL; + p_clcb = NULL; } } diff --git a/components/bt/host/bluedroid/stack/gatt/include/gatt_int.h b/components/bt/host/bluedroid/stack/gatt/include/gatt_int.h index 778e7d92bf..8701c746d1 100644 --- a/components/bt/host/bluedroid/stack/gatt/include/gatt_int.h +++ b/components/bt/host/bluedroid/stack/gatt/include/gatt_int.h @@ -76,9 +76,12 @@ typedef UINT8 tGATT_SEC_ACTION; #define GATT_HDR_SIZE 3 /* 1B opcode + 2B handle */ -/* wait for ATT cmd response timeout value */ -#define GATT_WAIT_FOR_RSP_TOUT 30 -#define GATT_WAIT_FOR_DISC_RSP_TOUT 15 +/** + * Wait for ATT cmd response timeout value (40 seconds). + * The max connection supervision timeout is 32 seconds, + * And The ATT cmd may not be sent out by controller immediately. + */ +#define GATT_WAIT_FOR_RSP_TOUT 40 #define GATT_REQ_RETRY_LIMIT 2 #define GATT_WAIT_FOR_IND_ACK_TOUT 5 diff --git a/components/bt/host/bluedroid/stack/hcic/hciblecmds.c b/components/bt/host/bluedroid/stack/hcic/hciblecmds.c index b74fdc2227..fef574fd6a 100644 --- a/components/bt/host/bluedroid/stack/hcic/hciblecmds.c +++ b/components/bt/host/bluedroid/stack/hcic/hciblecmds.c @@ -618,6 +618,8 @@ BOOLEAN btsnd_hcic_ble_start_enc (UINT16 handle, UINT8 rand[HCIC_BLE_RAND_DI_SIZ BT_HDR *p; UINT8 *pp; + HCI_TRACE_DEBUG("%s handle=%u LTK=%s", __func__, handle, bt_hex2str(ltk, HCIC_BLE_ENCRYT_KEY_SIZE)); + if ((p = HCI_GET_CMD_BUF(HCIC_PARAM_SIZE_BLE_START_ENC)) == NULL) { return (FALSE); } @@ -644,6 +646,8 @@ BOOLEAN btsnd_hcic_ble_ltk_req_reply (UINT16 handle, UINT8 ltk[HCIC_BLE_ENCRYT_K BT_HDR *p; UINT8 *pp; + HCI_TRACE_DEBUG("%s handle=%u LTK=%s", __func__, handle, bt_hex2str(ltk, HCIC_BLE_ENCRYT_KEY_SIZE)); + if ((p = HCI_GET_CMD_BUF(HCIC_PARAM_SIZE_LTK_REQ_REPLY)) == NULL) { return (FALSE); } @@ -668,6 +672,8 @@ BOOLEAN btsnd_hcic_ble_ltk_req_neg_reply (UINT16 handle) BT_HDR *p; UINT8 *pp; + HCI_TRACE_WARNING("%s handle=%u", __func__, handle); + if ((p = HCI_GET_CMD_BUF(HCIC_PARAM_SIZE_LTK_REQ_NEG_REPLY)) == NULL) { return (FALSE); } diff --git a/components/bt/host/bluedroid/stack/l2cap/l2c_api.c b/components/bt/host/bluedroid/stack/l2cap/l2c_api.c index 8030df8078..b7fbbbdcfc 100644 --- a/components/bt/host/bluedroid/stack/l2cap/l2c_api.c +++ b/components/bt/host/bluedroid/stack/l2cap/l2c_api.c @@ -1907,6 +1907,8 @@ BOOLEAN L2CA_RemoveFixedChnl (UINT16 fixed_cid, BD_ADDR rem_bda) tL2C_CCB *p_ccb; tBT_TRANSPORT transport = BT_TRANSPORT_BR_EDR; + L2CAP_TRACE_DEBUG("%s cid=%04x bda="MACSTR"", __func__, fixed_cid, MAC2STR(rem_bda)); + /* Check CID is valid and registered */ if ( (fixed_cid < L2CAP_FIRST_FIXED_CHNL) || (fixed_cid > L2CAP_LAST_FIXED_CHNL) || (l2cb.fixed_reg[fixed_cid - L2CAP_FIRST_FIXED_CHNL].pL2CA_FixedData_Cb == NULL) ) { diff --git a/components/bt/host/bluedroid/stack/l2cap/l2c_ble.c b/components/bt/host/bluedroid/stack/l2cap/l2c_ble.c index 88d18b08a2..39ba389451 100644 --- a/components/bt/host/bluedroid/stack/l2cap/l2c_ble.c +++ b/components/bt/host/bluedroid/stack/l2cap/l2c_ble.c @@ -92,6 +92,8 @@ BOOLEAN L2CA_CancelBleConnectReq (BD_ADDR rem_bda) { tL2C_LCB *p_lcb; + L2CAP_TRACE_DEBUG("%s rem_bda="MACSTR"", __func__, MAC2STR(rem_bda)); + /* There can be only one BLE connection request outstanding at a time */ if (btm_ble_get_conn_st() == BLE_CONN_IDLE) { L2CAP_TRACE_WARNING ("L2CA_CancelBleConnectReq - no connection pending"); @@ -99,10 +101,8 @@ BOOLEAN L2CA_CancelBleConnectReq (BD_ADDR rem_bda) } if (memcmp (rem_bda, l2cb.ble_connecting_bda, BD_ADDR_LEN)) { - L2CAP_TRACE_WARNING ("L2CA_CancelBleConnectReq - different BDA Connecting: %08x%04x Cancel: %08x%04x", - (l2cb.ble_connecting_bda[0] << 24) + (l2cb.ble_connecting_bda[1] << 16) + (l2cb.ble_connecting_bda[2] << 8) + l2cb.ble_connecting_bda[3], - (l2cb.ble_connecting_bda[4] << 8) + l2cb.ble_connecting_bda[5], - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], (rem_bda[4] << 8) + rem_bda[5]); + L2CAP_TRACE_WARNING ("L2CA_CancelBleConnectReq - different BDA Connecting: "MACSTR" Cancel: "MACSTR"", + MAC2STR(l2cb.ble_connecting_bda), MAC2STR(rem_bda)); return (FALSE); } @@ -148,16 +148,12 @@ BOOLEAN L2CA_UpdateBleConnParams (BD_ADDR rem_bda, UINT16 min_int, UINT16 max_in /* If we don't have one, create one and accept the connection. */ if (!p_lcb || !p_acl_cb) { - L2CAP_TRACE_WARNING ("L2CA_UpdateBleConnParams - unknown BD_ADDR %08x%04x", - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], - (rem_bda[4] << 8) + rem_bda[5]); + L2CAP_TRACE_WARNING ("L2CA_UpdateBleConnParams - unknown BD_ADDR "MACSTR"", MAC2STR(rem_bda)); return (FALSE); } if (p_lcb->transport != BT_TRANSPORT_LE) { - L2CAP_TRACE_WARNING ("L2CA_UpdateBleConnParams - BD_ADDR %08x%04x not LE", - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], - (rem_bda[4] << 8) + rem_bda[5]); + L2CAP_TRACE_WARNING ("L2CA_UpdateBleConnParams - BD_ADDR "MACSTR" not LE", MAC2STR(rem_bda)); return (FALSE); } @@ -172,7 +168,7 @@ BOOLEAN L2CA_UpdateBleConnParams (BD_ADDR rem_bda, UINT16 min_int, UINT16 max_in if (p_lcb->conn_update_mask & L2C_BLE_UPDATE_PARAM_FULL){ status = HCI_ERR_ILLEGAL_COMMAND; need_cb = true; - L2CAP_TRACE_ERROR("There are two connection parameter requests that are being updated, please try later "); + L2CAP_TRACE_ERROR("%s connection parameter update in progress, please try later", __func__); } if ((need_cb == TRUE) && (conn_callback_func.update_conn_param_cb != NULL)) { @@ -221,20 +217,16 @@ BOOLEAN L2CA_EnableUpdateBleConnParams (BD_ADDR rem_bda, BOOLEAN enable) p_lcb = l2cu_find_lcb_by_bd_addr (rem_bda, BT_TRANSPORT_LE); if (!p_lcb) { - L2CAP_TRACE_WARNING ("L2CA_EnableUpdateBleConnParams - unknown BD_ADDR %08x%04x", - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], - (rem_bda[4] << 8) + rem_bda[5]); + L2CAP_TRACE_WARNING ("L2CA_EnableUpdateBleConnParams - unknown BD_ADDR "MACSTR"", MAC2STR(rem_bda)); return (FALSE); } - L2CAP_TRACE_API ("%s - BD_ADDR %08x%04x enable %d current upd state 0x%02x", __FUNCTION__, - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], - (rem_bda[4] << 8) + rem_bda[5], enable, p_lcb->conn_update_mask); + L2CAP_TRACE_API ("%s - BD_ADDR "MACSTR" enable %d current upd state 0x%02x", + __func__, MAC2STR(rem_bda), enable, p_lcb->conn_update_mask); if (p_lcb->transport != BT_TRANSPORT_LE) { - L2CAP_TRACE_WARNING ("%s - BD_ADDR %08x%04x not LE (link role %d)", __FUNCTION__, - (rem_bda[0] << 24) + (rem_bda[1] << 16) + (rem_bda[2] << 8) + rem_bda[3], - (rem_bda[4] << 8) + rem_bda[5], p_lcb->link_role); + L2CAP_TRACE_WARNING ("%s - BD_ADDR "MACSTR" not LE (link role %d)", + __func__, MAC2STR(rem_bda), p_lcb->link_role); return (FALSE); } diff --git a/components/bt/host/bluedroid/stack/l2cap/l2c_utils.c b/components/bt/host/bluedroid/stack/l2cap/l2c_utils.c index 97cae231f7..0d3fed93d1 100644 --- a/components/bt/host/bluedroid/stack/l2cap/l2c_utils.c +++ b/components/bt/host/bluedroid/stack/l2cap/l2c_utils.c @@ -158,6 +158,9 @@ void l2cu_release_lcb (tL2C_LCB *p_lcb) { tL2C_CCB *p_ccb; + L2CAP_TRACE_DEBUG("%s handle=%u bda="MACSTR"", + __func__, p_lcb->handle, MAC2STR(p_lcb->remote_bd_addr)); + p_lcb->in_use = FALSE; p_lcb->is_bonding = FALSE; #if (BLE_INCLUDED == TRUE) diff --git a/components/bt/host/bluedroid/stack/smp/smp_act.c b/components/bt/host/bluedroid/stack/smp/smp_act.c index b467a1c13d..d05e1a7f7d 100644 --- a/components/bt/host/bluedroid/stack/smp/smp_act.c +++ b/components/bt/host/bluedroid/stack/smp/smp_act.c @@ -79,7 +79,7 @@ static bool lmp_version_below(BD_ADDR bda, uint8_t version) *******************************************************************************/ static void smp_update_key_mask (tSMP_CB *p_cb, UINT8 key_type, BOOLEAN recv) { - SMP_TRACE_DEBUG("%s before update role=%d recv=%d local_i_key = %02x, local_r_key = %02x\n", + SMP_TRACE_DEBUG("%s before update role=%d recv=%d local_i_key = %02x, local_r_key = %02x", __func__, p_cb->role, recv, p_cb->local_i_key, p_cb->local_r_key); if (((p_cb->le_secure_connections_mode_is_used) || @@ -103,8 +103,8 @@ static void smp_update_key_mask (tSMP_CB *p_cb, UINT8 key_type, BOOLEAN recv) } } - SMP_TRACE_DEBUG("updated local_i_key = %02x, local_r_key = %02x\n", p_cb->local_i_key, - p_cb->local_r_key); + SMP_TRACE_DEBUG("updated local_i_key = %02x, local_r_key = %02x", + p_cb->local_i_key, p_cb->local_r_key); } /******************************************************************************* @@ -115,7 +115,7 @@ void smp_send_app_cback(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { tSMP_EVT_DATA cb_data; tSMP_STATUS callback_rc; - SMP_TRACE_DEBUG("%s p_cb->cb_evt=%d\n", __func__, p_cb->cb_evt); + SMP_TRACE_DEBUG("%s cb_evt=%d", __func__, p_cb->cb_evt); if (p_cb->p_callback && p_cb->cb_evt != 0) { switch (p_cb->cb_evt) { case SMP_IO_CAP_REQ_EVT: @@ -171,11 +171,11 @@ void smp_send_app_cback(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) p_cb->local_r_key = 0; } - SMP_TRACE_DEBUG ("rcvd auth_req: 0x%02x, io_cap: %d \ - loc_oob_flag: %d loc_enc_size: %d," - "local_i_key: 0x%02x, local_r_key: 0x%02x\n", - p_cb->loc_auth_req, p_cb->local_io_capability, p_cb->loc_oob_flag, - p_cb->loc_enc_size, p_cb->local_i_key, p_cb->local_r_key); + SMP_TRACE_DEBUG ("rcvd auth_req: 0x%02x, io_cap: %d," + "loc_oob_flag: %d loc_enc_size: %d," + "local_i_key: 0x%02x, local_r_key: 0x%02x", + p_cb->loc_auth_req, p_cb->local_io_capability, p_cb->loc_oob_flag, + p_cb->loc_enc_size, p_cb->local_i_key, p_cb->local_r_key); p_cb->secure_connections_only_mode_required = (btm_cb.security_mode == BTM_SEC_MODE_SC) ? TRUE : FALSE; @@ -222,8 +222,6 @@ void smp_send_app_cback(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) p_cb->discard_sec_req = FALSE; smp_sm_event(p_cb, SMP_DISCARD_SEC_REQ_EVT, NULL); } - - SMP_TRACE_DEBUG("%s return\n", __func__); } /******************************************************************************* @@ -249,7 +247,7 @@ void smp_send_pair_fail(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_pair_req(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); #if (BLE_INCLUDED == TRUE) tBTM_SEC_DEV_REC *p_dev_rec = btm_find_dev (p_cb->pairing_bda); @@ -269,7 +267,7 @@ void smp_send_pair_req(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_pair_rsp(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); #if (BLE_INCLUDED == TRUE) p_cb->local_i_key &= p_cb->peer_i_key; @@ -291,7 +289,7 @@ void smp_send_pair_rsp(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_confirm(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); smp_send_cmd(SMP_OPCODE_CONFIRM, p_cb); } @@ -313,7 +311,7 @@ void smp_send_init(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_rand(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); smp_send_cmd(SMP_OPCODE_RAND, p_cb); } @@ -323,7 +321,7 @@ void smp_send_rand(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_pair_public_key(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); smp_send_cmd(SMP_OPCODE_PAIR_PUBLIC_KEY, p_cb); } @@ -365,7 +363,7 @@ void smp_send_enc_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { tBTM_LE_LENC_KEYS le_key; - SMP_TRACE_DEBUG("%s p_cb->loc_enc_size = %d\n", __func__, p_cb->loc_enc_size); + SMP_TRACE_DEBUG("%s loc_enc_size = %d", __func__, p_cb->loc_enc_size); smp_update_key_mask (p_cb, SMP_SEC_KEY_TYPE_ENC, FALSE); smp_send_cmd(SMP_OPCODE_ENCRYPT_INFO, p_cb); @@ -383,8 +381,6 @@ void smp_send_enc_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) (tBTM_LE_KEY_VALUE *)&le_key, TRUE); } - SMP_TRACE_DEBUG ("%s\n", __func__); - smp_key_distribution(p_cb, NULL); #endif ///BLE_INCLUDED == TRUE } @@ -395,7 +391,7 @@ void smp_send_enc_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) *******************************************************************************/ void smp_send_id_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); smp_update_key_mask (p_cb, SMP_SEC_KEY_TYPE_ID, FALSE); smp_send_cmd(SMP_OPCODE_IDENTITY_INFO, p_cb); @@ -420,7 +416,7 @@ void smp_send_id_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) void smp_send_csrk_info(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { tBTM_LE_LCSRK_KEYS key; - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); smp_update_key_mask (p_cb, SMP_SEC_KEY_TYPE_CSRK, FALSE); if (smp_send_cmd(SMP_OPCODE_SIGN_INFO, p_cb)) { @@ -455,12 +451,10 @@ void smp_proc_sec_req(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) tBTM_BLE_SEC_REQ_ACT sec_req_act; UINT8 reason; - SMP_TRACE_DEBUG("%s auth_req=0x%x", __func__, auth_req); - p_cb->cb_evt = 0; btm_ble_link_sec_check(p_cb->pairing_bda, auth_req, &sec_req_act); - SMP_TRACE_DEBUG("%s sec_req_act=0x%x", __func__, sec_req_act); + SMP_TRACE_DEBUG("%s auth_req=0x%x sec_req_act=0x%x", __func__, auth_req, sec_req_act); switch (sec_req_act) { case BTM_BLE_SEC_REQ_ACT_ENCRYPT: @@ -475,6 +469,8 @@ void smp_proc_sec_req(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) /* respond to non SC pairing request as failure in SC only mode */ if (p_cb->secure_connections_only_mode_required && (auth_req & SMP_SC_SUPPORT_BIT) == 0) { + SMP_TRACE_ERROR("%s SC mode not support, auth_req=0x%x", + __func__, auth_req); reason = SMP_PAIR_AUTH_FAIL; smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); } else { @@ -503,7 +499,7 @@ void smp_proc_sec_req(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) void smp_proc_sec_grant(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) { UINT8 res = *(UINT8 *)p_data; - SMP_TRACE_DEBUG("%s", __func__); + SMP_TRACE_DEBUG("%s res=0x%x", __func__, res); if (res != SMP_SUCCESS) { smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, p_data); } else { /*otherwise, start pairing */ @@ -560,7 +556,7 @@ void smp_proc_pair_cmd(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) UINT8 reason = SMP_ENC_KEY_SIZE; tBTM_SEC_DEV_REC *p_dev_rec = btm_find_dev (p_cb->pairing_bda); - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); /* erase all keys if it is slave proc pairing req*/ if (p_dev_rec && (p_cb->role == HCI_ROLE_SLAVE)) { btm_sec_clear_ble_keys(p_dev_rec); @@ -682,7 +678,7 @@ void smp_proc_confirm(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) UINT8 *p = (UINT8 *)p_data; UINT8 reason = SMP_INVALID_PARAMETERS; - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s", __func__); if (smp_command_has_invalid_parameters(p_cb)) { smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); @@ -1170,6 +1166,7 @@ void smp_proc_compare(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) } } else { + SMP_TRACE_ERROR("%s pairing failed - check confirm value error", __func__); reason = p_cb->failure = SMP_CONFIRM_VALUE_ERR; smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); } @@ -1213,6 +1210,7 @@ void smp_start_enc(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) } if (cmd != BTM_CMD_STARTED && cmd != BTM_BUSY) { + SMP_TRACE_ERROR("%s start encryption failed, cmd=0x%x", __func__, cmd); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); } } @@ -1239,7 +1237,7 @@ void smp_enc_cmpl(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) UINT8 enc_enable = *(UINT8 *)p_data; UINT8 reason = enc_enable ? SMP_SUCCESS : SMP_ENC_FAIL; - SMP_TRACE_DEBUG("%s\n", __func__); + SMP_TRACE_DEBUG("%s %u", __func__, enc_enable); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); } diff --git a/components/bt/host/bluedroid/stack/smp/smp_api.c b/components/bt/host/bluedroid/stack/smp/smp_api.c index b99c94abd8..4ae836e0a9 100644 --- a/components/bt/host/bluedroid/stack/smp/smp_api.c +++ b/components/bt/host/bluedroid/stack/smp/smp_api.c @@ -236,7 +236,7 @@ BOOLEAN SMP_PairCancel (BD_ADDR bd_addr) if ( (p_cb->state != SMP_STATE_IDLE) && (!memcmp (p_cb->pairing_bda, bd_addr, BD_ADDR_LEN)) ) { p_cb->is_pair_cancel = TRUE; - SMP_TRACE_DEBUG("Cancel Pairing: set fail reason Unknown"); + SMP_TRACE_ERROR("%s Cancel Pairing: set fail reason Unknown", __func__); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &err_code); status = TRUE; } @@ -434,6 +434,8 @@ void SMP_OobDataReply(BD_ADDR bd_addr, tSMP_STATUS res, UINT8 len, UINT8 *p_data } if (res != SMP_SUCCESS || len == 0 || !p_data) { + SMP_TRACE_ERROR("%s pairing failed, res=0x%x len=%u p_data=%p", + __func__, res, len, p_data); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &failure); } else { if (len > BT_OCTET16_LEN) { diff --git a/components/bt/host/bluedroid/stack/smp/smp_keys.c b/components/bt/host/bluedroid/stack/smp/smp_keys.c index 24ef814279..3b1d4ee8f1 100644 --- a/components/bt/host/bluedroid/stack/smp/smp_keys.c +++ b/components/bt/host/bluedroid/stack/smp/smp_keys.c @@ -332,7 +332,7 @@ void smp_generate_stk(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) output.opcode = HCI_BLE_ENCRYPT; memcpy(output.param_buf, p_cb->ltk, SMP_ENCRYT_DATA_SIZE); } else if (!smp_calculate_legacy_short_term_key(p_cb, &output)) { - SMP_TRACE_ERROR("%s failed", __func__); + SMP_TRACE_ERROR("%s pairing failed", __func__); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &status); return; } @@ -459,7 +459,7 @@ void smp_compute_csrk(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) UINT16_TO_STREAM(p, r); if (!SMP_Encrypt(er, BT_OCTET16_LEN, buffer, 4, &output)) { - SMP_TRACE_ERROR("smp_generate_csrk failed\n"); + SMP_TRACE_ERROR("%s pairing failed", __func__); if (p_cb->smp_over_br) { #if (CLASSIC_BT_INCLUDED == TRUE) smp_br_state_machine_event(p_cb, SMP_BR_AUTH_CMPL_EVT, &status); @@ -664,7 +664,7 @@ void smp_calculate_comfirm (tSMP_CB *p_cb, BT_OCTET16 rand, BD_ADDR bda) /* calculate e(k, r XOR p1), where k = TK */ if (!SMP_Encrypt(p_cb->tk, BT_OCTET16_LEN, p1, BT_OCTET16_LEN, &output)) { - SMP_TRACE_ERROR("smp_generate_csrk failed"); + SMP_TRACE_ERROR("%s calculate TK failed", __func__); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &status); } else { smp_calculate_comfirm_cont(p_cb, &output); @@ -701,7 +701,7 @@ static void smp_calculate_comfirm_cont(tSMP_CB *p_cb, tSMP_ENC *p) /* calculate: Confirm = E(k, p1' XOR p2) */ if (!SMP_Encrypt(p_cb->tk, BT_OCTET16_LEN, p2, BT_OCTET16_LEN, &output)) { - SMP_TRACE_ERROR("smp_calculate_comfirm_cont failed\n"); + SMP_TRACE_ERROR("%s pairing failed", __func__); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &status); } else { SMP_TRACE_DEBUG("p_cb->rand_enc_proc_state=%d\n", p_cb->rand_enc_proc_state); @@ -861,7 +861,7 @@ static void smp_generate_ltk_cont(tSMP_CB *p_cb, tSMP_INT_DATA *p_data) /* LTK = d1(ER, DIV, 0)= e(ER, DIV)*/ if (!SMP_Encrypt(er, BT_OCTET16_LEN, (UINT8 *)&p_cb->div, sizeof(UINT16), &output)) { - SMP_TRACE_ERROR("%s failed\n", __func__); + SMP_TRACE_ERROR("%s failed", __func__); smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &status); } else { /* mask the LTK */ @@ -1373,6 +1373,8 @@ void smp_calculate_numeric_comparison_display_number(tSMP_CB *p_cb, } if (p_cb->number_to_display >= (BTM_MAX_PASSKEY_VAL + 1)) { + SMP_TRACE_ERROR("%s pairing failed - invalid number to display %u", + __func__, p_cb->number_to_display); UINT8 reason; reason = p_cb->failure = SMP_PAIR_FAIL_UNKNOWN; smp_sm_event(p_cb, SMP_AUTH_CMPL_EVT, &reason); diff --git a/components/bt/host/bluedroid/stack/smp/smp_utils.c b/components/bt/host/bluedroid/stack/smp/smp_utils.c index 8ec4d548ac..f4d0987029 100644 --- a/components/bt/host/bluedroid/stack/smp/smp_utils.c +++ b/components/bt/host/bluedroid/stack/smp/smp_utils.c @@ -366,6 +366,7 @@ BOOLEAN smp_send_cmd(UINT8 cmd_code, tSMP_CB *p_cb) } if (!sent) { + SMP_TRACE_ERROR("%s failed, cmd_code=0x%02x", __func__, cmd_code); if (p_cb->smp_over_br) { #if (CLASSIC_BT_INCLUDED == TRUE) smp_br_state_machine_event(p_cb, SMP_BR_AUTH_CMPL_EVT, &failure); @@ -392,7 +393,7 @@ void smp_rsp_timeout(TIMER_LIST_ENT *p_tle) UINT8 failure = SMP_RSP_TIMEOUT; UNUSED(p_tle); - SMP_TRACE_EVENT("%s state:%d br_state:%d", __FUNCTION__, p_cb->state, p_cb->br_state); + SMP_TRACE_ERROR("%s state=%d br_state=%d", __func__, p_cb->state, p_cb->br_state); if (p_cb->smp_over_br) { #if (CLASSIC_BT_INCLUDED == TRUE) diff --git a/examples/bluetooth/bluedroid/classic_bt/hfp_ag/main/bt_app_hf.c b/examples/bluetooth/bluedroid/classic_bt/hfp_ag/main/bt_app_hf.c index c60bde9997..d4b0defcc4 100644 --- a/examples/bluetooth/bluedroid/classic_bt/hfp_ag/main/bt_app_hf.c +++ b/examples/bluetooth/bluedroid/classic_bt/hfp_ag/main/bt_app_hf.c @@ -1,5 +1,5 @@ /* - * SPDX-FileCopyrightText: 2021-2024 Espressif Systems (Shanghai) CO LTD + * SPDX-FileCopyrightText: 2021-2025 Espressif Systems (Shanghai) CO LTD * * SPDX-License-Identifier: Unlicense OR CC0-1.0 */ @@ -25,7 +25,6 @@ #include "sdkconfig.h" #include "bt_app_core.h" #include "bt_app_hf.h" -#include "osi/allocator.h" const char *c_hf_evt_str[] = { "CONNECTION_STATE_EVT", /*!< SERVICE LEVEL CONNECTION STATE CONTROL */ @@ -231,7 +230,7 @@ static void bt_app_send_data_task(void *arg) if (frame_data_num == 0) { continue; } - buf = osi_malloc(frame_data_num); + buf = (uint8_t *)malloc(frame_data_num); if (!buf) { ESP_LOGE(BT_HF_TAG, "%s, no mem", __FUNCTION__); continue; @@ -241,7 +240,7 @@ static void bt_app_send_data_task(void *arg) if (!done) { ESP_LOGE(BT_HF_TAG, "rb send fail"); } - osi_free(buf); + free(buf); vRingbufferGetInfo(s_m_rb, NULL, NULL, NULL, NULL, &item_size); if(s_audio_code == ESP_HF_AUDIO_STATE_CONNECTED_MSBC) {