The scan observer stops getting called after a failed attempt to connect to a peripheral using whitelist.

[Skara]

Hello All,

I have the following issue
- a peripheral and a central using nrf52832 with SDK 15.3 and S132
- on the peripheral I advertise with a whitelist
- the central scans with UUID filter activated for a specific UUID

Now when the central sees the peripheral, it tries to connect to it but since it is not in the centrals whitelist the connection is not established.
The problem on the central side is that the observer function nrf_ble_scan_on_ble_evt() stops getting called after the failed attempt to connect.

I reproduced this behavior using the ble_app_multirole_lesc example with some minor changes.
On the central I commented out the call to ble_advertising_start() so that it only scans.
On the peripheral I removed the scan_start() call so it only advertises and I activated the whitelist which has one entry.

I did put logging in nrf_ble_scan_on_adv_report() so that I can see whenever it gets called. When I run the central code, there is continuous log showing advertising packets from different devices. After a failed attempt to connect, I turn off the peripheral and there is no log output from nrf_ble_scan_on_adv_report() any more on the central.

This is how the log looks like on the central:
<info> ble_scan: B460775CF63C
<info> ble_scan: 775F1B8AEA41
<info> ble_scan: EE8BD6D1ABF4
<info> app: CENTRAL: Connected, handle: 0.
<info> app: CENTRAL: Searching for HRS on conn_handle 0x0
<info> peer_manager_handler: Connection security failed: role: Central, conn_handle: 0x0, procedure: Bonding, error: 4352
<warning> peer_manager_handler: Disconnecting conn_handle 0.
<info> app: CENTRAL: Disconnected, handle: 0, reason: 0x3E
<info> app: Scanning
<info> ble_scan: 44237CE1653F
<info> ble_scan: EE8BD6D1ABF4

Obviously this leads to a problem state where the central can not find any other devices to connect to. Stopping and starting the scan does not help. Only if the same peripheral appears again, the central starts calling nrf_ble_scan_on_adv_report again.

Do you know what could be causing this issue and how to resolve it? Does the SoftDevice get stuck somewhere?

Thanks,
Skara

[Skara]

Hey Torbjørn,

in my actual application I will have multiple different peripherals to which the central will try to connect to as soon as it sees any of them.

In this trace I filtered only the packets of the peripheral that the central is trying to connect to. The trace was made in a very noisy environment with more than 20 advertising BLE devices of which only one advertises the filtered UUID.

As I've written in my initial post, I did add a logging call in the observer function nrf_ble_scan_on_adv_report() which prints the addresses of the peripherals from which packets were received. Before powering on the peripheral, this log is coming continuously showing the addresses of many different devices. After the failed pair/bond and powering off the peripheral no log is to be seen as the observer function is never called again.

Best
Skara

[ovrebekk]

Hi Skara

How is the whitelist set in your test?

I added some logging every time the set_whitelist() function is run, and see that it never finds any peers to add to the list. 

In my test the two devices will just enter into an infinite connecting-> starting pairing-> timing out on passkey confirmation -> disconnecting -> reconnecting loop. 

As soon as I turn off the peripheral the scanner proceeds to pick up other advertise packets. 

Maybe I also need to run one of your other peripherals to reproduce the issue?

Best regards
Torbjørn

[Skara]

Hi Torbjørn,

the whitelist is only activated/applied if there are already bonded peers. So before starting the central I used the mobile nrf connect app to bond to the peripheral. Than just restart the peripheral and power the central on and you should be able to reproduce it.

Thanks
Skara

[ovrebekk]

Hi Skara

Thanks for the added details. I have been able to reproduce the issue now. It seems the SoftDevice is somehow getting stuck when trying to connect to the device, but I haven't been able to find a way to solve it yet. 

I will have to look more into this and get back to you later. 

Best regards
Torbjørn

[ovrebekk]

Hi again

Thanks a lot for the patience. After spending more time with this I believe I have tracked the issue down to the nrf_ble_scan_start() function, which is set up to ignore the NRF_ERROR_INVALID_STATE error when calling sd_ble_gap_scan_start(..) to restart the scan. 

I made the following small modification to the nrf_ble_scan_start() function (to log when INVALID_STATE is returned), and notice that before the stack ends up in the 'stuck' state I see the "Are we scanning or not??" message printed. 

ret_code_t nrf_ble_scan_start(nrf_ble_scan_t const * const p_scan_ctx)
{
    VERIFY_PARAM_NOT_NULL(p_scan_ctx);

    ret_code_t err_code;
    scan_evt_t scan_evt;

    memset(&scan_evt, 0, sizeof(scan_evt));

    nrf_ble_scan_stop();

    // If the whitelist is used and the event handler is not NULL, send the whitelist request to the main application.
    if (is_whitelist_used(p_scan_ctx))
    {
        if (p_scan_ctx->evt_handler != NULL)
        {
            scan_evt.scan_evt_id = NRF_BLE_SCAN_EVT_WHITELIST_REQUEST;
            p_scan_ctx->evt_handler(&scan_evt);
        }
    }

    // Start the scanning.
    err_code = sd_ble_gap_scan_start(&p_scan_ctx->scan_params, &p_scan_ctx->scan_buffer);

    // It is okay to ignore this error, because the scan stopped earlier.
    if ((err_code != NRF_ERROR_INVALID_STATE) && (err_code != NRF_SUCCESS))
    {
        NRF_LOG_ERROR("sd_ble_gap_scan_start returned 0x%x", err_code);
        return (err_code);
    }
    else if(err_code == NRF_ERROR_INVALID_STATE)
    {
        NRF_LOG_INFO("Are we scanning or not????");
    }
    NRF_LOG_DEBUG("Scanning");

    return NRF_SUCCESS;
}

Could you try to make the same change on your end, make sure that logging is enabled for the scan module, and see if you also get this message when the problem occurs?

Best regards
Torbjørn