BT_HCI_ERR_INSUFFICIENT_SECURITY during re-discovery

[muli]

Note. This issue only occurs if using the Nordic Soft Device controller or the Packetcraft controller. 

I am working with the nRF5340 audio development boards. 

I have a project with a central device (used as a Broadcast Assistant) and a peripheral device (used as an audio broadcast receiver). They both form an ACL connection and exchange data. 

Whenever the receiver is syncing to a broadcast source and it gets disconnected from the central for whatever reason, the central manages to re-connect to the peripheral, however the BASS discovery fails with BT_HCI_ERR_INSUFFICIENT_SECURITY. The following error is displayed : 

<wrn> bt_gatt: gatt_exchange_mtu_func: conn 0x200018c8 err 0x0e

 . 

The only way to solve this is by rebooting the receiver / peripheral. 

For both the central and receiver applications, bonding is disabled in the proj.conf as follows : 

CONFIG_BT_BONDABLE=n

In that case, I can't understand why the BASS re-discovery would fail due to a security error error.

As mentioned above. This only happens when using the Nordic Soft Device controller or the Packetcraft controller. Using the Zephyr controller, the re-discovery works fine without this security problem. 

How can there be this security issue only when using those two controllers, and by using the Zephyr controller with the exact same configuration (bonding disabled etc.) it is fine?

Below are the logs from my central application when it re-connects. Thanks in advance for any help or suggestions. 

Disconnected from device EE:0B:7C:30:59:12 (random) (reason 0x3e)
About to connect to EE:0B:7C:30:59:12
Connection pending..
Successfully connected to device EE:0B:7C:30:59:12 (random)
Now discovering..
[00:01:04.517,425] <wrn> bt_gatt: gatt_exchange_mtu_func: conn 0x200018c8 err 0x0e
[00:01:04.517,456] <dbg> bt_bap_broadcast_assistant: service_discover_func: Could not discover BASS
Error! BASS discover failed (-6)

    

[Hung Bui]

Hi Paul, 
It's quite strange the MTU exchange would have something to do with security level. 
Could you try to capture a sniffer trace so that it's more clear on why we have that error ? 
Just for clarification, could you point me to where you find that the error was BT_ATT_ERR_AUTHORIZATION?  as far as I know error 0x0e means BT_HCI_ERR_INSUFFICIENT_SECURITY

[muli]

 Hung Bui Here is a sniffer trace from the peripheral / receiver device. This sniffer didn't seem to capture packets when the connection dropped this time . I noticed an LL_TERMINTE_IND during one capture though. 

However, what is the most interesting here I believe are the packets captured during the initial connection from number 4583. There is an Insufficient Authentication error at 4606. It's looking like this is the source of the issue.

What I don't understand though is why the connection still succeeds that first time, and the BASS gets discovered by the central device. Only if the peripheral drops the connection later when it is syncing to an audio broadcast, and the central connects again, BASS discovery fails because of the insufficient security. 

Again this only happens when using either the Packetcraft or Nordic Soft device controller on the central side and not the Zephyr controller (with the exact same application)

How to possibly solve this? Thanks 

capture-peripheral-authentication-issue.pcapng

[muli]

 Hi Hung Bui 

For both the central / master and peripheral / receiver I am using the nRF5340 Audio development kits.

On the receiver there is an application running based on the applications\nrf5340_audio project part of NRF. It is modified to have the Scan Delegator functionality integrated. 

The central device has a customized application that uses the Zephyr Broadcast Assistant functionality. 

Both devices are using the Packetcraft controller v 3393. 

This disconnecting also happens when using the nRF Connect phone app for example when connected to the receiver. 

This only happens when the receiver is syncing between different broadcasts sources. i.e when the central commands it to switch broadcasts. The disconnect may happen straight away, or after it switches 10 or more times. It's always hard to predict when

It's kind of hard to test a normal BLE application on both devices as to replicate this, the receiver needs to be getting commands and to switch broadcast sources.  

[Hung Bui]

Hi Paul, 

I will need to check with the BLE Audio team to see if they have any idea. 
But could you confirm what you captured with the trace is the same problem that you described in the original question of BT_HCI_ERR_INSUFFICIENT_SECURITY issue ? 

From what I can see in the trace, it doesn't seem it hay anything to do with insufficient security and reconnection. 

[muli]

Hi Hung Bui ,

Yes, these traces were captured during those tests. 4 nRF5340 Audio development kits were used. One for the receiver, one for the central, and two Auracast broadcasters. 

I can't understand either how we don't see the packets when the central re-connects to the receiver and tries to re-discover with that error. This is what is going on from the central when it happens :  

Disconnected from device EE:0B:7C:30:59:12 (random) (reason 0x3e)
About to connect to EE:0B:7C:30:59:12
Connection pending..
Successfully connected to device EE:0B:7C:30:59:12 (random)
Now discovering..
[00:01:04.517,425] <wrn> bt_gatt: gatt_exchange_mtu_func: conn 0x200018c8 err 0x0e
[00:01:04.517,456] <dbg> bt_bap_broadcast_assistant: service_discover_func: Could not discover BASS
Error! BASS discover failed (-6)

[Hung Bui]

Hi Paul, 

I got some tips from our Audio R&D team: 

- The application is not official support integrating scan delegator and broadcast assistant

- We are suspecting that the ACL connection is affected by the Broadcast ISO. 

- Could you capture the trace with Zephyr controller  ? 

- It's suggested to capture the trace using professional sniffer (for example Ellisys) so that we can see if ACL connection is overlapped by the broadcast ISO. 

[muli]

Hi Hung Bui ,

Do you mean to capture traces from the receiver device again, but using the Zephyr controller instead of the Packetcraft one?

The disconnect still happens when using that controller , but oddly the re-connect and re-discovery works fine with that one.

Or did you mean to capture traces from the commander / Broadcast Assistant device? 

On another note, before I integrated the Scan Delegator into that audio application, I had a Nordic Uart Service (NUS) implemented there so that a commander could connect and send messages to the receiver over the NUS. It used to disconnect randomly in the exact same way if it was syncing to broadcast streams during the connection.  

Just on observation today (for what it's worth), I flashed the receiver device with the Zephyr sample ncs\v2.5.0\zephyr\samples\bluetooth\broadcast_audio_sink .It contains a Scan Delegator.  I flashed this together with the Packetcraft controller. The disconnect never happens when using this together with my Broadcast Assistant application.  

[Hung Bui]

Hi Paul, 

muli said:

Do you mean to capture traces from the receiver device again, but using the Zephyr controller instead of the Packetcraft one?

Yes correct. 

muli said:

The disconnect still happens when using that controller , but oddly the re-connect and re-discovery works fine with that one.

Does this mean in the traces provided previously, they don't have the part when the re-connection and re-discovery failed ? 

muli said:

On another note, before I integrated the Scan Delegator into that audio application, I had a Nordic Uart Service (NUS) implemented there so that a commander could connect and send messages to the receiver over the NUS. It used to disconnect randomly in the exact same way if it was syncing to broadcast streams during the connection.  

I think this matched with the theory from our R&D team that the ACL connection is effected by broadcast ISO regardless which service was used in the GATT server.

muli said:

Just on observation today (for what it's worth), I flashed the receiver device with the Zephyr sample ncs\v2.5.0\zephyr\samples\bluetooth\broadcast_audio_sink .It contains a Scan Delegator.  I flashed this together with the Packetcraft controller. The disconnect never happens when using this together with my Broadcast Assistant application.  

Sorry for maybe trivial question, did you mean you the disconnect never happens when combine the firmware with Broadcast Assistant code or when you use it to connect to your Broadcast Assistant board ? 

[muli]

Does this mean in the traces provided previously, they don't have the part when the re-connection and re-discovery failed ? 

The traces were captured during the part when the re-connection and re-discovery failed yes. I just don't understand why we don't see packets showing it.  

I think this matched with the theory from our R&D team that the ACL connection is effected by broadcast ISO regardless which service was used in the GATT server.

Yes, I agree

Sorry for maybe trivial question, did you mean you the disconnect never happens when combine the firmware with Broadcast Assistant code or when you use it to connect to your Broadcast Assistant board ? 

No, not a trivial question at all. I think there are so many parts and combinations here so it gets confusing:)

The disconnect never happens when I instead flash this sample to my receiver board instead of the updated Nordic audio application : ncs\v2.5.0\zephyr\samples\bluetooth\broadcast_audio_sink , and with the same Packetcraft controller

Of course this sample / application is not as complex as the Nordic audio application, but this does connect to my Broadcast Assistant application and receives the same commands from it for the Scan Delegator, and then receives broadcast data from the broadcast devices. The connection never drops between the two boards in that case. 

The Broadcast Assistant application remains the same for every test. 

[ovrebekk]

Hi Paul

I will take over this case from Hung since I have a bit more experience with LE Audio. 

It is interesting that it all works fine when switching to the broadcast_audio_sink application. Have you tried to capture a sniffer trace when everything works, to see if there is some critical difference that can be spotted in the trace? 

I think we should try to reproduce the issue internally so that we can do some tests on our own, speeding up the investigation into the issue. 

Would you be able to share your code so that I can try to reproduce the issue here? 

If you don't want to share your code in a public ticket just let me know, and I will make the ticket private. 

Best regards
Torbjørn

[muli]

Hi ovrebekk . Thanks for looking into this. I haven't actually collected sniffer traces when connected to the broadcast_audio_sink application. I wasn't sure if there is much point. 

What's a real headache is that when I am capturing traces when the problem occurs with the other receiver application, there are no packets indicating what is wrong. We can't see why it disconnected and the re-connection with failed GATT discovery. 

What could be worth trying, to replicate this, is take the existing Nordic audio application as it is, add just add the ability to have an ACL connection from a central device. Connect the central device, keep switching audio broadcasts on the receiver and see that the connection to the central drops at some point.

I can try and share my code next week also. 

Regards,

Paul 

[muli]

Hi ovrebekk 

I've taken the latest Nordic audio application from nrf\applications\nrf5340_audio

I've made some modifications to start advertising if it's a receiver device as follows : 

bt_le_adv_start(BT_LE_ADV_CONN, ad, ARRAY_SIZE(ad), NULL,0);

and allows a connection from a central device. 

When a central is connected and the receiver is streaming broadcast audio, occasionally the connection drops and I get this error and crash :  

HL [00:01:13.699,676] <inf> bt_mgmt: Disconnected: C2:DA:2D:C3:36:C7 (random) (reason 0x08)
HL [00:01:13.699,707] <wrn> streamctrl_broadcast_sink: Unexpected/unhandled bt_mgmt event: 6
HL [00:01:13.699,707] <err> bt_mgmt_adv: No valid advertising data stored
HL [00:01:13.699,737] <err> bt_mgmt: ERR_CHK Err_code: [-2] @ line: 177
HL [00:01:13.699,737] <err> os: r0/a1:  0x00000003  r1/a2:  0x00000004  r2/a3:  0x00000003
HL [00:01:13.699,737] <err> os: r3/a4:  0x00060591 r12/ip:  0x0000000c r14/lr:  0x0006061b
HL [00:01:13.699,768] <err> os:  xpsr:  0x41100000
HL [00:01:13.699,768] <err> os: s[ 0]:  0x00000000  s[ 1]:  0x00000010  s[ 2]:  0x20017a70  s[ 3]:  0x0006fdd4
HL [00:01:13.699,768] <err> os: s[ 4]:  0x20017a78  s[ 5]:  0x00000000  s[ 6]:  0x00000000  s[ 7]:  0x00000000
HL [00:01:13.699,768] <err> os: s[ 8]:  0x00000000  s[ 9]:  0x00009903  s[10]:  0x00006d6f  s[11]:  0x200033d0
HL [00:01:13.699,798] <err> os: s[12]:  0x00000002  s[13]:  0x200033d0  s[14]:  0x00000002  s[15]:  0x20017a70
HL [00:01:13.699,798] <err> os: fpscr:  0x00000004
HL [00:01:13.699,829] <err> os: Faulting instruction address (r15/pc): 0x00009910
HL [00:01:13.699,829] <err> os: >>> ZEPHYR FATAL ERROR 3: Kernel oops on CPU 0
HL [00:01:13.699,859] <err> os: Current thread: 0x20004208 (sysworkq)
HL [00:01:13.699,859] <err> error_handler: Caught system error -- reason 3. Entering infinite loop