Crash at disconnect + RTT Viewer weird behavior

[genzy9]

Hello guys,

I am new in the BLE world.

I am currently using a BLE Android application running on a tablet + nrf52832 communication with another chip through UART.

I have this weird bug when I try to disconnect the connection from the tablet the nrf52 firmware just crash.

From the Android app I just call 

mBluetoothGatt.disconnect();

When the user press disconnect on the tablet. I expect the event  BLE_GAP_EVT_DISCONNECTED to be called in the nrf fw. I know the ble_evt_handler is called at least once since when the tablet connect to the device , the  BLE_GAP_EVT_CONNECTED event is triggered and processed. But for some reasons I dont get, I dont think the  BLE_GAP_EVT_DISCONNECTED is ever triggered since another module is supposed to receive data through UART when this even occurs and the data is never received. Plus it is supposed to advertise again but it does not. Instead I think it just reboots.

So I tried to used JTT viewer to debug with logs and once I connect to my device something weird happen: the UART message I am supposed to send when a disconnection occurs is sent, and the device start advertising again! How is that possible???

This is the code that handles the ble event:

static void ble_evt_handler(ble_evt_t const * p_ble_evt, void * p_context)
{
    static const char CONNECT[] = "hello";
    static const char DISCONNECT[] = "bye"; 
    ret_code_t err_code;

    switch (p_ble_evt->header.evt_id)
    {
        case BLE_GAP_EVT_CONNECTED:
            NRF_LOG_INFO("ble_evt_handler Connected");
                
            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);

            // SEND CONNECT to my module through UART
            ble_atk_send_UART_data(CONNECT,sizeof(CONNECT));                 
            break;

        case BLE_GAP_EVT_DISCONNECTED:
            NRF_LOG_INFO("ble_evt_handler Disconnected");

            ble_atk_send_UART_data(DISCONNECT,sizeof(DISCONNECT));
            
            // Start advertising again
            advertising_start();
            break;

My main roughly look lie that (simplified)

                    log_init();

                    NRF_LOG_INFO("Initialization");
                    timers_init();
                    uart_init();
                    power_management_init();
                    ble_stack_init();
                    set_passkey();
                    NRF_LOG_INFO("BLE Stack Init done");
                    
                    waitHello(); // wait until we received hello from UART from another module

                    // Last part of the init, once we received HELLO 
                    NRF_LOG_INFO("GAP init...");
                    gap_params_init();
                    NRF_LOG_INFO("GATT init...");
                    gatt_init();
                    NRF_LOG_INFO("Services init...");
                    services_init();
                    NRF_LOG_INFO("Peer manager init...");
                    peer_manager_init();
                    NRF_LOG_INFO("Connection parameter init...");
                    //delete_bonds();
                    conn_params_init();
                    NRF_LOG_INFO("Advertising init...");
                    advertising_init();
                    
                    advertising_start();
                    
                    for(;;) 
                    {
                        nrf_pwr_mgmt_run();
                    }

First part of the logs when the device start advertising and the android device connect:

As you can see the connection is ok and the last line shows me that the device is successfully disconnected.

But this happens only when RTT Viewer is running and printing logs!!!

If I disconnect RTT Viewer, the BLE_GAP_EVT_DISCONNECTED seems to be never called since no data is sent through UART and the device doesnt advertise again.

As long as RTT viewer is connected everything is OK, as long it is not running, I have this weird bug on disconnect and the device crash.

I know this might be confusing and hard to explain so if you have any ideas... I can provide everything just ask.

Thanks

EDIT:

I did not notice but I was using Debug mode and optimisation 0, so I moved to no debug flag and -O3 and it is better now. I just put a flag in BLE_GAP_EVT_DISCONNECTED  and BLE_GAP_EVT_CONNECTED to notice me this event occurred and I will process it directly in the main loop. Now it did the trick. I think I have a lot of BLE events that the handler is sometimes preempted by another ble interrupt.  

I dont know exactly what happened but this post helped me out: https://devzone.nordicsemi.com/f/nordic-q-a/25429/application-crash-after-disconnection

https://devzone.nordicsemi.com/f/nordic-q-a/13777/can-ble_nus_string_send-be-called-from-a-twi-callback

maybe I was calling an interrupt with low priority from an interrupt with high priority? 

Somehow heavy process must not be done in the ble handler

[Vidar Berg]

Hi,

It's generally good practice to keep the processing time inside interrupts short, but I'm not sure how it relates to the crash you mentioned. It's also a bit strange that it seems to work ok as long as you are debug mode (note: chip enters debug mode when you start viewing RTT messages). Have you kept the default error handling in your app (see Error module)? This is usually the only place where the app may trigger a reboot.

[genzy9]

You right. I just put a flag to true when DISCONNECT event is received and it will be handle in my main loop, seems to work for now, we will investigate later.

But the problem might be on our UART so not sure it's all related to the nrf52 chip.

Yes I did not change the default behavior. I am fine with rebooting in case of an error.

Let's consider the previous issue as solved for now.

Could you help me to solve the PM_EVT_CONN_SEC_FAILED ? What does it mean?

I set no security settings from Android side (all default) and from the nrf chip in the pm :

    // Security parameters to be used for all security procedures.
    sec_param.bond           = SEC_PARAM_BOND;
    sec_param.mitm           = 0;
    sec_param.io_caps        = BLE_GAP_IO_CAPS_DISPLAY_ONLY;
    sec_param.oob            = 0;
    sec_param.min_key_size   = 7;
    sec_param.max_key_size   = 16;
    sec_param.kdist_own.enc  = 1;
    sec_param.kdist_own.id   = 1;
    sec_param.kdist_peer.enc = 1;
    sec_param.kdist_peer.id  = 1;

[Vidar Berg]

The PM_EVT_CONN_SEC_FAILED event signals the application that a bonding or link encryption procedure has failed, but you have to check the event data (error code) to find the reason for the failure. Is PM_LOG_ENABLED set to '1' in your project? That should make the PM log the error code like this:

<info> peer_manager_handler: Connection security failed: role: Peripheral, conn_handle: 0x0, procedure: Encryption, error: 4102

Also, I don't think it's related to the failure, but  .io_caps should be set BLE_GAP_IO_CAPS_NONE when you are not setting the 'mitm' flag.