Connection using old pairing information saved

I am running an experiment to use a static keys for pairing information without breaking the existing flow of pairing/bonding.
What I am doing is I am storing the pairing info of my central device and storing it into a structure and then erasing the flash to remove those information, and after reset I am retrieving those bonding information and connecting again using the same central devices but I am getting "Peer removed bonding info" response on my phone.

void store_ltk_in_zephyr(void)
{
    int id, err;
    struct bt_keys pairing_info = {
    .addr = {
        .type = BT_ADDR_LE_PUBLIC,
        .a.val = {0x43,0x82,0x5E,0xC7,0xE8,0xF4,0xFD}
    },
    .irk = {0x8A, 0x27, 0x1E, 0xA7, 0x92, 0x2A, 0xF0, 0x15, 0x41, 0x69, 0x48, 0xDD, 0xC0, 0x7E, 0xDD, 0xF7},
    .ltk = {
        .val = {0xc0, 0xe6, 0x9a, 0x0a, 0xf7, 0x4b, 0xdc, 0xb7, 0x7d, 0x23, 0xf4, 0xb4, 0x89, 0x8d, 0x96, 0x02},
        .ediv = {0x00,0x00},
        .rand = {0x00,0x00,0x00,0x00,0x00,0x00,0x00,0x00},
      }
    };

    // Store the keys using the settings API
    err = bt_keys_store(&pairing_info);
    if (err) {
        printk("Failed to store keys (err %d)\n", err);
    } else {
        printk("Keys stored successfully\n");
    }
}


In main, I am calling like this to load the info onto the flash- 

  settings_subsys_init();
  //smp_bt_register();
	bt_conn_auth_cb_register(&auth_cb_display);
  bt_conn_auth_info_cb_register(&conn_auth_info_callbacks);
	err = bt_enable(NULL);
	if (err) {
		printk("Bluetooth init failed (err %d)\n", err);
    k_sleep(K_MSEC(100));
		err = bt_enable(NULL);                                      //Trying one more time after this system reset
    if(err) NVIC_SystemReset();
	}
  store_ltk_in_zephyr();
  if (IS_ENABLED(CONFIG_SETTINGS)) {
    settings_load();
  }


And on connect I am using like this-
  bt_conn_set_security(conn, BT_SECURITY_L1|BT_SECURITY_FORCE_PAIR);


Do let me know, how can I connect with the same bonding info which I have made a copy of from the same bonding structure.

Parents
  • Hello,

    To troubleshoot this, I recommend you start by enabling CONFIG_BT_LOG_SNIFFER_INFO to have the keys printed on boot. This would help confirm us confirm if they keys were successfully stored or not.

    Best regards,

    Vidar

  • I am reading the pairing info using nrfjprog --memrd 0xfe000 -n 1024, as I know its taking the info from the settings page and the address of the page is this -

    Not getting any logs related to bonding on boot using CONFIG_BT_LOG_SNIFFER_INFO.

  • It's because you have enabled debug logging in HCI core. Please try to disable that to reduce the total number of logs messages. 

    You can also enable CONFIG_BT_KEYS_LOG_LEVEL_DBG=y CONFIG_BT_SMP_LOG_LEVEL_DBG=y to enable more logging relevant for BLE security.

  • ou can also enable CONFIG_BT_KEYS_LOG_LEVEL_DBG=y CONFIG_BT_SMP_LOG_LEVEL_DBG=y to enable more logging relevant for BLE security.

    Getting these logs from the suggestions-

    00> [00:00:00.020,874] <inf> fs_nvs: 2 Sectors of 4096 bytes
    00> [00:00:00.020,904] <inf> fs_nvs: alloc wra: 0, f98
    00> [00:00:00.020,904] <inf> fs_nvs: data wra: 0, b4
    00> [00:00:06.323,638] <inf> bt_sdc_hci_driver: SoftDevice Controller build revision: 
    00>                                             36 f0 e5 0e 87 68 48 fb  02 fd 9f 82 cc 32 e5 7b |6....hH. .....2.{
    00>                                             91 b1 5c ed                                      |..\.             
    00> [00:00:06.326,904] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
    00> [00:00:06.326,934] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
    00> [00:00:06.326,965] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 54.58864 Build 1214809870
    00> [00:00:06.327,331] <dbg> bt_smp: bt_smp_init: LE SC enabled
    00> [00:00:06.327,636] <inf> bt_hci_core: No ID address. App must call settings_load()
    00> BT is ready now 
    00> [00:00:06.328,247] <dbg> bt_keys: bt_keys_store: Stored keys for F4:E8:C7:5E:82:43 (public)
    00> Keys stored successfully
    00> [00:00:06.328,674] <dbg> bt_keys: keys_set: name f4e8c75e82430 val 0000000000000000000000000000c0e69a0af74bdcb77d23f4b4898d96028a271ea7922af015416948ddc07eddf7000000000000000000000000000000000000
    00> [00:00:06.328,887] <dbg> bt_keys: bt_keys_get_addr: F4:E8:C7:5E:82:43 (public)
    00> [00:00:06.329,101] <dbg> bt_keys: bt_keys_get_addr: created 0x2001265c for F4:E8:C7:5E:82:43 (public)
    00> [00:00:06.329,284] <dbg> bt_keys: keys_set: Successfully restored keys for F4:E8:C7:5E:82:43 (public)
    00> [00:00:06.329,925] <inf> bt_hci_core: Identity: D3:C4:88:DC:F4:8D (random)
    00> [00:00:06.329,956] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x118f, manufacturer 0x0059
    00> [00:00:06.329,986] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x118f
    00> Bluetooth initialized
    00> Advertising successfully started
    00> [00:00:06.336,639] <err> bt_gatt: Unable to register handle 0x002d
    00> [00:00:06.360,717] <dbg> bt_smp: bt_smp_pkey_ready: 

  • It should be printed when BLE is enabled. What logs are you getting? Is the Bluetooth ID being printed.

    For printing the logs that you have mentioned, bt_dev_show_info() has to be called which is called in the call stack -


    But in my call stack this loop exited before calling for bt_dev_show_info() because of the highlighted part.

  • The ID is correctly printed after settings_load(). Next you may want to verify that the key and peer andress have the correct endianess. If you use the same phone to bond with your zephyr application, do you see the same public address in your bond table?

    And on connect I am using like this-
    Fullscreen
    1
    bt_conn_set_security(conn, BT_SECURITY_L1|BT_SECURITY_FORCE_PAIR);
    XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
      bt_conn_set_security(conn, BT_SECURITY_L1|BT_SECURITY_FORCE_PAIR);
    The BT_SECURITY_FORCE_PAIR flag should not be set if you want the link to be encrypted with the existing key. Also the sec. level should be set to '2'.
  • The BT_SECURITY_FORCE_PAIR flag should not be set if you want the link to be encrypted with the existing key. Also the sec. level should be set to '2'.

    I have made these changes and tried to connect, but the issue remains same.

    I am seeing below logs when trying to connect-

    00> Connected
    00> [00:00:32.147,583] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:32.147,766] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.147,949] <dbg> bt_keys: bt_keys_get_addr: created 0x200126b8 for 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.148,162] <dbg> bt_smp: smp_init: prnd 1b6108926f3a6d0aa5ca0235c29450af
    00> [00:00:32.303,466] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x20004250 conn 0x20003e58 handle 0 encrypt 0x00 hci status 0x06
    00> Security failed: 5D:F9:D2:71:90:43 (random) level 1 err 2
    00> [00:00:32.303,680] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:32.303,863] <dbg> bt_smp: smp_init: prnd c58951f430b834164a58620adc842f37
    00> [00:00:32.393,463] <dbg> bt_smp: bt_smp_disconnected: chan 0x20004250 cid 0x0006
    00> [00:00:32.393,646] <dbg> bt_keys: bt_keys_clear: 5D:F9:D2:71:90:43 (random) (keys 0x0000)
    00> MTU exchange failed (err 14)[00:00:32.394,317] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.394,500] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> Disconnected (reason 0x13)

Reply
  • The BT_SECURITY_FORCE_PAIR flag should not be set if you want the link to be encrypted with the existing key. Also the sec. level should be set to '2'.

    I have made these changes and tried to connect, but the issue remains same.

    I am seeing below logs when trying to connect-

    00> Connected
    00> [00:00:32.147,583] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:32.147,766] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.147,949] <dbg> bt_keys: bt_keys_get_addr: created 0x200126b8 for 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.148,162] <dbg> bt_smp: smp_init: prnd 1b6108926f3a6d0aa5ca0235c29450af
    00> [00:00:32.303,466] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x20004250 conn 0x20003e58 handle 0 encrypt 0x00 hci status 0x06
    00> Security failed: 5D:F9:D2:71:90:43 (random) level 1 err 2
    00> [00:00:32.303,680] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:32.303,863] <dbg> bt_smp: smp_init: prnd c58951f430b834164a58620adc842f37
    00> [00:00:32.393,463] <dbg> bt_smp: bt_smp_disconnected: chan 0x20004250 cid 0x0006
    00> [00:00:32.393,646] <dbg> bt_keys: bt_keys_clear: 5D:F9:D2:71:90:43 (random) (keys 0x0000)
    00> MTU exchange failed (err 14)[00:00:32.394,317] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:32.394,500] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> Disconnected (reason 0x13)

Children
  • Please verify that they keys and addresses are stored with the correct endianess.

  • Please verify that they keys and addresses are stored with the correct endianess.

    Verified the endianess of the address, but strangely I got pairing request in one of the connecting state and suddenly connection dropped and when I tried to reconnect then showed the same issue of "Peer removed pairing info" -

    Sharing the complete logs-

    00> Connected
    00> [00:00:14.397,277] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:14.397,460] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:14.397,644] <dbg> bt_keys: bt_keys_get_addr: created 0x200126b8 for 5D:F9:D2:71:90:43 (random)
    00> [00:00:14.397,827] <dbg> bt_smp: smp_init: prnd eceb84c80129c1c1d95fe1f0fdf379a1
    00> MTU exchange done[00:00:14.921,752] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x003a
    00> [00:00:15.341,827] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:15.342,010] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:15.371,490] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x01 len 6
    00> [00:00:15.371,520] <dbg> bt_smp: smp_pairing_req: req: io_capability 0x04, oob_flag 0x00, auth_req 0x09, max_key_size 0x10, init_key_dist 0x0B, resp_key_dist 0x0B
    00> [00:00:15.371,551] <dbg> bt_smp: smp_pairing_req: rsp: io_capability 0x03, oob_flag 0x00, auth_req 0x09, max_key_size 0x10, init_key_dist 0x02, resp_key_dist 0x00
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 4 Steps: 0
    00> 
    00>  Battery Notif delay handler 
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 5 Steps: 0
    00> 
    00>  Battery Notif delay handler 
    00> Connection param updated to interval:39, latency:0, timeout:600
    00> [00:00:19.703,552] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x0c len 64
    00> [00:00:19.703,582] <dbg> bt_smp: smp_public_key: 
    00> [00:00:19.728,485] <dbg> bt_smp: bt_smp_dhkey_ready: 0x200335f0
    00> [00:00:19.800,933] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x04 len 16
    00> [00:00:19.800,964] <dbg> bt_smp: smp_pairing_random: 
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 6 Steps: 0
    00> [00:00:19.898,468] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x0d len 16
    00> [00:00:19.898,468] <dbg> bt_smp: smp_dhkey_check: 
    00> [00:00:19.903,869] <dbg> bt_smp: sc_smp_send_dhkey_check: 
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 7 Steps: 0
    00> [00:00:20.288,665] <dbg> bt_keys: bt_keys_clear: 5D:F9:D2:71:90:43 (random) (keys 0x0000)
    00> [00:00:20.289,123] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.289,337] <dbg> bt_keys: bt_keys_get_addr: created 0x200126b8 for 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.289,367] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x20004250 conn 0x20003e58 handle 0 encrypt 0x01 hci status 0x00
    00> [00:00:20.289,550] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> Security changed: 5D:F9:D2:71:90:43 (random) level 2
    00> [00:00:20.337,219] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x08 len 16
    00> [00:00:20.337,249] <dbg> bt_smp: smp_ident_info: 
    00> [00:00:20.337,432] <dbg> bt_keys: bt_keys_get_type: type 2 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.337,615] <dbg> bt_keys: bt_keys_find: type 2 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.337,799] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.385,925] <dbg> bt_smp: bt_smp_recv: Received SMP code 0x09 len 7
    00> [00:00:20.386,138] <dbg> bt_smp: smp_ident_addr_info: identity F4:E8:C7:5E:82:43 (public)
    00> [00:00:20.386,322] <dbg> bt_keys: bt_keys_find_addr: F4:E8:C7:5E:82:43 (public)
    00> [00:00:20.386,505] <dbg> bt_keys: bt_keys_clear: F4:E8:C7:5E:82:43 (public) (keys 0x0000)
    00> [00:00:20.388,153] <dbg> bt_keys: bt_keys_get_type: type 2 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.388,336] <dbg> bt_keys: bt_keys_find: type 2 5D:F9:D2:71:90:43 (random)
    00> [00:00:20.388,549] <dbg> bt_keys: bt_keys_find_addr: F4:E8:C7:5E:82:43 (public)
    00> [00:00:20.392,181] <dbg> bt_smp: smp_pairing_complete: got status 0x0
    00> [00:00:20.392,242] <inf> bt_keys: SC LTK: 0xabdef306709a0c78cb84c36f5523c397
    00> [00:00:20.397,644] <dbg> bt_keys: bt_keys_store: Stored keys for F4:E8:C7:5E:82:43 (public)
    00> Pairing completed: F4:E8:C7:5E:82:43 (public), bonded: 1
    00> Count : 1 Bonded device address: F4:E8:C7:5E:82:43
    00> [00:00:20.398,315] <dbg> bt_keys: bt_keys_clear: F4:E8:C7:5E:82:43 (public) (keys 0x0022)
    00> Bonded device number : 0
    00> [00:00:20.403,442] <dbg> bt_keys: bt_keys_find_addr: F4:E8:C7:5E:82:43 (public)
    00> [00:00:20.483,398] <dbg> bt_smp: bt_smp_disconnected: chan 0x20004250 cid 0x0006
    00> [00:00:20.483,764] <dbg> bt_keys: bt_keys_find_addr: F4:E8:C7:5E:82:43 (public)
    00> [00:00:20.483,947] <dbg> bt_keys: bt_keys_find_addr: F4:E8:C7:5E:82:43 (public)
    00> Disconnected (reason 0x16)
    00> Watchdog is getting fed here : adv 1 and conn 0
    00> remaining_ticks:0 timer_init success:1, remaining ticks: 5898240
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 8 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 9 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 10 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 11 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 12 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 13 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 14 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 15 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 16 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 17 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 18 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 19 Steps: 0
    00> [00:00:31.210,784] <dbg> bt_keys: bt_keys_find_irk: 5D:F9:D2:71:90:43 (random)
    00> [00:00:31.210,998] <dbg> bt_keys: bt_keys_find_irk: No IRK for 5D:F9:D2:71:90:43 (random)
    00> [00:00:31.211,059] <dbg> bt_smp: bt_smp_accept: conn 0x20003e58 handle 1
    00> [00:00:31.211,090] <dbg> bt_smp: bt_smp_connected: chan 0x20004250 cid 0x0006
    00> [00:00:31.211,334] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> Watchdog is getting fed here : adv 0 and conn 1
    00> Connected
    00> [00:00:31.211,639] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:31.211,822] <dbg> bt_keys: bt_keys_get_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:31.212,005] <dbg> bt_keys: bt_keys_get_addr: created 0x2001265c for 5D:F9:D2:71:90:43 (random)
    00> [00:00:31.212,219] <dbg> bt_smp: smp_init: prnd 86aa511c69a537ff90c84ffb4dc306ae
    00> [00:00:31.363,739] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x20004250 conn 0x20003e58 handle 1 encrypt 0x00 hci status 0x06
    00> Security failed: 5D:F9:D2:71:90:43 (random) level 1 err 2
    00> [00:00:31.363,983] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:31.364,166] <dbg> bt_smp: smp_init: prnd 05c7a4ba5e074e4c9a073f9e3ad08653
    00> [00:00:31.453,765] <dbg> bt_smp: bt_smp_disconnected: chan 0x20004250 cid 0x0006
    00> [00:00:31.453,948] <dbg> bt_keys: bt_keys_clear: 5D:F9:D2:71:90:43 (random) (keys 0x0000)
    00> MTU exchange failed (err 14)[00:00:31.454,681] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> [00:00:31.454,864] <dbg> bt_keys: bt_keys_find_addr: 5D:F9:D2:71:90:43 (random)
    00> Disconnected (reason 0x13)
    00> Watchdog is getting fed here : adv 1 and conn 0
    00> remaining_ticks:0 timer_init success:1, remaining ticks: 5898240
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 20 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 21 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 22 Steps: 0
    00> 
    00>  Battery Notif delay handler 
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 23 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 24 Steps: 0
    00> 
    00>  Battery Notif delay handler 
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 25 Steps: 0
    00> Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 26 Steps: 0
    00> battery_level_update APP_MODE 0 and charging state :0
    00> Data read from device :16
    00> STC3117: STC31xx_GetRunningCounter 0

    Also one part Vidar- As the phone generated random addresses for connection then on connection the addresses are changing and thats why its not able to compare the current address with the address retrieved from the Keys.

  • Sharing the debug log where the addresses are being compared on connect when the Security level is begin checked-


    As you can see on the left side window - one of the address is being pulled from the flash correctly.

  • Also one part Vidar- As the phone generated random addresses for connection then on connection the addresses are changing and thats why its not able to compare the current address with the address retrieved from the Keys.

    I was refering to the public address exchanged during bonding. This address does not change, nor does the identity resolving key (IRK) used to identify the peer device.

    I did a test using the peripheral UART sample from SDK v2.6.1 and I managed to secure the link using bonding information previously exchanged with an application from the nRF5 SDK.

    diff --git a/src/main.c b/src/main.c
    index 7526fd6..01dab23 100644
    --- a/src/main.c
    +++ b/src/main.c
    @@ -22,6 +22,11 @@
     #include <zephyr/bluetooth/uuid.h>
     #include <zephyr/bluetooth/gatt.h>
     #include <zephyr/bluetooth/hci.h>
    +#include <zephyr/bluetooth/addr.h>
    +
    +/* BLE internal headers, use with caution. */
    +#include <host/keys.h>
    +#include <host/smp.h>
     
     #include <bluetooth/services/nus.h>
     
    @@ -448,8 +453,8 @@ static void pairing_failed(struct bt_conn *conn, enum bt_security_err reason)
     
     
     static struct bt_conn_auth_cb conn_auth_callbacks = {
    -	.passkey_display = auth_passkey_display,
    -	.passkey_confirm = auth_passkey_confirm,
    +	//.passkey_display = auth_passkey_display,
    +	//.passkey_confirm = auth_passkey_confirm,
     	.cancel = auth_cancel,
     };
     
    @@ -570,6 +575,66 @@ static void configure_gpio(void)
     	}
     }
     
    +static void bond_cb(const struct bt_bond_info *info, void *user_data)
    +{
    +	ARG_UNUSED(info);
    +
    +	*(int *) user_data += 1;
    +	LOG_INF("Existing bond found");
    +
    +	return;
    +}
    +
    +static void pre_shared_bond_set(void)
    +{
    +	int err;
    +	int bond_num = 0;
    +	struct bt_keys *pairing_info;
    +
    +	bt_foreach_bond(BT_ID_DEFAULT, bond_cb, &bond_num);
    +
    +	if (bond_num) {
    +		return;
    +	}
    +
    +	bt_addr_le_t addr = {
    +	    .type = BT_ADDR_LE_PUBLIC,
    +	    .a.val = {0x23, 0x50, 0x20, 0xc5, 0x44, 0x78}
    +	};
    +
    +	struct bt_ltk ltk = {
    +	    .val = {0xaa, 0xfe, 0x46, 0x96, 0x78, 0x98, 0xe5, 0x04, 0x5d, 0xe6, 0x8e,
    +	            0x8d, 0x82, 0xc4, 0x55, 0x9c},
    +	    .ediv = {0},
    +	    .rand = {0}		
    +	};
    +
    +	struct bt_irk irk = {
    +		.val = {0xd6, 0x2f, 0x47, 0x3a, 0xd5, 0x8b, 0x0b, 0x18, 0x8b, 0xf4, 0x84, 0x5d, 0x15, 0x93, 0x99, 0x29},
    +		.rpa.val = {0}		
    +	}; 
    +
    +	pairing_info = bt_keys_get_addr(0, &addr);
    +	if (pairing_info == NULL) {
    +		LOG_ERR("Failed to get keyslot");
    +	}
    +
    +	memcpy(&pairing_info->ltk, &ltk, sizeof(pairing_info->ltk));
    +	memcpy(&pairing_info->irk, &irk, sizeof(pairing_info->irk));
    +
    +	pairing_info->flags = 16; //SMP_FLAG_SC
    +	pairing_info->enc_size = BT_SMP_MAX_ENC_KEY_SIZE;
    +	pairing_info->keys = BT_KEYS_IRK | BT_KEYS_LTK_P256;
    +
    +	err = bt_keys_store(pairing_info);
    +    if (err) {
    +        LOG_ERR("Failed to store keys (err %d)\n", err);
    +    } else {
    +        LOG_INF("Keys stored successfully\n");
    +    }
    +
    +}
    +
     int main(void)
     {
     	int blink_status = 0;
    @@ -604,10 +669,12 @@ int main(void)
     	LOG_INF("Bluetooth initialized");
     
     	k_sem_give(&ble_init_ok);
    -
    +	
     	if (IS_ENABLED(CONFIG_SETTINGS)) {
     		settings_load();
     	}
    +	
    +	pre_shared_bond_set();
     
     	err = bt_nus_init(&nus_cb);
     	if (err) {

    Log output after applying the hardcoded bonding information:

    00> [00:00:00.017,578] <inf> bt_hci_core: HW Platform: Nordic Semiconductor (0x0002)
    00> [00:00:00.017,608] <inf> bt_hci_core: HW Variant: nRF52x (0x0002)
    00> [00:00:00.017,639] <inf> bt_hci_core: Firmware: Standard Bluetooth controller (0x00) Version 54.58864 Build 1214809870
    00> [00:00:00.018,035] <dbg> bt_smp: bt_smp_init: LE SC enabled
    00> [00:00:00.018,341] <inf> bt_hci_core: No ID address. App must call settings_load()
    00> [00:00:00.018,341] <inf> peripheral_uart: Bluetooth initialized
    00> [00:00:00.018,554] <dbg> bt_keys: keys_set: name 7864c02053230 val 1010220000000000000000000000aafe46967898e5045de68e8d82c4559cd62f573ad58b0b18abf4845d259399e9000000000000000000000000000000000000
    00> [00:00:00.018,676] <dbg> bt_keys: bt_keys_get_addr: 78:44:C5:20:50:23 (public)
    00> [00:00:00.018,768] <dbg> bt_keys: bt_keys_get_addr: created 0x20003a44 for 78:44:C5:20:50:23 (public)
    00> [00:00:00.018,890] <dbg> bt_keys: keys_set: Successfully restored keys for 78:44:C5:20:50:23 (public)
    00> [00:00:00.019,653] <inf> bt_hci_core: Identity: F3:2D:57:2C:CF:0B (random)
    00> [00:00:00.019,714] <inf> bt_keys: SC LTK: 0x9c55c4828d8ee65d04e598789646feaa
    00> [00:00:00.019,744] <inf> bt_hci_core: HCI: version 5.4 (0x0d) revision 0x118f, manufacturer 0x0059
    00> [00:00:00.019,775] <inf> bt_hci_core: LMP: version 5.4 (0x0d) subver 0x118f
    00> [00:00:00.023,101] <err> peripheral_uart: bond found
    00> [00:00:00.049,896] <dbg> bt_smp: bt_smp_pkey_ready: 
    00> [00:00:03.079,132] <dbg> bt_smp: bt_smp_accept: conn 0x20002228 handle 0
    00> [00:00:03.079,162] <dbg> bt_smp: bt_smp_connected: chan 0x200024f4 cid 0x0006
    00> [00:00:03.079,315] <dbg> bt_keys: bt_keys_find_addr: 78:44:C5:20:50:23 (public)
    00> [00:00:03.079,650] <inf> peripheral_uart: Connected 78:44:C5:20:50:23 (public)
    00> [00:00:03.242,462] <dbg> bt_keys: bt_keys_find: type 32 78:44:C5:20:50:23 (public)
    00> [00:00:03.362,304] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x200024f4 conn 0x20002228 handle 0 encrypt 0x01 hci status 0x00
    00> [00:00:03.362,457] <inf> peripheral_uart: Security changed: 78:44:C5:20:50:23 (public) level 2
    00> [00:00:03.782,012] <wrn> bt_l2cap: Ignoring data for unknown channel ID 0x003a

    Project

    peripheral_uart_pre_shared_bond.zip

    Please note that the key structs and functions require internal headers that are not meant to be exposed to the application. The 'bt_keys' parameters may also vary depending on the pairing method used. Therefore, if you plan to use this approach in production, it is particularly important to perform thorough testing and verification of your final solution before release.

  • I tried your flow too, but still seeing the same error on my central device-

    00> [00:00:00.004,150] <dbg> bt_hci_core: bt_hci_driver_register: Registered SoftDevice Controller
    00> [00:00:00.004,241] <dbg> bt_sdc_hci_driver: configure_memory_usage: BT mempool size: 3001, required: 2656
    00> *** Booting nRF Connect SDK v3.5.99-ncs1-1 ***
    00> [00:00:00.004,364] <inf> mflt: Reset Reason, RESETREAS=0x4
    00> --- 225 messages dropped ---
    00> [00:00:00.199,340] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 7
    00> [00:00:00.199,340] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x202a
    00> [00:00:00.199,371] <dbg> bt_hci_core: hci_cmd_done: opcode 0x202a status 0x00 buf 0x200348b0
    00> --- 41 messages dropped ---
    00> [00:00:00.200,744] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0xfc01 param_len 0
    00> [00:00:00.200,775] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:00.200,805] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0xfc01 len 3
    00> --- 100 messages dropped ---
    00> [00:00:00.236,930 len 29
    00> 4Interrupt observed 
    00> LSM osurce value :0 0
    00> Total Activity: 3 Steps: 0
    00> [00:00:28.557,159] <dbg> bt_sdc_hci_driver: event_packet_process: LE Meta Event (0x0a), len (31)
    00> [00:00:28.557,189] <dbg> bt_hci_core: bt_recv: buf 0x20034464 len 33
    00> [00:00:28.557,281] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
    00> [00:00:28.557,312] <dbg> bt_hci_core: rx_work_handler: buf 0x20034464 type 1 len 33
    00> [00:00:28.557,312] <dbg> bt_hci_core: hci_event: event 0x3e
    00> [00:00:28.557,342] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x0a
    00> [00:00:28.557,678] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: status 0x00 handle 0 role 1 peer 4B:0D:2B:0F:F4:26 (random) peer RPA 00:00:00:00:00:00
    00> [00:00:28.557,830] <dbg> bt_hci_core: bt_hci_le_enh_conn_complete: local RPA 00:00:00:00:00:00
    00> [00:00:28.558,013] <dbg> bt_keys: bt_keys_find_irk: 4B:0D:2B:0F:F4:26 (random)
    00> [00:00:28.558,044] <dbg> bt_sdc_crypto: bt_encrypt_le: key
    00>                                         8a 27 1e a7 92 2a f0 15  41 69 48 dd c0 7e dd f7 |.'...*.. AiH..~..
    00> [00:00:28.558,074] <dbg> bt_sdc_crypto: bt_encrypt_le: plaintext
    00>                                         2b 0d 4b 00 00 00 00 00  00 00 00 00 00 00 00 00 |+.K..... ........
    00> [00:00:28.558,135] <dbg> bt_sdc_crypto: bt_encrypt_le: enc_data
    00>                                         af a7 b0 61 52 ed 88 23  bc e3 70 39 f8 31 01 29 |...aR..# ..p9.1.)
    00> [00:00:28.558,319] <dbg> bt_keys: bt_keys_find_irk: No IRK for 4B:0D:2B:0F:F4:26 (random)
    00> [00:00:28.558,349] <dbg> bt_adv: bt_le_adv_resume: Host cannot resume connectable advertising (-12)
    00> [00:00:28.558,410] <dbg> bt_smp: bt_smp_accept: conn 0x20003e58 handle 0
    00> [00:00:28.558,410] <dbg> bt_smp: bt_smp_connected: chan 0x200042b0 cid 0x0006
    00> [00:00:28.558,685] <dbg> bt_keys: bt_keys_find_addr: 4B:0D:2B:0F:F4:26 (random)
    00> Watchdog is getting fed here : adv 0 and conn 1
    00> Connected
    00> [00:00:28.558,959] <dbg> bt_smp: smp_send_security_req: 
    00> [00:00:28.559,143] <dbg> bt_keys: bt_keys_get_addr: 4B:0D:2B:0F:F4:26 (random)
    00> [00:00:28.559,326] <dbg> bt_keys: bt_keys_get_addr: created 0x20012818 for 4B:0D:2B:0F:F4:26 (random)
    00> [00:00:28.559,509] <dbg> bt_smp: smp_init: prnd e98d424ab56b8fd658ae17ef6a544ce4
    00> [00:00:28.559,570] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2016 param_len 2
    00> [00:00:28.559,570] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.559,600] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x2016 len 5
    00> [00:00:28.559,661] <dbg> bt_hci_core: process_events: count 2
    00> [00:00:28.559,661] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.559,661] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.559,692] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.559,692] <dbg> bt_hci_core: send_cmd: Sending command 0x2016 (buf 0x200348b0) to driver
    00> [00:00:28.559,722] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 5 type 0
    00> [00:00:28.559,722] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.559,753] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.559,783] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.559,814] <dbg> bt_hci_core: process_events: ev->state 1
    00> [00:00:28.559,844] <dbg> bt_sdc_hci_driver: event_packet_process: Command Status (0x2016) status: 0x00
    00> [00:00:28.559,844] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.559,875] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2016
    00> [00:00:28.559,875] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2016 status 0x00 buf 0x200348b0
    00> [00:00:28.559,997] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.560,028] <dbg> bt_hci_core: process_events: count 3
    00> [00:00:28.560,028] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,058] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,058] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.560,089] <dbg> bt_hci_core: bt_send: buf 0x200363bc len 11 type 2
    00> [00:00:28.560,089] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.560,119] <dbg> bt_sdc_hci_driver: acl_handle: 
    00> [00:00:28.560,150] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.560,180] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.560,211] <dbg> bt_hci_core: process_events: count 3
    00> [00:00:28.560,211] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,241] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,241] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.560,272] <dbg> bt_hci_core: bt_send: buf 0x200363dc len 10 type 2
    00> [00:00:28.560,272] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.560,302] <dbg> bt_sdc_hci_driver: acl_handle: 
    00> [00:00:28.560,302] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.560,363] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.560,394] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x2016 len 0
    00> [00:00:28.560,424] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2032 param_len 7
    00> [00:00:28.560,424] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.560,455] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x2032 len 10
    00> [00:00:28.560,516] <dbg> bt_hci_core: process_events: count 3
    00> [00:00:28.560,516] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.560,516] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.560,546] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.560,546] <dbg> bt_hci_core: send_cmd: Sending command 0x2032 (buf 0x200348b0) to driver
    00> [00:00:28.560,577] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 10 type 0
    00> [00:00:28.560,577] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.560,607] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.560,638] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.560,668] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,668] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.560,699] <dbg> bt_sdc_hci_driver: event_packet_process: Command Status (0x2032) status: 0x00
    00> [00:00:28.560,729] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.560,760] <dbg> bt_hci_core: hci_cmd_status: opcode 0x2032
    00> [00:00:28.560,760] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2032 status 0x00 buf 0x200348b0
    00> [00:00:28.560,852] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.560,913] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x2032 len 0
    00> battery_level_update APP_MODE 0 and charging state :0
    00> Data read from device :16
    00> STC3117: STC31xx_GetRunningCounter 0
    00> [00:00:28.623,168] <dbg> bt_sdc_hci_driver: event_packet_process: Event (0x13) len 5
    00> [00:00:28.623,168] <dbg> bt_hci_core: bt_recv: buf 0x20034694 len 7
    00> [00:00:28.623,199] <dbg> bt_hci_core: hci_num_completed_packets: num_handles 1
    00> [00:00:28.623,199] <dbg> bt_hci_core: hci_num_completed_packets: handle 0 count 1
    00> [00:00:28.712,799] <dbg> bt_sdc_hci_driver: event_packet_process: Event (0x13) len 5
    00> [00:00:28.712,829] <dbg> bt_hci_core: bt_recv: buf 0x20034694 len 7
    00> [00:00:28.712,829] <dbg> bt_hci_core: hci_num_completed_packets: num_handles 1
    00> [00:00:28.712,860] <dbg> bt_hci_core: hci_num_completed_packets: handle 0 count 1
    00> [00:00:28.803,039] <dbg> bt_sdc_hci_driver: event_packet_process: LE Meta Event (0x05), len (13)
    00> [00:00:28.803,039] <dbg> bt_hci_core: bt_recv: buf 0x20034464 len 15
    00> [00:00:28.803,161] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
    00> [00:00:28.803,161] <dbg> bt_hci_core: rx_work_handler: buf 0x20034464 type 1 len 15
    00> [00:00:28.803,192] <dbg> bt_hci_core: hci_event: event 0x3e
    00> [00:00:28.803,192] <dbg> bt_hci_core: hci_le_meta_event: subevent 0x05
    00> [00:00:28.803,222] <dbg> bt_hci_core: le_ltk_request: handle 0
    00> [00:00:28.803,253] <dbg> bt_smp: bt_smp_encrypt_change: chan 0x200042b0 conn 0x20003e58 handle 0 encrypt 0x00 hci status 0x06
    00> Security failed: 4B:0D:2B:0F:F4:26 (random) level 1 err 2
    00> [00:00:28.803,466] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x201b param_len 2
    00> [00:00:28.803,497] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.803,497] <dbg> bt_hci_core: bt_hci_cmd_send: opcode 0x201b len 5
    00> [00:00:28.803,558] <dbg> bt_hci_core: process_events: count 3
    00> [00:00:28.803,558] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.803,588] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.803,588] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.803,619] <dbg> bt_hci_core: send_cmd: Sending command 0x201b (buf 0x200348b0) to driver
    00> [00:00:28.803,619] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 5 type 0
    00> [00:00:28.803,649] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.803,649] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.803,802] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.803,833] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.803,833] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.803,863] <dbg> bt_sdc_hci_driver: event_packet_process: Command Complete (0x201b) status: 0x00, ncmd: 1, len 6
    00> [00:00:28.803,894] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 8
    00> [00:00:28.803,894] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x201b
    00> [00:00:28.803,924] <dbg> bt_hci_core: hci_cmd_done: opcode 0x201b status 0x00 buf 0x200348b0
    00> [00:00:28.804,016] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 3 events
    00> [00:00:28.892,913] <dbg> bt_sdc_hci_driver: event_packet_process: Event (0x05) len 4
    00> [00:00:28.892,944] <dbg> bt_hci_core: bt_recv: buf 0x20034464 len 6
    00> [00:00:28.892,974] <dbg> bt_hci_core: hci_disconn_complete_prio: status 0x00 handle 0 reason 0x13
    00> [00:00:28.893,066] <dbg> bt_hci_core: rx_work_handler: Getting net_buf from queue
    00> [00:00:28.893,096] <dbg> bt_hci_core: rx_work_handler: buf 0x20034464 type 1 len 6
    00> [00:00:28.893,096] <dbg> bt_hci_core: hci_event: event 0x05
    00> [00:00:28.893,127] <dbg> bt_hci_core: hci_disconn_complete: status 0x00 handle 0 reason 0x13
    00> [00:00:28.893,188] <dbg> bt_hci_core: process_events: count 3
    00> [00:00:28.893,188] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.893,218] <dbg> bt_hci_core: process_events: ev->state 1
    00> [00:00:28.893,218] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.893,280] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
    00> [00:00:28.893,341] <dbg> bt_smp: bt_smp_disconnected: chan 0x200042b0 cid 0x0006
    00> [00:00:28.893,524] <dbg> bt_keys: bt_keys_clear: 4B:0D:2B:0F:F4:26 (random) (keys 0x0000)
    00> MTU exchange failed (err 14)[00:00:28.894,165] <dbg> bt_keys: bt_keys_find_addr: 4B:0D:2B:0F:F4:26 (random)
    00> [00:00:28.894,348] <dbg> bt_keys: bt_keys_find_addr: 4B:0D:2B:0F:F4:26 (random)
    00> Disconnected (reason 0x13)
    00> Watchdog is getting fed here : adv 1 and conn 0
    00> [00:00:28.894,653] <dbg> bt_id: set_random_address: D3:C4:88:DC:F4:8D
    00> [00:00:28.894,653] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2006 param_len 15
    00> [00:00:28.894,683] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.894,714] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x2006 len 18
    00> [00:00:28.894,744] <dbg> bt_hci_core: process_events: count 2
    00> [00:00:28.894,775] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.894,775] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.894,805] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.894,805] <dbg> bt_hci_core: send_cmd: Sending command 0x2006 (buf 0x200348b0) to driver
    00> [00:00:28.894,836] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 18 type 0
    00> [00:00:28.894,836] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.894,866] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.894,897] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.894,927] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.894,958] <dbg> bt_sdc_hci_driver: event_packet_process: Command Complete (0x2006) status: 0x00, ncmd: 1, len 4
    00> [00:00:28.894,989] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.894,989] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2006
    00> [00:00:28.895,019] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2006 status 0x00 buf 0x200348b0
    00> [00:00:28.895,111] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
    00> [00:00:28.895,141] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x2006 len 1
    00> [00:00:28.895,172] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2008 param_len 32
    00> [00:00:28.895,202] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.895,202] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x2008 len 35
    00> [00:00:28.895,263] <dbg> bt_hci_core: process_events: count 2
    00> [00:00:28.895,294] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.895,294] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.895,294] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.895,324] <dbg> bt_hci_core: send_cmd: Sending command 0x2008 (buf 0x200348b0) to driver
    00> [00:00:28.895,324] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 35 type 0
    00> [00:00:28.895,355] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.895,355] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.895,416] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.895,416] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.895,477] <dbg> bt_sdc_hci_driver: event_packet_process: Command Complete (0x2008) status: 0x00, ncmd: 1, len 4
    00> [00:00:28.895,477] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.895,507] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2008
    00> [00:00:28.895,507] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2008 status 0x00 buf 0x200348b0
    00> [00:00:28.895,629] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
    00> [00:00:28.895,660] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x2008 len 1
    00> [00:00:28.895,690] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x2009 param_len 32
    00> [00:00:28.895,690] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.895,721] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x2009 len 35
    00> [00:00:28.895,782] <dbg> bt_hci_core: process_events: count 2
    00> [00:00:28.895,782] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.895,782] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.895,812] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.895,812] <dbg> bt_hci_core: send_cmd: Sending command 0x2009 (buf 0x200348b0) to driver
    00> [00:00:28.895,843] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 35 type 0
    00> [00:00:28.895,843] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.895,874] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.895,904] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.895,935] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.895,965] <dbg> bt_sdc_hci_driver: event_packet_process: Command Complete (0x2009) status: 0x00, ncmd: 1, len 4
    00> [00:00:28.895,996] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.895,996] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x2009
    00> [00:00:28.896,026] <dbg> bt_hci_core: hci_cmd_done: opcode 0x2009 status 0x00 buf 0x200348b0
    00> [00:00:28.896,118] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
    00> [00:00:28.896,148] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x2009 len 1
    00> remaining_ticks:0 timer_init success:1, remaining ticks: 5898240
    00> [00:00:28.896,301] <dbg> bt_adv: bt_le_adv_resume: Resuming connectable advertising
    00> [00:00:28.896,484] <dbg> bt_id: set_random_address: D3:C4:88:DC:F4:8D
    00> [00:00:28.896,484] <dbg> bt_hci_core: bt_hci_cmd_create: opcode 0x200a param_len 1
    00> [00:00:28.896,514] <dbg> bt_hci_core: bt_hci_cmd_create: buf 0x200348b0
    00> [00:00:28.896,545] <dbg> bt_hci_core: bt_hci_cmd_send_sync: buf 0x200348b0 opcode 0x200a len 4
    00> [00:00:28.896,575] <dbg> bt_hci_core: process_events: count 2
    00> [00:00:28.896,606] <dbg> bt_hci_core: process_events: ev->state 4
    00> [00:00:28.896,606] <dbg> bt_hci_core: send_cmd: calling net_buf_get
    00> [00:00:28.896,636] <dbg> bt_hci_core: send_cmd: calling sem_take_wait
    00> [00:00:28.896,636] <dbg> bt_hci_core: send_cmd: Sending command 0x200a (buf 0x200348b0) to driver
    00> [00:00:28.896,667] <dbg> bt_hci_core: bt_send: buf 0x200348b0 len 4 type 0
    00> [00:00:28.896,667] <dbg> bt_sdc_hci_driver: hci_driver_send: 
    00> [00:00:28.896,667] <dbg> bt_sdc_hci_driver: cmd_handle: 
    00> [00:00:28.896,820] <dbg> bt_sdc_hci_driver: hci_driver_send: Exit: 0
    00> [00:00:28.896,850] <dbg> bt_hci_core: process_events: ev->state 0
    00> [00:00:28.896,881] <dbg> bt_sdc_hci_driver: event_packet_process: Command Complete (0x200a) status: 0x00, ncmd: 1, len 4
    00> [00:00:28.896,911] <dbg> bt_hci_core: bt_recv: buf 0x200348b0 len 6
    00> [00:00:28.896,911] <dbg> bt_hci_core: hci_cmd_complete: opcode 0x200a
    00> [00:00:28.896,942] <dbg> bt_hci_core: hci_cmd_done: opcode 0x200a status 0x00 buf 0x200348b0
    00> [00:00:28.897,033] <dbg> bt_hci_core: hci_tx_thread: Calling k_poll with 2 events
    00> [00:00:28.897,064] <dbg> bt_hci_core: bt_hci_cmd_send_sync: rsp 0x200348b0 opcode 0x200a len 1

Related