Skip to content

samples: Bluetooth: BAP Unicast samples improvements #90039

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

Thalley
Copy link
Collaborator

@Thalley Thalley commented May 15, 2025

Improve reporting information in the samples and fix a few issues.

Make the reporting interval configurable to make it easier
to actually follow. Improve what gets reported.

Add check for SDU size to ensure correctness when not
using LIBLC3.

Signed-off-by: Emil Gydesen <[email protected]>
@Thalley Thalley force-pushed the unicast_samples_improvements branch from 02797d2 to 78a8b2a Compare May 15, 2025 23:06
@Thalley Thalley changed the title Unicast samples improvements samples: Bluetooth: BAP Unicast samples improvements May 15, 2025
@Thalley Thalley marked this pull request as ready for review May 15, 2025 23:24
@Thalley Thalley requested review from Copilot and removed request for niym-ot, jthm-ot and babrsn May 15, 2025 23:25
Copy link

@Copilot Copilot AI left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull Request Overview

This PR improves reporting information in the Bluetooth BAP Unicast samples and fixes a few issues in audio data handling. Key changes include enhanced logging for transmission and reception (with configurable reporting intervals) and a restructuring of sink and source stream variables to better track transmitted and received SDUs.

Reviewed Changes

Copilot reviewed 7 out of 7 changed files in this pull request and generated no comments.

Show a summary per file
File Description
tests/bsim/bluetooth/audio_samples/bap_unicast_client/Kconfig Adds configuration file for the unicast client test sample.
samples/bluetooth/bap_unicast_server/src/main.c Updates audio stream handling and logging, along with refactoring of sink/source stream structures.
samples/bluetooth/bap_unicast_server/Kconfig Introduces the INFO_REPORTING_INTERVAL configuration option.
samples/bluetooth/bap_unicast_client/src/stream_tx.c Enhances transmission logic with assertions and improved logging.
samples/bluetooth/bap_unicast_client/src/stream_lc3.c Adds logging for LC3 encoding failures.
samples/bluetooth/bap_unicast_client/src/main.c Improves reception logging and resets counters on stream start.
samples/bluetooth/bap_unicast_client/Kconfig Adds configuration for INFO_REPORTING_INTERVAL for the unicast client.
Comments suppressed due to low confidence (1)

samples/bluetooth/bap_unicast_client/src/stream_tx.c:93

  • [nitpick] Consider rephrasing the assertion message to indicate that the configured SDU length exceeds the available mock data size, which may improve clarity when the assertion fires.
__ASSERT(bap_stream->qos->sdu <= ARRAY_SIZE(mock_data), "Configured codec SDU len %u does not match mock data size %zu", bap_stream->qos->sdu, ARRAY_SIZE(mock_data));

@cvinayak
Copy link
Collaborator

Please enable the below kconfig for local target testing if the peripheral data sampling clock is not compensated for drifting Central sleep clock.

# Ignore HCI ISO data Tx sequence numbers
# CONFIG_BT_CTLR_ISOAL_PSN_IGNORE=y

The samples in this PR use ‘k_work_schedule’ with delay as sampling clock which will go out of sync with the Central sleep clock. The Controller will drop sending data with packet sequence numbers that eventually does not meet the time-of-arrival in both Central and Peripheral side.

Do not use OS delay or timeouts as sampling clock, use Number of Completed Packets related callback or drift compensate the sampling clock.

Example of sampling clock drift compensation can be found here:
#83139

@Thalley
Copy link
Collaborator Author

Thalley commented May 16, 2025

Please enable the below kconfig for local target testing if the peripheral data sampling clock is not compensated for drifting Central sleep clock.

# Ignore HCI ISO data Tx sequence numbers
# CONFIG_BT_CTLR_ISOAL_PSN_IGNORE=y

The samples in this PR use ‘k_work_schedule’ with delay as sampling clock which will go out of sync with the Central sleep clock. The Controller will drop sending data with packet sequence numbers that eventually does not meet the time-of-arrival in both Central and Peripheral side.

Do not use OS delay or timeouts as sampling clock, use Number of Completed Packets related callback or drift compensate the sampling clock.

Example of sampling clock drift compensation can be found here: #83139

I will update the server sample to use the number of completed packets approach that we use in the BAP unicast client sample (and to some extend the BAP broadcast source sample) in a separate PR

Improve reporting by introducing a configurable reporting interval
and make the report text more useful.

Change TX to always send the same size, as that is what is
expected/required by LE Audio.

Signed-off-by: Emil Gydesen <[email protected]>
@Thalley Thalley force-pushed the unicast_samples_improvements branch from 06aa4a4 to c7516a6 Compare May 16, 2025 09:49
@Thalley
Copy link
Collaborator Author

Thalley commented May 16, 2025

Please enable the below kconfig for local target testing if the peripheral data sampling clock is not compensated for drifting Central sleep clock.

# Ignore HCI ISO data Tx sequence numbers
# CONFIG_BT_CTLR_ISOAL_PSN_IGNORE=y

The samples in this PR use ‘k_work_schedule’ with delay as sampling clock which will go out of sync with the Central sleep clock. The Controller will drop sending data with packet sequence numbers that eventually does not meet the time-of-arrival in both Central and Peripheral side.
Do not use OS delay or timeouts as sampling clock, use Number of Completed Packets related callback or drift compensate the sampling clock.
Example of sampling clock drift compensation can be found here: #83139

I will update the server sample to use the number of completed packets approach that we use in the BAP unicast client sample (and to some extend the BAP broadcast source sample) in a separate PR

Followup PR to improve TX on the server side: #90052

@cvinayak
Copy link
Collaborator

Tested with rebased to #89845.

Client Log:

[2025-05-16 15:10:04.360] *** Booting Zephyr OS build v4.1.0-4123-g2264f9283ff9 ***
[2025-05-16 15:10:04.364] Initializing
[2025-05-16 15:10:04.388] [00:00:00.446,929] <wrn> bt_hci_core: Num of Controller's ACL packets != ACL bt_conn_tx contexts (7 != 3)
[2025-05-16 15:10:04.398] [00:00:00.446,960] <wrn> bt_hci_core: Num of Controller's ISO packets != ISO bt_conn_tx contexts(8 != 4)
[2025-05-16 15:10:04.408] [00:00:00.449,096] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[2025-05-16 15:10:04.416] [00:00:00.449,127] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[2025-05-16 15:10:04.423] [00:00:00.449,127] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 4.1 Build 99
[2025-05-16 15:10:04.433] [00:00:00.450,775] <inf> bt_hci_core: HCI transport: IPC
[2025-05-16 15:10:04.438] [00:00:00.450,866] <inf> bt_hci_core: Identity: FF:91:CC:FE:7B:2E (random)
[2025-05-16 15:10:04.445] [00:00:00.450,897] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x0000, manufacturer 0x05f1
[2025-05-16 15:10:04.455] [00:00:00.450,927] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0xffff
[2025-05-16 15:10:04.462] Initialized
[2025-05-16 15:10:04.463] Waiting for connection
[2025-05-16 15:10:04.465] Scanning successfully started
[2025-05-16 15:10:04.468] Device found: FF:6C:F3:56:DB:E0 (random) (RSSI -90)
[2025-05-16 15:10:04.472] [AD]: 9 data_len 28
[2025-05-16 15:10:05.481] Device found: F2:76:57:3D:89:BD (random) (RSSI -80)
[2025-05-16 15:10:05.485] [AD]: 1 data_len 1
[2025-05-16 15:10:05.488] [AD]: 3 data_len 2
[2025-05-16 15:10:05.489] [AD]: 22 data_len 8
[2025-05-16 15:10:05.490] Audio server found with type 1, contexts 0x000f001f and meta_len 0; connecting
[2025-05-16 15:10:05.497] MTU exchanged: 23/23
[2025-05-16 15:10:05.499] Connected: F2:76:57:3D:89:BD (random)
[2025-05-16 15:10:05.503] MTU exchanged: 65/65
[2025-05-16 15:10:05.915] Connected
[2025-05-16 15:10:05.915] Discovering sinks
[2025-05-16 15:10:05.917] codec_cap 0x200091e0 dir 0x01
[2025-05-16 15:10:05.921] codec id 0x06 cid 0x0000 vid 0x0000 count 19
[2025-05-16 15:10:05.924] data: type 0x01 value_len 2
[2025-05-16 15:10:05.926] ff1f
[2025-05-16 15:10:05.927] data: type 0x02 value_len 1
[2025-05-16 15:10:05.929] 02
[2025-05-16 15:10:05.930] data: type 0x03 value_len 1
[2025-05-16 15:10:05.932] 01
[2025-05-16 15:10:05.933] data: type 0x04 value_len 4
[2025-05-16 15:10:05.935] 28007800
[2025-05-16 15:10:05.936] data: type 0x05 value_len 1
[2025-05-16 15:10:05.938] 01
[2025-05-16 15:10:05.939] meta: type 0x01 value_len 2
[2025-05-16 15:10:05.941] 0600
[2025-05-16 15:10:07.614] dir 1 loc 4
[2025-05-16 15:10:07.615] snk ctx 31 src ctx 15
[2025-05-16 15:10:08.874] Sink #0: ep 0x2000473c
[2025-05-16 15:10:08.876] Sink #1: ep 0x20004824
[2025-05-16 15:10:10.115] Discover sinks complete: err 0
[2025-05-16 15:10:10.117] Sinks discovered
[2025-05-16 15:10:10.119] Discovering sources
[2025-05-16 15:10:10.120] codec_cap 0x200091e0 dir 0x02
[2025-05-16 15:10:10.123] codec id 0x06 cid 0x0000 vid 0x0000 count 19
[2025-05-16 15:10:10.127] data: type 0x01 value_len 2
[2025-05-16 15:10:10.130] ff1f
[2025-05-16 15:10:10.130] data: type 0x02 value_len 1
[2025-05-16 15:10:10.133] 02
[2025-05-16 15:10:10.133] data: type 0x03 value_len 1
[2025-05-16 15:10:10.136] 01
[2025-05-16 15:10:10.136] data: type 0x04 value_len 4
[2025-05-16 15:10:10.138] 28007800
[2025-05-16 15:10:10.139] data: type 0x05 value_len 1
[2025-05-16 15:10:10.142] 01
[2025-05-16 15:10:10.142] meta: type 0x01 value_len 2
[2025-05-16 15:10:10.144] 0600
[2025-05-16 15:10:12.024] dir 2 loc 3
[2025-05-16 15:10:12.024] snk ctx 31 src ctx 15
[2025-05-16 15:10:12.027] Source #0: ep 0x2000490c
[2025-05-16 15:10:12.985] Discover sources complete: err 0
[2025-05-16 15:10:12.988] Sources discovered
[2025-05-16 15:10:12.990] Configuring streams
[2025-05-16 15:10:12.991] Audio Stream 0x20005108 configured
[2025-05-16 15:10:12.994] Configured sink stream[0]
[2025-05-16 15:10:12.997] Audio Stream 0x20005130 configured
[2025-05-16 15:10:13.000] Configured sink stream[1]
[2025-05-16 15:10:13.002] Audio Stream 0x20005158 configured
[2025-05-16 15:10:13.005] Configured source stream[0]
[2025-05-16 15:10:13.008] Creating unicast group
[2025-05-16 15:10:13.010] [00:00:09.048,828] <dbg> bt_iso: bt_iso_chan_add: iso 0x20004320 chan 0x2000558c
[2025-05-16 15:10:13.017] [00:00:09.048,889] <dbg> bt_iso: bt_iso_chan_add: iso 0x20004418 chan 0x200055ec
[2025-05-16 15:10:13.025] [00:00:09.048,919] <dbg> bt_iso: hci_le_set_cig_params: id 0, latency C to P 10, latency P to C 10, interval C to P 10000, interval P to C 10000, sca 0, packing 0, framing 0, num_cis 2
[2025-05-16 15:10:13.042] [00:00:09.048,919] <dbg> bt_iso: hci_le_set_cig_params: [0]: id 0, c_phy 2, c_sdu 40, c_rtn 2, p_phy 2, p_sdu 40, p_rtn 2
[2025-05-16 15:10:13.053] [00:00:09.048,950] <dbg> bt_iso: hci_le_set_cig_params: [1]: id 1, c_phy 2, c_sdu 40, c_rtn 2, p_phy 2, p_sdu 0, p_rtn 0
[2025-05-16 15:10:13.065] Unicast group created
[2025-05-16 15:10:13.067] Setting stream QoS
[2025-05-16 15:10:13.068] QoS: waiting for 3 streams
[2025-05-16 15:10:13.614] Audio Stream 0x20005158 QoS set
[2025-05-16 15:10:13.617] QoS: waiting for 3 streams
[2025-05-16 15:10:13.619] Audio Stream 0x20005108 QoS set
[2025-05-16 15:10:13.622] QoS: waiting for 3 streams
[2025-05-16 15:10:13.625] Audio Stream 0x20005130 QoS set
[2025-05-16 15:10:13.627] Stream QoS Set
[2025-05-16 15:10:13.629] Enabling streams
[2025-05-16 15:10:13.631] Audio Stream 0x20005108 enabled
[2025-05-16 15:10:13.634] Audio Stream 0x20005130 enabled
[2025-05-16 15:10:13.636] Audio Stream 0x20005158 enabled
[2025-05-16 15:10:13.639] Streams enabled
[2025-05-16 15:10:13.640] Connecting streams
[2025-05-16 15:10:13.642] [00:00:09.678,985] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x2000558c iso 0x20004320 disconnected -> connecting
[2025-05-16 15:10:14.035] [00:00:10.029,632] <dbg> bt_iso: hci_le_cis_established: status 0x00  handle 7
[2025-05-16 15:10:14.079] [00:00:10.029,663] <dbg> bt_iso: store_cis_info: iso_chan 0x2000558c tx 0x200055d0 rx 0x200055b0
[2025-05-16 15:10:14.091] [00:00:10.029,693] <dbg> bt_iso: bt_iso_connected: 0x20004320
[2025-05-16 15:10:14.100] [00:00:10.029,724] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x2000558c iso 0x20004320 connecting -> connected
[2025-05-16 15:10:14.117] Audio Stream 0x20005158 connected
[2025-05-16 15:10:14.120] Audio Stream 0x20005108 connected
[2025-05-16 15:10:14.126] [00:00:10.030,303] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x200055ec iso 0x20004418 disconnected -> connecting
[2025-05-16 15:10:14.140] Audio Stream 0x20005108 started
[2025-05-16 15:10:14.146] [00:00:10.098,358] <inf> lc3: Extracting LC3 configuration values
[2025-05-16 15:10:14.156] [00:00:10.098,388] <inf> lc3: Initializing sine wave data
[2025-05-16 15:10:14.161] [00:00:10.098,846] <inf> lc3: Setting up LC3 encoder
[2025-05-16 15:10:14.170] [00:00:10.099,121] <inf> stream_tx: Registered 0x20005108 for TX
[2025-05-16 15:10:15.369] [00:00:10.433,013] <dbg> bt_iso: hci_le_cis_established: status 0x3e  handle 8
[2025-05-16 15:10:15.379] [00:00:10.433,044] <dbg> bt_iso: bt_iso_disconnected: 0x20004418
[2025-05-16 15:10:15.389] [00:00:10.433,074] <dbg> bt_iso: bt_iso_chan_disconnected: 0x200055ec, reason 0x3e
[2025-05-16 15:10:15.399] [00:00:10.433,105] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x200055ec iso 0x20004418 connecting -> disconnected
[2025-05-16 15:10:15.416] [00:00:10.433,105] <wrn> bt_conn: conn 0x20004418 failed to establish. RF noise?
[2025-05-16 15:10:15.427] [00:00:10.433,135] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20004418
[2025-05-16 15:10:24.945] [00:00:20.010,040] <inf> stream_tx: Stream 0x20005108: Sent 1000 total SDUs of size 40
[2025-05-16 15:10:34.945] [00:00:30.010,040] <inf> stream_tx: Stream 0x20005108: Sent 2000 total SDUs of size 40
[2025-05-16 15:10:44.944] [00:00:40.010,040] <inf> stream_tx: Stream 0x20005108: Sent 3000 total SDUs of size 40
[2025-05-16 15:10:54.944] [00:00:50.010,040] <inf> stream_tx: Stream 0x20005108: Sent 4000 total SDUs of size 40
[2025-05-16 15:11:04.945] [00:01:00.010,772] <inf> stream_tx: Stream 0x20005108: Sent 5000 total SDUs of size 40

Server log:

[2025-05-16 15:02:33.162] *** Booting Zephyr OS build v4.1.0-4122-ge96c1dd97ce6 ***
[2025-05-16 15:02:33.190] [00:00:00.274,902] <wrn> bt_hci_core: Num of Controller's ACL packets != ACL bt_conn_tx contexts (7 != 3)
[2025-05-16 15:02:33.574] [00:00:00.274,902] <wrn> bt_hci_core: Num of Controller's ISO packets != ISO bt_conn_tx contexts(8 != 2)
[2025-05-16 15:02:33.584] [00:00:00.277,313] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[2025-05-16 15:02:33.592] [00:00:00.277,313] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[2025-05-16 15:02:33.599] [00:00:00.277,343] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 4.1 Build 99
[2025-05-16 15:02:33.609] [00:00:00.278,961] <inf> bt_hci_core: HCI transport: IPC
[2025-05-16 15:02:33.614] [00:00:00.279,052] <inf> bt_hci_core: Identity: F2:76:57:3D:89:BD (random)
[2025-05-16 15:02:33.622] [00:00:00.279,083] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x0000, manufacturer 0x05f1
[2025-05-16 15:02:33.631] [00:00:00.279,113] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0xffff
[2025-05-16 15:02:33.638] Bluetooth initialized
[2025-05-16 15:02:33.640] [00:00:00.279,235] <dbg> bt_iso: bt_iso_server_register: 0x200002fc
[2025-05-16 15:02:33.647] Location successfully set
[2025-05-16 15:02:33.649] Supported contexts successfully set
[2025-05-16 15:02:33.652] Available contexts successfully set
[2025-05-16 15:02:33.656] Advertising successfully started
[2025-05-16 15:09:37.464] Connected: FF:91:CC:FE:7B:2E (random)
[2025-05-16 15:09:37.468] [00:07:04.051,971] <inf> bt_smp: Remote is using Debug Public key
[2025-05-16 15:09:44.657] ASE Codec Config: conn 0x20001918 ep 0x20002034 dir 1
[2025-05-16 15:09:44.662] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:09:44.666] data: type 0x01 value_len 1
[2025-05-16 15:09:44.668] 03
[2025-05-16 15:09:44.668] data: type 0x02 value_len 1
[2025-05-16 15:09:44.671] 01
[2025-05-16 15:09:44.672] data: type 0x03 value_len 4
[2025-05-16 15:09:44.673] 01000000
[2025-05-16 15:09:44.674] data: type 0x04 value_len 2
[2025-05-16 15:09:44.676] 2800
[2025-05-16 15:09:44.678]   Frequency: 16000 Hz
[2025-05-16 15:09:44.679]   Frame Duration: 10000 us
[2025-05-16 15:09:44.681]   Channel allocation: 0x1
[2025-05-16 15:09:44.684]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:09:44.689]   Frames per SDU: 1
[2025-05-16 15:09:44.691] ASE Codec Config stream 0x20004af0
[2025-05-16 15:09:44.796] ASE Codec Config: conn 0x20001918 ep 0x2000211c dir 1
[2025-05-16 15:09:44.802] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:09:44.806] data: type 0x01 value_len 1
[2025-05-16 15:09:44.808] 03
[2025-05-16 15:09:44.808] data: type 0x02 value_len 1
[2025-05-16 15:09:44.811] 01
[2025-05-16 15:09:44.811] data: type 0x03 value_len 4
[2025-05-16 15:09:44.813] 01000000
[2025-05-16 15:09:44.814] data: type 0x04 value_len 2
[2025-05-16 15:09:44.816] 2800
[2025-05-16 15:09:44.818]   Frequency: 16000 Hz
[2025-05-16 15:09:44.819]   Frame Duration: 10000 us
[2025-05-16 15:09:44.822]   Channel allocation: 0x1
[2025-05-16 15:09:44.824]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:09:44.829]   Frames per SDU: 1
[2025-05-16 15:09:44.831] ASE Codec Config stream 0x20004b18
[2025-05-16 15:09:44.936] ASE Codec Config: conn 0x20001918 ep 0x20002204 dir 2
[2025-05-16 15:09:44.941] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:09:44.946] data: type 0x01 value_len 1
[2025-05-16 15:09:44.947] 03
[2025-05-16 15:09:44.949] data: type 0x02 value_len 1
[2025-05-16 15:09:44.951] 01
[2025-05-16 15:09:44.951] data: type 0x03 value_len 4
[2025-05-16 15:09:44.954] 01000000
[2025-05-16 15:09:44.954] data: type 0x04 value_len 2
[2025-05-16 15:09:44.956] 2800
[2025-05-16 15:09:44.957]   Frequency: 16000 Hz
[2025-05-16 15:09:44.960]   Frame Duration: 10000 us
[2025-05-16 15:09:44.962]   Channel allocation: 0x1
[2025-05-16 15:09:44.965]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:09:44.969]   Frames per SDU: 1
[2025-05-16 15:09:44.971] ASE Codec Config stream 0x20004ac4
[2025-05-16 15:09:45.147] QoS: stream 0x20004ac4 qos 0x200079b0
[2025-05-16 15:09:45.149] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:09:45.157] QoS: stream 0x20004af0 qos 0x200079b0
[2025-05-16 15:09:45.160] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:09:45.166] QoS: stream 0x20004b18 qos 0x200079b0
[2025-05-16 15:09:45.170] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:09:45.177] [00:07:12.241,760] <wrn> bt_conn: Unable to allocate buffer within timeout
[2025-05-16 15:09:45.184] [00:07:12.241,790] <err> bt_att: Unable to allocate buffer for op 0x1b
[2025-05-16 15:09:45.191] [00:07:12.241,790] <wrn> bt_gatt: No buffer available to send notification
[2025-05-16 15:09:45.198] [00:07:12.241,821] <wrn> bt_ascs: Out of buffers for ase state notification. Will retry in 70ms
[2025-05-16 15:09:46.058] Enable: stream 0x20004af0 meta_len 4
[2025-05-16 15:09:46.060] Enable: stream 0x20004b18 meta_len 4
[2025-05-16 15:09:46.064] Enable: stream 0x20004ac4 meta_len 4
[2025-05-16 15:09:46.067] [00:07:12.940,856] <dbg> bt_iso: hci_le_cis_req: acl_handle 0 cis_handle 7 cig_id 0 cis 0
[2025-05-16 15:09:46.075] [00:07:12.940,917] <dbg> bt_iso: iso_accept: 0x20001c48
[2025-05-16 15:09:46.082] [00:07:12.940,917] <dbg> bt_iso: bt_iso_chan_add: iso 0x20001c48 chan 0x20004eb0
[2025-05-16 15:09:46.089] [00:07:12.940,979] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004eb0 iso 0x20001c48 disconnected -> connecting
[2025-05-16 15:09:46.101] [00:07:13.152,435] <dbg> bt_iso: hci_le_cis_established: status 0x00  handle 7
[2025-05-16 15:09:46.108] [00:07:13.152,465] <dbg> bt_iso: store_cis_info: iso_chan 0x20004eb0 tx 0x20004ef4 rx 0x20004ed4
[2025-05-16 15:09:46.117] [00:07:13.152,465] <dbg> bt_iso: bt_iso_connected: 0x20001c48
[2025-05-16 15:09:46.124] [00:07:13.152,526] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004eb0 iso 0x20001c48 connecting -> connected
[2025-05-16 15:09:46.134] Audio Stream 0x20004af0 started
[2025-05-16 15:09:46.545] [00:07:13.291,046] <dbg> bt_iso: hci_le_cis_req: acl_handle 0 cis_handle 8 cig_id 0 cis 1
[2025-05-16 15:09:46.558] [00:07:13.291,107] <dbg> bt_iso: iso_accept: 0x20001d40
[2025-05-16 15:09:46.566] [00:07:13.291,137] <dbg> bt_iso: bt_iso_chan_add: iso 0x20001d40 chan 0x20004f10
[2025-05-16 15:09:46.575] [00:07:13.291,168] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004f10 iso 0x20001d40 disconnected -> connecting
[2025-05-16 15:09:46.591] [00:07:13.504,638] <dbg> bt_iso: hci_le_cis_established: status 0x00  handle 8
[2025-05-16 15:09:46.602] [00:07:13.504,669] <dbg> bt_iso: store_cis_info: iso_chan 0x20004f10 tx 0x20004f54 rx 0x20004f34
[2025-05-16 15:09:46.614] [00:07:13.504,699] <dbg> bt_iso: bt_iso_connected: 0x20001d40
[2025-05-16 15:09:46.623] [00:07:13.504,730] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004f10 iso 0x20001d40 connecting -> connected
[2025-05-16 15:09:46.637] Audio Stream 0x20004b18 started
[2025-05-16 15:09:46.642] Start: stream 0x20004ac4
[2025-05-16 15:09:46.643] Failed to send audio data on streams[0] (0x20004ac4): (-77)
[2025-05-16 15:09:46.652] Audio Stream 0x20004ac4 started
[2025-05-16 15:09:54.237] [00:07:21.331,634] <dbg> bt_iso: bt_iso_disconnected: 0x20001c48
[2025-05-16 15:09:54.243] [00:07:21.331,634] <dbg> bt_iso: bt_iso_chan_disconnected: 0x20004eb0, reason 0x08
[2025-05-16 15:09:54.251] [00:07:21.331,695] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004eb0 iso 0x20001c48 connected -> disconnected
[2025-05-16 15:09:54.263] [00:07:21.331,726] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20001c48
[2025-05-16 15:09:54.270] [00:07:21.331,817] <wrn> bt_ascs: No callback for disabled set
[2025-05-16 15:09:54.275] Audio Stream 0x20004af0 stopped with reason 0x08
[2025-05-16 15:09:54.280] [00:07:21.331,970] <wrn> bt_ascs: No callback for disabled set
[2025-05-16 15:09:54.287] Audio Stream 0x20004ac4 stopped with reason 0x08
[2025-05-16 15:09:54.291] [00:07:21.332,366] <dbg> bt_iso: bt_iso_disconnected: 0x20001d40
[2025-05-16 15:09:54.298] [00:07:21.332,366] <dbg> bt_iso: bt_iso_chan_disconnected: 0x20004f10, reason 0x08
[2025-05-16 15:09:54.306] [00:07:21.332,427] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004f10 iso 0x20001d40 connected -> disconnected
[2025-05-16 15:09:54.317] [00:07:21.332,458] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20001d40
[2025-05-16 15:09:54.323] [00:07:21.332,580] <wrn> bt_ascs: No callback for disabled set
[2025-05-16 15:09:54.329] Audio Stream 0x20004b18 stopped with reason 0x08
[2025-05-16 15:09:54.333] Disconnected: FF:91:CC:FE:7B:2E (random), reason 0x08 
[2025-05-16 15:09:54.339] Advertising successfully started
[2025-05-16 15:10:05.512] Connected: FF:91:CC:FE:7B:2E (random)
[2025-05-16 15:10:05.515] [00:07:32.100,799] <inf> bt_smp: Remote is using Debug Public key
[2025-05-16 15:10:12.635] ASE Codec Config: conn 0x20001918 ep 0x20002034 dir 1
[2025-05-16 15:10:12.639] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:10:12.644] data: type 0x01 value_len 1
[2025-05-16 15:10:12.647] 03
[2025-05-16 15:10:12.647] data: type 0x02 value_len 1
[2025-05-16 15:10:12.649] 01
[2025-05-16 15:10:12.650] data: type 0x03 value_len 4
[2025-05-16 15:10:12.652] 01000000
[2025-05-16 15:10:12.652] data: type 0x04 value_len 2
[2025-05-16 15:10:12.656] 2800
[2025-05-16 15:10:12.656]   Frequency: 16000 Hz
[2025-05-16 15:10:12.658]   Frame Duration: 10000 us
[2025-05-16 15:10:12.661]   Channel allocation: 0x1
[2025-05-16 15:10:12.663]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:10:12.668]   Frames per SDU: 1
[2025-05-16 15:10:12.670] ASE Codec Config stream 0x20004af0
[2025-05-16 15:10:12.774] ASE Codec Config: conn 0x20001918 ep 0x2000211c dir 1
[2025-05-16 15:10:12.780] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:10:12.784] data: type 0x01 value_len 1
[2025-05-16 15:10:12.787] 03
[2025-05-16 15:10:12.787] data: type 0x02 value_len 1
[2025-05-16 15:10:12.789] 01
[2025-05-16 15:10:12.789] data: type 0x03 value_len 4
[2025-05-16 15:10:12.791] 01000000
[2025-05-16 15:10:12.792] data: type 0x04 value_len 2
[2025-05-16 15:10:12.796] 2800
[2025-05-16 15:10:12.796]   Frequency: 16000 Hz
[2025-05-16 15:10:12.798]   Frame Duration: 10000 us
[2025-05-16 15:10:12.801]   Channel allocation: 0x1
[2025-05-16 15:10:12.803]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:10:12.808]   Frames per SDU: 1
[2025-05-16 15:10:12.810] ASE Codec Config stream 0x20004b18
[2025-05-16 15:10:12.914] ASE Codec Config: conn 0x20001918 ep 0x20002204 dir 2
[2025-05-16 15:10:12.920] codec_cfg 0x06 cid 0x0000 vid 0x0000 count 16
[2025-05-16 15:10:12.924] data: type 0x01 value_len 1
[2025-05-16 15:10:12.926] 03
[2025-05-16 15:10:12.926] data: type 0x02 value_len 1
[2025-05-16 15:10:12.929] 01
[2025-05-16 15:10:12.930] data: type 0x03 value_len 4
[2025-05-16 15:10:12.931] 01000000
[2025-05-16 15:10:12.933] data: type 0x04 value_len 2
[2025-05-16 15:10:12.936] 2800
[2025-05-16 15:10:12.936]   Frequency: 16000 Hz
[2025-05-16 15:10:12.938]   Frame Duration: 10000 us
[2025-05-16 15:10:12.941]   Channel allocation: 0x1
[2025-05-16 15:10:12.943]   Octets per frame: 40 (negative means value not pressent)
[2025-05-16 15:10:12.948]   Frames per SDU: 1
[2025-05-16 15:10:12.949] ASE Codec Config stream 0x20004ac4
[2025-05-16 15:10:13.055] QoS: stream 0x20004ac4 qos 0x200079b0
[2025-05-16 15:10:13.058] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:10:13.064] QoS: stream 0x20004af0 qos 0x200079b0
[2025-05-16 15:10:13.068] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:10:13.074] QoS: stream 0x20004b18 qos 0x200079b0
[2025-05-16 15:10:13.079] QoS: interval 10000 framing 0x00 phy 0x02 sdu 40 rtn 2 latency 10 pd 40000
[2025-05-16 15:10:13.084] [00:07:40.150,634] <wrn> bt_conn: Unable to allocate buffer within timeout
[2025-05-16 15:10:13.093] [00:07:40.150,634] <err> bt_att: Unable to allocate buffer for op 0x1b
[2025-05-16 15:10:13.100] [00:07:40.150,665] <wrn> bt_gatt: No buffer available to send notification
[2025-05-16 15:10:13.107] [00:07:40.150,695] <wrn> bt_ascs: Out of buffers for ase state notification. Will retry in 70ms
[2025-05-16 15:10:13.965] Enable: stream 0x20004af0 meta_len 4
[2025-05-16 15:10:13.970] Enable: stream 0x20004b18 meta_len 4
[2025-05-16 15:10:13.973] Enable: stream 0x20004ac4 meta_len 4
[2025-05-16 15:10:13.976] [00:07:40.849,731] <dbg> bt_iso: hci_le_cis_req: acl_handle 0 cis_handle 8 cig_id 0 cis 0
[2025-05-16 15:10:13.984] [00:07:40.849,792] <dbg> bt_iso: iso_accept: 0x20001c48
[2025-05-16 15:10:13.989] [00:07:40.849,792] <dbg> bt_iso: bt_iso_chan_add: iso 0x20001c48 chan 0x20004eb0
[2025-05-16 15:10:13.998] [00:07:40.849,853] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004eb0 iso 0x20001c48 disconnected -> connecting
[2025-05-16 15:10:14.009] [00:07:41.061,309] <dbg> bt_iso: hci_le_cis_established: status 0x00  handle 8
[2025-05-16 15:10:14.016] [00:07:41.061,340] <dbg> bt_iso: store_cis_info: iso_chan 0x20004eb0 tx 0x20004ef4 rx 0x20004ed4
[2025-05-16 15:10:14.026] [00:07:41.061,340] <dbg> bt_iso: bt_iso_connected: 0x20001c48
[2025-05-16 15:10:14.031] [00:07:41.061,401] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004eb0 iso 0x20001c48 connecting -> connected
[2025-05-16 15:10:14.043] Audio Stream 0x20004af0 started
[2025-05-16 15:10:14.369] [00:07:41.269,958] <dbg> bt_iso: hci_le_cis_req: acl_handle 0 cis_handle 7 cig_id 0 cis 1
[2025-05-16 15:10:14.379] [00:07:41.270,019] <dbg> bt_iso: iso_accept: 0x20001d40
[2025-05-16 15:10:14.385] [00:07:41.270,050] <dbg> bt_iso: bt_iso_chan_add: iso 0x20001d40 chan 0x20004f10
[2025-05-16 15:10:14.393] [00:07:41.270,080] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004f10 iso 0x20001d40 disconnected -> connecting
[2025-05-16 15:10:14.407] [00:07:41.464,721] <dbg> bt_iso: hci_le_cis_established: status 0x3e  handle 7
[2025-05-16 15:10:14.415] [00:07:41.464,752] <dbg> bt_iso: bt_iso_disconnected: 0x20001d40
[2025-05-16 15:10:14.422] [00:07:41.464,752] <dbg> bt_iso: bt_iso_chan_disconnected: 0x20004f10, reason 0x3e
[2025-05-16 15:10:14.431] [00:07:41.464,782] <dbg> bt_iso: bt_iso_chan_set_state_debug: chan 0x20004f10 iso 0x20001d40 connecting -> disconnected
[2025-05-16 15:10:14.444] [00:07:41.464,813] <wrn> bt_conn: conn 0x20001d40 failed to establish. RF noise?
[2025-05-16 15:10:14.453] [00:07:41.464,813] <dbg> bt_iso: bt_iso_cleanup_acl: 0x20001d40
[2025-05-16 15:10:25.047] Incoming audio on stream 0x20004af0 len 40 (1000)
[2025-05-16 15:10:35.056] Incoming audio on stream 0x20004af0 len 40 (2000)
[2025-05-16 15:10:45.056] Incoming audio on stream 0x20004af0 len 40 (3000)
[2025-05-16 15:10:55.055] Incoming audio on stream 0x20004af0 len 40 (4000)
[2025-05-16 15:11:05.055] Incoming audio on stream 0x20004af0 len 40 (5000)
[2025-05-16 15:11:15.055] Incoming audio on stream 0x20004af0 len 40 (6000)
[2025-05-16 15:11:25.054] Incoming audio on stream 0x20004af0 len 40 (7000)
[2025-05-16 15:11:35.054] Incoming audio on stream 0x20004af0 len 40 (8000)
[2025-05-16 15:11:45.053] Incoming audio on stream 0x20004af0 len 40 (9000)
[2025-05-16 15:11:55.053] Incoming audio on stream 0x20004af0 len 40 (10000)
[2025-05-16 15:12:05.072] Incoming audio on stream 0x20004af0 len 40 (11000)
[2025-05-16 15:12:15.072] Incoming audio on stream 0x20004af0 len 40 (12000)
[2025-05-16 15:12:25.071] Incoming audio on stream 0x20004af0 len 40 (13000)
[2025-05-16 15:12:35.081] Incoming audio on stream 0x20004af0 len 40 (14000)
[2025-05-16 15:12:45.081] Incoming audio on stream 0x20004af0 len 40 (15000)
[2025-05-16 15:12:55.080] Incoming audio on stream 0x20004af0 len 40 (16000)
[2025-05-16 15:13:05.080] Incoming audio on stream 0x20004af0 len 40 (17000)
[2025-05-16 15:13:15.079] Incoming audio on stream 0x20004af0 len 40 (18000)
[2025-05-16 15:13:25.089] Incoming audio on stream 0x20004af0 len 40 (19000)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: Done
Development

Successfully merging this pull request may close these issues.

3 participants