Issue with sd_ble_gap_disconnect

[ves]

Hello everybody

I hit another issue with sd_ble_gap_disconnect.

The short story is this one. I want the peripheral to initiate a disconnect if no activity for a predefined interval. At this moment, for test purpose only, i just implemented a timer which triggers sd_ble_gap_disconnect 5sec after the connect event. So i have my application running on a 52810 board. I use nrfConnect to connect to the device and the device triggers disconnect 5 sec after. After disconnect event i reconnect manually again to the device in nrfConnect. The log captured in the console shows like this

[00:00:00.000,000] <info> app_timer: RTC: initialized.
[00:00:00.000,000] <info> app: Ble tutorial started.
[00:00:00.000,000] <info> app: on adv_evt - evt = 3
[00:00:00.000,000] <info> app: Fast advertising.
[00:00:00.000,000] <info> app: Connected to a previously bonded device.
[00:00:00.000,000] <info> app: BLE event received. Event type = 16

[00:00:00.000,000] <info> app: Connected.
[00:00:00.454,162] <info> app: BLE event received. Event type = 18

[00:00:00.717,834] <info> app: BLE event received. Event type = 18

[00:00:04.967,285] <info> app: on adv_evt - evt = 3
[00:00:04.967,285] <info> app: Fast advertising.
[00:00:04.967,285] <info> app: BLE event received. Event type = 17

[00:00:04.967,346] <info> app: Disconnected.
[00:00:04.967,346] <info> app: Connected to a previously bonded device.
[00:00:04.967,346] <info> app: BLE event received. Event type = 16

[00:00:04.967,346] <info> app: Connected.
[00:00:05.447,326] <info> app: BLE event received. Event type = 18

[00:00:05.714,721] <info> app: BLE event received. Event type = 18

[00:00:09.967,346] <error> app: ERROR 8 [NRF_ERROR_INVALID_STATE] at C:\dev\52810\nRF5_SDK_17.0.2_d674dde\examples\ble_peripheral\ble_app_empty\main.c:338
PC at: 0x0001F429
[00:00:09.982,727] <error> app: End of error report

As you can see there is a first Disconnect event but the second one is missing because the device crashes and it shows the error report with error code = 8 which is invalid parameters

Digging further, the crash happens in in send_update_request when calling sd_ble_gap_conn_param_update because the second parameter p_new_conn_params is totaly invalid. Soething happen when pushet to the stack. SP = 20005f40 which is reasonable

In caller function update_timeout_handler the p_instance variable has valid values, but somehow when calling send_update_request the address is changed from 20002d8c+8 (how it is shown in update_timeout_handler) to 3ff00000 and this wrong value is pushed on the stack

Here is the call stack (hope you can access the link)

the way i call sd_ble_gap_disconnect is this one:

  - i instantiated a timer in main with time_ms = 5000 

 

const nrf_drv_timer_t INACTIVITYTIMER = NRF_DRV_TIMER_INSTANCE(1);
...
nrf_drv_timer_config_t timer_cfg = NRF_DRV_TIMER_DEFAULT_CONFIG;
err_code = nrf_drv_timer_init(&INACTIVITYTIMER, &timer_cfg, inactivity_timer_evt_handler);
...
time_ticks = nrf_drv_timer_ms_to_ticks(&INACTIVITYTIMER, time_ms);
nrf_drv_timer_extended_compare(&INACTIVITYTIMER, NRF_TIMER_CC_CHANNEL0, time_ticks, NRF_TIMER_SHORT_COMPARE0_CLEAR_MASK, true);

In ble_evt_handler on connect/disconnect events i start/stop the timer

 switch (p_ble_evt->header.evt_id)
    {
        case BLE_GAP_EVT_DISCONNECTED:
            NRF_LOG_INFO("Disconnected.");
            err_code = bsp_indication_set(BSP_INDICATE_DISCONNECTED);
            APP_ERROR_CHECK(err_code);
            nrf_drv_timer_disable(&INACTIVITYTIMER);
            board_state = DISCONNECTED;
            break;

        case BLE_GAP_EVT_CONNECTED:
            NRF_LOG_INFO("Connected.");
            err_code = bsp_indication_set(BSP_INDICATE_CONNECTED);
            APP_ERROR_CHECK(err_code);
            m_conn_handle = p_ble_evt->evt.gap_evt.conn_handle;
            err_code = nrf_ble_qwr_conn_handle_assign(&m_qwr, m_conn_handle);
            APP_ERROR_CHECK(err_code);
            nrf_drv_timer_enable(&INACTIVITYTIMER);
            board_state = CONNECTED;
            break;

And finally in the timer callback, sd_ble_gap_disconnect is invoked

 switch (event_type)
    {
    case NRF_TIMER_EVENT_COMPARE0:
      if (board_state == CONNECTED && m_conn_handle != BLE_CONN_HANDLE_INVALID)
        {
        sd_ble_gap_disconnect(m_conn_handle, BLE_HCI_REMOTE_USER_TERMINATED_CONNECTION);
        }

The environment i use is segger studio and sdk 17.02

The issue happens randomly after 2 to 20 manual reconnects

What am i doing wrong?

[ves]

It looks awneil is right. Its about NRF_ERROR_INVALID_STATE.

send_update_request is calling sd_ble_gap_conn_param_update and the error is returned by the last one.

According to the documentation the return value of sd_ble_gap_conn_param_update 

NRF_ERROR_INVALID_STATE

Disconnection in progress or link has not been established.

My guess now is that i am in the situation i send a disconnect when 52810 is already disconnected but disconnect event is not yet processed. 

Will dig further

[ves]

After further digging i have a theory.

I trigger the disconnect from my timer handler which has a timeout value of 5sec

The soft device performs a sd_ble_gap_conn_param_update from inside another timer (app timer) which has a timeout value of 5sec as it is set in my app

#define FIRST_CONN_PARAMS_UPDATE_DELAY  APP_TIMER_TICKS(5000)

Now between the trigger of disconnect and soft device entering disconnected state some time interval is needed.

If inside this time interval app_timer triggers sd_ble_gap_conn_param_update then this function will return an invalid state because the disconnect process is in progress.

Here is a log supporting this theory. I put a long info in my timer handler: “disconnect triggered” and another log info in send_update_request just before sd_ble_gap_conn_param_update

>>>> success case: disconnect happens before sd_ble_gap_conn_param_update

[00:00:04.996,459] <info> app: Connected.

[00:00:09.913,818] <info> app: disconnect triggered

[00:00:09.992,248] <info> app: Disconnected.

 

>>>> success case: disconnect happens before sd_ble_gap_conn_param_update

[00:00:09.992,309] <info> app: Connected.

[00:00:14.909,973] <info> app: disconnect triggered

[00:00:14.964,782] <info> app: Disconnected.

 

>>>> failure case: sd_ble_gap_conn_param_update is triggered before disconnect complete

[00:00:14.964,782] <info> app: Connected.

[00:00:19.883,544] <info> app: disconnect triggered

[00:00:19.964,782] <info> app: send_update_request

[00:00:19.969,482] <error> app: ERROR 8 [NRF_ERROR_INVALID_STATE] at C:\dev\52810\nRF5_SDK_17.0.2_d674dde\examples\ble_peripheral\ble_app_empty\main.c:339 PC at: 0x0001F429

[00:00:19.984,863] <error> app: End of error report

The bad luck was that both timeouts have the same value

I need Nordic if possible to confirm this theory and suggest a way to avoid this issue.

In my case disconnect is triggered by app and I can handle the invalid state return because I know the state of the app.

But this issue might happen also when disconnect is triggered by the remote device if it is triggered at some time close to   FIRST_CONN_PARAMS_UPDATE_DELAY 

[ves]

Hi Hung

thx for the answer.

Yes in case disconnect is triggered by the application the solution is ok, but in case disconnect is triggered by the remote device it doesnt work. The question which comes to my mind is if it is safe to ignore NRF_ERROR_INVALID_STATE. 

Would that be possible that sd_ble_gap_conn_param_update return value to tell the caller the action cannot be completed because a disconnect is in progress e.g. NRF_ERROR_BUSY, or...

[awneil]

ves said:

The question which comes to my mind is if it is safe to ignore NRF_ERROR_INVALID_STATE

That depends on your application!

The error tells you, "this call did nothing, because the system is in the wrong state".

• In your case, it seems you didn't want it to happen anyhow - so no harm done
• If, however, you thought you should have been in the right state, and you did want it to happen - then you're going to have to take some recovery action.

This is really just about software design - not particularly specific to Nordic.

[ves]

The setup is this one: i have my nrf52810 device connected with a remote device which is my phone.

If i trigger disconnect from the app on my 52810 and get into a NRF_ERROR_INVALID_STATE i can check if disconnect is in progress but not completed and can ignore  Its a transient state

If i trigger a disconnect from my pone and get into an invalid state on nrf52810 i have no clue if there is a disconnect in progress but not completed. So can i ignore it? Better would be if i can get some information from SD and this points to Nordic.

[Hung Bui]

Hi Viorel, 
No, there isn't an issue if the connection is disconnecting and you call sd_ble_gap_conn_param_update () before it's actually disconnected and you get NRF_ERROR_INVALID_STATE. The softdevice would simply ignore the command and proceed to disconnect. It's fine to ignore NRF_ERROR_INVALID_STATE error from sd_ble_gap_conn_param_update (). 

[ves]

Hi Hung

Take the second usecase in my previous post.

sd_ble_gap_conn_param_update on nrf52810 device returns NRF_ERROR_INVALID_STATE.

At this point i dont know if it is because a disconnect received over the air is in progress, so i can ignore it, or it is because some other reason, so i need to take some actions.

Then again the question if sd_ble_gap_conn_param_update can return other than invalid state error in case a disconnect is in progress

[ves]

.. or there is an other API which i can use to interrogate the status of the SD

[Hung Bui]

Hi Viorel, 
There are only two options that the function would return INVALID_STATE: Disconnection in progress or link has not been established.

In both case it wouldn't cause any consequence to the softdevice. You can safely ignore that. 

[ves]

Great and thanks!

I think this case can be closed now 

[awneil]

ves said:

I think this case can be closed now

You do that by marking the solution: