Supervision timeout does not expire during 120hz data streaming

[chris.c]

Hi,

I am using an two nrf5340 with hci_ipc enabled one acting as central and one as peripheral built on v2.9.0

The issue I am having is that the supervision timeout doesn't expire when I hard reset the peripheral whilst sending data (len 91) via notifications at 120hz .

My current fix is to set CONFIG_BT_ATT_LOG_LEVEL_DBG=y which then doesn't miss a supervision timeout event. This doesn't feel like a good long term solution to fixing whatever timing issue this is. Please could you help me.  

Problem Flow from Central perspective:

1. Scan and connect
2. Characteristic and CCC descriptor discovery
3. Enable Notifications
4. Central MTU Updated TX: 247 RX: 247 bytes
5. PHY updated: TX PHY 2M, RX PHY 2M
6. Connection Params:interval 7.50 ms, latency 1, timeout 100 ms
7. start stream data over notifications at 120hz
8. wait 3 seconds
9. Hit reset on peripheral 
10. Central Hangs indefinitely with no supervision timeout 

[chris.c]

If I use CONFIG_LOG_MODE_MINIMAL it all works fine however if I use CONFIG_LOG_MODE_DEFERRED I can see that messages are being dropped:

[00:00:43.546,661] <dbg> bt_att: bt_att_recv: Received ATT chan 0x2000f1d8 code 0x1b len 91
--- 2 messages dropped ---
[00:00:43.554,168] <dbg> bt_att: bt_att_recv: Received ATT chan 0x2000f1d8 code 0x1b len 91
--- 3 messages dropped ---
[00:00:43.569,213] <dbg> bt_att: att_notify: chan 0x2000f1d8 handle 0x0012
--- 2 messages dropped ---
[00:00:43.586,059] <dbg> bt_att: att_notify: chan 0x2000f1d8 handle 0x0012
--- 3 messages dropped ---
[00:00:43.599,151] <dbg> bt_att: att_notify: chan 0x2000f1d8 handle 0x0012
--- 3 messages dropped ---
[00:00:43.666,656] <dbg> bt_att: bt_att_recv: Received ATT chan 0x2000f1d8 code 0x1b len 91
--- 1 messages dropped ---
[00:00:43.689,178] <dbg> bt_att: bt_att_recv: Received ATT chan 0x2000f1d8 code 0x1b len 91
--- 5 messages dropped ---

Why exactly does using the minimal log stop messages from being dropped? 

[Einar Thorsrud]

Hi,

The issue I am having is that the supervision timeout doesn't expire when I hard reset the peripheral whilst sending data (len 91) via notifications at 120hz .

If the peripheral disconnects after a reset, you should always get a supervision timeout. If yo don't see it, perhaps it is related to the logging issue you asked about? Or that your code does not handle it or something else happens that masks it? Have you done any debugging to learn the state of your application after the supervision timeout shoudl have occured?

chris.c said:

Why exactly does using the minimal log stop messages from being dropped? 

With deferred logging, logging is not procesed in place, but deferred to a low priority thread. If you log a lot (as with BT debug loggign enabled), you will quickly fill the buffer before the logs are processed when using deferred logging. Does it help to set CONFIG_LOG_BUFFER_SIZE=8192 (or another high value) in your prj.conf?

[chris.c]

Would this explain why I’m not seeing supervision timeout though? 
Or why slowing down the process down by enabling log minimal + att debug would enable it to work correctly? 

I’m also still confused why I don’t see supervision timeout but you do! 

[Einar Thorsrud]

Yese, it is odd that I never reproduce the same behaviour on my end. But if there are memory corruption issues (which is just a hunch for now, but I have no better suggestion at the moment), it can manifest itself in many different ways. And even if buildign teh same project but with different toolchain or platform, you will typically see different behaviours (if for instance there is an array or buffer being written out of bonds, and whatever is next to it in RAM chagne, the behaviour will change).

[chris.c]

I’m not really sure where to go from here with it. Is this something you are still going to look at?

I know you don’t see the same issue as me but what part of streaming the notifications at a high data rate would break the disconnect callback ? 

[Einar Thorsrud]

Hi,

Yes, I can continue to look into this, but I suggest that you first go over the code to make sure you have controll over array boundaries etc, and other potential sources for memory corruption issues. This is time consuming but requiered in this case.

[chris.c]

Hi,

I’m currently going through the code and nothing has helped so far but will continue looking. 

sorry for maybe a stupid question but is the network core not entirely separate and it handles the disconnect callbacks? How could I corrupt the memory on the network core when all my arrays are on the application core?