Hi,
I have a peripheral which is sending data to a central via the NUS service. Everything works as expected until the central is removed (e.g. power failure)
The problem is the time between the central is removed and the peripherals recognises the disconnect (connection timeout). If in that time bt_nus_send() is called more than three times, it blocks. It then releases after the disconnect callback.
I've recognized the error, cause after I received a disconnect callback, i immediately start extended advertising again. The restart of the advertising fails, if the bt_nus_send() is blocking.
I've two questions:
- Is there a way to get an error of the bt_nus_send() instead of blocking?
- Why is the restart of the advertising failing; what has this to do with the bt_nus_send()
I've to say, I've found a workaround. I'm using k_work_schedule in the disconnect callback to start advertising 50ms delayed. This works fine. But I will do it the right way, maybe I don't need the delay if I get to the bottom of this.
Attached you'll find a logging of the 4th calling of bt_nus_send(). I've logged the start and end of bt_nus_send() function and where the function blocks
[00:01:05.247,375] <inf> app: Button pressed: 65247, Counter: 12 [00:01:05.247,802] <inf> protocol: enqueu [00:01:05.248,199] <inf> ble: Dequeue: Type:0x40;Length:10 [00:01:05.248,596] <inf> ble: start bt_nus_send() [00:01:05.248,962] <dbg> bt_conn: bt_conn_ref: handle 2 ref 2 -> 3 --------- here is where the function blocks ----------------- [00:01:07.894,470] <dbg> bt_sdc_hci_driver: event_packet_process: Event (0x05) len 4 [00:01:07.894,958] <dbg> bt_hci_core: bt_recv: buf 0x20014a28 len 6 [00:01:07.895,416] <dbg> bt_hci_core: hci_disconn_complete_prio: status 0x00 handle 2 reason 0x08 [00:01:07.895,965] <dbg> bt_conn: bt_conn_ref: handle 2 ref 3 -> 4 [00:01:07.896,423] <dbg> bt_conn: bt_conn_set_state: connected -> disconnect-complete [00:01:07.896,881] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x20009e78 CID 0x0004 [00:01:07.897,430] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x20009e78 CID 0x0004 [00:01:07.897,949] <dbg> bt_att: chan_tx_complete: TX Complete chan 0x20009e78 CID 0x0004 [00:01:07.898,468] <dbg> bt_conn: bt_conn_unref: handle 2 ref 4 -> 3 [00:01:07.898,956] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue [00:01:07.899,414] <dbg> bt_hci_core: rx_work_handler: buf 0x20014a28 type 1 len 6 [00:01:07.899,932] <dbg> bt_hci_core: hci_event: event 0x05 [00:01:07.905,364] <dbg> bt_hci_core: hci_disconn_complete: status 0x00 handle 2 reason 0x08 [00:01:07.905,883] <dbg> bt_conn: bt_conn_ref: handle 2 ref 3 -> 4 [00:01:07.906,341] <dbg> bt_conn: bt_conn_set_state: disconnect-complete -> disconnected [00:01:07.906,799] <dbg> bt_conn: tx_notify: conn 0x20002498 [00:01:07.907,226] <dbg> bt_conn: bt_conn_unref: handle 2 ref 4 -> 3 [00:01:07.907,714] <dbg> bt_hci_core: process_events: count 3 [00:01:07.918,182] <dbg> bt_hci_core: process_events: ev->state 0 [00:01:07.918,579] <dbg> bt_hci_core: process_events: ev->state 1 [00:01:07.918,975] <dbg> bt_hci_core: process_events: ev->state 0 [00:01:07.919,403] <dbg> bt_conn: bt_conn_prepare_events: [00:01:07.919,769] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events [00:01:07.920,257] <dbg> bt_conn: deferred_work: conn 0x20002498 [00:01:07.920,684] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20002498 chan 0x20003d6c [00:01:07.921,173] <dbg> bt_l2cap: l2cap_disconnected: ch 0x20003d6c cid 0x0005 [00:01:07.921,661] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20002498 chan 0x20003e30 [00:01:07.922,180] <dbg> bt_l2cap: bt_l2cap_chan_del: conn 0x20002498 chan 0x20009e7c [00:01:07.922,668] <dbg> bt_att: bt_att_disconnected: chan 0x20009e7c cid 0x0004 [00:01:07.923,156] <dbg> bt_att: att_chan_detach: chan 0x20009e78 [00:01:07.933,654] <dbg> bt_gatt: bt_gatt_disconnected: conn 0x20002498 [00:01:07.934,112] <inf> ble: NUS disabled [00:01:07.934,417] <inf> protocol: enqueu [00:01:07.934,753] <dbg> bt_gatt: disconnected_cb: ccc 0x200005c4 reseted [00:01:07.935,211] <dbg> bt_att: bt_att_released: chan 0x20009e78 [00:01:07.935,638] <wrn> ble: Disconnected (reason 8) [00:01:07.936,035] <dbg> bt_conn: bt_conn_unref: handle 2 ref 3 -> 2 [00:01:07.936,523] <dbg> bt_conn: bt_conn_unref: handle 2 ref 2 -> 1 [00:01:07.936,981] <err> ble: Failed to start ext advertising idx: 0 (err -12) [00:01:07.943,023] <dbg> bt_gatt: gatt_notify: conn 0x20002498 handle 0x0012 [00:01:07.943,481] <wrn> bt_att: Not connected [00:01:07.943,847] <dbg> bt_conn: bt_conn_unref: handle 2 ref 1 -> 0 [00:01:07.944,305] <dbg> bt_adv: bt_le_adv_resume: No valid legacy adv [00:01:07.949,798] <inf> ble: end bt_nus_send() [00:01:07.950,103] <wrn> ble: Failed to send (err -128)
Thanks a lot and Best Regards,
Phobios
