Headset: Could not create BIG sync -5 After a period of losting Sync from Gateway

[TueTD]

I am developing app in BIS mode and have encountered this problem.

When the signal from the Gateway is too weak that make the Headset must re-sync multiple time. The headset cannot create BIG group after call 

bt_hci_cmd_send_sync with the return -5 which cause Headset is unable to sync again.

My temporary solution for this problem is the headset software reset.

To reproduce:

1. Set CONFIG_BLE_ADV_TX_POWER_NEG_40DBM=y for the gateway. 
2. Make the Headset lost sync for a period. (Not turning off the Gateway power).

I found this issue https://github.com/zephyrproject-rtos/zephyr/issues/59099 but i don't know if it related to my problem since i don't see any hci reset in the code.

Bug log Attach:

00> HL [00:01:09.012,725] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x1001 param_len 0
00> HL [00:01:09.012,756] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2001ad3c
00> HL [00:01:09.012,756] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2001ad3c opcode 0x1001 len 3
00> HL [00:01:09.012,786] <dbg> bt_hci_core: process_events: count 2
00> HL [00:01:09.012,786] <dbg> bt_hci_core: process_events: ev->state 4
00> HL [00:01:09.012,817] <dbg> bt_hci_core: send_cmd: calling net_buf_get
00> HL [00:01:09.012,817] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
00> HL [00:01:09.012,817] <dbg> bt_hci_core: send_cmd: Sending command 0x1001 (buf 0x2001ad3c) to driver
00> HL [00:01:09.012,817] <dbg> bt_hci_core: bt_send: buf 0x2001ad3c len 3 type 0
00> HL [00:01:09.012,847] <dbg> bt_hci_core: process_events: ev->state 0
00> HL [00:01:09.012,878] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
00> HL [00:01:09.012,969] <dbg> bt_hci_core: bt_recv: buf 0x2001ad3c len 14
00> HL [00:01:09.012,969] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x1001
00> HL [00:01:09.013,000] <dbg> bt_hci_core: hci_cmd_done: opcode 0x1001 status 0x00 buf 0x2001ad3c
00> HL [00:01:09.013,000] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2001ad3c opcode 0x1001 len 9
00> HL [00:01:09.902,038] <dbg> bt_hci_core: bt_recv: buf 0x20019e9c len 48
00> HL [00:01:09.902,069] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
00> HL [00:01:09.902,069] <dbg> bt_hci_core: rx_work_handler: buf 0x20019e9c type 1 len 48
00> HL [00:01:09.902,069] <dbg> bt_hci_core: hci_event: event 0x3e
00> HL [00:01:09.902,099] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x0f
00> HL [00:01:09.902,130] <inf> bis_headset: base_recv_cb: Received BASE with 1 subgroup(s) from broadcast sink
00> HL [00:01:09.902,130] <inf> bis_headset: base_recv_cb: BIS 0   index = 1
00> HL [00:01:09.902,160] <wrn> bis_headset: bitrate_check: Get codec Bitrate 80
00> HL [00:01:09.902,160] <inf> bis_headset: get_codec_info: Retrieve the codec configuration for LC3
00> HL [00:01:09.902,160] <inf> bis_headset: print_codec: Codec config for LC3:
00> HL [00:01:09.902,191] <inf> bis_headset: print_codec:   Frequency: 48000 Hz
00> HL [00:01:09.902,191] <inf> bis_headset: print_codec:   Frame Duration: 10000 us
00> HL [00:01:09.902,191] <inf> bis_headset: print_codec:   Octets per frame: 80 (64000 kbps)
00> HL [00:01:09.902,221] <inf> bis_headset: print_codec:   Frames per SDU: 1
00> HL [00:01:09.902,221] <inf> bis_headset: print_codec:   Channel allocation: 0x1
00> HL [00:01:09.902,221] <inf> bis_headset: base_recv_cb: Stream 0 in subgroup 0 from broadcast sink
00> HL [00:01:09.902,252] <inf> bis_headset: base_recv_cb: Channel HL active
00> HL [00:01:09.902,252] <inf> bis_headset: base_recv_cb: Waiting for syncable
00> HL [00:01:09.902,313] <dbg> bt_hci_core: bt_recv: buf 0x20019e9c len 22
00> HL [00:01:09.902,343] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
00> HL [00:01:09.902,343] <dbg> bt_hci_core: rx_work_handler: buf 0x20019e9c type 1 len 22
00> HL [00:01:09.902,343] <dbg> bt_hci_core: hci_event: event 0x3e
00> HL [00:01:09.902,374] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x22
00> HL [00:01:09.902,374] <inf> bis_headset: syncable_cb: Syncing to broadcast stream index 0
00> HL [00:01:09.902,374] <dbg> bt_audio_broadcast_sink: broadcast_sink_ep_init: ep 0x2000e204
00> HL [00:01:09.902,435] <dbg> bt_iso: bt_iso_chan_add: iso 0x20004438 chan 0x2000e2e4
00> HL [00:01:09.902,435] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x206b param_len 25
00> HL [00:01:09.902,465] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2001ad3c
00> HL [00:01:09.902,465] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2001ad3c opcode 0x206b len 28
00> HL [00:01:09.902,496] <dbg> bt_hci_core: process_events: count 2
00> HL [00:01:09.902,496] <dbg> bt_hci_core: process_events: ev->state 4
00> HL [00:01:09.902,526] <dbg> bt_hci_core: send_cmd: calling net_buf_get
00> HL [00:01:09.902,526] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
00> HL [00:01:09.902,526] <dbg> bt_hci_core: send_cmd: Sending command 0x206b (buf 0x2001ad3c) to driver
00> HL [00:01:09.902,526] <dbg> bt_hci_core: bt_send: buf 0x2001ad3c len 28 type 0
00> HL [00:01:09.902,557] <dbg> bt_hci_core: process_events: ev->state 0
00> HL [00:01:09.902,587] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
00> HL [00:01:09.902,709] <dbg> bt_hci_core: bt_recv: buf 0x2001ad3c len 6
00> HL [00:01:09.902,709] <dbg> bt_hci_core: hci_cmd_status: opcode 0x206b
00> HL [00:01:09.902,740] <dbg> bt_hci_core: hci_cmd_done: opcode 0x206b status 0x0c buf 0x2001ad3c
00> HL [00:01:09.902,740] <wrn> bt_hci_core: bt_hci_cmd_send_sync: opcode 0x206b status 0x0c
00> HL [00:01:09.902,770] <dbg> bt_iso: bt_iso_big_sync: Could not create BIG sync -5
00> HL [00:01:09.902,770] <wrn> bis_headset: syncable_cb: Unable to sync to broadcast source, ret: -5
00> HL [00:01:10.012,725] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x1001 param_len 0
00> HL [00:01:10.012,756] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x2001ad3c
00> HL [00:01:10.012,756] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x2001ad3c opcode 0x1001 len 3
00> HL [00:01:10.012,786] <dbg> bt_hci_core: process_events: count 2
00> HL [00:01:10.012,786] <dbg> bt_hci_core: process_events: ev->state 4
00> HL [00:01:10.012,817] <dbg> bt_hci_core: send_cmd: calling net_buf_get
00> HL [00:01:10.012,817] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
00> HL [00:01:10.012,817] <dbg> bt_hci_core: send_cmd: Sending command 0x1001 (buf 0x2001ad3c) to driver
00> HL [00:01:10.012,817] <dbg> bt_hci_core: bt_send: buf 0x2001ad3c len 3 type 0
00> HL [00:01:10.012,847] <dbg> bt_hci_core: process_events: ev->state 0
00> HL [00:01:10.012,878] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
00> HL [00:01:10.012,969] <dbg> bt_hci_core: bt_recv: buf 0x2001ad3c len 14
00> HL [00:01:10.012,969] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x1001
00> HL [00:01:10.013,000] <dbg> bt_hci_core: hci_cmd_done: opcode 0x1001 status 0x00 buf 0x2001ad3c
00> HL [00:01:10.013,000] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x2001ad3c opcode 0x1001 len 9

I am using NCS V2.2.0 with my custom board. I did the same test with Audio DK and NCS 2.4.0

[Amanda Hsieh]

Hi, 

This is a known issue, we can replicate the issue by toggling the power of the BIS gateway frequently or putting the headset in the middle of in/out of the radio range from the gateway. The team is working on it, but no promised schedule. Sorry for the inconvenience. 

Regards,
Amanda H.