Bluetooth mesh provisioning freezes after the key exchange

[Vladimir]

Hi. Bluetooth mesh provisioning freezes. I tried to change gatt proxy for better compatibility with sdk 15. Mesh sdk: 2.2.0

I changed mesh_gatt.c file only:

Added:

static void gatt_handler(nrf_ble_gatt_t * p_gatt, nrf_ble_gatt_evt_t const * p_evt) {
    if (p_evt->evt_id == NRF_BLE_GATT_EVT_ATT_MTU_UPDATED) {
        m_gatt.connections[p_evt->conn_handle].effective_mtu = p_evt->params.att_mtu_effective;
    }
}

Then I removed following code because sdk 15 already handle that events in the same way:

/* TODO: The following events should be handled by an SDK module/the application. */
        case BLE_GATTS_EVT_SYS_ATTR_MISSING:
        {
            NRF_MESH_ERROR_CHECK(sd_ble_gatts_sys_attr_set(p_ble_evt->evt.gatts_evt.conn_handle, NULL, 0, 0));
            break;
        }

        case BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST:
        {
            ble_gap_data_length_params_t dl_params;
            memset(&dl_params, BLE_GAP_DATA_LENGTH_AUTO, sizeof(dl_params));
            NRF_MESH_ERROR_CHECK(sd_ble_gap_data_length_update(p_ble_evt->evt.gap_evt.conn_handle,
                                                               &dl_params,
                                                               NULL));
            break;
        }

        case BLE_GAP_EVT_SEC_PARAMS_REQUEST:
            NRF_MESH_ERROR_CHECK(sd_ble_gap_sec_params_reply(p_ble_evt->evt.gap_evt.conn_handle,
                                                             BLE_GAP_SEC_STATUS_PAIRING_NOT_SUPP,
                                                             NULL,
                                                             NULL));
            break;

        case BLE_GAP_EVT_PHY_UPDATE_REQUEST:
        {
            ble_gap_phys_t const phys =
            {
                .rx_phys = BLE_GAP_PHY_AUTO,
                .tx_phys = BLE_GAP_PHY_AUTO,
            };
            NRF_MESH_ERROR_CHECK(sd_ble_gap_phy_update(p_ble_evt->evt.gap_evt.conn_handle, &phys));
            break;
        }

        case BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST:
            exchange_mtu_req_handle(p_ble_evt);
            break;

Provisioning log:

 0> <t:      11881>, fsm.c,  199, PB-GATT bearer: state S_IDLE -> S_LISTENING
 0> <t:      11885>, mesh_initializer.c,   87, Device UUID : 005955BB000000004862CBB042C6BD93
 0> <error> nrf_ble_gatt: sd_ble_gap_data_length_update() (request) on connection 0x2 returned NRF_ERROR_RESOURCES.
 0> <error> nrf_ble_gatt: The requested TX/RX packet length is too long by 178/178 octets.
 0> <t:     545462>, fsm.c,  232, PB-GATT bearer: E: E_CONNECTED
 0> <t:     545469>, fsm.c,  185, PB-GATT bearer: A: A_LINK_OPEN
 0> <t:     545472>, fsm.c,  199, PB-GATT bearer: state S_LISTENING -> S_CONNECTED
 0> <t:     601791>, fsm.c,  232, PB-GATT bearer: E: E_TX_READY
 0> <t:     601794>, fsm.c,  185, PB-GATT bearer: A: A_LINK_TIMER_START
 0> <t:     601797>, fsm.c,  199, PB-GATT bearer: state S_CONNECTED -> S_LINK_ACTIVE
 0> <t:     649706>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:     649709>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:     649712>, prov_provisionee.c,  317, Provisionee: invite received!
 0> <t:     649715>, prov_provisionee.c,  110, Provisionee: sending capabilities
 0> <t:     649718>, fsm.c,  232, PB-GATT bearer: E: E_PDU_TX
 0> <t:     649721>, fsm.c,  185, PB-GATT bearer: A: A_PDU_TX
 0> <t:     652904>, fsm.c,  232, PB-GATT bearer: E: E_TX_COMPLETE
 0> <t:     652907>, fsm.c,  185, PB-GATT bearer: A: A_PDU_ACK
 0> <t:     652912>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:     652915>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:     652918>, prov_provisionee.c,  341, Provisionee: provisioning start message received!
 0> <t:     656145>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:     656148>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:     656151>, prov_provisionee.c,  369, Provisionee: public key message received!
 0> <t:     656155>, fsm.c,  232, PB-GATT bearer: E: E_PDU_TX
 0> <t:     656158>, fsm.c,  185, PB-GATT bearer: A: A_PDU_TX
 0> <t:     670467>, fsm.c,  232, PB-GATT bearer: E: E_TX_COMPLETE
 0> <t:     670471>, fsm.c,  185, PB-GATT bearer: A: A_PDU_ACK

[Vladimir]

I found that if I change MTU size to 23 provisioning will be completed successfully. Is it possible to set MTU size more than 23? Why this behavior occurs?

[Bjørn Kvaale]

Sorry for the delayed response. Could you please explain why you have gotten rid of the code? Where in sdk 15 is this being handled otherwise? Have you merged the mesh functionality with an sdk example?

[Vladimir]

Thank you for the reply.

BLE_GATTS_EVT_SYS_ATTR_MISSING is handled in the gatt_cache_manager.

BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST is handled in the nrf_ble_gatt

BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST is handled in the nrf_ble_gatt

BLE_GAP_EVT_SEC_PARAMS_REQUEST - security dispatcher

BLE_GAP_EVT_PHY_UPDATE_REQUEST - is handled by my code

I merged the mesh functionality with my project based on examples with own ble services.

[Hung Bui]

Hi Vladimir, 

I'm sorry for the late response. I just got the case from Bjørn and will try to assist you. 

Could you clarify which MTU size you set to 23 that make the provisioning worked ? 

In our proxy provisioning example we support upto 69byte MTU, I don't see any problem when doing provisioning with that MTU. 

I assume your plan is to have a merged application of normal BLE app and a proxy + mesh app together ? 

It's important to see when the provisioning crashed, turn on Logging (at debug level ) would give some more information about the provisioning and what went wrong. 

[Vladimir]

Is it possible that problem occurs because of Keil compiler?

I set MTU size 69 and provisioning freezes. sdk_config.h:

#ifndef NRF_SDH_BLE_GATT_MAX_MTU_SIZE
#define NRF_SDH_BLE_GATT_MAX_MTU_SIZE 69
#endif

But if I define NRF_SDH_BLE_GATT_MAX_MTU_SIZE equals 23 - everything is ok.

Yes, our plan is to use BLE and Mesh together.

Log from SEGGER RTT:

# SEGGER J-Link RTT Viewer V5.12f Terminal Log File
# Compiled: 16:04:47 on May 17 2016
# Logging started @ 19 Oct 2018 17:14:38
 0> <t:      11731>, fsm.c,  222, PB-GATT bearer: init
 0> <t:      11741>, prov_bearer_adv.c,  381, PB-ADV: context at 0x20007038 added to bearer
 0> <t:      11746>, fsm.c,  232, PB-GATT bearer: E: E_LISTEN_START
 0> <t:      11749>, fsm.c,  185, PB-GATT bearer: A: A_LISTEN_START
 0> <t:      11764>, fsm.c,  199, PB-GATT bearer: state S_IDLE -> S_LISTENING
 0> <t:    1651099>, fsm.c,  232, PB-GATT bearer: E: E_CONNECTED
 0> <t:    1651102>, fsm.c,  185, PB-GATT bearer: A: A_LINK_OPEN
 0> <t:    1651105>, fsm.c,  199, PB-GATT bearer: state S_LISTENING -> S_CONNECTED
 0> <t:    1751084>, fsm.c,  232, PB-GATT bearer: E: E_TX_READY
 0> <t:    1751087>, fsm.c,  185, PB-GATT bearer: A: A_LINK_TIMER_START
 0> <t:    1751090>, fsm.c,  199, PB-GATT bearer: state S_CONNECTED -> S_LINK_ACTIVE
 0> <t:    1792612>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:    1792615>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:    1792618>, prov_provisionee.c,  317, Provisionee: invite received!
 0> <t:    1792621>, prov_provisionee.c,  110, Provisionee: sending capabilities
 0> <t:    1792624>, fsm.c,  232, PB-GATT bearer: E: E_PDU_TX
 0> <t:    1792627>, fsm.c,  185, PB-GATT bearer: A: A_PDU_TX
 0> <t:    1795809>, fsm.c,  232, PB-GATT bearer: E: E_TX_COMPLETE
 0> <t:    1795812>, fsm.c,  185, PB-GATT bearer: A: A_PDU_ACK
 0> <t:    1795818>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:    1795820>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:    1795823>, prov_provisionee.c,  341, Provisionee: provisioning start message received!
 0> <t:    1799048>, fsm.c,  232, PB-GATT bearer: E: E_PDU_RX
 0> <t:    1799052>, fsm.c,  185, PB-GATT bearer: A: A_PDU_RX
 0> <t:    1799055>, prov_provisionee.c,  369, Provisionee: public key message received!
 0> <t:    1799058>, fsm.c,  232, PB-GATT bearer: E: E_PDU_TX
 0> <t:    1799061>, fsm.c,  185, PB-GATT bearer: A: A_PDU_TX
 0> <t:    1814973>, fsm.c,  232, PB-GATT bearer: E: E_TX_COMPLETE
 0> <t:    1814976>, fsm.c,  185, PB-GATT bearer: A: A_PDU_ACK
 0> <t:    3764959>, fsm.c,  232, PB-GATT bearer: E: E_LINK_TIMEOUT
 0> <t:    3764962>, fsm.c,  185, PB-GATT bearer: A: A_LINK_CLOSE
 0> <t:    3764965>, fsm.c,  199, PB-GATT bearer: state S_LINK_ACTIVE -> S_CONNECTED
 0> <t:    3766885>, fsm.c,  232, PB-GATT bearer: E: E_DISCONNECTED
 0> <t:    3766888>, fsm.c,  185, PB-GATT bearer: A: A_LINK_CLOSE_NOTIFY
 0> <t:    3766892>, prov_bearer_adv.c,  381, PB-ADV: context at 0x20007038 added to bearer
 0> <t:    3766896>, fsm.c,  199, PB-GATT bearer: state S_CONNECTED -> S_IDLE
 0> <t:    3766901>, fsm.c,  232, PB-GATT bearer: E: E_LISTEN_START
 0> <t:    3766904>, fsm.c,  185, PB-GATT bearer: A: A_LISTEN_START
 0> <t:    3766919>, fsm.c,  199, PB-GATT bearer: state S_IDLE -> S_LISTENING