BLE connection error

Development setup:

  • 2 x nRF52840 SoC
  • Our own PCB’s with inverted F-antenna
  • LE PHY 1M
  • nRF Connect SDK v1.8.0

Hi,

During testing we experience an issue which seems to be related to the central and peripheral being on the edge of range.

The test setup is a single central and a single peripheral with log output to UART. The distance between the two devices is chosen so the devices continuously connects and disconnects. The central upon connection subscribes to sensor data on several services. The peripheral samples a sensor and notifies the data. Below you find part of the log file. 

15-06-2022 01:57:29.786 [RX] - [18:21:20.569,732] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:35.112 [RX] - [18:21:25.916,4
15-06-2022 01:57:35.128 [RX] - 42] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:37.048 [RX] - [18
15-06-2022 01:57:37.069 [RX] - :21:27.852,996] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:39.260 [RX] - [18:21:30.0
15-06-2022 01:57:39.281 [RX] - 64,605] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:40.904 [RX] - [18:21:31.687,744] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:43.319 [RX] - [18:21:34.122,772]
15-06-2022 01:57:43.335 [RX] -  <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:46.293 [RX] - [18:21:37.077,911] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:49.570 [RX] - [18:21:40.353,759] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:55.071 [RX] - [18:21:45.855,346] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:57.013 [RX] - [18:21:47.797,943] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:57:59.045 [RX] - [18:21:49.84
15-06-2022 01:57:59.066 [RX] - 8,541] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:02.296 [RX] - [18:21:53.080,230] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:04.414 [RX] - [18:21:55.196,685] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:07.435 [RX] - [18:21:58.218,566] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:10.672 [RX] - [18:22:01.454,895] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:13.339 [RX] - [18:22:04.123,199] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:16.058 [RX] - [18:22:06.859,558] <wrn> bt_
15-06-2022 01:58:16.074 [RX] - hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:29.158 [RX] - [18:22:19.961,63
15-06-2022 01:58:29.184 [RX] - 9] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:20.075,714] <wrn> bt_hci_core: opcode 0x200a status 0x09

15-06-2022 01:58:31.196 [RX] - [18:22:21.962,554] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:21.962,829] <wrn> bt_hci_core: opcode 0xfc0e status 0x02
[18:22:22.963,104] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:22.963,348] <wrn> bt_hci_core: opcode 0xfc0e status 0x02

15-06-2022 01:58:33.164 [RX] - [18:22:23.963,623] <wrn> bt_hci_core: o
15-06-2022 01:58:33.200 [RX] - pcode 0xfc0f status 0x02
[18:22:23.963,867] <wrn> bt_hci_core: opcode 0xfc0e status 0x02
[18:22:24.964,172] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:24.964,416] <wrn> bt_hci_core: opcode 0xfc0e status 0x02

15-06-2022 01:58:34.272 [RX] - [18:22:25.
15-06-2022 01:58:34.304 [RX] - 075,836] <err> bt_conn: not connected!
[18:22:25.964,691] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:25.964,935] <wrn> bt_hci_core: opcode 0xfc0e status 0x02

15-06-2022 01:58:36.199 [RX] - [18:22:26.965,240] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:26.965,515] <wrn> bt_hci_core: opcode 0xfc0e status 0x02
[18:22:27.965,789] <wrn> bt_hci_core: opcode 0xfc0f status 0x02
[18:22:27.966,033] <wrn> bt_hci_core: opcode 0xfc0e status 0x02

The problem is that the central no longer has connection with the peripheral and a power cycle of the central does not help.

The peripheral seems to think that it is in a connection, and therefore does not start advertising again.

Best regards,

Annette

  • Hi Vidar,

    Please try to bump CONFIG_BT_MAX_CONN to 3 and see if you are able to replicate the same. It is more of a workaround, but I believe/hope it will fix the problem for now.

    If I increment CONFIG_BT_MAX_CONN to 3 wouldn't this cause the central to start scanning again after creating the connection and the peripheral to start advertising again after being connected with?

    To monitor if the issue occurs I have added a function to conn.c that returns struct bt_conn->err and struct bt_conn->state. In the application I have created a monitor task that checks the application's against the structbt_conn->state from conn.c if there is an inconsistency between the two for approximately half a minute I let the watchdog bite.

    As far as I can see when the issue occurs the struct bt_conn->err is 0, but the struct bt_conn->state is 1 which is BT_CONN_DISCONNECT_COMPLETE. 

    Another thing to mention is that the central gets configured with the Bluetooth MAC address of the only peripheral it is allowed to connect with. The address is added to the filter and the filter enabled in the central with bt_scan_filter_add() / bt_scan_filter_enable(). 

    Status code 0x9 indicates that the connection limit has been exceeded by the way.

    Is this strange when having the filter enabled?

    Best regards,

    Annette

  • Hi Annette,

    CONFIG_BT_MAX_CONN configures the number of concurrent links that shall be supported by the stack, but it is up to the application to decide if it wants to re-start scanning or connectable advertising following a new connection. An example of this is the multilink central sample in Zephyr which only starts scanning if number of connections is less than CONFIG_BT_MAX_CONN as seen here: https://github.com/nrfconnect/sdk-zephyr/blob/d6cd4fc1ceec4bb41c217709c373e5b9ffd05e51/samples/bluetooth/central_multilink/src/central_multilink.c#L159

    Also, the opcode that returned 0x9 (connection limit exceeded) was for advertising start

    Is this strange when having the filter enabled?

    I suspect it may be a race somewhere causing advertising start to get called before the controller's internal state has completed the transition from connected to disconnected. Are you calling advertising start directly from the 'disconnected' callback?

    Best regards,

    Vidar

Related