SDK10.0.0 hid_keyboard reset issues

[helen]

Hi,

My customer occur a problem with nRF5 SDK10.0.0, the sample ble_app_hids_keyboard.

We test the sample on nRF51DK.

We connect the DK with an Android phone, and bonded(with nrf connect).

Then when I turn off the bluetooth, the DK reset(I add a printf at the front of the main function, which was the only change of the sample).

And I test with SDK11.0.0, there isn't the problem. 

1、Is it a bug of SDK10.0.0?

1、My customer develop there project with 10.0.0, is there any method to fix the issue?

Fullscreen 8400.log.txt Download

[18:00:58.981]收←◆***
[18:00:59.232]收←◆*************system start*******************

[DM]: >> dm_init.
[DM]: Initializing Application Instance 0x00000000.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000001.
[DM]: Initializing Peer Instance 0x00000002.
[DM]: Initializing Peer Instance 0x00000003.
[DM]: Initializing Peer Instance 0x00000004.
[DM]: Initializing Peer Instance 0x00000005.
[DM]: Initializing Peer Instance 0x00000006.
[DM]: Storage handle 0x0003F800.
[DM]:[0x00]: Block handle 0x0003F800.
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x01]: Block handle 0x0003F858.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x02]: Block handle 0x0003F8B0.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x03]: Block handle 0x0003F908.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x04]: Block handle 0x0003F960.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x05]: Bloca0003[0FFvFFFFFFFFFFF0h0003[0FFeFFFFFxFFFFFi]e[DM]: >> dm_whw, :
[18:01:06.787]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]: Searching for device 0x90 0x76 0x0E 0x64 0xA6 0x62.
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x05]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x06]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]: Notifying application of event 0x11

[18:01:10.238]收←◆[DM]: Disconnect Reason 0x0013
[DM]: Notifying application of event 0x12
[DM]:[CI 0x00]: Freeing connection instance
[DM]:[00]: Freed connection instance.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: >> dm_whitelist_create
[DM]: Created whitelist, number of IRK = 0x00, number of addr = 0x00
[DM]: << dm_whitelist_create
[ADV]: Starting fast advertisement.

[18:01:40.243]收←◆[ADV]: Timed out from fast advertising, starting slow advertising.
[DM]: >> dm_whitelist_create
[DM]: Created whitelist, number of IRK = 0x00, number of addr = 0x00
[DM]: << dm_whitelist_create
[ADV]: Starting slow advertisement.

[18:02:10.332]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]: Searching for device 0x90 0x76 0x0E 0x64 0xA6 0x62.
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x05]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x06]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]: Notifying application of event 0x11

[18:02:12.294]收←◆[DM]: Disconnect Reason 0x0013
[DM]: Notifying application of event 0x12
[DM]:[CI 0x00]: Freeing connection instance
[DM]:[00]: Freed connection instance.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: >> dm_whitelist_create
[DM]: Created whitelist, number of IRK = 0x00, number of addr = 0x00
[DM]: << dm_whitelist_create
[ADV]: Starting fast advertisement.

[18:02:18.270]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]: Searching for device 0x90 0x76 0x0E 0x64 0xA6 0x62.
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x05]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x06]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]: Notifying application of event 0x11

[18:02:21.360]收←◆[DM]: Disconnect Reason 0x0013
[DM]: Notifying application of event 0x12
[DM]:[CI 0x00]: Freeing connection instance
[DM]:[00]: Freed connection instance.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: >> dm_whitelist_create
[DM]: Created whitelist, number of IRK = 0x00, number of addr = 0x00
[DM]: << dm_whitelist_create
[ADV]: Starting fast advertisement.

[18:02:25.339]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]: Searching for device 0x90 0x76 0x0E 0x64 0xA6 0x62.
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x05]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[DI 0x06]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]: Notifying application of event 0x11

[18:02:27.650]收←◆[DM]: >> BLE_GAP_EVT_SEC_PARAMS_REQUEST
[DM]:[DI 0x00]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]: Allocated device instance 0x00
[DM]:[CI 0x00]:[DI 0x00]: Bonded!
[DM]: 0x01, 0x01, 0x01, 0x01
[DM]: Notifying application of event 0x13

[18:02:30.039]收←◆[DM]: >> BLE_GAP_EVT_CONN_SEC_UPDATE, Mode 0x01, Level 0x02
[DM]: --> gatts_context_apply
[DM]:[CI 0x00]: State 0x86, Size 0x00000000
[DM]: Notifying application of event 0x15

[18:02:30.188]收←◆[DM]: >> BLE_GAP_EVT_AUTH_STATUS, status 00000000

0x00 0x04 0x03 0x00 0x03 0x02 

0xC5 0x9F 0x78 0xF1 0x6B 0x2F 0x40 0x5B 0xD0 0x26 0xE1 0xC8 0x4F 0xAB 0xEE 0x62 0x20 0x00 0x48 0xC9 0x55 0x0D 0xD8 0x43 0x27 0x56 0xBC 0x31 
[DM]:[CI 0x00]:[DI 0x00]: Bonded!
[DM]: --> device_context_store
[DM]:[DI 00]:[CI 00]: -> Storing bonding information.
[DM]: --> gatts_context_store
[DM]:[0x00]: Storing service context

0x03 0x00 0x00 0x00 0x14 0x00 0x00 0x00 0x11 0x00 0x02 0x00 0x00 0x00 0x17 0x00 0x02 0x00 0x00 0x00 0x20 0x00 0x02 0x00 0x00 0x00 0xFD 0x3E 
[DM]:[0x00]: GATTS Data size 0x00000014
[DM]: Service context successfully stored.
[DM]: Notifying application of event 0x14
[DM]:[0x00]:[0xFF]: Bond context Event
[DM]: Notifying application of event 0x22
[DM]:[0x00]:[0xFF]: Service context Event
[DM]: Notifying application of event 0x32

[18:02:31.284]收←◆[DM]: >> dm_service_context_set
[DM]: --> gatts_context_store
[DM]:[0x00]: Updating stored service context

0x03 0x00 0x00 0x00 0x14 0x00 0x00 0x00 0x11 0x00 0x02 0x00 0x00 0x00 0x17 0x00 0x02 0x00 0x01 0x00 0x20 0x00 0x02 0x00 0x00 0x00 0x2E 0x79 
[DM]:[0x00]: GATTS Data size 0x00000014
[DM]: Service context successfully stored.
[DM]: << dm_service_context_set

[18:02:31.683]收←◆[DM]:[?**
[18:02:31.938]收←◆*************system start*******************

[DM]: >> dm_init.
[DM]: Initializing Application Instance 0x00000000.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000001.
[DM]: Initializing Peer Instance 0x00000002.
[DM]: Initializing Peer Instance 0x00000003.
[DM]: Initializing Peer Instance 0x00000004.
[DM]: Initializing Peer Instance 0x00000005.
[DM]: Initializing Peer Instance 0x00000006.
[DM]: Storage handle 0x0003F800.
[DM]:[0x00]: Block handle 0x0003F800.
[DM]:[DI 0x00]: Device type 0x00.
[DM]: Device Addr 0x01 0x00 0x00 0x46 0x00 0x00.
[DM]:[0x01]: Block handle 0x0003F858.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x02]: Block handle 0x0003F8B0.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x03]: Block handle 0x0003F908.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x04]: Block handle 0x0003F960.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[000003F0cFFFFFFFF FFF]00003F0yFFFFFFFFxFFF<ra.[DM]: >> dm_wth0ft[: 
[18:02:32.430]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]:[00]:[Block ID 0x0003F800]:Loading bond information at 200028f4, size 0x0000001C, offset 0x0000001C.
[DM]:[0x00]:[0xFF]: Bond context Event
[DM]: Notifying application of event 0x21
[DM]:[00]:Loading service context at 20002910, size 0x0000001C, offset 0x00000038.
[DM]:[CI 0x00]:[DI 0x00]: --> gatts_context_load
[DM]:[0x00]:[0xFF]: Service context Event
[DM]: Notifying application of event 0x31
[DM]:[00]:[Block ID 0x0003F800]: Service context loaded, size 0x00000014

0x03 0x00 0x00 0x00 0x14 0x00 0x00 0x00 0x11 0x00 0x02 0x00 0x00 0x00 0x17 0x00 0x02 0x00 0x00 0x00 0x20 0x00 0x02 0x00 0x00 0x00 0xFD 0x3E 
[DM]: Notifying application of event 0x11

[18:02:33.023]收←◆[DM]: >> BLE_GAP_EVT_SEC_INFO_REQUEST

0xC5 0x9F 0x78 0xF1 0x6B 0x2F 0x40 0x5B 0xD0 0x26 0xE1 0xC8 0x4F 0xAB 0xEE 0x62 0x20 

[18:02:33.123]收←◆[DM]: >> BLE_GAP_EVT_CONN_SEC_UPDATE, Mode 0x01, Level 0x02
[DM]: --> gatts_context_apply
[DM]:[CI 0x00]: State 0x8A, Size 0x00000014
[DM]: Setting stored context.
[DM]: Notifying application of event 0x15

[18:03:01.103]收←◆[DM]: Disconnect Reaso?**
[18:03:01.361]收←◆*************system start*******************

[DM]: >> dm_init.
[DM]: Initializing Application Instance 0x00000000.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000001.
[DM]: Initializing Peer Instance 0x00000002.
[DM]: Initializing Peer Instance 0x00000003.
[DM]: Initializing Peer Instance 0x00000004.
[DM]: Initializing Peer Instance 0x00000005.
[DM]: Initializing Peer Instance 0x00000006.
[DM]: Storage handle 0x0003F800.
[DM]:[0x00]: Block handle 0x0003F800.
[DM]:[DI 0x00]: Device type 0x00.
[DM]: Device Addr 0x01 0x00 0x00 0x46 0x00 0x00.
[DM]:[0x01]: Block handle 0x0003F858.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x02]: Block handle 0x0003F8B0.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x03]: Block handle 0x0003F908.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x04]: Block handle 0x0003F960.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[000003Fx:FFFFFFFFFFFFFF00003F  FFFFFFFFFFFFFmIr[DM]: >> dm_we 0 h[]h
[18:03:15.982]收←◆[DM]: Request to allocation connection instance
[DM]:[00]: Connection Instance Allocated.
[DM]:[00]:[Block ID 0x0003F800]:Loading bond information at 200028f4, size 0x0000001C, offset 0x0000001C.
[DM]:[0x00]:[0xFF]: Bond context Event
[DM]: Notifying application of event 0x21
[DM]:[00]:Loading service context at 20002910, size 0x0000001C, offset 0x00000038.
[DM]:[CI 0x00]:[DI 0x00]: --> gatts_context_load
[DM]:[0x00]:[0xFF]: Service context Event
[DM]: Notifying application of event 0x31
[DM]:[00]:[Block ID 0x0003F800]: Service context loaded, size 0x00000014

0x03 0x00 0x00 0x00 0x14 0x00 0x00 0x00 0x11 0x00 0x02 0x00 0x00 0x00 0x17 0x00 0x02 0x00 0x00 0x00 0x20 0x00 0x02 0x00 0x00 0x00 0xFD 0x3E 
[DM]: Notifying application of event 0x11

[18:03:16.260]收←◆[DM]: >> BLE_GAP_EVT_SEC_INFO_REQUEST

0xC5 0x9F 0x78 0xF1 0x6B 0x2F 0x40 0x5B 0xD0 0x26 0xE1 0xC8 0x4F 0xAB 0xEE 0x62 0x20 

[18:03:16.504]收←◆[DM]: >> BLE_GAP_EVT_CONN_SEC_UPDATE, Mode 0x01, Level 0x02
[DM]: --> gatts_context_apply
[DM]:[CI 0x00]: State 0x8A, Size 0x00000014
[DM]: Setting stored context.
[DM]: Notifying application of event 0x15

[18:03:45.183]收←◆[DM]: Disconnect Reaso?**
[18:03:45.442]收←◆*************system start*******************

[DM]: >> dm_init.
[DM]: Initializing Application Instance 0x00000000.
[DM]: Initializing Connection Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000000.
[DM]: Initializing Peer Instance 0x00000001.
[DM]: Initializing Peer Instance 0x00000002.
[DM]: Initializing Peer Instance 0x00000003.
[DM]: Initializing Peer Instance 0x00000004.
[DM]: Initializing Peer Instance 0x00000005.
[DM]: Initializing Peer Instance 0x00000006.
[DM]: Storage handle 0x0003F800.
[DM]:[0x00]: Block handle 0x0003F800.
[DM]:[DI 0x00]: Device type 0x00.
[DM]: Device Addr 0x01 0x00 0x00 0x46 0x00 0x00.
[DM]:[0x01]: Block handle 0x0003F858.
[DM]:[DI 0x01]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x02]: Block handle 0x0003F8B0.
[DM]:[DI 0x02]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x03]: Block handle 0x0003F908.
[DM]:[DI 0x03]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0x04]: Block handle 0x0003F960.
[DM]:[DI 0x04]: Device type 0xFF.
[DM]: Device Addr 0xFF 0xFF 0xFF 0xFF 0xFF 0xFF.
[DM]:[0h0003[0FFiFFF F0FFFFF0o000300 F[FFFFFFFxFFFd[c[DM]: >> dm_wh 0 h[ w

[Edvin]

Hello,

Try to add DEBUG to your preprocessor definitions and set a breakpoint inside the error handler (app_error_handler() in app_error.c, line 49).

See if this breakpoint is hit or not. If it is hit, what is the error_code, line_num and p_file_name (add it to watch to see the actual file name). 

Best regards,

Edvin

[helen]

Hi Edvin,

At the main function, I can set a breakpoint.

but at the app_error.h(you said app_error.c, but I think you mean app_error.h), I am not able to set a breakpoint there, neither the app_error.c

Do you have a nRF51DK? If so, maybe you can have a test with nRF5 SDK 10.0.0.

Bonding with a cellphone and then turn off the buletooth, the DK will reset.

[Edvin]

I meant the app_error.c file:

As you can see, I set a breakpoint here (app_error.c line 82). As you can see, I have added m_error_code, m_line_num and p_file_name to "Watch 1", so that I can see them in the "Watch 1" window in the bottom right. To test that this works, you can do as I did here, to add APP_ERROR_CHECK(1) somewhere in your project, just to see that the breakpoint triggers correctly, and that you can see the location (file name and line number), and the error_code (1) in these parameters.

Note that the line number (and error_code) is in hexadecimal format. In this case, it means 0x214 = 532 decimal.

Actually, I tested the ble_app_hids_keyboard from SDK10.0.0, and I see that the device resets. As I suspected, it is the error handler that receives an error_code != 0.

In fact, it is line 10 in this snippet in on_adv_evt() in main.c:

case BLE_ADV_EVT_PEER_ADDR_REQUEST:
        {
            ble_gap_addr_t peer_address;

            // Only Give peer address if we have a handle to the bonded peer.
            if(m_bonded_peer_handle.appl_id != DM_INVALID_ID)
            {
                            
                err_code = dm_peer_addr_get(&m_bonded_peer_handle, &peer_address);
                APP_ERROR_CHECK(err_code);

                err_code = ble_advertising_peer_addr_reply(&peer_address);
                APP_ERROR_CHECK(err_code);
                
            }
            break;

So the dm_peer_addr_get returns 0x8005:

NB: I needed to turn off optimization, because the file name was optimized out, so it looked like jibberish before I did:

So to the problem:

I guess that the whitelist is requested before the device manager (dm) is done storing the data in flash. Since it is fixed in SDK11.0.0, I don't think we should spend much time on this. You can look at how this is implemented in SDK11.0.0. 

Alternatively, you can add a small delay before you start advertising after the disconnect. Currently, the advertisement is started on line 384 in ble_advertising.c.

Comment out that part, and add ble_advertising_start() after a small amount of time from main.c, and see if that helps.

Best regards,

Edvin