Keyboard example failure in sending keys after power-cycle with Android KitKat

[MJin]

Hello

We are facing problem and please help us how to solve this problem.

> Condition,

- NRF52 DK
- SDK version: nRF5_SDK_14.2.0_17b948a
- Examble: ble_peripheral\ble_app_hids_keyboard

> Problem:

- Pairing to Android KitKat 4.4.2 or 4.4.4

- Sending characters "hello" by pressing button 1 is working well

- Power-cycle and connected again(previously bonded device)

- Sending characters "hello" by pressing button 1 is not working....(Higher Android version and Windows 10, iOS is OK)

- Our developing keyboard (based on ble_peripheral\ble_app_hids_keyboard) has same problem.

> Under analysis

sd_ble_gatts_hvx returns NRF_ERROR_INVALID_STATE in ble_hids_inp_rep_send() even after normal connection.

I'm finding a answers in Q&A, but not easy to get answers,

Please give us any tips or help for this problem.

Sincerely yours,

[Susheel Nuguru]

hvx will return invalid state error if there is no connection. Can you please make sure that you are calling hvx while you are still in connection? It seems that there could be a disconnect event that has been ignored?

[MJin]

1. sd_ble_gatts_hvx() returns NRF_ERROR_INVALID_STATE when connection is okey, there is no BLE_GAP_EVT_DISCONNECTED event.

2. I've compared to Android KitKat and others(windows 10)

In KitKat, BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST event was not received. 

What Should I check?, please help me.

-----------------------------------------------------------------------------------------------------------------------------------

Following is a dump trace of "nRF5_SDK_14.2.0_17b948a\examples\ble_peripheral\ble_app_hids_keyboard"

I Added a trace in nrf_ble_gatt_on_ble_evt() like this

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;
}

NRF_LOG_INFO("[%s:%d] p_ble_evt->header.evt_id: 0x%02x", __func__, __LINE__, p_ble_evt->header.evt_id);

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

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

------------------------------------------------------------------------------------------------------------------------------

1. Windows 10 after power-cycle

0> <info> app: HID Keyboard example started.
0> <debug> app: pm_whitelist_get returns 1 addr in whitelist and 1 irk whitelist
0> <info> app: Fast advertising with whitelist.
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x10
0> <info> ble_gatt: BLE_GAP_EVT_CONNECTED
0> <info> app: Connected to a previously bonded device.
0> <info> app: [on_connect:105] p_hids->conn_handle : 0
0> <info> app: Connected
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x23
0> <info> ble_gatt: BLE_GAP_EVT_DATA_LENGTH_UPDATE_REQUEST
0> <debug> ble_gatt: Peer on connection 0x0 requested a data length of 251 bytes.
0> <debug> ble_gatt: Updating data length to 27 bytes on connection 0x0.
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x24
0> <info> ble_gatt: BLE_GAP_EVT_DATA_LENGTH_UPDATE
0> <debug> ble_gatt: Data length updated to 27 on connection 0x0.
0> <debug> ble_gatt: max_rx_octets: 27
0> <debug> ble_gatt: max_tx_octets: 27
0> <debug> ble_gatt: max_rx_time: 328
0> <debug> ble_gatt: max_tx_time: 328
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x14
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x1A
0> <info> app: Connection secured: role: 1, conn_handle: 0x0, procedure: 0.
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x55
0> <info> ble_gatt: BLE_GATTS_EVT_EXCHANGE_MTU_REQUEST
0> <debug> ble_gatt: Peer on connection 0x0 requested an ATT MTU of 525 bytes.
0> <debug> ble_gatt: Updating ATT MTU to 23 bytes (desired: 23) on connection 0x0.
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x50
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x57

///////////////////////////////////////////////////////////////////////////////////////////////////////

2. KitKat 4.4.2 after power-cycle

0> <info> app: HID Keyboard example started.
0> <debug> app: pm_whitelist_get returns 1 addr in whitelist and 1 irk whitelist
0> <info> app: Fast advertising with whitelist.
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x10
0> <info> ble_gatt: BLE_GAP_EVT_CONNECTED
0> <info> app: Connected to a previously bonded device.
0> <info> app: [on_connect:105] p_hids->conn_handle : 0
0> <info> app: Connected
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x14
0> <info> ble_gatt: [nrf_ble_gatt_on_ble_evt:499] p_ble_evt->header.evt_id: 0x1A
0> <info> app: Connection secured: role: 1, conn_handle: 0x0, procedure: 0.
0> <info> app: [ble_hids_inp_rep_send:1282] err_code:8
0> <info> app: [ble_hids_inp_rep_send:1300] err_code:8
0> <info> app: [send_key_scan_press_release:920] err_code:8
0> <info> app: 8 = keys_send(1)
0> <info> app: [ble_hids_inp_rep_send:1282] err_code:8
0> <info> app: [ble_hids_inp_rep_send:1300] err_code:8
0> <info> app: [send_key_scan_press_release:920] err_code:8
0> <info> app: 8 = keys_send(1)
0> <info> app: [ble_hids_inp_rep_send:1282] err_code:8
0> <info> app: [ble_hids_inp_rep_send:1300] err_code:8
0> <info> app: [send_key_scan_press_release:920] err_code:8
0> <info> app: 8 = keys_send(1)

[MJin]

If you test "nRF5_SDK_14.2.0_17b948a\examples\ble_peripheral\ble_app_hids_keyboard" with KitKat, you can see it.

[Susheel Nuguru]

kitkat is quite old and  it is very likely that the ble stack on the phone with kitkat probably has some bugs. errors like this are easily pinpointed if you get some sniffer log of the BLE traffic from these devices.

[MJin]

Hello Aryan

It took a time getting a log.

Hear are logs with normal Window10 and strange KitKat 4.4.2.

Please give me a tip why nRF52 could not send "hello" in second connection.

Sincerely yours,

nRF52DK MAC: 81:bd:6a:a1:59:c1
Win10 BT MAC: B0-35-9F-81-D6-83
KitKat 4.4.2 BT MAC: BC:72:B1:CF:C5:56 <-- Not visible in log8688.2018.6.18 nRF Sniffer Test.zip

[Susheel Nuguru]

Your log is showing only the data packets and seems like it cannot be filtered based on protocol. I cannot debug it since to do that i need to decode each and every data packet. I am not an expert in wireshark, but there must be a way where your output log will allow me to filter packets based on protocol (for example, L2CAP or HCI etc)