bt_enable hangs on nRF52840

On calling `bt_enable`, I find that the program hangs - the function fails to complete.

Enabling logging, it looks like HCI command buffers aren't being properly released:

*** Using nRF Connect SDK v2.9.0-7787b2649840 ***
*** Using Zephyr OS v3.7.99-1f8f3dc29142 ***
[00:00:00.043,243] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.043,273] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.043,304] <inf> fs_nvs: data wra: 0, 0
[00:00:00.043,762] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision:
                                            2d 79 a1 c8 6a 40 b7 3c  f6 74 f9 0b 22 d3 c4 80 |-y..j@.< .t.."...
                                            74 72 82 ba                                      |tr..
[00:00:00.044,525] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x0c03 param_len 0
[00:00:00.044,586] <dbg> net_buf: net_buf_alloc_len_debug: (0x200074b0) net_buf_alloc():1362: pool 0x20003ec8 size 259
[00:00:00.044,616] <dbg> net_buf: net_buf_alloc_len_debug: (0x200074b0) allocated buf 0x20017ca4
[00:00:00.044,708] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20017ca4
[00:00:00.044,738] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20017ca4 opcode 0x0c03 len 3
[00:00:00.044,799] <dbg> net_buf: net_buf_ref: (0x200074b0) buf 0x20017ca4 (old) ref 1 pool_id 4
[00:00:00.044,830] <dbg> net_buf: net_buf_ref: (0x200074b0) buf 0x20017ca4 (old) ref 2 pool_id 4
[00:00:00.044,891] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.044,982] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:00.045,013] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:00.045,074] <dbg> net_buf: net_buf_ref: (0x20007600) buf 0x20017ca4 (old) ref 3 pool_id 4
[00:00:00.045,135] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x0c03 (buf 0x20017ca4) to driver
[00:00:00.045,166] <dbg> bt_hci_core: bt_send: buf 0x20017ca4 len 3 type 0
[00:00:00.045,288] <dbg> net_buf: net_buf_unref_debug: (0x20007600) buf 0x20017ca4 ref 4 pool_id 4 frags 0
[00:00:00.045,349] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.045,501] <dbg> net_buf: net_buf_alloc_len_debug: (0x20007280) net_buf_alloc():1362: pool 0x20003f58 size 258
[00:00:00.045,532] <dbg> net_buf: net_buf_alloc_len_debug: (0x20007280) allocated buf 0x20017a80
[00:00:00.045,593] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20017a80 len 6
[00:00:00.045,654] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x0c03
[00:00:00.045,715] <dbg> bt_hci_core: hci_cmd_done: opcode 0x0c03 status 0x00  buf 0x20017a80
[00:00:00.045,745] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:00.045,806] <dbg> net_buf: net_buf_unref_debug: (0x20007280) buf 0x20017ca4 ref 3 pool_id 4 frags 0
[00:00:00.045,837] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.045,898] <dbg> net_buf: net_buf_unref_debug: (0x20007280) buf 0x20017a80 ref 1 pool_id 7 frags 0
[00:00:00.046,173] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:00.046,325] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20017ca4 opcode 0x0c03 len 1
[00:00:00.046,386] <dbg> bt_hci_core: hci_reset_complete: status 0x00
[00:00:00.046,417] <dbg> net_buf: net_buf_unref_debug: (0x200074b0) buf 0x20017ca4 ref 2 pool_id 4 frags 0
[00:00:00.046,447] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x1003 param_len 0
[00:00:00.046,508] <dbg> net_buf: net_buf_alloc_len_debug: (0x200074b0) net_buf_alloc():1362: pool 0x20003ec8 size 259
[00:00:00.046,569] <dbg> net_buf: net_buf_alloc_len_debug: (0x200074b0) allocated buf 0x20017cc0
[00:00:00.046,630] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x20017cc0
[00:00:00.046,661] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x20017cc0 opcode 0x1003 len 3
[00:00:00.046,691] <dbg> net_buf: net_buf_ref: (0x200074b0) buf 0x20017cc0 (old) ref 1 pool_id 4
[00:00:00.046,752] <dbg> net_buf: net_buf_ref: (0x200074b0) buf 0x20017cc0 (old) ref 2 pool_id 4
[00:00:00.046,813] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.046,905] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:00.046,936] <dbg> bt_hci_core: hci_core_send_cmd: fetch cmd
[00:00:00.046,997] <dbg> net_buf: net_buf_ref: (0x20007600) buf 0x20017cc0 (old) ref 3 pool_id 4
[00:00:00.047,058] <dbg> bt_hci_core: hci_core_send_cmd: Sending command 0x1003 (buf 0x20017cc0) to driver
[00:00:00.047,088] <dbg> bt_hci_core: bt_send: buf 0x20017cc0 len 3 type 0
[00:00:00.047,180] <dbg> net_buf: net_buf_unref_debug: (0x20007600) buf 0x20017cc0 ref 4 pool_id 4 frags 0
[00:00:00.047,210] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.047,393] <dbg> net_buf: net_buf_alloc_len_debug: (0x20007280) net_buf_alloc():1362: pool 0x20003f58 size 258
[00:00:00.047,454] <dbg> net_buf: net_buf_alloc_len_debug: (0x20007280) allocated buf 0x20017a80
[00:00:00.047,515] <dbg> bt_hci_core: bt_recv_unsafe: buf 0x20017a80 len 14
[00:00:00.047,546] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x1003
[00:00:00.047,607] <dbg> bt_hci_core: hci_cmd_done: opcode 0x1003 status 0x00  buf 0x20017a80
[00:00:00.047,668] <dbg> bt_hci_core: hci_cmd_done: sync cmd released
[00:00:00.047,698] <dbg> net_buf: net_buf_unref_debug: (0x20007280) buf 0x20017cc0 ref 3 pool_id 4 frags 0
[00:00:00.047,760] <dbg> bt_hci_core: bt_tx_irq_raise: kick TX
[00:00:00.047,821] <dbg> net_buf: net_buf_unref_debug: (0x20007280) buf 0x20017a80 ref 1 pool_id 7 frags 0
[00:00:00.048,065] <dbg> bt_hci_core: tx_processor: TX process start
[00:00:00.048,217] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x20017cc0 opcode 0x1003 len 9
[00:00:00.048,278] <dbg> bt_hci_core: read_local_features_complete: status 0x00
[00:00:00.048,309] <dbg> net_buf: net_buf_unref_debug: (0x200074b0) buf 0x20017cc0 ref 2 pool_id 4 frags 0
[00:00:00.048,370] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x1001 param_len 0
[00:00:00.048,431] <dbg> net_buf: net_buf_alloc_len_debug: (0x200074b0) net_buf_alloc():1362: pool 0x20003ec8 size 259
[00:00:00.048,492] <wrn> net_buf: net_buf_alloc():1362: Pool 0x20003ec8 low on buffers.
[00:00:01.048,706] <wrn> net_buf: net_buf_alloc():1362: Pool 0x20003ec8 blocked for 1 secs
[00:00:01.048,797] <wrn> net_buf: net_buf_alloc():1362: Pool 0x20003ec8 low on buffers.
[00:00:02.049,041] <wrn> net_buf: net_buf_alloc():1362: Pool 0x20003ec8 blocked for 2 secs

Parents Reply Children
No Data
Related