NCS BLE scan filter calls filter match callback after filter was disabled

Hi, I am fighting with a bug I found in SDK v2.8.0 for BLE scan filter on a test project as follows: 2 Devices (Ezurio BL653-DVK using the nRF52833), both having central and peripheral roles (but one acting as a client, and the other as the server, so 2 different SW projects).

Server device start an advertising (indirect, connectable,advertising the NUS service UUID). Client device starts an active scan with a filter for UUID and the connect_if_match flag true. When the connections happens (in connected callback), a work entry is given to the SysWorker, so that the advertising of the Server is stoppped, and restarted with non-connectable parameters and manufacturer data. The Client also gives the worker the task to start non-connectable advertising, stop the previous scan (if necessary, as it should be stopped in the BLE Stack), and start an active scan with connect_if_match false and a filter for manufacturer data.

In our example code, the callback for filter match UUID is different as the filter for Manufacturer Data. The problem is, after client stops the scan, disables and removes all filters, and restarts the scan with new parameters and callback, it sucessfully calls the new callback when it scans the manufacturer data of the advertisement from the server, but the old callback for UUID is still being called (even though the UUID filter was disabled and verified that after the filter initialization and start for Manufacturer Data, the status of the filters is correct: UUID disabled count 0, MFG enabled count 1. But the callback for UUID gets called repeteadly.

// Snippet from main, start scan with filter for UUID
bt_scan_init(&scan_init);
bt_scan_cb_register(&scan_nus_cb);

err = bt_scan_filter_add(BT_SCAN_FILTER_TYPE_UUID, BT_UUID_NUS_SERVICE);
if (err)
{
    printk("Scanning filters cannot be set (err %d)\n", err);
    return err;
}
err = bt_scan_filter_enable(BT_SCAN_UUID_FILTER, true);
if (err)
{
    printk("Filters cannot be turned on (err %d)\n", err);
    return err;
}
err = bt_scan_start(BT_SCAN_TYPE_SCAN_ACTIVE);
if (err)
{
    printk("Scanning failed to start (err %d)\n", err);
    return err;
}
printk("NUS scanning started\n");
struct bt_filter_status filter_status;
bt_scan_filter_status_get(&filter_status);
printk("UUID filter status. Enabled=%d, cnt=%d\n", (int)filter_status.uuid.enabled, filter_status.uuid.cnt);
printk("MFG filter status. Enabled=%d, cnt=%d\n", (int)filter_status.manufacturer_data.enabled, filter_status.manufacturer_data.cnt);

// scan parameters for UUID
static struct bt_scan_init_param scan_init = {
    .connect_if_match = true,
    .scan_param = &scan_param,
    .conn_param = NULL
};
static struct bt_le_scan_param scan_param = {
    .type     = BT_LE_SCAN_TYPE_ACTIVE,
    .interval = BT_GAP_SCAN_FAST_INTERVAL,
    .window   = BT_GAP_SCAN_FAST_WINDOW,
    .options  = BT_LE_SCAN_OPT_NONE,
    .timeout  = 0,
};

// callback for scan filter for UUID (NUS Service)
static void scan_filter_nus_match(struct bt_scan_device_info* device_info, struct bt_scan_filter_match* filter_match, bool connectable)
{
    static char nus_found_addr[BT_ADDR_LE_STR_LEN];
    bt_addr_le_to_str(device_info->recv_info->addr, nus_found_addr, sizeof(nus_found_addr));
    if (current_connection != NULL)
    {
        // THIS SHOULD NOT HAPPEN AFTER CONNECTION! Connection has been made, scan stopped, filter for UUID has been disabled!
        printk("NUS filter when already connected, connectable=%d, addr=%s\n", (int)connectable, nus_found_addr);
    }
    else
    {
        printk("NUS service found, connectable=%d, addr=%s\n", (int)connectable, nus_found_addr);
    }
}

// BLE connected callback
static void connected_cb(struct bt_conn* conn, uint8_t err)
{
    if (err)
    {
        printk("Connection failed (err %u)\n", err);
        return;
    }

    char addr[BT_ADDR_LE_STR_LEN];
    bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));
    printk("Connected to %s\n", addr);
    current_connection = bt_conn_ref(conn);

    adv_param = &adv_param_noconn;
    k_work_submit(&adv_work);
}

// callback for SysWork entry (pushed from connected callback
static void adv_work_cb(struct k_work* work)
{
    printk("adv_work_cb\n");
    if (adv_param == &adv_param_noconn)
    {
        int res = bt_scan_stop();
        if (res == -EALREADY)
        {
            printk("Scanning already stopped\n");
        }
        else if (res != 0)
        {
            printk("bt_scan_stop failed, res=%d\n", res);
            return;
        }
        else
        {
            printk("Scanning stopped\n");
        }
        res = adv_start();
        if (res)
        {
            printk("adv_start failed\n");
        }
        res = scan_dm_start();
        if (res)
        {
            printk("scan_dm_start failed, res=%d\n", res);
        }
    }
}

// starts scan for manufacturer data
static int scan_dm_start(void)
{
    int err;

    bt_scan_filter_remove_all();
    bt_scan_filter_disable();

    bt_scan_init(&scan_dm_init);
    bt_scan_cb_register(&scan_dm_cb);

    err = bt_scan_filter_add(BT_SCAN_FILTER_TYPE_MANUFACTURER_DATA, &scan_mfg_data);
    if (err)
    {
        printk("Scanning filters cannot be set (err %d)\n", err);
        return err;
    }
    err = bt_scan_filter_enable(BT_SCAN_MANUFACTURER_DATA_FILTER, true);
    if (err)
    {
        printk("Filters cannot be turned on (err %d)\n", err);
        return err;
    }
    err = bt_scan_start(BT_SCAN_TYPE_SCAN_ACTIVE);
    if (err)
    {
        printk("Scanning failed to start (err %d)\n", err);
        return err;
    }
    printk("DM scanning started\n");

    struct bt_filter_status filter_status;
    bt_scan_filter_status_get(&filter_status);
    printk("UUID filter status. Enabled=%d, cnt=%d\n", (int)filter_status.uuid.enabled, filter_status.uuid.cnt);
    printk("MFG filter status. Enabled=%d, cnt=%d\n", (int)filter_status.manufacturer_data.enabled, filter_status.manufacturer_data.cnt);

    return err;
}

// scan parameters for Manufacturer Data filter
static struct bt_scan_init_param scan_dm_init = {
    .connect_if_match = false,
    .scan_param = &scan_param,
    .conn_param = NULL
};

// callback for scan manufacturer data
static void scan_filter_dm_match(struct bt_scan_device_info* device_info, struct bt_scan_filter_match* filter_match, bool connectable)
{
    static char mfg_found_addr[BT_ADDR_LE_STR_LEN];
    bt_addr_le_to_str(device_info->recv_info->addr, mfg_found_addr, sizeof(mfg_found_addr));
    if (current_connection != NULL)
    {
        printk("MFG found, connectable=%d, addr=%s\n", (int)connectable, mfg_found_addr);
        bt_addr_le_t addr;
        bt_addr_le_copy(&addr, device_info->recv_info->addr);
        bt_data_parse(device_info->adv_data, filter_data_dm_cb, &addr);
    }
    else
    {
        printk("MFG found when not connected, connectable=%d, addr=%s\n", (int)connectable, mfg_found_addr);
    }
}


I have tested with NCS v2.8.0.

*** Booting nRF Connect SDK v2.8.0-a2386bfc8401 ***
*** Using Zephyr OS v3.7.99-0bc3393fb112 ***
Starting Central
[00:00:00.001,129] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
                                            fe 2c f9 6a 7f 36 22 2e  a0 79 c0 40 be 2c 03 20 |.,.j.6". .y.@.,. 
                                            40 c2 f3 32                                      |@..2             
[00:00:00.003,448] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
[00:00:00.003,479] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
[00:00:00.003,509] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 254.63788 Build 573996906
[00:00:00.004,364] <inf> bt_hci_core: Identity: F4:F3:73:46:A2:F2 (random)
[00:00:00.004,394] <inf> bt_hci_core: HCI: version 6.0 (0x0e) revision 0x104e, manufacturer 0x0059
[00:00:00.004,425] <inf> bt_hci_core: LMP: version 6.0 (0x0e) subver 0x104e
bt_enabled OK
NUS scanning started
UUID filter status. Enabled=1, cnt=1
MFG filter status. Enabled=0, cnt=0
NUS service found, connectable=1, addr=E2:A0:F3:36:D9:D0 (random)
NUS service connecting
Connected to E2:A0:F3:36:D9:D0 (random)
adv_work_cb
Scanning stopped
No previous advertising
Starting advertising
Advertising started
DM scanning started
UUID filter status. Enabled=0, cnt=0
MFG filter status. Enabled=1, cnt=1
NUS filter when already connected, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
MFG found, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
NUS filter when already connected, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
MFG found, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
NUS filter when already connected, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
MFG found, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
NUS filter when already connected, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
MFG found, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
NUS filter when already connected, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)
MFG found, connectable=0, addr=E2:A0:F3:36:D9:D0 (random)


With same code above mentioned and NCS v2.7.0 (and v2.6.2) there is even a critical bug, as the client gets completely frozen after connection (but shows no Hard fault or Kernel Fault or anything like that, not even a blinky LED in main task), and server reports a BLE disconnection due to timeout.

For context, end goal is related to the Nordic Distance Measurement example project, but the example starts the advertisement and scan that trigger the distance measurement from the beginning, before connection. We want to actually have the distance measurement only after the BLE connection, which is why we prepared this example project to clarify that change in adv/scan independent of our application code.

Any comment, advice or guidance on this matter would be appreciated.

Regards

test_scan_uuid_mfg_error.zip

Related