MTU negotiation problem

[dingari]

I'm facing a rather strange problem with an nRF52832 board I'm developing for. I'm using SDK 15.2 and S132 v6.0.0.

Sometimes, during the connection/negotiation phase, my device seems to get stuck in a weird state and can't send notifications. I've examined my logs and found out that when it works, I receive BLE_GATTC_EVT_EXCHANGE_MTU_RSP, and when it gets stuck, there is no such event received.

This is an example of a failed connection attempt:

<info> app: BLE_GAP_EVT_CONNECTED, conn handle: 1, role: 1
<debug> app: max_conn_interval: 11 ms
<debug> app: min_conn_interval: 11 ms
<debug> app: slave_latency: 0 connection events
<debug> app: conn_sup_timeout: 2000 ms
<debug> nrf_ble_gatt: Data length updated to 64 on connection 0x1.
<debug> nrf_ble_gatt: max_rx_octets: 64
<debug> nrf_ble_gatt: max_tx_octets: 64
<debug> nrf_ble_gatt: max_rx_time: 2120
<debug> nrf_ble_gatt: max_tx_time: 2120
<debug> app: BLE EVENT: 0x0024
<debug> nrf_ble_gatt: Peer on connection 0x1 requested an ATT MTU of 515 bytes.
<debug> nrf_ble_gatt: Updating ATT MTU to 64 bytes (desired: 64) on connection 0x1.
<debug> app: BLE EVENT: 0x0055
<debug> app: BLE EVENT: 0x0050
<debug> app: BLE_GATTS_EVT_WRITE, handle: 0x0017, len: 2
<error> app: Failed to notify, error: NRF_ERROR_INVALID_STATE (0x0008)

The central I'm connecting to is a Mac. This happens in the logs on the central:

default	12:11:12.512164+0000	bluetoothd	Sending MTU Request - MTU:515 Transport:2
default	12:11:12.555573+0000	bluetoothd	Received MTU Response - Response:64 Requested:515 Transport:2

This is an example of a successful attempt:

<info> app: BLE_GAP_EVT_CONNECTED, conn handle: 1, role: 1
<debug> app: max_conn_interval: 11 ms
<debug> app: min_conn_interval: 11 ms
<debug> app: slave_latency: 0 connection events
<debug> app: conn_sup_timeout: 2000 ms
<debug> nrf_ble_gatt: Data length updated to 64 on connection 0x1.
<debug> nrf_ble_gatt: max_rx_octets: 64
<debug> nrf_ble_gatt: max_tx_octets: 64
<debug> nrf_ble_gatt: max_rx_time: 2120
<debug> nrf_ble_gatt: max_tx_time: 2120
<debug> app: BLE EVENT: 0x0024
<debug> nrf_ble_gatt: Peer on connection 0x1 requested an ATT MTU of 515 bytes.
<debug> nrf_ble_gatt: Updating ATT MTU to 64 bytes (desired: 64) on connection 0x1.
<debug> app: BLE EVENT: 0x0055
<debug> nrf_ble_gatt: ATT MTU updated to 64 bytes on connection 0x1 (response).
<debug> app: BLE EVENT: 0x003A
<debug> app: BLE EVENT: 0x0050

And the central:

default	12:14:35.229238+0000	bluetoothd	Sending MTU Request - MTU:515 Transport:2
default	12:14:35.260755+0000	bluetoothd	Received MTU Request - MTU:64 Transport:2
default	12:14:35.264938+0000	bluetoothd	Received MTU Response - Response:64 Requested:515 Transport:2

Is there anything obvious that could be missing in some parameters/negotiation steps?

[Simonr]

Hi

I think we're still misunderstanding one another. The MTU request is not required by the Bluetooth specification, but we have opted to add this MTU request in our on_connected_evt. on_connected_evt is not called before the BLE_GAP_CONNECTED event, but rather called when this event is triggered (l497 in nrf_ble_gatt.c)

void nrf_ble_gatt_on_ble_evt(ble_evt_t const * p_ble_evt, void * p_context)
{
    nrf_ble_gatt_t * p_gatt      = (nrf_ble_gatt_t *)p_context;
    uint16_t         conn_handle = p_ble_evt->evt.common_evt.conn_handle;

    if (conn_handle >= NRF_BLE_GATT_LINK_COUNT)
    {
        return;
    }

    switch (p_ble_evt->header.evt_id)
    {
        case BLE_GAP_EVT_CONNECTED:
            on_connected_evt(p_gatt, p_ble_evt);
            break;

        case BLE_GAP_EVT_DISCONNECTED:
            on_disconnected_evt(p_gatt, p_ble_evt);
            break;

        case BLE_GATTC_EVT_EXCHANGE_MTU_RSP:
            on_exchange_mtu_rsp_evt(p_gatt, p_ble_evt);
            break;

        case BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST:
            on_exchange_mtu_request_evt(p_gatt, p_ble_evt);
            break;

#if !defined (S112)
        case BLE_GAP_EVT_DATA_LENGTH_UPDATE:
            on_data_length_update_evt(p_gatt, p_ble_evt);
            break;

        case BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST:
            on_data_length_update_request_evt(p_gatt, p_ble_evt);
            break;
#endif // !defined (S112)

        default:
            break;
    }

Best regards,

Simon

[dingari]

Hi Simon,

I understand. I just meant that the GATT module receives BLE_GAP_CONNECTED before my application.

Don't you think there's an imposed problem if both peripheral and central simultaneously initiate an MTU update request? If I don't request the MTU update from the peripheral, I never get in the strange state where my notifications fail with NRF_ERROR_INVALID_STATE.

[Simonr]

Hi again

Can you check if you have an sd_ble_gattc_exchange_mtu_request() function somewhere else in your application, as an INVALID state from this function either means you've been disconnected (which does not seem to be the case) or that it an MTU request has already been sent, so it might be that this is called twice in your application for some reason.

Best regards,

Simon

[Marco Pennacchietti]

The only 2 call are in the original file nrf_ble_gatt.c  (in nrf_ble_gatt_on_ble_evt and on_connected_evt routine

Marco

[Simonr]

Hi

Please try one more thing. There is an event you can call and wait for in order to check whether notifications are enabled as well. It might not be implemented in your application as it is characteristic specifig, but you can check the on_write() function in the ble_app_uart example for reference. The generated BLE_NUS_EVT_COMM_STARTED; will confirm that notifications are enabled here.

Please let us know how and where you enable notifications from your central device. 

Best regards,

Simon