Decrease time to sync audio broadcast

[RakeLund]

We have a project with a device acting as a ble peripheral and a broadcast sink. First the ACL connection is set up and then it will scan for and sync to a broadcast with a configured name. 

In the current prototype the time from starting to scan for broadcast and until the audio stream is synced and ready is typically 10-20seconds, with getting the BASE and BIG sync taking the longest. Is this expected with LE Audio broadcast or should it be possible to significantly reduce this delay?

Here are some logs that shows the timing (in ms):

[15552::INFO] (broadcast_sink.cpp:1116) Scanning for broadcaster XXX
[15634::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[15804::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[15976::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[16234::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[16404::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[16553::INFO] (broadcast_sink.cpp:999) Attempting to PA sync to the broadcaster with id 0x199823
[16554::INFO] (broadcast_sink.cpp:1006) Waiting for PA sync to complete
[16564::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[17424::INFO] (broadcast_sink.cpp:428) Found broadcaster with ID 0x199823 and addr 02:97:3C:BC:C5:EF (
[17744::INFO] (broadcast_sink.cpp:473) PA sync 0x2000dbd8 synced for broadcast sink with broadcast ID 
[17744::INFO] (broadcast_sink.cpp:1013) Broadcast source PA synced, creating Broadcast Sink
[17745::INFO] (broadcast_sink.cpp:1020) Broadcast Sink created, waiting for BASE
[24944::INFO] (broadcast_sink.cpp:785) Received BASE with 1 subgroups from broadcast sink 0x2000e228
[24944::INFO] (broadcast_sink.cpp:791) Subgroup: 0 BIS: 0 index = 1
[24944::INFO] (broadcast_sink.cpp:621) Octets per frame: 40
[24944::INFO] (broadcast_sink.cpp:766) Codec info: id: 0x06, cid: 0x0000, vid: 0x0000, frequency: 2400
[24944::INFO] (broadcast_sink.cpp:830) Received SYNCABLE from broadcast sink 0x2000e228: unencrypted
[24944::INFO] (broadcast_sink.cpp:1027) BASE received, waiting for syncable 
[24944::INFO] (broadcast_sink.cpp:1034) Waiting for broadcast code
[24945::INFO] (broadcast_sink.cpp:1041) Waiting for BIS sync request
[24945::INFO] (broadcast_sink.cpp:1048) Syncing to broadcast
[00:00:24.945,129] <dbg> bt_bap_broadcast_sink: broadcast_sink_ep_init: ep 0x2000e338
[00:00:24.945,159] <dbg> bt_bap_iso: bt_bap_iso_bind_ep: iso 0x2000e100 ep 0x2000e338 dir sink
[00:00:24.945,556] <dbg> bt_bap_broadcast_sink: broadcast_sink_set_ep_state: ep 0x2000e338 id 0x00 idle -> qos-configured
[24945::INFO] (broadcast_sink.cpp:1055) Waiting for BIG sync
[32144::INFO] (broadcast_sink.cpp:785) Received BASE with 1 subgroups from broadcast sink 0x2000e228
[32144::INFO] (broadcast_sink.cpp:791) Subgroup: 0 BIS: 0 index = 1
[32144::INFO] (broadcast_sink.cpp:621) Octets per frame: 40
[32144::INFO] (broadcast_sink.cpp:766) Codec info: id: 0x06, cid: 0x0000, vid: 0x0000, frequency: 2400
[00:00:32.150,909] <dbg> bt_bap_broadcast_sink: broadcast_sink_iso_connected: stream 0x2000ca34
[00:00:32.150,909] <dbg> bt_bap_broadcast_sink: broadcast_sink_set_ep_state: ep 0x2000e338 id 0x00 qos-configured -> streaming
[32150::INFO] (broadcast_sink.cpp:339) Stream 0x2000ca34 started

Both sides (broadcast sink and broadcast source) is nrf5340 and running nrf Connect v2.6.0, so we're also wondering if there has been changes to the audio implementation lately that might be beneficial for this issue?

[Maria Gilje]

Hello,

From the release notes for the versions from nRF Connect SDK v2.6.0 to v2.9.0 I did not find any specific points which addressed sync time. I would like to do a quick test though to see if v2.9.0 is quicker. It looks like you are running the BAP Broadcast source and sink samples?

That being said, I think you should be able to adjust some settings to make the sync quicker, but I'm not 100% sure here. I will check this in parallel with running the samples.

Best regards,

Maria

[Maria Gilje]

I have tested with nRF Connect SDK v2.9.0 now and the sync seems to be quicker than 20 seconds. See the log below.

*** Booting nRF Connect SDK v2.9.0-7787b2649840 ***
*** Using Zephyr OS v3.7.99-1f8f3dc29142 ***
[00:00:00.290,008] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.290,039] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[00:00:00.290,069] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 3.7 Build 99
[00:00:00.292,236] <inf> bt_hci_core: Identity: D1:D9:6F:57:FD:47 (random)
[00:00:00.292,266] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x0000, manufacturer 0x0059
[00:00:00.292,297] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0xffff
Bluetooth initialized
[00:00:00.292,358] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,358] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,358] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,388] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,388] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,419] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,419] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,419] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,449] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,449] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,449] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,449] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,480] <wrn> usb_nrfx: invalid endpoint type
[00:00:00.292,480] <wrn> usb_nrfx: invalid endpoint type
Reset
Starting advertising
Waiting for Broadcast Assistant
[00:00:00.534,240] <wrn> usb_device: Endpoint 0x88 already disabled
[00:00:00.534,423] <wrn> usb_device: Endpoint 0x08 already disabled
[00:00:00.540,863] <wrn> usb_device: Endpoint 0x88 already disabled
[00:00:00.541,076] <wrn> usb_device: Endpoint 0x08 already disabled
No Broadcast Assistant connected
Scanning for broadcast sources
Waiting for Broadcaster
Found broadcaster with ID 0xDD7889 and addr 33:93:8D:E2:71:F9 (random) and sid 0x00
broadcaster_broadcast_id = 0xDD7889
Attempting to PA sync to the broadcaster with id 0xDD7889
Waiting for PA synced
PA sync 0x200087a0 synced for broadcast sink with broadcast ID 0xDD7889
Broadcast source PA synced, creating Broadcast Sink
Receive state updated, pa sync state: 2
Broadcast Sink created, waiting for BASE
[00:00:11.960,449] <dbg> bt_bap_broadcast_sink: pa_decode_base: Updating BASE for sink 0x20008d00 with 1 subgroups

Receive state updated, pa sync state: 2
subgroup 0 bis_sync: 0x00000000
Received BASE with 1 subgroups from broadcast sink 0x20008d00
bis_index_bitfield = 0x00000002
Broadcast sink (0x20008d00) is syncable, BIG not encrypted
BASE received, waiting for syncable
Waiting for broadcast code
Waiting for BIS sync request
Syncing to broadcast with bitfield: 0x00000002 = 0x00000002 (bis_index) & 0xffffffff (req_bis_sync), stream_count = 1
[00:00:11.961,181] <dbg> bt_bap_broadcast_sink: broadcast_sink_ep_init: ep 0x20008da4
[00:00:11.961,303] <dbg> bt_bap_iso: bt_bap_iso_bind_ep: iso 0x20008b64 ep 0x20008da4 dir sink
[00:00:11.961,364] <dbg> bt_iso: bt_iso_chan_add: iso 0x200067a8 chan 0x20008b64
[00:00:11.961,791] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20008b64 iso 0x200067a8 disconnected -> connecting
[00:00:11.961,853] <dbg> bt_bap_broadcast_sink: broadcast_sink_set_ep_state: ep 0x20008da4 id 0x00 idle -> qos-configured
Waiting for stream(s) started
Receive state updated, pa sync state: 2
subgroup 0 bis_sync: 0x00000002
[00:00:13.173,034] <dbg> bt_iso: hci_le_big_sync_established: BIG[0] 0x20008b14 sync established, status 0x00 
[00:00:13.173,034] <dbg> bt_iso: bt_iso_connected: 0x200067a8
[00:00:13.173,492] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20008b64 iso 0x200067a8 connecting -> connected
[00:00:13.173,522] <dbg> bt_bap_broadcast_sink: broadcast_sink_iso_connected: stream 0x20000fb8
Stream 0x20000fb8 connected
[00:00:13.173,583] <dbg> bt_bap_broadcast_sink: broadcast_sink_set_ep_state: ep 0x20008da4 id 0x00 qos-configured -> streaming
Stream 0x20000fb8 started
Enable: stream with codec 0x20008d64
Enabling LC3 decoder with frame duration 10000us, frequency 16000Hz and with channel allocation 0x00000002, 40 octets per frame and 1 frame blocks per SDU
Waiting for PA disconnected
Stream 0x20000fb8: received 1000 total ISO packets: Valid 1000 | Error 0 | Loss 0

Is this a good enough reason for you to upgrade to nRF Connect SDK v2.9.0 or should I find more tangible indicators for improvements in nRF Connect SDK?

One I can think of off the top of my head is that the ISO features for the SoftDevice Controller has improved since nRF Connect SDK v2.6.0, since that was the first version where the controller supported ISO at all.

Best regards,

Maria

[RakeLund]

Thank you for running this test, it at least shows it should be possible to get the delay down. I tried running the broadcast sink sample v2.6.0 to check if the sample itself would behave differently than 2.9.0, but both on a nrf5340 audio dk and normal nrf5340 dk it failed to start advertising/scanning with an I/O error, not sure what is wrong. 

I also tried running the nrf5340 audio application on my nrf5340 audio dk just to compare and even with 2.6.0 the syncing to a broadcast is very quick (~1 second) so I think the real issue is related to the fact that we're also keeping an ACL connection at the same time. I will do some more investigations.

[Maria Gilje]

RakeLund said:

I tried running the broadcast sink sample v2.6.0 to check if the sample itself would behave differently than 2.9.0, but both on a nrf5340 audio dk and normal nrf5340 dk it failed to start advertising/scanning with an I/O error, not sure what is wrong. 

This could be because of the introduction of sysbuild (from v2.7.0). Include --sysbuild to the west build command or check the "Use sysbuild" option with the nRF Connect for VS Code extension.

RakeLund said:

I also tried running the nrf5340 audio application on my nrf5340 audio dk just to compare and even with 2.6.0 the syncing to a broadcast is very quick (~1 second) so I think the real issue is related to the fact that we're also keeping an ACL connection at the same time. I will do some more investigations.

Let me know if I there is anything I can help with!

Best regards,

Maria

[RakeLund]

I was able to build and run the samples in the end, but the broadcast sink is failing when I try to sync to our broadcast source, maybe because we only have 1 stream/1 channel while it's expecting 2?

Then I tried running 2 nrf5340DK one with the broadcast sink sample and one with the broadcast source sample, both with nrf connect sdk 2.6.0 and it's a lot quicker than our application (2~3seconds while ours is 10-20seconds). So I doubt an upgrade of sdk will fix the issue alone. 
I will compare the sample to our application to see if there any obvious differences. Do you have any other pointers as to what to look for? Or some debug logs I could add with configurations in prj.conf? 

[Maria Gilje]

Hello,

RakeLund said:

I was able to build and run the samples in the end, but the broadcast sink is failing when I try to sync to our broadcast source, maybe because we only have 1 stream/1 channel while it's expecting 2?

Maybe. A Kconfig symbol for selecting BIS channels was introduced to the sample after v2.6.0, so this may cause the sync to fail with your custom broadcaster. The broadcast sink (from v2.9.0) will print "Failed to find a valid BIS" in that case. The default should be that it expects the left channel (CONFIG_TARGET_BROADCAST_CHANNEL=1), but setting CONFIG_TARGET_BROADCAST_CHANNEL to 0 or 2 instead will make it expect mono or the right channel respectively.

RakeLund said:

I will compare the sample to our application to see if there any obvious differences. Do you have any other pointers as to what to look for? Or some debug logs I could add with configurations in prj.conf? 

Would you be willing to share your prj.conf file so our developers can take a look. They would know if some configurations could cause increased sync times.

Best regards,

Maria

[RakeLund]

Here's our prj.conf I just removed a few names and ids

# Debugging and Optimization
CONFIG_DEBUG=y
CONFIG_DEBUG_INFO=y
CONFIG_DEBUG_OPTIMIZATIONS=y
CONFIG_DEBUG_THREAD_INFO=y

# C++ Support
CONFIG_CPP=y
CONFIG_STD_CPP17=y
CONFIG_GLIBCXX_LIBCPP=y

# Logging
CONFIG_LOG=y
CONFIG_LOG_MODE_MINIMAL=n
CONFIG_LOG_MODE_DEFERRED=y
CONFIG_LOG_BACKEND_UART=y
CONFIG_LOG_BACKEND_RTT=y
CONFIG_LOG_BUFFER_SIZE=2048
CONFIG_STDOUT_CONSOLE=y

# Bluetooth Settings
CONFIG_BT=y
CONFIG_BT_HCI=y
CONFIG_BT_PERIPHERAL=y
CONFIG_BT_PRIVACY=n
CONFIG_BT_DEVICE_NAME="XXXX"
CONFIG_BT_EXT_ADV=y
CONFIG_BT_GATT_DYNAMIC_DB=y
CONFIG_BT_OBSERVER=y
CONFIG_BT_SCAN=y
CONFIG_BT_PER_ADV_SYNC=y
CONFIG_BT_HCI_VS_EXT=n
CONFIG_BT_HCI_ACL_FLOW_CONTROL=n
CONFIG_BT_MAX_CONN=2
CONFIG_BT_SCAN_WITH_IDENTITY=y
CONFIG_BT_PER_ADV=y
CONFIG_BT_BUF_ACL_RX_SIZE=502
CONFIG_BT_ATT_PREPARE_COUNT=2
CONFIG_BT_L2CAP_TX_MTU=498
CONFIG_BT_L2CAP_DYNAMIC_CHANNEL=y
CONFIG_BT_BUF_ACL_TX_COUNT=10
CONFIG_BT_BUF_ACL_TX_SIZE=502
CONFIG_BT_CTLR_DATA_LENGTH_MAX=1004
CONFIG_BT_BAP_BROADCAST_SINK_LOG_LEVEL_DBG=y
CONFIG_BT_BAP_ISO_LOG_LEVEL_DBG=y
CONFIG_BT_SMP=y
CONFIG_BT_AUDIO=y
CONFIG_BT_BAP_BROADCAST_SINK=y
CONFIG_BT_BAP_SCAN_DELEGATOR=y
CONFIG_BT_PAC_SNK=y
CONFIG_BT_BAP_BROADCAST_ASSISTANT=y
CONFIG_BT_BAS=y
CONFIG_BT_DIS=y
CONFIG_BT_DIS_HW_REV_STR="XXX"
CONFIG_BT_DIS_PNP=n
CONFIG_BT_DIS_SERIAL_NUMBER=n
CONFIG_BT_DIS_FW_REV=y
CONFIG_BT_DIS_HW_REV=y
CONFIG_BT_SETTINGS=y
CONFIG_SETTINGS_RUNTIME=y
CONFIG_SETTINGS=y
CONFIG_SETTINGS_NONE=y
CONFIG_BT_DIS_SETTINGS=y
CONFIG_BT_DIS_STR_MAX=21
CONFIG_BT_PER_ADV_SYNC_MAX=2
CONFIG_BT_BAP_BROADCAST_SNK_SUBGROUP_COUNT=2
CONFIG_BT_BAP_BROADCAST_SNK_STREAM_COUNT=2
CONFIG_BT_GAP_AUTO_UPDATE_CONN_PARAMS=y
CONFIG_BT_PERIPHERAL_PREF_MAX_INT=32
CONFIG_BT_PERIPHERAL_PREF_MIN_INT=32

# Audio and Codec
CONFIG_LIBLC3=y
CONFIG_SW_CODEC_LC3_T2_SOFTWARE=y

# Stack and Threading
CONFIG_MAIN_STACK_SIZE=4096
CONFIG_TIMESLICING=y
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=2304

# UART and Console
CONFIG_UART_INTERRUPT_DRIVEN=y
CONFIG_UART_LINE_CTRL=y
CONFIG_UART_ASYNC_API=n
CONFIG_UART_CONSOLE=y
CONFIG_SERIAL=y
CONFIG_CONSOLE=y

# USB Device
CONFIG_USB_DEVICE_STACK=y
CONFIG_USB_DEVICE_PRODUCT="XXXX"
CONFIG_USB_DEVICE_PID=0xXXXX
CONFIG_USB_DEVICE_INITIALIZE_AT_BOOT=n

# Flash and Bootloader
CONFIG_FLASH=y
CONFIG_BOOTLOADER_MCUBOOT=y

# MCU Manager
CONFIG_MCUMGR=y
CONFIG_MCUMGR_GRP_IMG=y
CONFIG_MCUMGR_GRP_OS=y
CONFIG_MCUMGR_TRANSPORT_BT=y
CONFIG_MCUMGR_TRANSPORT_BT_AUTHEN=n
CONFIG_NCS_SAMPLE_MCUMGR_BT_OTA_DFU=y

# Peripheral Drivers
CONFIG_NRFX_I2S0=y
CONFIG_DATA_FIFO=y
CONFIG_I2C=y
CONFIG_ADC=y
CONFIG_ADC_NRFX_SAADC=y
CONFIG_NRFX_SAADC=y
CONFIG_SAMPLE_RATE_CONVERTER=y
CONFIG_SAMPLE_RATE_CONVERTER_FILTER_SIMPLE=y

# Floating Point Unit
CONFIG_FPU=y
CONFIG_FP_HARDABI=y

# Power Management
CONFIG_POWEROFF=y

# Board and RPMsg
CONFIG_BOARD_ENABLE_CPUNET=y
CONFIG_NCS_INCLUDE_RPMSG_CHILD_IMAGE=y

# RTT Console
CONFIG_USE_SEGGER_RTT=y
CONFIG_RTT_CONSOLE=y