Security failed level 1 err 9 connecting error with bonded device

Hi all!

I'm developing a BLE device implementing automation IO profile, peripheral role.

I can connect normally and discover all services and characteristics from nRF Connect android app, but after bonding, I never can connect again, I receive 

Security failed: 3C:CD:5D:3F:DC:50 (public) level 1 err 9
Disconnected (reason 61)

Am I missing something? Do I need to manually save bond information?

My code is the following:

#include <zephyr/zephyr.h>
#include <zephyr/logging/log.h>
#include <zephyr/bluetooth/bluetooth.h>
#include <zephyr/bluetooth/uuid.h>
#include <zephyr/bluetooth/gatt.h>
#include <zephyr/settings/settings.h>

#include <device.h>
#include <drivers/flash.h>
#include <storage/flash_map.h>
#include <fs/nvs.h>

#include <stdio.h>
#include <string.h>

#include "../cfg/config.h"
#include "ble.h"

#include <zephyr/kernel.h>
#include <zephyr/sys/reboot.h>
#include <zephyr/sys/printk.h>
#include <inttypes.h>

LOG_MODULE_REGISTER(ble);

static void ccc_changed(const struct bt_gatt_attr *attr, uint16_t value) {
}

static ssize_t uart_tx_chr_read(struct bt_conn *conn, const struct bt_gatt_attr *attr, void *buf, uint16_t len, uint16_t offset) {
	return 0;
}

static ssize_t uart_rx_chr_write(struct bt_conn *conn, const struct bt_gatt_attr *attr, const void *buf, uint16_t len, uint16_t offset, uint8_t flags){
	return 0;
}

static ssize_t device_name_chr_write(struct bt_conn *conn, const struct bt_gatt_attr *attr, const void *buf, uint16_t len, uint16_t offset, uint8_t flags){

	char prueba[100] = {};
	memcpy(prueba, buf, len);
	printk("Nuevo nombre: %s\n", prueba);

	return 0;
}

/* Custom service variables */
#define BT_UUID_SERVER_UART BT_UUID_128_ENCODE(0x0003CDD0, 0x0000, 0x1000, 0x8000, 0x00805f9b0131)
static struct bt_uuid_128 server_uart_tx_uuid = BT_UUID_INIT_128(
	BT_UUID_128_ENCODE(0x0003CDD1, 0x0000, 0x1000, 0x8000, 0x00805f9b0131));
static struct bt_uuid_128 server_uart_rx_uuid = BT_UUID_INIT_128(
	BT_UUID_128_ENCODE(0x0003CDD2, 0x0000, 0x1000, 0x8000, 0x00805f9b0131));

static const uint8_t device_name[] = DEF_BLE_NAME;
static struct bt_uuid_16 automation_io_uuid = BT_UUID_INIT_16( 0x1815 );
static struct bt_uuid_16 device_name_uuid = BT_UUID_INIT_16( BT_UUID_GAP_DEVICE_NAME_VAL );

/* UART custom service declaration */
BT_GATT_SERVICE_DEFINE(automation_io_svc,
	BT_GATT_PRIMARY_SERVICE(&automation_io_uuid),
	BT_GATT_CHARACTERISTIC(&device_name_uuid.uuid,
			       BT_GATT_CHRC_WRITE_WITHOUT_RESP | BT_GATT_CHRC_NOTIFY,
				   BT_GATT_PERM_READ | BT_GATT_PERM_WRITE,
				   NULL, device_name_chr_write, NULL
				   ),		   
	BT_GATT_CHARACTERISTIC(&server_uart_tx_uuid.uuid,
			       BT_GATT_CHRC_NOTIFY,
				   BT_GATT_PERM_READ,
				   uart_tx_chr_read, NULL, NULL
				   ),		   
	BT_GATT_CCC(ccc_changed,
		    BT_GATT_PERM_READ | BT_GATT_PERM_WRITE),				   
	BT_GATT_CHARACTERISTIC(&server_uart_rx_uuid.uuid,
			       BT_GATT_CHRC_WRITE_WITHOUT_RESP,
				   BT_GATT_PERM_WRITE,
				   NULL, uart_rx_chr_write, NULL
				   ),
);

static struct bt_data ad[] = {
	BT_DATA_BYTES(BT_DATA_FLAGS, (BT_LE_AD_GENERAL | BT_LE_AD_NO_BREDR)),
	BT_DATA(BT_DATA_NAME_COMPLETE, device_name, sizeof(device_name)-1),
    BT_DATA(BT_DATA_UUID16_ALL, &automation_io_uuid.val, sizeof(automation_io_uuid.val)),
};

static void connected(struct bt_conn *conn, uint8_t err)
{
	if (err) {
		printk("Connection failed (err %u)\n", err);
		return;
	}

	printk("Connected\n");
}

static void disconnected(struct bt_conn *conn, uint8_t reason)
{
	printk("Disconnected (reason %u)\n", reason);
}

static void security_changed(struct bt_conn *conn, bt_security_t level,
			     enum bt_security_err err)
{
	char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	if (!err) {
		printk("Security changed: %s level %u\n", addr, level);
	} else {
		printk("Security failed: %s level %u err %d\n", addr, level,
			err);
	}
}

BT_CONN_CB_DEFINE(conn_callbacks) = {
	.connected        = connected,
	.disconnected     = disconnected,
	.security_changed = security_changed,
};

static void auth_passkey_display(struct bt_conn *conn, unsigned int passkey)
{
	char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	printk("Passkey for %s: %06u\n", addr, passkey);
}

static void auth_cancel(struct bt_conn *conn)
{
	char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	printk("Pairing cancelled: %s\n", addr);
}

static void pairing_complete(struct bt_conn *conn, bool bonded)
{
	char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	printk("Pairing completed: %s, bonded: %d\n", addr, bonded);
}

static void pairing_failed(struct bt_conn *conn, enum bt_security_err reason)
{
	char addr[BT_ADDR_LE_STR_LEN];

	bt_addr_le_to_str(bt_conn_get_dst(conn), addr, sizeof(addr));

	printk("Pairing failed conn: %s, reason %d\n", addr, reason);
}

static struct bt_conn_auth_cb conn_auth_callbacks = {
	.passkey_display = auth_passkey_display,
	.cancel = auth_cancel,
};

static struct bt_conn_auth_info_cb conn_auth_info_callbacks = {
	.pairing_complete = pairing_complete,
	.pairing_failed = pairing_failed
};

int ble_init(void) {
    int err;
	LOG_INF("%s", "Starting BLE");

	err = bt_conn_auth_cb_register(&conn_auth_callbacks);
	if (err) {
		printk("Failed to register authorization callbacks.\n");
		return -1;
	}

	err = bt_conn_auth_info_cb_register(&conn_auth_info_callbacks);
	if (err) {
		printk("Failed to register authorization info callbacks.\n");
		return -1;
	}

 	err = bt_enable(NULL);
	if (err) {
		LOG_ERR("%s", "BLE enable error");
		return -1;
	}
	else {
		LOG_INF("%s", "Bluetooth initialized");
	}

	if (IS_ENABLED(CONFIG_SETTINGS)) {
		settings_load();
		LOG_INF("%s", "Settings loaded");
	}

	/* Start advertising  */
	err = bt_le_adv_start(BT_LE_ADV_CONN, ad, ARRAY_SIZE(ad), NULL, 0);
	if (err) {
		LOG_ERR("Advertising failed to start (err %d)", err);
		return -1;
	}

	return 0;
}

Thanks!

Pedro.

Parents
  • Hi Pedro,

    Are you able to upload your project so I can try to reproduce the error on my end? The pairing fails because the link is encrypted/decrypted incorrectly, which is unusual error. The bonding information should be stored to flash automatically be the Zephyr host. 

    Best regards,

    Vidar

  • Hi Vidar,

    Attached to this post you can find the project. 

    Thanks for your help!

    ble-io-bridge-periph.zip

    Edit: I'm using ncs 2.0.2

  • Hi Vidar,

    I tried with 4645.zephyr.hex, I see when scanning Nordic_HIDS_keyboard, then I connect and try to bond. I confirm from phone side, but when trying to confirm from nRF52 DK side, it does nothing when pressing button 1. Maybe our nrF52 DK is damaged. 

    You can send me same example but with no display or keyboard callbacks, so it can bond without having to confirm.

    Kind regards,

    Pedro.

  • Hi Pedro,

    I've re-built the sample without the IO capabilities, so it defaults to LESC just works pairing and I also disabled NFC OOB pairing support. Hope it works.

    8737.zephyr.hex

    Best regards,

    Vidar

  • Hi Vidar,

    It connects and bonds correctly to P20 pro, but then, when try to connect, it never connects again:

    Connected 3C:CD:5D:3F:DC:50 (public)
    Advertising successfully started
    W: Not connected!
    Security failed: 3C:CD:5D:3F:DC:50 (public) level 1 err 9
    Disconnected from 3C:CD:5D:3F:DC:50 (public) (reason 61)
    Advertising continued
    Connected 3C:CD:5D:3F:DC:50 (public)
    Advertising successfully started
    W: Not connected!
    Security failed: 3C:CD:5D:3F:DC:50 (public) level 1 err 9
    Disconnected from 3C:CD:5D:3F:DC:50 (public) (reason 61)
    Advertising continued
    Connected 3C:CD:5D:3F:DC:50 (public)
    Advertising successfully started
    W: Not connected!
    Security failed: 3C:CD:5D:3F:DC:50 (public) level 1 err 9
    Disconnected from 3C:CD:5D:3F:DC:50 (public) (reason 61)

    I tried also with a Xiaomi Mi 9T Pro and all work ok, even after bonding. But I tried with an old Samsung Galaxy J5 with Android 5.1.1 and it bonds, but for some reason, it can not discover services and characteristics.

    I hope this helps.

    Kind regards,

    Pedro.

  • Hi Pedro,

    Do you have an extra DK or nRF52840 Dongle laying around that you can use to capture a sniffer trace with the nRF Sniffer

    I've created a new hex file which will print the encryption key (LTK). You can use JLink RTT Viewer if you have problems viewing UART logs. 

    2742.zephyr.hex

    Kind regards,

    Vidar

  • Hi Vidar,

    If done tests again with both mobiles. 

    Huawei P20 Pro

    Now it works fine. It connects correctly after bonding. See UART log and sniffer trace. p20-pro.pcapng

    *** Booting Zephyr OS build v3.3.99-ncs1-1 ***
    Starting Bluetooth Peripheral HIDS keyboard example
    [00:00:00.007,385] <inf> fs_nvs: nvs_mount: 6 Sectors of 4096 bytes
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: alloc wra: 0, fd0
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: data wra: 0, 1c
    [00:00:00.007,568] <inf> bt_sdc_hci_driver: hci_driver_open: SoftDevice Controller build revision: 
                                                e0 7e 2e c1 5e 05 85 23  46 15 dc fa 8e 29 7d 70 |.~..^..# F....)}p
                                                10 93 a5 fc                                      |....             
    [00:00:00.010,192] <inf> bt_hci_core: hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.010,223] <inf> bt_hci_core: hci_vs_init: HW Variant: nRF52x (0x0002)
    [00:00:00.010,253] <inf> bt_hci_core: hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 224.11902 Build 2231721665
    [00:00:00.010,681] <inf> bt_hci_core: bt_init: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.011,291] <inf> bt_hci_core: bt_dev_show_info: Identity: D7:06:A1:24:26:8D (random)
    [00:00:00.011,352] <inf> bt_hci_core: bt_dev_show_info: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
    [00:00:00.011,383] <inf> bt_hci_core: bt_dev_show_info: LMP: version 5.4 (0x0d) subver 0x1077
    Advertising successfully started
    Connected 79:E9:E4:BA:EC:DB (random)
    Advertising successfully started
    Security changed: 79:E9:E4:BA:EC:DB (random) level 2
    [00:00:16.172,271] <inf> bt_keys: bt_keys_show_sniffer_info: SC LTK: 0x9817d9b2bac95f1571a50ab7c81db99b
    Pairing completed: 3C:CD:5D:3F:DC:50 (public), bonded: 1
    Output report has been received 3C:CD:5D:3F:DC:50 (public)

    The operations done were: connect -> bond -> disconnect -> connect -> disconnect -> connect

    Samsung Galaxy J5

    Can not discover services. I did connect -> bond -> disconnect -> connect. See UART log and sniffer trace. galaxy-j5.pcapng

    *** Booting Zephyr OS build v3.3.99-ncs1-1 ***
    Starting Bluetooth Peripheral HIDS keyboard example
    [00:00:00.007,385] <inf> fs_nvs: nvs_mount: 6 Sectors of 4096 bytes
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: alloc wra: 0, fd0
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: data wra: 0, 1c
    [00:00:00.007,568] <inf> bt_sdc_hci_driver: hci_driver_open: SoftDevice Controller build revision: 
                                                e0 7e 2e c1 5e 05 85 23  46 15 dc fa 8e 29 7d 70 |.~..^..# F....)}p
                                                10 93 a5 fc                                      |....             
    [00:00:00.010,192] <inf> bt_hci_core: hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.010,223] <inf> bt_hci_core: hci_vs_init: HW Variant: nRF52x (0x0002)
    [00:00:00.010,253] <inf> bt_hci_core: hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 224.11902 Build 2231721665
    [00:00:00.010,681] <inf> bt_hci_core: bt_init: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.011,322] <inf> bt_hci_core: bt_dev_show_info: Identity: D7:06:A1:24:26:8D (random)
    [00:00:00.011,352] <inf> bt_hci_core: bt_dev_show_info: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
    [00:00:00.011,383] <inf> bt_hci_core: bt_dev_show_info: LMP: version 5.4 (0x0d) subver 0x1077
    Advertising successfully started
    Connected 78:C3:E9:2F:A2:A1 (public)
    Advertising successfully started
    Security changed: 78:C3:E9:2F:A2:A1 (public) level 2
    [00:00:19.207,000] <inf> bt_keys: bt_keys_show_sniffer_info: Legacy LTK: 0xd1eb5ef3da7190910bc8048ae2db095d (peripheral)
    [00:00:19.207,061] <inf> bt_keys: bt_keys_show_sniffer_info: Legacy LTK: 0x3e34fdd7dd50cad6199205f79ce5f009 (central)
    Pairing completed: 78:C3:E9:2F:A2:A1 (public), bonded: 1
    Disconnected from 78:C3:E9:2F:A2:A1 (public) (reason 19)
    Advertising continued
    Connected 78:C3:E9:2F:A2:A1 (public)
    Advertising successfully started
    Security changed: 78:C3:E9:2F:A2:A1 (public) level 2

    I hope it helps.

    Kind regards,

    Pedro.

Reply
  • Hi Vidar,

    If done tests again with both mobiles. 

    Huawei P20 Pro

    Now it works fine. It connects correctly after bonding. See UART log and sniffer trace. p20-pro.pcapng

    *** Booting Zephyr OS build v3.3.99-ncs1-1 ***
    Starting Bluetooth Peripheral HIDS keyboard example
    [00:00:00.007,385] <inf> fs_nvs: nvs_mount: 6 Sectors of 4096 bytes
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: alloc wra: 0, fd0
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: data wra: 0, 1c
    [00:00:00.007,568] <inf> bt_sdc_hci_driver: hci_driver_open: SoftDevice Controller build revision: 
                                                e0 7e 2e c1 5e 05 85 23  46 15 dc fa 8e 29 7d 70 |.~..^..# F....)}p
                                                10 93 a5 fc                                      |....             
    [00:00:00.010,192] <inf> bt_hci_core: hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.010,223] <inf> bt_hci_core: hci_vs_init: HW Variant: nRF52x (0x0002)
    [00:00:00.010,253] <inf> bt_hci_core: hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 224.11902 Build 2231721665
    [00:00:00.010,681] <inf> bt_hci_core: bt_init: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.011,291] <inf> bt_hci_core: bt_dev_show_info: Identity: D7:06:A1:24:26:8D (random)
    [00:00:00.011,352] <inf> bt_hci_core: bt_dev_show_info: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
    [00:00:00.011,383] <inf> bt_hci_core: bt_dev_show_info: LMP: version 5.4 (0x0d) subver 0x1077
    Advertising successfully started
    Connected 79:E9:E4:BA:EC:DB (random)
    Advertising successfully started
    Security changed: 79:E9:E4:BA:EC:DB (random) level 2
    [00:00:16.172,271] <inf> bt_keys: bt_keys_show_sniffer_info: SC LTK: 0x9817d9b2bac95f1571a50ab7c81db99b
    Pairing completed: 3C:CD:5D:3F:DC:50 (public), bonded: 1
    Output report has been received 3C:CD:5D:3F:DC:50 (public)

    The operations done were: connect -> bond -> disconnect -> connect -> disconnect -> connect

    Samsung Galaxy J5

    Can not discover services. I did connect -> bond -> disconnect -> connect. See UART log and sniffer trace. galaxy-j5.pcapng

    *** Booting Zephyr OS build v3.3.99-ncs1-1 ***
    Starting Bluetooth Peripheral HIDS keyboard example
    [00:00:00.007,385] <inf> fs_nvs: nvs_mount: 6 Sectors of 4096 bytes
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: alloc wra: 0, fd0
    [00:00:00.007,415] <inf> fs_nvs: nvs_mount: data wra: 0, 1c
    [00:00:00.007,568] <inf> bt_sdc_hci_driver: hci_driver_open: SoftDevice Controller build revision: 
                                                e0 7e 2e c1 5e 05 85 23  46 15 dc fa 8e 29 7d 70 |.~..^..# F....)}p
                                                10 93 a5 fc                                      |....             
    [00:00:00.010,192] <inf> bt_hci_core: hci_vs_init: HW Platform: Nordic Semiconductor (0x0002)
    [00:00:00.010,223] <inf> bt_hci_core: hci_vs_init: HW Variant: nRF52x (0x0002)
    [00:00:00.010,253] <inf> bt_hci_core: hci_vs_init: Firmware: Standard Bluetooth controller (0x00) Version 224.11902 Build 2231721665
    [00:00:00.010,681] <inf> bt_hci_core: bt_init: No ID address. App must call settings_load()
    Bluetooth initialized
    [00:00:00.011,322] <inf> bt_hci_core: bt_dev_show_info: Identity: D7:06:A1:24:26:8D (random)
    [00:00:00.011,352] <inf> bt_hci_core: bt_dev_show_info: HCI: version 5.4 (0x0d) revision 0x1077, manufacturer 0x0059
    [00:00:00.011,383] <inf> bt_hci_core: bt_dev_show_info: LMP: version 5.4 (0x0d) subver 0x1077
    Advertising successfully started
    Connected 78:C3:E9:2F:A2:A1 (public)
    Advertising successfully started
    Security changed: 78:C3:E9:2F:A2:A1 (public) level 2
    [00:00:19.207,000] <inf> bt_keys: bt_keys_show_sniffer_info: Legacy LTK: 0xd1eb5ef3da7190910bc8048ae2db095d (peripheral)
    [00:00:19.207,061] <inf> bt_keys: bt_keys_show_sniffer_info: Legacy LTK: 0x3e34fdd7dd50cad6199205f79ce5f009 (central)
    Pairing completed: 78:C3:E9:2F:A2:A1 (public), bonded: 1
    Disconnected from 78:C3:E9:2F:A2:A1 (public) (reason 19)
    Advertising continued
    Connected 78:C3:E9:2F:A2:A1 (public)
    Advertising successfully started
    Security changed: 78:C3:E9:2F:A2:A1 (public) level 2

    I hope it helps.

    Kind regards,

    Pedro.

Children
Related