Issue with the auto connect feature

Hi,

I'm developing a BLE Central using a nRF52840 DK. My project goal is to analyze the quality and the robustness of a peripheral's BLE connection.

For some parts of my testing procedure, I need the central to automatically reconnect to the peripheral. I achieve that by calling bt_le_set_auto_conn right after bt_conn_le_create.

I will add a reproducible sample at the end of this question. Nevertheless the central works this way:

  1. Scan the nearby until it found a device with a particular name (actually hardcoded in the central)
  2. Connect to that peripheral
  3. Activate bt_le_set_auto_conn
  4. Set the BLE security level to 3 (Encryption and authentication)
    1. Automatically confirm the passkey
  5. Start some threads (one to read the RSSI and one to retrieve the packet error rate)
  6. Wait
    1. When the connection is lost
      1. Stop the threads
      2. Release some memory
      3. Do not start scanning
    2. Reconnect to the peripheral when it comes back in range

What I observed

When the auto connect feature is enable, the disconnected callback is not called on a disconnection. However the connected callback is called on every reconnection.

The kernel was panicking on reconnection because since the disconnection callback is not called, the thread created before isn't close indeed that on reconnection, the central try to recreate the thread that already exist making him panicking.
I highly suspect that because then I tried to correct this by passing the bt_conn object to the thread on creation and in the while (1) loop in the thread's entrypoint, adding a switch to check the connection state and returning (to close the thread) if the connection was in a other state than BT_CONN_STATE_CONNECTED and now the thread is closed on disconnection, the kernel isn't panicking on reconnection.

After the first disconnection, the connection with the peripheral will closed every 30 seconds (I suspect that because the link isn't encrypted (neither the pairing complete callback or the security changed callback are call on a reconnection) and my peripheral need at least a security level 3)

The errors

[00:00:01.973,541] <inf> main: Connected: 7F:D6:F3:3C:D3:8A
[00:00:01.974,060] <dbg> main: bla bla bla
[00:00:02.075,500] <inf> main: Data length updated. Length 69/69 bytes, time 2120/2120 us
[00:00:02.327,972] <inf> main: Passkey confirmed
[00:00:02.775,115] <inf> main: Security changed to level 4
[00:00:02.876,007] <inf> main: pairing_complete: Pairing complete
[00:00:02.974,182] <dbg> main: bla bla bla
[00:00:03.569,091] <inf> main: Phy updated to 2M
[00:00:03.974,334] <dbg> main: bla bla bla
[00:00:04.974,517] <inf> main: peer disconnected
<---- I disconnected the peripheral by turning off the bluetooth ---->
<---- Then I turned on the bluetooth on the peripheral ---->
[00:00:09.155,853] <err> bt_l2cap: No available L2CAP context for conn 0x20002040
[00:00:09.155,883] <err> bt_smp: No available SMP context for conn 0x20002040
[00:00:09.155,914] <err> bt_att: No available ATT context for conn 0x20002040
[00:00:09.155,914] <inf> main: Connected: CA:D5:C8:E6:52:E9
[00:00:09.156,036] <dbg> main: bla bla bla
[00:00:09.157,531] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x0004
[00:00:09.257,415] <inf> main: Data length updated. Length 69/69 bytes, time 2120/2120 us
[00:00:10.156,097] <dbg> main: bla bla bla
[00:00:10.657,501] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x0006
[00:00:11.156,219] <dbg> main: bla bla bla
...

My questions

I presume that the auto connect feature "disable" the disconnected callback, why this behavior ?

What are this L2CAP, SMP and ATT errors ?? I know for sure that they are not raised by the connected callback in itself (my function) because I added a print at its beginning and the errors printed before mine.

What are this L2CAP warning that come after the connection callback saying that it's ignoring data for "unknown channel" ??

Limitations

I don't have access to the peripheral code. However, it must work with any peripheral. I actually use 4 different peripherals and the result are the same.

Setup

  • nRF52840 DK
  • nRF SDK v2.7.0
  • WSL2 (Ubuntu 22.04) on a Windows 10 host
  • If it's matter, I do not use the VS Code extension but the CLI version

Minimum reproducible example (main.c & prj.conf)

I reduce a lot the code by removing threads, discovering phases, buttons, ect... However, I added a dummy thread just to see if the device is connected or not

#include <zephyr/types.h>
#include <stddef.h>
#include <errno.h>
#include <zephyr/kernel.h>
#include <zephyr/device.h>
#include <zephyr/sys/printk.h>
#include <zephyr/sys/util.h>
#include <zephyr/drivers/gpio.h>

#include <zephyr/logging/log.h>
#include <zephyr/logging/log_ctrl.h>

#include <zephyr/bluetooth/bluetooth.h>
#include <zephyr/bluetooth/hci.h>
#include <zephyr/bluetooth/conn.h>
#include <zephyr/bluetooth/uuid.h>
#include <zephyr/bluetooth/gatt.h>
#include <zephyr/sys/byteorder.h>

#define PERIPHERAL_TO_CONNECT_TO "HereIsThePeripheralName"

LOG_MODULE_REGISTER(main, LOG_LEVEL_DBG);

static struct bt_conn *default_conn;

#define THREAD_STACK_SIZE_EXAMPLE 1000
static k_tid_t th_id_example;
static struct k_thread th_data_example;
static K_THREAD_STACK_DEFINE(th_stack_example, THREAD_STACK_SIZE_EXAMPLE);

static void start_scan(void);

static bool parse_data_cb(struct bt_data *data, void *user_data)
{
  bt_addr_le_t *addr = user_data;

  switch (data->type)
  {
    case BT_DATA_NAME_SHORTENED:
    case BT_DATA_NAME_COMPLETE:
      ((uint8_t *)data->data)[data->data_len] = '\0';
      LOG_INF("[DEVICE]: %02X:%02X:%02X:%02X:%02X:%02X\tDevice name: %s", addr->a.val[5], addr->a.val[4], addr->a.val[3], addr->a.val[2], addr->a.val[1], addr->a.val[0], data->data);
      if (strncmp(data->data, PERIPHERAL_TO_CONNECT_TO, data->data_len) == 0)
      {
        int err = bt_le_scan_stop();
        if (err)
        {
          LOG_ERR("Stop LE scan failed (err %d)", err);
          return false;
        }

        struct bt_conn_le_create_param *create_param = BT_CONN_LE_CREATE_CONN;
        struct bt_le_conn_param *param = BT_LE_CONN_PARAM_DEFAULT;
      
        err = bt_conn_le_create(addr, create_param, param, &default_conn);
        if (err)
        {
          LOG_WRN("Connection failed (err %d)", err);
          start_scan();
        }
        err = bt_le_set_auto_conn(addr, param);
        if (err)
        {
          LOG_ERR("Error: bt_le_set_auto_conn() return %d", err);
          start_scan();
        }
        return false;
      }
      break;
    default:
      break;
    }
  return true;
}

static void on_device_found_cb(const bt_addr_le_t *addr, int8_t rssi, uint8_t type, struct net_buf_simple *ad)
{
  if (type == BT_GAP_ADV_TYPE_ADV_IND || type == BT_GAP_ADV_TYPE_ADV_DIRECT_IND || type == BT_GAP_ADV_TYPE_EXT_ADV || type == BT_GAP_ADV_TYPE_SCAN_RSP)
  {
    if (rssi < -30)
      bt_data_parse(ad, parse_data_cb, (void *)addr);
  }
}

static void start_scan(void)
{
  int err;

  struct bt_le_scan_param scan_param = {
    .type = BT_LE_SCAN_TYPE_ACTIVE,
    .options = BT_LE_SCAN_OPT_NONE,
    .interval = BT_GAP_SCAN_FAST_INTERVAL,
    .window = BT_GAP_SCAN_FAST_WINDOW,
  };

  err = bt_le_scan_start(&scan_param, on_device_found_cb);
  if (err)
  {
    LOG_ERR("Scanning failed to start (err %d)", err);
    return;
  }

  LOG_INF("Scanning successfully started");
}

static enum bt_conn_state get_state(struct bt_conn *conn)
{
  struct bt_conn_info info;

  int err = bt_conn_get_info(conn, &info);
  if (err)
  {
    LOG_ERR("Error: bt_conn_get_info() return %d", err);
    return BT_CONN_STATE_DISCONNECTED;
  }
  return info.state;
}

static void thread_entrypoint_example(void *p1, void *p2, void *p3)
{
  struct bt_conn *conn = p1;

  while (1)
  {
    switch (get_state(conn))
    {
      case BT_CONN_STATE_CONNECTED:
        LOG_DBG("bla bla bla");
        break;
      default:
        LOG_INF("peer disconnected");
        return;
    }
    k_sleep(K_SECONDS(1));
  }
}

static void connected_cb(struct bt_conn *conn, uint8_t conn_err)
{
  const bt_addr_le_t * addr = bt_conn_get_dst(conn);

  if (conn_err)
  {
    LOG_ERR("Failed to connect to %02X:%02X:%02X:%02X:%02X:%02X (err %u)", addr->a.val[5], addr->a.val[4], addr->a.val[3], addr->a.val[2], addr->a.val[1], addr->a.val[0], conn_err);
    bt_conn_unref(default_conn);
    default_conn = NULL;
    start_scan();
  }

  LOG_INF("Connected: %02X:%02X:%02X:%02X:%02X:%02X", addr->a.val[5], addr->a.val[4], addr->a.val[3], addr->a.val[2], addr->a.val[1], addr->a.val[0]);

  if (conn == default_conn)
  {
    int err = bt_conn_set_security(conn, BT_SECURITY_L3);
    if (err)
      LOG_ERR("Error while pairing %d", err);

    th_id_example = k_thread_create(&th_data_example,
      th_stack_example,
      K_THREAD_STACK_SIZEOF(th_stack_example),
      thread_entrypoint_example,
      conn,
      NULL,
      NULL,
      K_PRIO_PREEMPT(1),
      0,
      K_NO_WAIT);
  }
}

static void disconnected_cb(struct bt_conn *conn, uint8_t reason)
{
  LOG_INF("Beginning disconnected_cb");

  k_thread_abort(th_id_example);

  const bt_addr_le_t * addr = bt_conn_get_dst(conn);
  if (default_conn != conn)
    return;

  LOG_INF("Disconnected: %02X:%02X:%02X:%02X:%02X:%02X (reason 0x%02x)", addr->a.val[5], addr->a.val[4], addr->a.val[3], addr->a.val[2], addr->a.val[1], addr->a.val[0], reason);
}

static void auth_passkey_display_cb(struct bt_conn *conn, unsigned int passkey)
{
  LOG_INF("Passkey is: %06u", passkey);
}

static void auth_passkey_confirm_cb(struct bt_conn *conn, unsigned int passkey)
{
  LOG_INF("Passkey confirmed");
  bt_conn_auth_passkey_confirm(conn);
}

static void le_param_updated_cb(struct bt_conn *conn, uint16_t interval, uint16_t latency, uint16_t timeout)
{
  LOG_INF("CONN PARAMS UPDATED interval %d, latency %d, timeout %d", interval, latency, timeout);
}

static bool le_param_req_cb(struct bt_conn *conn, struct bt_le_conn_param *param)
{
  LOG_INF("CONN PARAMS UPDATE REQUESTED interval_min %d, interval_max %d, latency %d, timeout %d", param->interval_min, param->interval_max, param->latency, param->timeout);

  return true;
}

static void auth_cancel_cb(struct bt_conn *conn)
{
  LOG_INF("Pairing cancelled");
}

static void le_phy_update_cb(struct bt_conn *conn, struct bt_conn_le_phy_info *param)
{
  switch (param->tx_phy)
  {
    case BT_CONN_LE_TX_POWER_PHY_1M:
    case BT_CONN_LE_TX_POWER_PHY_2M:
      LOG_INF("Phy updated to %dM", param->tx_phy);
      break;
    default:
      LOG_INF("Phy updated to CODED");
      break;
  }
}

static void le_data_len_updated(struct bt_conn *conn, struct bt_conn_le_data_len_info *info)
{
  uint16_t tx_len = info->tx_max_len;
  uint16_t tx_time = info->tx_max_time;
  uint16_t rx_len = info->rx_max_len;
  uint16_t rx_time = info->rx_max_time;
  LOG_INF("Data length updated. Length %d/%d bytes, time %d/%d us", tx_len, rx_len, tx_time, rx_time);
}

static void security_changed_cb(struct bt_conn *conn, bt_security_t level, enum bt_security_err err)
{
  if (err)
    LOG_ERR("Error on security changed. err %d", err);
  else
  {
    switch (level)
    {
      case BT_SECURITY_L0:
        LOG_INF("Security changed to level 0");
        break;
      case BT_SECURITY_L1:
        LOG_INF("Security changed to level 1");
        break;
      case BT_SECURITY_L2:
        LOG_INF("Security changed to level 2");
        break; 
      case BT_SECURITY_L3:
        LOG_INF("Security changed to level 3");
        break;
      case BT_SECURITY_L4:
        LOG_INF("Security changed to level 4");
        break;
      default:
        LOG_INF("Security changed to FORCE_PAIR");
        break;
    }
  }
}

static void pairing_complete(struct bt_conn *conn, bool bonded)
{
  if (!bonded)
    LOG_INF("Pairing failed");
  else
    LOG_INF("Pairing complete");
}

BT_CONN_CB_DEFINE(conn_callbacks) = {
  .connected = connected_cb,
  .disconnected = disconnected_cb,
  .le_param_req = le_param_req_cb,
  .le_param_updated = le_param_updated_cb,
  .le_data_len_updated = le_data_len_updated,
  .le_phy_updated = le_phy_update_cb,
  .security_changed = security_changed_cb,
};

static struct bt_conn_auth_cb conn_auth_callbacks = {
  .passkey_display = auth_passkey_display_cb,
  .passkey_confirm = auth_passkey_confirm_cb,
  .cancel = auth_cancel_cb,
};

static struct bt_conn_auth_info_cb auth_info_cb = {
  .pairing_complete = pairing_complete
};

int main(void)
{
  LOG_INIT();

  int err = bt_conn_auth_cb_register(&conn_auth_callbacks);
  bt_conn_auth_info_cb_register(&auth_info_cb);

  err = bt_enable(NULL);
  if (err)
  {
    LOG_ERR("Bluetooth init failed (err %d)", err);
    return 1;
  }

  bt_set_bondable(true);
  LOG_INF("Bluetooth initialized");

  start_scan();

  return 0;
}

CONFIG_BT=y
CONFIG_BT_DEVICE_NAME="test"
CONFIG_BT_CENTRAL=y
CONFIG_BT_GATT_CLIENT=y
CONFIG_CONSOLE=y
CONFIG_GPIO=y
CONFIG_SERIAL=y
CONFIG_EVENTS=y
CONFIG_BT_SMP=y
CONFIG_BT_BONDABLE=y
CONFIG_LOG=y
CONFIG_LOG_BACKEND_UART=y
CONFIG_LOG_MODE_DEFERRED=y
CONFIG_LOG_PRINTK=y
CONFIG_DEBUG=y
CONFIG_BT_USER_PHY_UPDATE=y
CONFIG_BT_AUTO_PHY_UPDATE=n
CONFIG_BT_USER_DATA_LEN_UPDATE=y
CONFIG_BT_AUTO_DATA_LEN_UPDATE=n
Parents
  • Hello,

    I must admit that I was not aware of this auto_conn feature, and thus, I don't know if it is intentional that the disconnected callback should disappear. However, it sounds odd that it should, since it is useful for the application to know whether you are currently connected or not. 

    Let me ask internally, and I will get back to you, hopefully this week, no later than the beginning of next week.

    Best regards,

    Edvin

  • Hi,

    I hope you are well.

    Have you made any progress in the understanding of my problem ?

    Kind regards,

    Victor

  • It is difficult to say why 3rd party devices decide to disconnect without access to their application. Do you have any way to "forget device" on the 3rd party device, which would mean to delete the bonding information? Perhaps it has old bonding data that is no longer present on the nRF, which can cause it to disconnect. 

    I don't know, but they may also decide to use the error BT_SECURITY_ERR_UNSPECIFIED, for all I know.

    Best regards,

    Edvin

  • I deleted the bonding information after 3-4 tests in a row, it didn't change the result.

    Kind regards,

    Victor

  • So you deleted it on both the nRF and the peripheral at the same time?

    Can you please provide a sniffer trace? You can use the nRF Sniffer for Bluetooth LE for this. I am not sure if it helps, but it may give some hints about what's going on. However, if all it says is that the peripheral decides to disconnect, then you need to talk to the developers of the peripheral and ask what it expects the central to behave like.

    Best regards,

    Edvin

  • I effectively deleted the bonded information on both devices at the same time.

    I'm currently trying to install the nRF Sniffer following this guide. However, I don't see the nRF Sniffer interface in the start page of Wireshark (I did refresh multiple time, reopened Wireshark in normal user and in admin, verified that the extcap files from the nRF Sniffer are in the "Personal Extcap" folder, rebooted the computer).

    At page the end of page 8, when I need to run the nRF Sniffer Tool to list the available interfaces, I get 2 errors and the same string as presented in the guide (line 2 and 3):

    C:\NSS\Wireshark\extcap>nrf_sniffer_ble.bat --extcap-interfaces
    C:\NSS\Wireshark\extcap\nrf_sniffer_ble.py:187: SyntaxWarning: invalid escape sequence '\s'
      "{validation=^\s*((37|38|39)\s*,\s*){0,2}(37|38|39){1}\s*$}{required=true}" % CTRL_ARG_ADVHOP)
    C:\NSS\Wireshark\extcap\nrf_sniffer_ble.py:716: SyntaxWarning: invalid escape sequence '\s'
      m = re.search("^\s*rssi\s*(>=?)\s*(-?[0-9]+)\s*$", capture_filter, re.IGNORECASE)
      extcap {version=4.1.1}{display=nRF Sniffer for Bluetooth LE}{help=https://www.nordicsemi.com/Software-and-Tools/Development-Tools/nRF-Sniffer-for-Bluetooth-LE}
    interface {value=COM7-None}{display=nRF Sniffer for Bluetooth LE COM7}
    control {number=0}{type=selector}{display=Device}{tooltip=Device list}
    control {number=1}{type=selector}{display=Key}{tooltip=}
    control {number=2}{type=string}{display=Value}{tooltip=6 digit passkey or 16 or 32 bytes encryption key in hexadecimal starting with '0x', big endian format.If the entered key is shorter than 16 or 32 bytes, it will be zero-padded in front'}{validation=\b^(([0-9]{6})|(0x[0-9a-fA-F]{1,64})|([0-9A-Fa-f]{2}[:-]){5}([0-9A-Fa-f]{2}) (public|random))$\b}
    control {number=3}{type=string}{display=Adv Hop}{default=37,38,39}{tooltip=Advertising channel hop sequence. Change the order in which the sniffer switches advertising channels. Valid channels are 37, 38 and 39 separated by comma.}{validation=^\s*((37|38|39)\s*,\s*){0,2}(37|38|39){1}\s*$}{required=true}
    control {number=7}{type=button}{display=Clear}{tooltop=Clear or remove device from Device list}
    control {number=4}{type=button}{role=help}{display=Help}{tooltip=Access user guide (launches browser)}
    control {number=5}{type=button}{role=restore}{display=Defaults}{tooltip=Resets the user interface and clears the log file}
    control {number=6}{type=button}{role=logger}{display=Log}{tooltip=Log per interface}
    value {control=0}{value= }{display=All advertising devices}{default=true}
    value {control=0}{value=[00,00,00,00,00,00,0]}{display=Follow IRK}
    value {control=1}{value=0}{display=Legacy Passkey}{default=true}
    value {control=1}{value=1}{display=Legacy OOB data}
    value {control=1}{value=2}{display=Legacy LTK}
    value {control=1}{value=3}{display=SC LTK}
    value {control=1}{value=4}{display=SC Private Key}
    value {control=1}{value=5}{display=IRK}
    value {control=1}{value=6}{display=Add LE address}
    value {control=1}{value=7}{display=Follow LE address}

    The string "interface" are correct, it show the right COM port on which is connected the DK with the sniffer firmware (Checked with the nRF Connect for VS code (I did not connect the VS terminal to the devkit)).

    I'm using Python 3.11.9

    This is the interface Wireshark provide on the start page:

    Kind regards,
    Victor

  • Can you please try to install jlink v7.88j, and make sure that you tick off this box when installing?

    Then restart Wireshark after the installation is complete. The DK is programmed with the sniffer firmware, right? Try power cycling it after it is programmed, and plug it into the computer before you start wireshark. What are you using as your sniffer device? And which .hex file did you program onto it?

    Please download JLink from here:

    https://www.segger.com/downloads/jlink/?utm_medium=top_menu&utm_source=www

    Best regards,

    Edvin

Reply Children
  • Hi Edvin,

    I reinstall J-Link, using the version v7.88j and the link you provided. It did not solve the issue.

    I tried with three different devkits:

    • 2x nRF52840 DK
    • 1x nRF52840-Preview-DK

    I flashed the .hex file named "sniffer_nrf52840dk_nrf52840_4.1.1.hex" on the three previously said devkit.

    I connected a terminal to the devkit through the COM port, I did see some values, absolutely not human readable, but at least this means that the devkits was running.

    Kind regards,

    Victor

  • I see the same output as you do when running the "nrf_sniffer_ble.bat --extcap-interfaces".

    But it doesn't show up as a device in Wireshark?

    What happens if you try to select one of the USBPcap1 or USBPcap2? 

    BR,
    Edvin

Related