Connectivity issues with HID example

[i_4556]

Hello and thanks for reading. Also happy holidays.

We are using an NRF5340, and are having some issues with connectivity. I would therefore welcome any suggestions you may have. We are using Zephyr SDK 2.5.0, and a windows 11 laptop.

Our product, among other functions, acts as a wireless mouse via HID over GATT. With most of the laptops we have tested with, everything works well. We have one laptop however where there are persistent and debilitating connectivity issues.

After much head-scratching, and wanting to isolate the problem, we decided to test with an nrf5340DK, and the Nordic example code for an HID mouse. The only change we made was adding a call to

bt_unpair(BT_ID_DEFAULT,NULL);

in the disconnected function, as the problem occurs when we try to reconnect after the laptop forgets the device.

The problem persists, which is why I am now turning to you for any suggestions you may have.

The problem manifests like this: we start with a freshly booted laptop, and a newly programmed device. We connect to the device from windows, and it works perfectly. We then go to the laptop bluetooth settings and select "delete device" (forget this device on older versions of windows). The device disappears as expected, but from here on the bug occurs and although we can see the device if we then scan for it, we can almost never reconnect. When the issue occurs, we never get to the stage where the laptop asks us to enter the pin; we simply get the please try again error message. Power cycling the device will not fix the issue, although power cycling the laptop will, as will sometimes reprogramming the device.

I have included below the log from the serial port: As you can see, I connect successfully, then am unable to connect, then connect successfully, then have multiple failed attempts.

*** Booting nRF Connect SDK v2.5.0 ***
[00:00:00.416,900] <inf> fs_nvs: 2 Sectors of 4096 bytes
[00:00:00.416,900] <inf> fs_nvs: alloc wra: 0, fe8
[00:00:00.416,900] <inf> fs_nvs: data wra: 0, 0
Bluetooth authentication callbacks registered.
[00:00:00.438,507] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.438,537] <inf> bt_hci_core: HW Variant: nRF53x (0x0003)
[00:00:00.438,568] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 197.47763 Build 2370639017
[00:00:00.439,361] <inf> bt_hci_core: No ID address. App must call settings_load()
Bluetooth initialized
[00:00:00.440,246] <inf> bt_hci_core: Identity: DE:C1:62:6E:0C:34 (random)
[00:00:00.440,277] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x2102, manufacturer 0x0059
[00:00:00.440,307] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x2102
Advertising successfully started
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 168782
Security changed: 00:D4:9E:B3:49:E3 (public) level 4
[00:02:18.406,524] <inf> bas: BAS Notifications enabled
[00:02:41.837,036] <inf> bas: BAS Notifications disabled
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x13)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 436605
[00:02:58.307,434] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 064518
Security changed: 00:D4:9E:B3:49:E3 (public) level 4
[00:03:29.822,479] <inf> bas: BAS Notifications enabled
[00:03:50.867,980] <inf> bas: BAS Notifications disabled
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x13)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 739262
[00:04:01.985,992] <wrn> bt_hci_core: Not reporting packet for non-connected conn
[00:04:01.986,083] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 330312
[00:04:20.478,424] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x2a)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 324202
[00:04:47.343,658] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 150110
Security changed: 00:D4:9E:B3:49:E3 (public) level 4
[00:05:18.078,643] <inf> bas: BAS Notifications enabled
[00:05:30.588,897] <inf> bas: BAS Notifications disabled
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x13)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 523576
[00:05:52.819,366] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 727059
[00:06:14.644,531] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 440553
[00:06:18.379,547] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 003510
[00:06:32.779,724] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x2a)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 642024
[00:06:35.974,700] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 698805
[00:06:51.319,854] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x2a)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 236151
[00:07:04.414,916] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)
Connected 00:D4:9E:B3:49:E3 (public)
Passkey for 00:D4:9E:B3:49:E3 (public): 533490
[00:07:10.714,965] <wrn> bt_smp: Not connected!
Security failed: 00:D4:9E:B3:49:E3 (public) level 1 err 9
Disconnected from 00:D4:9E:B3:49:E3 (public) (reason 0x23)

I do also have several NRF52840 dongles, and can use one to sniff the packets if you think that would be usefull.

Thank you for all your time!

[Hung Bui]

Hi, 
I see the same issue in this new trace: 

The central sent a PHY_UPDATE_IND and a PHY_REQ immediately after that (before PHY_UPDATE_IND instance take place). This most likely violating the spec. 

I'm not so sure how we can solve the problem for this laptop as it seems the issue come from the laptop. One think I can suggest is to try calling LL_PHY_REQ from the peripheral side a little bit later. You can do that by setting CONFIG_BT_AUTO_PHY_UPDATE=n this will avoid the peripheral sending the request. You can then check if the laptop behave normally after. If the central doesn't send the request to switch to 2M, you can program the code to send the request after some time after connected, 5 seconds for example.