Connection hangs/drops randomly without triggering callback

[i_4556]

Hello and thanks for reading.

I have a critical problem with my device, and seeing as the problem is BLE related I figured I would ask your help as well. We are using the NRF5340 as a peripheral. There are two operating modes; in one, the peripheral acts as an HID mouse; a computer connects, we perform pairing (security level 2), and then the device sends movements and clicks based on on-board sensors. In the other, we use a custom service to send back live data from those same sensors (basically NUS).

We have tested both modes, using an Amazon tablet running Android, an IOS phone, and windows 10, and in all modes and operating systems, we have the same critical failure. After a random amount of time, typically around 4-5 minutes, the connection seems to mysteriously hang.

On the Central side, it shows as disconnected. So for example when the device is acting as a mouse, windows will move the device from connected to paired, and the cursor stops moving. When we try our custom service, we stop getting data and on windows the program we use enters it's disconnect routine.

On the peripheral side, its like the connection slipped out in the night without leaving a note. The disconnect is never called, and even with BT_DEBUG enabled I never get the message telling me the connection has disconnected with the reason. I know the NRF hasnt reset or something because I continue to get log messages in the console, shortly followed by warnings about overflowing buffers (because without the connection active theres nowhere for the data to go).

Thinking that maybe the gathering data thread was just monopolizing the processor or something, I tried connecting with our application, but never sending the command to start gathering data. The windows application just sits there and receives the heartbeat message every 5 seconds. The problem persists.

At this point I need to reach out for help, as we need to get this fixed quickly so we can start final testing and shipping. Essentially our bug has the connection being abandoned after a random amount of time, central disconnects, and then the disconnect callback is never called. The desired behavior is that we dont disconnect unexpectedly.

We are using Visual studio code and SDK 2.5.0 with zephyr if that helps.

Looking around on the forums, one thought is that maybe we dont have our clock tree set up perfectly or something? We are using an external oscillator for the HF clock but with the internal capacitors, and for the LF clock we need the internal resonator and capacitors. How _should_ our project config look for that configuration? Right now I have the following, which at least seems to be at the correct tick rate; a 1ms delay takes one ms:

In the network core:

#clock config

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC_CALIBRATION=y

CONFIG_CLOCK_CONTROL_NRF_K32SRC_500PPM=y

And in the main core:

#SYSTEM & CLOCK

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y

Here is my full config file:

#GPIO
CONFIG_GPIO=y
CONFIG_PINCTRL=y
# CONFIG_DK_LIBRARY=y

#UART & SERIAL
CONFIG_SERIAL=y
CONFIG_NEWLIB_LIBC=y
CONFIG_NEWLIB_LIBC_FLOAT_PRINTF=y

#SYSTEM & CLOCK
CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y
CONFIG_MAIN_STACK_SIZE=16384
CONFIG_LOG=y
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=8192

#CPP
CONFIG_CPP=y
CONFIG_REQUIRES_FULL_LIBCPP=y
CONFIG_STD_CPP20=y

#i2C
CONFIG_I2C=y

#spi
CONFIG_SPI=y

#flash
CONFIG_SETTINGS=y
CONFIG_FLASH=y
CONFIG_FLASH_PAGE_LAYOUT=y
CONFIG_NVS=y
CONFIG_FLASH_MAP=y
CONFIG_MPU_ALLOW_FLASH_WRITE=y
CONFIG_FILE_SYSTEM=y
CONFIG_SOC_FLASH_NRF=y

#math
CONFIG_CMSIS_DSP=y
CONFIG_NEWLIB_LIBC=y
# CONFIG_FPU=y
# CONFIG_CMSIS_DSP_TRANSFORM=y
# CONFIG_TFM_ENABLE_CP10CP11=y
CONFIG_CMSIS_DSP_FILTERING=y

#BLE
CONFIG_BT=y
CONFIG_BT_SETTINGS=y
CONFIG_BT_GATT_CLIENT=y
CONFIG_BT_PERIPHERAL=y
# CONFIG_BT_DEVICE_NAME="AAVAANRF" #Set dynamically in BLE_COMMANDS.h
CONFIG_BT_DEBUG_LOG=y
CONFIG_BT_CENTRAL=y
CONFIG_BT_BROADCASTER=y
CONFIG_BT_OBSERVER=y

CONFIG_BT_DEVICE_NAME_DYNAMIC=y
CONFIG_BT_DEVICE_NAME_MAX=30

#NUS
CONFIG_BT_NUS=y
CONFIG_BT_NUS_AUTHEN=n

#DFU
CONFIG_BOOTLOADER_MCUBOOT=y
CONFIG_NCS_SAMPLE_MCUMGR_BT_OTA_DFU=y




#BT BATTERY SERVICE (BAS)
CONFIG_BT_BAS=y

#DIS
CONFIG_BT_DIS=y
CONFIG_BT_DIS_PNP=y
CONFIG_BT_DIS_MANUF="AAVAA"
CONFIG_BT_DIS_PNP_VID_SRC=2
CONFIG_BT_DIS_PNP_VID=0x1915
CONFIG_BT_DIS_PNP_PID=0xEEEE
CONFIG_BT_DIS_PNP_VER=0x0100

#BT HID
CONFIG_NCS_SAMPLES_DEFAULTS=y

CONFIG_BT_MAX_CONN=6
CONFIG_BT_MAX_PAIRED=20
CONFIG_BT_SMP=y
CONFIG_BT_L2CAP_TX_BUF_COUNT=5
CONFIG_BT_DEVICE_APPEARANCE=962

CONFIG_BT_HIDS=y
CONFIG_BT_HIDS_MAX_CLIENT_COUNT=2
CONFIG_BT_HIDS_DEFAULT_PERM_RW_ENCRYPT=y
CONFIG_BT_GATT_UUID16_POOL_SIZE=40
CONFIG_BT_GATT_CHRC_POOL_SIZE=20

CONFIG_BT_CONN_CTX=y

#2MEG PHY & MTU
# CONFIG_BT_CTLR_PHY_2M=y
# CONFIG_BT_AUTO_PHY_UPDATE=y
# CONFIG_BT_USER_PHY_UPDATE=y

CONFIG_BT_BUF_ACL_RX_SIZE=256
CONFIG_BT_L2CAP_TX_MTU=252

CONFIG_BT_PERIPHERAL_PREF_MIN_INT=6
CONFIG_BT_PERIPHERAL_PREF_MAX_INT=24
CONFIG_BT_PERIPHERAL_PREF_LATENCY=0
CONFIG_BT_PERIPHERAL_PREF_TIMEOUT=400

#ADC
CONFIG_ADC=y
CONFIG_ADC_ASYNC=y

#timer
CONFIG_COUNTER=y

I can post any other information as needed.

Thanks for your time!

[Simonr]

Hi

This issue seems very strange to be honest, and I don't really have some working theories of what this could be caused by based on this description. Are you also able to reproduce this with an nRF5340 DK running this application? It would also be helpful to see a sniffer trace so we can get some info of what's happening over-the-air. The clock configuration looks okay to me, but it does seem like the radio on the nRF5340 side stops transmitting all of a sudden. Does a disconnect occur eventually, when the connection times out with the central device?

Best regards,

Simon

[i_4556]

Hello and thank you for your answer. I am testing with the dev board now.

In the meantime, a thought occurred to me; I am not using the watchdog timer, in either the network or main core. Are they disabled by default, or do I need to manually disable them?

When the problem occurs, it does seem to happen around the 4 minute mark, and I am wondering if there is something significant about that timeframe.

I have also tested powering the device from USB rather than battery, and the problem persists, so I dont think the problem is related to a weak battery.

EDIT: I have tested with the sniffer, please find the file attached. Skip to packet 35876, that is the last good packet. It really looks like the network core just stops suddenly for some reason... It never stops/disconnects either, even twenty minutes later my application core still thinks it has a good connection...

nrf5340_netwrok_error.pcapng

EDIT2: I may have gotten it working, in that in ten 5 minute tests I have experienced zero errors. Unfortunatly I made a bunch of changes so I dont know what did it, but heres what I did:

1) Homogenized the clock configs in both the main and network core, they now both contain

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC=y

CONFIG_CLOCK_CONTROL_NRF_K32SRC_RC_CALIBRATION=y

CONFIG_CLOCK_CONTROL_NRF_K32SRC_500PPM=y

CONFIG_SOC_HFXO_CAP_EXTERNAL=y

CONFIG_SOC_HFXO_CAP_INTERNAL=n

2) Added the following magic line of code to the network core config

CONFIG_RESET_ON_FATAL_ERROR=n

3) Removed the ability to have multiple centrals connect to my peripheral. for now we arent using this feature, so not a huge deal. In my network core config I commented out

# CONFIG_BT_CTLR_SDC_PERIPHERAL_COUNT=3

4) Removed the ability to store pairing information. I do need to add this feature back in at some point, but for now in my disconnect callback I have

bt_unpair(BT_ID_DEFAULT, BT_ADDR_LE_ANY);

Does any of this make sense, could any of this plausibly be the problem?

[Simonr]

Hi

Glad to hear you might have fixed the issue. My guess is setting HFXO_CAP_EXTERNAL=y in both cores is what has fixed this, as without it the network cores might have drifted which would explain the issue occurring not right away but after a while (4-5 minutes). You should still do more testing and over longer periods than just 5 minutes. What are the external capacitor values set to the HF crystal you're using, and can you upload the HF crystal datasheet so I can double check that the capacitor values make sense?

Also, the CONFIG_RESET_ON_FATAL_ERROR=n should only be used for debugging, as if the device runs into a fatal error it will stop entirely and not reset and try to get back up and running. When this is set, you can debug and see where the device gets stuck, but it's not recommended to be used in release products.

As for the watchdog, you should see a watchdog reset occur if the watchdog is triggered. The default value for it is not ~4 minutes if I recall correctly, so I think that is a dead end.

Let me know how your testing goes, and if it still persists I'll do a proper review of the sniffer trace as well.

Best regards,

Simon

[i_4556]

Hello and thank you for your reply. I am a little surprised that I need to set the clock config twice, in both the app and net cores; this feels like a recipe for mistakes and a landmine for new developers; maybe NRF should consider revising this in a future version? I assume I should also make the same change in my MCUBoot confing too then?

Our oscillator is this one: https://www.mouser.ca/datasheet/2/122/ECX-1048-1115630.pdf for which we have added a set of 10pF ceramic caps. I am not the hardware developer, so I cant really comment on how they were chosen. I know the hardware dev. is threatening to remove them to save space and instead use the internal caps on the NRF; in that case I would need to make the following changes right:

CONFIG_SOC_HFXO_CAP_EXTERNAL=n

CONFIG_SOC_HFXO_CAP_INTERNAL=y

SOC_HFXO_CAP_INT_VALUE_X2=20

Per your suggestions, I have rolled back the change to the CONFIG_RESET_ON_FATAL_ERROR, and everything is still working. We have done more tests, including one overnight, and everything seems to be working.

Thank you for all your help. While you are here, if you dont mind, do you have an example for configuring a peripheral to accept multiple central connections? We need our device to accept to simultaneous centrals.

Also, I seem to be getting some incorrect performance from the flash memory with NVS, in that NVS needs to be primed or something before it works properly. I have been testing with this code:

void Prime_Flash()

{

    //now prime the file system, ive no idea why we need this but it works...

    const float test_value = 0xDEADBEEF; //random number, doesnt actually matter

    float read_value = 0;

    int i = 0;

    while ((i < 25) && (test_value != read_value)) //usually takes 12 tries

    {

        NUS_Send("Write %u %i \n", i, nvs_write(&fs, TEST_REGISTER_ID, &test_value, sizeof(test_value)));

        // nvs_write(&fs, TEST_REGISTER_ID, &test_value, sizeof(test_value));

        k_msleep(10);

        NUS_Send("Read %u %i \n", i, nvs_read(&fs, TEST_REGISTER_ID, &read_value, sizeof(read_value)));

        // nvs_read(&fs, TEST_REGISTER_ID, &read_value, sizeof(read_value));

        k_msleep(10);

        i++;

    }

    NUS_Send("Flash ready took %i tries \n",i);

}

And I get the following results:

Write 0 4
Read 0 -2
Write 1 4
Read 1 -2
Write 2 4
Read 2 -2
Write 3 4
Read 3 -2
Write 4 4
Read 4 -2
Write 5 4
Read 5 -2
Write 6 4
Read 6 4
Write 7 4
Read 7 4
Write 8 4
Read 8 4
Write 9 4
Read 9 4
Write 10 4
Read 10 4
Write 11 4
Read 11 4
Write 12 4
Read 12 4
Flash ready took 13 tries

This happens consistently, where it takes 13 tries before the flash can be used properly. As near as I can tell, once we get that Flash ready then everything works fine until the next reset. 

I initialize the flash with:

void Initialise_Flash()

{

    //prepare flash memory

    fs.flash_device = NVS_PARTITION_DEVICE;

    if (!device_is_ready(fs.flash_device))

        printk("Flash device %s is not ready\n", fs.flash_device->name);

    fs.offset = NVS_PARTITION_OFFSET;

    flash_get_page_info_by_offs(fs.flash_device, fs.offset, &info);

    fs.sector_size = info.size;

    fs.sector_count = FLASH_SECTOR_COUNT;

    nvs_mount(&fs);

}

And it seems to work, I get the message

I: 2 Sectors of 4096 bytes
I: alloc wra: 0, f40
I: data wra: 0, 54

I doubt this is the expected behavior; do you have any suggestions what I am doing wrong?

Thanks!

[Simonr]

Hi

Sorry about the late reply here, but we've had a few bank holidays in Norway.

i_4556 said:

maybe NRF should consider revising this in a future version?

This is noted and I'll put up a feature request internally on this. The problem is it is two separate images where this must be set which is why it's needed twice as of now I believe. Yes, you should also set this in the MCUBoot image config IIRC.

For the crystal load capacitors we recommend following the following formula where CL is the load capacitance in the crystal datasheet and Ccap is what the optimal capacitor value in our designs would be: Ccap = 2 * CL - 4pF. Removing them to use the internal caps should be perfectly fine, and the settings seem correct. 

Your other questions are not really related to the initial ticket, so I'd recommend you create separate tickets for the other questions. If the initial issue reappears it will be easier to follow up in this case if we don't have multiple topics ongoing at the same time. Most peripheral samples support connecting to multiple devices, but in order to connect to multiple at the same time you need to make sure it starts advertising again after connecting to a central.

Best regards,

Simon