From 62b826c2f86182807065842ca561ac1598240cc8 Mon Sep 17 00:00:00 2001 From: Rahul Tank Date: Mon, 19 Jan 2026 12:29:52 +0530 Subject: [PATCH] fix(nimble): Add extra logs to track critical failures --- nimble/host/src/ble_att.c | 5 +++++ nimble/host/src/ble_att_svr.c | 12 ++++++++++++ nimble/host/src/ble_gap.c | 10 ++++++++++ nimble/host/src/ble_gattc.c | 11 +++++++++++ nimble/host/src/ble_hs_flow.c | 3 +++ nimble/host/src/ble_l2cap.c | 9 +++++++++ nimble/host/src/ble_sm.c | 24 ++++++++++++++++++++++++ 7 files changed, 74 insertions(+) diff --git a/nimble/host/src/ble_att.c b/nimble/host/src/ble_att.c index c37cb6bba..50a4f164e 100644 --- a/nimble/host/src/ble_att.c +++ b/nimble/host/src/ble_att.c @@ -508,6 +508,9 @@ ble_att_rx_handle_unknown_request(uint8_t op, uint16_t conn_handle, { /* If this is command (bit6 is set to 1), do nothing */ if (op & 0x40) { + BLE_HS_LOG(INFO, "ATT command discarded (no response required); " + "op=0x%02x conn_handle=0x%04x cid=0x%04x\n", + op, conn_handle, cid); return; } #if MYNEWT_VAL(BLE_GATTS) @@ -558,6 +561,8 @@ ble_att_rx_extended(uint16_t conn_handle, uint16_t cid, struct os_mbuf **om) entry = ble_att_rx_dispatch_entry_find(op); if (entry == NULL) { + BLE_HS_LOG(INFO, "ATT handler not found; op=0x%02x conn_handle=0x%04x " + "cid=0x%04x; packet dropped\n", op, conn_handle, cid); ble_att_rx_handle_unknown_request(op, conn_handle, cid, om); return BLE_HS_ENOTSUP; } diff --git a/nimble/host/src/ble_att_svr.c b/nimble/host/src/ble_att_svr.c index 98bd03679..31a9cd5d2 100644 --- a/nimble/host/src/ble_att_svr.c +++ b/nimble/host/src/ble_att_svr.c @@ -348,6 +348,9 @@ ble_att_svr_check_perms(uint16_t conn_handle, int is_read, if (is_read) { if (!(entry->ha_flags & BLE_ATT_F_READ)) { + BLE_HS_LOG(INFO, "ATT read not permitted; " + "conn_handle=0x%04x attr_handle=0x%04x\n", + conn_handle, entry->ha_handle_id); *out_att_err = BLE_ATT_ERR_READ_NOT_PERMITTED; return BLE_HS_EREJECT; } @@ -357,6 +360,9 @@ ble_att_svr_check_perms(uint16_t conn_handle, int is_read, author = entry->ha_flags & BLE_ATT_F_READ_AUTHOR; } else { if (!(entry->ha_flags & BLE_ATT_F_WRITE)) { + BLE_HS_LOG(INFO, "ATT write not permitted; " + "conn_handle=0x%04x attr_handle=0x%04x\n", + conn_handle, entry->ha_handle_id); *out_att_err = BLE_ATT_ERR_WRITE_NOT_PERMITTED; return BLE_HS_EREJECT; } @@ -578,6 +584,9 @@ ble_att_svr_read_handle(uint16_t conn_handle, uint16_t attr_handle, entry = ble_att_svr_find_by_handle(attr_handle); if (entry == NULL) { + BLE_HS_LOG(INFO, "ATT read: invalid handle; " + "conn_handle=0x%04x attr_handle=0x%04x\n", + conn_handle, attr_handle); if (out_att_err != NULL) { *out_att_err = BLE_ATT_ERR_INVALID_HANDLE; } @@ -660,6 +669,9 @@ ble_att_svr_write_handle(uint16_t conn_handle, uint16_t attr_handle, entry = ble_att_svr_find_by_handle(attr_handle); if (entry == NULL) { + BLE_HS_LOG(INFO, "ATT write: invalid handle; " + "conn_handle=0x%04x attr_handle=0x%04x\n", + conn_handle, attr_handle); if (out_att_err != NULL) { *out_att_err = BLE_ATT_ERR_INVALID_HANDLE; } diff --git a/nimble/host/src/ble_gap.c b/nimble/host/src/ble_gap.c index 76532c8c4..9b6444302 100644 --- a/nimble/host/src/ble_gap.c +++ b/nimble/host/src/ble_gap.c @@ -743,6 +743,8 @@ ble_gap_conn_find(uint16_t handle, struct ble_gap_conn_desc *out_desc) ble_hs_unlock(); if (conn == NULL) { + BLE_HS_LOG(INFO, "GAP conn_find: connection not found; " + "conn_handle=0x%04x\n", handle); return BLE_HS_ENOTCONN; } else { return 0; @@ -8271,6 +8273,8 @@ ble_gap_terminate(uint16_t conn_handle, uint8_t hci_reason) conn = ble_hs_conn_find(conn_handle); if (conn == NULL) { + BLE_HS_LOG(INFO, "GAP terminate: connection not found; " + "conn_handle=0x%04x\n", conn_handle); rc = BLE_HS_ENOTCONN; goto done; } @@ -8636,6 +8640,8 @@ ble_gap_update_params(uint16_t conn_handle, conn = ble_hs_conn_find(conn_handle); if (conn == NULL) { + BLE_HS_LOG(INFO, "GAP update_params: connection not found; " + "conn_handle=0x%04x\n", conn_handle); rc = BLE_HS_ENOTCONN; goto done; } @@ -8643,12 +8649,16 @@ ble_gap_update_params(uint16_t conn_handle, /* Don't allow two concurrent updates to the same connection. */ dup = ble_gap_update_entry_find(conn_handle, NULL); if (dup != NULL) { + BLE_HS_LOG(INFO, "GAP update_params: update already in progress; " + "conn_handle=0x%04x\n", conn_handle); rc = BLE_HS_EALREADY; goto done; } entry = ble_gap_update_entry_alloc(); if (entry == NULL) { + BLE_HS_LOG(INFO, "GAP update_params: entry alloc failed; " + "conn_handle=0x%04x\n", conn_handle); rc = BLE_HS_ENOMEM; goto done; } diff --git a/nimble/host/src/ble_gattc.c b/nimble/host/src/ble_gattc.c index cb5f7cb98..c94c3326a 100644 --- a/nimble/host/src/ble_gattc.c +++ b/nimble/host/src/ble_gattc.c @@ -1693,6 +1693,8 @@ ble_gattc_exchange_mtu(uint16_t conn_handle, ble_gatt_mtu_fn *cb, void *cb_arg) proc = ble_gattc_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "GATTC proc alloc failed; conn_handle=0x%04x op=mtu\n", + conn_handle); rc = BLE_HS_ENOMEM; goto done; } @@ -1925,6 +1927,8 @@ ble_gattc_disc_all_svcs(uint16_t conn_handle, ble_gatt_disc_svc_fn *cb, proc = ble_gattc_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "GATTC proc alloc failed; " + "conn_handle=0x%04x op=disc_all_svcs\n", conn_handle); rc = BLE_HS_ENOMEM; goto done; } @@ -3207,6 +3211,8 @@ ble_gattc_disc_all_dscs(uint16_t conn_handle, uint16_t start_handle, proc = ble_gattc_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "GATTC proc alloc failed; " + "conn_handle=0x%04x op=disc_all_dscs\n", conn_handle); rc = BLE_HS_ENOMEM; goto done; } @@ -3760,6 +3766,8 @@ ble_gattc_read(uint16_t conn_handle, uint16_t attr_handle, proc = ble_gattc_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "GATTC proc alloc failed; " + "conn_handle=0x%04x op=read\n", conn_handle); rc = BLE_HS_ENOMEM; goto done; } @@ -4598,6 +4606,9 @@ ble_gattc_write(uint16_t conn_handle, uint16_t attr_handle, proc = ble_gattc_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "GATTC proc alloc failed; " + "conn_handle=0x%04x op=write attr=0x%04x\n", + conn_handle, attr_handle); rc = BLE_HS_ENOMEM; goto done; } diff --git a/nimble/host/src/ble_hs_flow.c b/nimble/host/src/ble_hs_flow.c index ea902a1cf..1548d3b93 100644 --- a/nimble/host/src/ble_hs_flow.c +++ b/nimble/host/src/ble_hs_flow.c @@ -214,6 +214,9 @@ ble_hs_flow_acl_free(struct os_mempool_ext *mpe, void *data, void *arg) conn = ble_hs_conn_find(conn_handle); if (conn != NULL) { ble_hs_flow_inc_completed_pkts(conn); + } else { + BLE_HS_LOG(INFO, "ACL free: connection not found; " + "conn_handle=0x%04x; flow credit may be lost\n", conn_handle); } ble_hs_unlock_nested(); diff --git a/nimble/host/src/ble_l2cap.c b/nimble/host/src/ble_l2cap.c index 9a32edfba..bd74e88da 100644 --- a/nimble/host/src/ble_l2cap.c +++ b/nimble/host/src/ble_l2cap.c @@ -304,6 +304,15 @@ ble_l2cap_remove_rx(struct ble_hs_conn *conn, struct ble_l2cap_chan *chan) #else conn->bhc_rx_chan = NULL; #endif + if (chan->rx_buf == NULL) { + BLE_HS_LOG(INFO, "L2CAP remove_rx: rx_buf already NULL; " + "conn_handle=0x%04x scid=0x%04x\n", + conn->bhc_handle, chan->scid); + } else { + BLE_HS_LOG(INFO, "L2CAP remove_rx: freeing partial rx_buf; " + "conn_handle=0x%04x scid=0x%04x rx_len=%d\n", + conn->bhc_handle, chan->scid, chan->rx_len); + } os_mbuf_free_chain(chan->rx_buf); chan->rx_buf = NULL; chan->rx_len = 0; diff --git a/nimble/host/src/ble_sm.c b/nimble/host/src/ble_sm.c index 15ab72e57..f23e16d7c 100644 --- a/nimble/host/src/ble_sm.c +++ b/nimble/host/src/ble_sm.c @@ -1639,6 +1639,8 @@ ble_sm_random_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpectedly received pairing random value. * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected pairing random; " + "conn_handle=0x%04x no proc in RANDOM state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->out_of_order = 1; } else { @@ -1692,6 +1694,8 @@ ble_sm_confirm_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpectedly received pairing confirm value. * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected pairing confirm; " + "conn_handle=0x%04x no proc in CONFIRM state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->out_of_order = 1; } else { @@ -2113,6 +2117,8 @@ ble_sm_pair_rsp_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpectedly received pairing response. * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected pairing response; " + "conn_handle=0x%04x no proc in PAIR state\n", conn_handle); res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->app_status = BLE_HS_SM_US_ERR(BLE_SM_ERR_UNSPECIFIED); res->out_of_order = 1; @@ -2520,6 +2526,8 @@ ble_sm_enc_info_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpected encryption info received * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected encryption info; " + "conn_handle=0x%04x no proc in KEY_EXCH state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->out_of_order = 1; @@ -2559,6 +2567,8 @@ ble_sm_master_id_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpected central indentification info recieved * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected master ID; " + "conn_handle=0x%04x no proc in KEY_EXCH state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->out_of_order = 1; @@ -2599,6 +2609,8 @@ ble_sm_id_info_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpected ID info received * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected identity info; " + "conn_handle=0x%04x no proc in KEY_EXCH state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->out_of_order = 1; @@ -2638,6 +2650,8 @@ ble_sm_id_addr_info_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpected identity address info received * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected identity addr info; " + "conn_handle=0x%04x no proc in KEY_EXCH state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->out_of_order = 1; @@ -2677,6 +2691,8 @@ ble_sm_sign_info_rx(uint16_t conn_handle, struct os_mbuf **om, * Unexpected signing info received * Recommended action: Ignore */ + BLE_HS_LOG(INFO, "SMP: unexpected signing info; " + "conn_handle=0x%04x no proc in KEY_EXCH state\n", conn_handle); res->app_status = BLE_HS_ENOENT; res->sm_err = BLE_SM_ERR_UNSPECIFIED; res->out_of_order = 1; @@ -2894,6 +2910,8 @@ ble_sm_pair_initiate(uint16_t conn_handle) proc = ble_sm_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "SMP: proc alloc failed; " + "conn_handle=0x%04x op=pair_initiate\n", conn_handle); res.app_status = BLE_HS_ENOMEM; } else { proc->conn_handle = conn_handle; @@ -2934,6 +2952,8 @@ ble_sm_slave_initiate(uint16_t conn_handle) } else { proc = ble_sm_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "SMP: proc alloc failed; " + "conn_handle=0x%04x op=slave_initiate\n", conn_handle); res.app_status = BLE_HS_ENOMEM; } else { proc->conn_handle = conn_handle; @@ -2978,6 +2998,8 @@ ble_sm_enc_initiate(uint16_t conn_handle, uint8_t key_size, } else { proc = ble_sm_proc_alloc(); if (proc == NULL) { + BLE_HS_LOG(INFO, "SMP: proc alloc failed; " + "conn_handle=0x%04x op=enc_initiate\n", conn_handle); res.app_status = BLE_HS_ENOMEM; } else { proc->conn_handle = conn_handle; @@ -3043,6 +3065,8 @@ ble_sm_rx(struct ble_l2cap_chan *chan) false : true); rc = res.app_status; } else { + BLE_HS_LOG(INFO, "SMP: no handler for opcode; " + "op=0x%02x conn_handle=0x%04x\n", op, conn_handle); rc = BLE_HS_ENOTSUP; }