LE Audio timeout behaviour (0x08) interfacing with third party devices.

[kieran.cheung]

Hi, I'm currently developing a device that acts as an LE Audio client. Everything works as expected when interfacing with an LE Audio server counterpart on a 5340 Audio DK, also using the Zephyr BLE Audio API.

However I recently attempted to interface my client with a third party pair of LE Audio headphones, specifically the Earfun Air Pro 3s, and upon enabling the streams (bt_audio_stream_enable) the device receives no response callback and supposedly hits the supervisory timeout (disconnect reason 0x08.) At first I suspected this may be an issue with the headphones, and I haven't ruled out this possibility.

But then I decided to test the nrF5340 audio application (unmodified) with the Android LE Audio framework in the developer settings, which seems to work decently well with the Earfun Air Pro 3s. I found that the 5340 headset application was successfully receiving and playing back the stream for 4s, but then receives a timeout event and immediately stops playing. 

There's a chance these are unrelated issues but seeing as they both involve supervision timeouts, there's the possibility something is not being handled correctly on the 5340? Can something about the LE Audio framework cause it to stop sending packets to the peer device? Has the audio application been tested with any third party devices?

I have tried changing the clock source with:

CONFIG_CLOCK_CONTROL_NRF_K32SRC_SYNTH=y

As I heard this has been related to other timeout issues, but that doesn't seem to be the cause here as it has no effect.

Log from headset:

HL [00:01:04.268,341] <inf> cis_headset: Connected: 0C:C4:13:2F:AD:44 (public)
HL [00:01:09.610,137] <inf> ble_audio_services: Volume = 10, mute state = 0
HL [00:08:10.497,955] <dbg> bt_audio_stream: bt_audio_stream_attach: conn 0x20002db8 stream 0x2000a728 ep 0x2000ba34 codec 0x2000ba44
HL [00:08:10.587,951] <dbg> bt_audio_stream: bt_audio_stream_iso_listen: stream 0x2000a728 conn 0x20002db8
HL [00:08:10.683,288] <wrn> audio_datapath: I2S RX continuing stream
HL [00:08:10.691,284] <wrn> audio_datapath: I2S RX overrun. Single msg
HL [00:08:10.704,315] <inf> audio_datapath: Drft comp state: INIT
HL [00:08:11.243,072] <dbg> bt_audio_stream: bt_audio_stream_iso_accept: acl 0x20002db8
HL [00:08:11.243,072] <dbg> bt_audio_stream: bt_audio_stream_iso_accept: iso_chan 0x2000bb20
HL [00:08:11.440,124] <inf> audio_datapath: Drft comp state: CALIB
HL [00:08:11.441,101] <wrn> audio_datapath: Data received, total underruns: 755
HL [00:08:11.492,218] <wrn> audio_datapath: Data received, total underruns: 756
HL [00:08:11.540,344] <inf> audio_datapath: Drft comp state: OFFSET
HL [00:08:12.021,820] <inf> audio_datapath: Drft comp state: LOCKED
HL [00:08:12.029,510] <inf> audio_datapath: Pres comp state: MEAS
HL [00:08:12.139,495] <inf> audio_datapath: Pres comp state: WAIT
HL [00:08:12.239,501] <inf> audio_datapath: Pres comp state: INIT
HL [00:08:12.249,511] <inf> audio_datapath: Pres comp state: MEAS
HL [00:08:12.359,497] <inf> audio_datapath: Pres comp state: LOCKED
HL [00:08:16.800,872] <inf> cis_headset: Stream stopped
HL [00:08:16.800,903] <dbg> bt_audio_stream: bt_audio_stream_iso_listen: stream 0x2000a728 conn 0x20002db8
HL [00:08:16.801,727] <inf> cis_headset: Disconnected: 0C:C4:13:2F:AD:44 (public) (reason 0x08)
HL [00:08:16.802,673] <inf> cis_headset: Direct advertising to 0C:C4:13:2F:AD:44 (public) started

[Kenneth]

We are looking into this, can you add the following config in the gateway for getting more information?

CONFIG_BT_AUDIO_DEBUG_UNICAST_CLIENT=y
CONFIG_BT_AUDIO_STREAM_LOG_LEVEL_DBG=y
CONFIG_LOG_BUFFER_SIZE=8192

Kenneth

[kieran.cheung]

Hi Kenneth,

Here is the log I get when trying to connect using a build of the 5340 application from version 2.2.99-dev3 with only the following changes in addition to the log flags you mentioned.

• CONFIG_BT_AUDIO_PRESENTATION_DELAY_US=25000
• CONFIG_BT_AUDIO_MAX_TRANSPORT_LATENCY_MS=30
• Connecting to headphones based on their name.

Fullscreen Connection Attempt Log.txt Download

*** Booting Zephyr OS build v3.2.99-ncs1-1547-ge2bec540218d ***
GW [00:00:00.258,728] <inf> fw_info:
         nRF5340 Audio nRF5340 Audio DK cpuapp
         NCS base version: 2.2.99-dev3
         Cmake run : Wed Feb 15 13:52:27 2023
GW [00:00:00.258,728] <inf> fw_info: ------- DEBUG BUILD -------
GW [00:00:00.258,728] <inf> fw_info: Compiled for GATEWAY device
GW [00:00:00.269,348] <inf> board_version: Compatible board/HW version found: 1.0.0
GW [00:00:02.304,779] <wrn> bt_hci_core: Controller to host flow control not supported
GW [00:00:02.307,922] <inf> bt_hci_core: No ID address. App must call settings_load()
GW [00:00:02.307,983] <inf> ble: MAC: 00:00:00:00:00:00 (public)
GW [00:00:02.308,532] <inf> ble: Controller version: 3310
GW [00:00:02.399,932] <dbg> bt_audio_stream: unicast_group_add_stream: group 0x2000ec94 stream 0x2000d1ac dir 1
GW [00:00:02.399,932] <dbg> bt_audio_stream: get_new_iso: Returning new audio_iso for group 0x2000ec94
GW [00:00:02.399,963] <dbg> bt_unicast_client: bt_unicast_client_new_audio_iso: New audio_iso 0x2000e96c
GW [00:00:02.399,963] <dbg> bt_audio_stream: unicast_group_add_stream: Added stream 0x2000d1ac to group 0x2000ec94
GW [00:00:02.399,963] <dbg> bt_audio_stream: unicast_group_add_stream: group 0x2000ec94 stream 0x2000d1d4 dir 1
GW [00:00:02.399,993] <dbg> bt_audio_stream: get_new_iso: Returning new audio_iso for group 0x2000ec94
GW [00:00:02.399,993] <dbg> bt_unicast_client: bt_unicast_client_new_audio_iso: New audio_iso 0x2000e9fc
GW [00:00:02.400,024] <dbg> bt_audio_stream: unicast_group_add_stream: Added stream 0x2000d1d4 to group 0x2000ec94
GW [00:00:02.400,024] <dbg> bt_audio_stream: bt_audio_cig_create: group 0x2000ec94 qos 0x20000420
GW [00:00:02.400,878] <dbg> cis_gateway: le_audio_play_pause_cb: Play/pause cb, state: 1
GW [00:00:02.400,939] <dbg> cis_gateway: bond_check: Stored bonding found: 70:5A:6F:60:62:71 (public)
GW [00:00:02.403,137] <inf> cis_gateway: Scanning successfully started
GW [00:00:08.131,042] <inf> cis_gateway: Found Whitelisted Advertiser
GW [00:00:08.229,888] <inf> cis_gateway: Connected: 70:5A:6F:60:62:71 (public)
GW [00:00:08.730,285] <dbg> cis_gateway: security_changed_cb: Security changed: level 2
GW [00:00:09.031,494] <dbg> bt_unicast_client: unicast_client_read_func: conn 0x20005470 err 0x00 len 61
GW [00:00:09.031,494] <dbg> bt_unicast_client: unicast_client_read_func: handle 0x004b
GW [00:00:09.031,494] <dbg> bt_unicast_client: unicast_client_read_func: pac #0
GW [00:00:09.031,524] <dbg> bt_unicast_client: unicast_client_ep_set_codec: ep (nil) codec id 0x06 cid 0x0000 vid 0x0000 len 19
GW [00:00:09.031,524] <dbg> bt_unicast_client: unicast_client_codec_config_store: #0 type 0x01 len 2
GW [00:00:09.031,555] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               80 00                                            |..
GW [00:00:09.031,555] <dbg> bt_unicast_client: unicast_client_codec_config_store: #1 type 0x02 len 1
GW [00:00:09.031,555] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               13                                               |.
GW [00:00:09.031,585] <dbg> bt_unicast_client: unicast_client_codec_config_store: #2 type 0x03 len 1
GW [00:00:09.031,585] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               01                                               |.
GW [00:00:09.031,616] <dbg> bt_unicast_client: unicast_client_codec_config_store: #3 type 0x04 len 4
GW [00:00:09.031,616] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               4b 00 64 00                                      |K.d.
GW [00:00:09.031,616] <dbg> bt_unicast_client: unicast_client_codec_config_store: #4 type 0x05 len 1
GW [00:00:09.031,646] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               02                                               |.
GW [00:00:09.031,646] <dbg> bt_unicast_client: unicast_client_ep_set_metadata: ep (nil) len 4 codec 0x2000f218
GW [00:00:09.031,677] <dbg> bt_unicast_client: unicast_client_codec_metadata_store: #0 type 0x01 len 2
GW [00:00:09.031,677] <dbg> bt_unicast_client: unicast_client_codec_metadata_store: data
                                               08 00                                            |..
GW [00:00:09.031,677] <dbg> bt_unicast_client: unicast_client_read_func: pac 0x2000f214 codec 0x06 config count 5 meta count 1
GW [00:00:09.031,707] <dbg> bt_unicast_client: unicast_client_read_func: pac #1
GW [00:00:09.031,707] <dbg> bt_unicast_client: unicast_client_ep_set_codec: ep (nil) codec id 0x06 cid 0x0000 vid 0x0000 len 19
GW [00:00:09.031,707] <dbg> bt_unicast_client: unicast_client_codec_config_store: #0 type 0x01 len 2
GW [00:00:09.031,738] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               34 00                                            |4.
GW [00:00:09.031,738] <dbg> bt_unicast_client: unicast_client_codec_config_store: #1 type 0x02 len 1
GW [00:00:09.031,768] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               23                                               |#
GW [00:00:09.031,768] <dbg> bt_unicast_client: unicast_client_codec_config_store: #2 type 0x03 len 1
GW [00:00:09.031,768] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               01                                               |.
GW [00:00:09.031,799] <dbg> bt_unicast_client: unicast_client_codec_config_store: #3 type 0x04 len 4
GW [00:00:09.031,799] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               28 00 50 00                                      |(.P.
GW [00:00:09.031,799] <dbg> bt_unicast_client: unicast_client_codec_config_store: #4 type 0x05 len 1
GW [00:00:09.031,829] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               02                                               |.
GW [00:00:09.031,829] <dbg> bt_unicast_client: unicast_client_ep_set_metadata: ep (nil) len 4 codec 0x2000f280
GW [00:00:09.031,829] <dbg> bt_unicast_client: unicast_client_codec_metadata_store: #0 type 0x01 len 2
GW [00:00:09.031,860] <dbg> bt_unicast_client: unicast_client_codec_metadata_store: data
                                               42 00                                            |B.
GW [00:00:09.031,860] <dbg> bt_unicast_client: unicast_client_read_func: pac 0x2000f27c codec 0x06 config count 5 meta count 1
GW [00:00:09.031,890] <dbg> bt_unicast_client: unicast_client_pacs_context_discover: conn 0x20005470 params 0x2000d130
GW [00:00:09.230,285] <dbg> bt_unicast_client: unicast_client_pacs_context_read_func: conn 0x20005470 err 0x00 len 4
GW [00:00:09.230,285] <dbg> bt_unicast_client: unicast_client_pacs_context_read_func: pac 0x2000f214 context 0x0fff
GW [00:00:09.230,316] <dbg> bt_unicast_client: unicast_client_pacs_context_read_func: pac 0x2000f27c context 0x0fff
GW [00:00:09.230,316] <dbg> bt_unicast_client: unicast_client_pacs_location_discover: conn 0x20005470 params 0x2000d130
GW [00:00:09.970,977] <dbg> bt_unicast_client: unicast_client_pacs_location_discover_cb: conn 0x20005470 attr 0x20015a54 handle 0x0057
GW [00:00:09.971,038] <dbg> bt_unicast_client: unicast_client_pacs_location_read: conn 0x20005470 params 0x2000d130
GW [00:00:10.090,576] <dbg> bt_unicast_client: unicast_client_pacs_location_read_func: conn 0x20005470 err 0x00 len 4
GW [00:00:10.090,606] <dbg> bt_unicast_client: unicast_client_pacs_location_read_func: dir 1 loc 3
GW [00:00:10.090,667] <dbg> cis_gateway: bond_check: Stored bonding found: 70:5A:6F:60:62:71 (public)
GW [00:00:10.091,400] <inf> cis_gateway: Scanning successfully started
GW [00:00:10.091,400] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_discover: conn 0x20005470 params 0x2000d130
GW [00:00:10.661,041] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_discover_cb: conn 0x20005470 attr 0x20015a54 handle 0x0069
GW [00:00:10.661,041] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_discover_cb: Subscribing to handle 105
GW [00:00:10.661,102] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_read: conn 0x20005470 params 0x2000d130
GW [00:00:10.780,364] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_read_func: conn 0x20005470 err 0x00 len 4
GW [00:00:10.780,395] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_read_func: sink context 15, source context 75
GW [00:00:10.780,487] <dbg> cis_gateway: available_contexts_cb: conn: 70:5A:6F:60:62:71 (public), snk ctx 15 src ctx 75

GW [00:00:10.780,487] <dbg> bt_unicast_client: unicast_client_ase_discover: conn 0x20005470 params 0x2000d130
GW [00:00:10.900,482] <dbg> bt_unicast_client: unicast_client_ase_read_func: conn 0x20005470 err 0x00 len 2
GW [00:00:10.900,482] <dbg> bt_unicast_client: unicast_client_ase_read_func: handle 0x0086
GW [00:00:10.900,482] <dbg> bt_unicast_client: unicast_client_ep_init: ep 0x2000eea4 dir 0x01 handle 0x0086
GW [00:00:10.900,543] <dbg> bt_unicast_client: unicast_client_ep_set_status: ep 0x2000eea4 handle 0x0086 id 0x01 dir 1 state idle -> idle
GW [00:00:10.900,543] <dbg> bt_unicast_client: unicast_client_ep_subscribe: ep 0x2000eea4 handle 0x86
GW [00:00:10.900,573] <dbg> bt_unicast_client: unicast_client_ase_read_func: conn 0x20005470 err 0x00 len 2
GW [00:00:10.900,604] <dbg> bt_unicast_client: unicast_client_ase_read_func: handle 0x0089
GW [00:00:10.900,604] <dbg> bt_unicast_client: unicast_client_ep_init: ep 0x2000ef90 dir 0x01 handle 0x0089
GW [00:00:10.900,634] <dbg> bt_unicast_client: unicast_client_ep_set_status: ep 0x2000ef90 handle 0x0089 id 0x02 dir 1 state idle -> idle
GW [00:00:10.900,665] <dbg> bt_unicast_client: unicast_client_ep_subscribe: ep 0x2000ef90 handle 0x89
GW [00:00:10.900,695] <dbg> bt_unicast_client: unicast_client_ase_read_func: conn 0x20005470 err 0x00 len 2
GW [00:00:10.900,695] <dbg> bt_unicast_client: unicast_client_ase_read_func: handle 0x008c
GW [00:00:10.900,695] <wrn> bt_unicast_client: No space left to parse ASE
GW [00:00:10.900,726] <dbg> bt_unicast_client: unicast_client_ase_cp_discover: conn 0x20005470 params 0x2000d130
GW [00:00:11.770,996] <dbg> bt_unicast_client: unicast_client_cp_discover_func: conn 0x20005470 attr 0x20015a54 handle 0x0098
GW [00:00:11.770,996] <dbg> bt_unicast_client: unicast_client_ep_set_cp: conn 0x20005470 0x0098
GW [00:00:11.771,057] <dbg> cis_gateway: discover_sink_cb: Sink discover complete: err 0
GW [00:00:11.771,087] <dbg> bt_audio_stream: bt_audio_stream_config: conn 0x20005470 stream 0x2000d1ac, ep 0x2000ef90 codec 0x200003bc codec id 0x06 codec cid 0x0000 codec vid 0x0000
GW [00:00:11.771,087] <dbg> bt_audio_stream: bt_audio_stream_attach: conn 0x20005470 stream 0x2000d1ac ep 0x2000ef90 codec 0x200003bc
GW [00:00:11.771,087] <dbg> bt_unicast_client: unicast_client_ep_config: ep 0x2000ef90 buf 0x20001314 codec 0x200003bc
GW [00:00:11.771,087] <dbg> bt_unicast_client: unicast_client_ep_config: id 0x02 dir 0x01 codec 0x06
GW [00:00:11.771,118] <dbg> bt_unicast_client: unicast_client_codec_data_add: #0: data type 0x01 len 1
GW [00:00:11.771,118] <dbg> bt_unicast_client: unicast_client_codec_data_add: data
                                               08                                               |.
GW [00:00:11.771,179] <dbg> bt_unicast_client: unicast_client_codec_data_add: #1: data type 0x02 len 1
GW [00:00:11.771,179] <dbg> bt_unicast_client: unicast_client_codec_data_add: data
                                               01                                               |.
GW [00:00:11.771,209] <dbg> bt_unicast_client: unicast_client_codec_data_add: #2: data type 0x03 len 4
GW [00:00:11.771,209] <dbg> bt_unicast_client: unicast_client_codec_data_add: data
                                               01 00 00 00                                      |....
GW [00:00:11.771,240] <dbg> bt_unicast_client: unicast_client_codec_data_add: #3: data type 0x04 len 2
GW [00:00:11.771,240] <dbg> bt_unicast_client: unicast_client_codec_data_add: data
                                               78 00                                            |x.
GW [00:00:11.771,270] <dbg> bt_unicast_client: bt_unicast_client_ep_send: conn 0x20005470 ep 0x2000ef90 buf 0x20001314 len 27
GW [00:00:11.890,960] <dbg> bt_unicast_client: unicast_client_ep_notify: conn 0x20005470 ep 0x2000ef90 len 41
GW [00:00:11.890,991] <dbg> bt_unicast_client: unicast_client_ep_set_status: ep 0x2000ef90 handle 0x0089 id 0x02 dir 1 state idle -> codec-configured
GW [00:00:11.890,991] <dbg> bt_unicast_client: unicast_client_ep_config_state: dir 0x01 unframed_supported 0x01 phy 0x02 rtn 15 latency 4000 pd_min 25000 pd_max 40000 codec 0x06
GW [00:00:11.890,991] <dbg> bt_unicast_client: unicast_client_ep_set_codec: ep 0x2000ef90 codec id 0x06 cid 0x0000 vid 0x0000 len 16
GW [00:00:11.891,021] <dbg> bt_unicast_client: unicast_client_codec_config_store: #0 type 0x01 len 1
GW [00:00:11.891,021] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               08                                               |.
GW [00:00:11.891,052] <dbg> bt_unicast_client: unicast_client_codec_config_store: #1 type 0x02 len 1
GW [00:00:11.891,052] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               01                                               |.
GW [00:00:11.891,052] <dbg> bt_unicast_client: unicast_client_codec_config_store: #2 type 0x03 len 4
GW [00:00:11.891,082] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               01 00 00 00                                      |....
GW [00:00:11.891,082] <dbg> bt_unicast_client: unicast_client_codec_config_store: #3 type 0x04 len 2
GW [00:00:11.891,113] <dbg> bt_unicast_client: unicast_client_codec_config_store: data
                                               78 00                                            |x.
GW [00:00:11.891,113] <inf> cis_gateway: LEFT sink stream connected
GW [00:00:11.891,113] <dbg> bt_audio_stream: bt_audio_stream_qos: conn 0x20005470 group 0x2000ec94
GW [00:00:11.891,143] <dbg> bt_unicast_client: bt_unicast_client_ep_qos: ep 0x2000ef90 buf 0x20001314 qos 0x20000420
GW [00:00:11.891,174] <dbg> bt_unicast_client: bt_unicast_client_ep_qos: id 0x02 cig 0x00 cis 0x00 interval 10000 framing 0x00 phy 0x02 sdu 120 rtn 2 latency 30 pd 25000
GW [00:00:11.891,174] <dbg> bt_unicast_client: bt_unicast_client_ep_send: conn 0x20005470 ep 0x2000ef90 buf 0x20001314 len 18
GW [00:00:11.950,744] <dbg> bt_unicast_client: unicast_client_ep_notify: conn 0x20005470 ep 0x2000ef90 len 17
GW [00:00:11.950,775] <dbg> bt_unicast_client: unicast_client_ep_set_status: ep 0x2000ef90 handle 0x0089 id 0x02 dir 1 state codec-configured -> qos-configured
GW [00:00:11.950,775] <dbg> bt_unicast_client: unicast_client_ep_qos_update: ep 0x2000ef90 dir 1 audio_iso 0x2000e96c
GW [00:00:11.950,775] <dbg> bt_unicast_client: unicast_client_ep_qos_state: dir 0x01 cig 0x00 cis 0x00 codec 0x06 interval 10000 framing 0x00 phy 0x02 rtn 2 latency 30 pd 25000
GW [00:00:11.950,805] <dbg> bt_audio_stream: bt_audio_stream_enable: stream 0x2000d1ac
GW [00:00:11.950,805] <dbg> bt_unicast_client: bt_unicast_client_enable: stream 0x2000d1ac
GW [00:00:11.950,805] <dbg> bt_unicast_client: unicast_client_ep_enable: ep 0x2000ef90 buf 0x20001314 metadata count 1
GW [00:00:11.950,836] <dbg> bt_unicast_client: unicast_client_ep_enable: id 0x02
GW [00:00:11.950,836] <dbg> bt_unicast_client: unicast_client_codec_data_add: #0: meta type 0x02 len 2
GW [00:00:11.950,866] <dbg> bt_unicast_client: unicast_client_codec_data_add: meta
                                               04 00                                            |..
GW [00:00:11.950,866] <dbg> bt_unicast_client: bt_unicast_client_ep_send: conn 0x20005470 ep 0x2000ef90 buf 0x20001314 len 8
GW [00:00:15.981,170] <dbg> bt_unicast_client: unicast_client_cp_notify: conn 0x20005470 len 0
GW [00:00:15.981,170] <dbg> bt_unicast_client: unicast_client_cp_notify: Unsubscribed
GW [00:00:15.981,170] <dbg> bt_unicast_client: unicast_client_ep_notify: conn 0x20005470 ep 0x2000ef90 len 0
GW [00:00:15.981,201] <dbg> bt_unicast_client: unicast_client_ep_notify: Unsubscribed
GW [00:00:15.981,201] <dbg> bt_unicast_client: unicast_client_ep_notify: conn 0x20005470 ep 0x2000eea4 len 0
GW [00:00:15.981,201] <dbg> bt_unicast_client: unicast_client_ep_notify: Unsubscribed
GW [00:00:15.981,231] <dbg> bt_unicast_client: unicast_client_disconnected: conn 0x20005470 reason 0x08
GW [00:00:15.981,231] <dbg> bt_unicast_client: unicast_client_ep_reset: conn 0x20005470
GW [00:00:15.981,231] <dbg> bt_unicast_client: unicast_client_reset: ep 0x2000eea4
GW [00:00:15.981,262] <dbg> bt_audio_stream: bt_audio_stream_reset: stream (nil)
GW [00:00:15.981,262] <dbg> bt_unicast_client: unicast_client_reset: ep 0x2000ef90
GW [00:00:15.981,292] <dbg> bt_audio_stream: bt_audio_stream_reset: stream 0x2000d1ac
GW [00:00:15.981,292] <dbg> bt_audio_stream: bt_audio_stream_detach: stream 0x2000d1ac
GW [00:00:15.981,292] <dbg> bt_audio_stream: bt_audio_stream_disconnect: stream 0x2000d1ac iso (nil)
GW [00:00:15.981,414] <inf> cis_gateway: Disconnected: 70:5A:6F:60:62:71 (public) (reason 0x08)
GW [00:00:15.981,506] <dbg> cis_gateway: bond_check: Stored bonding found: 70:5A:6F:60:62:71 (public)
GW [00:00:15.981,506] <inf> cis_gateway: Scanning successfully started
GW [00:00:17.684,173] <inf> cis_gateway: Found Whitelisted Advertiser
GW [00:00:17.714,141] <inf> cis_gateway: Connected: 70:5A:6F:60:62:71 (public)
GW [00:00:17.914,428] <err> cis_gateway: Security failed: level 1 err 2
GW [00:00:18.015,075] <wrn> bt_att: Not connected
GW [00:00:18.015,106] <err> bt_conn: not connected!
GW [00:00:18.016,296] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_notify_cb: conn 0x20005470 len 0
GW [00:00:18.016,296] <dbg> bt_unicast_client: unicast_client_pacs_avail_ctx_notify_cb: Unsubscribed
GW [00:00:18.016,326] <wrn> bt_gatt: conn 0x20005470 err 0x0e
GW [00:00:18.016,845] <dbg> bt_unicast_client: unicast_client_disconnected: conn 0x20005470 reason 0x16
GW [00:00:18.016,876] <dbg> bt_unicast_client: unicast_client_ep_reset: conn 0x20005470
GW [00:00:18.016,876] <dbg> bt_unicast_client: unicast_client_reset: ep 0x2000eea4
GW [00:00:18.016,906] <dbg> bt_audio_stream: bt_audio_stream_reset: stream (nil)
GW [00:00:18.016,906] <dbg> bt_unicast_client: unicast_client_reset: ep 0x2000ef90
GW [00:00:18.016,906] <dbg> bt_audio_stream: bt_audio_stream_reset: stream (nil)
GW [00:00:18.016,998] <inf> cis_gateway: Disconnected: 70:5A:6F:60:62:71 (public) (reason 0x16)
GW [00:00:18.016,998] <wrn> cis_gateway: Connection not found
GW [00:00:18.017,028] <wrn> cis_gateway: Unknown connection
GW [00:00:18.017,089] <dbg> cis_gateway: bond_check: Stored bonding found: 70:5A:6F:60:62:71 (public)
GW [00:00:18.017,639] <inf> cis_gateway: Scanning successfully started
GW [00:00:19.174,102] <inf> cis_gateway: Found Whitelisted Advertiser
GW [00:00:19.311,676] <inf> cis_gateway: Connected: 70:5A:6F:60:62:71 (public)
GW [00:00:19.511,932] <err> cis_gateway: Security failed: level 1 err 2
GW [00:00:19.612,640] <wrn> bt_att: Not connected
GW [00:00:19.612,670] <err> bt_conn: not connected!

After the timeout, at ~15.9s the device then continuously finds and fails to pair to the headphones until I cycle both. I believe this is because the initial headphone that the gateway tries to enable the stream to asserts (it visibly seems to blink red and turn off while the other continues blinking for advertising) and the other one keeps advertising, but security fails because of (I'm guessing) some spec behaviour around pairing to the same address.

I have also reported this to the headphone manufacturer, but as I noted they work with Android which makes it harder to dismiss the problem as only relevant to the headphone and not the 5340.

Thanks

[Kenneth]

They are discussing this internally, but from the log it seems the headset is OK with the QoS setting, but suddenly headset disconnected. The reason is 0x08, which means headset stop sending any packets. Probably the issue is from headset side. Will let you know if I receive more feedback internally.

Kenneth

[kieran.cheung]

Hi Kenneth,

I've just been informed by the headphone manufacturer that their technical team has also encountered this problem when interfacing with certain devices and will be submitting a case with Qualcomm who must be supplying the LE Audio firmware component for the headphones.

Once I receive an update on this issue I will try again, but for now I'm assuming this bug is completely due to the headphone side.

Thanks for your help!