Persist Bonding Information with nimBLE

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Persist Bonding Information with nimBLE

Postby IanWhitehead » Thu Nov 07, 2019 10:01 pm

Hi,

I have been developing an app based on the bluetooth/nimble/bleprph example. Setting
.sm_io_cap = BLE_SM_IO_CAP_DISP_YES_NO
I am able to successfully complete a bonding operation. If, however, the peer device disconnects and tries to reconnect, the bonding process has to be repeated. A system reset, or system power cycle, also require the bonding process to be repeated.

Looking though the nimBLE code (esp-idf\components\bt\host\nimble\nimble\nimble\host\store) indicates to me that persisting of the Bonding Information is supported. In the ESP-IDF menuconfig (Component config - Bluetooth - NimBLE Options) there is an option to set the number of bonds to save across reboots (set to 3).

Is persisting bonding information currently supported for nimble under ESP-IDF? If so, what additional steps are required to initialize and implement?

I did find the following structure members in ble_hs_cfg (esp-idf\components\bt\host\nimble\nimble\nimble\host\include\host\ble_hs.h):

Code: Select all

    /* XXX: These need to go away. Instead, the nimble host package should
     * require the host-store API (not yet implemented)..
     */
    /** Storage Read callback handles read of security material */
    ble_store_read_fn *store_read_cb;

    /** Storage Write callback handles write of security material */
    ble_store_write_fn *store_write_cb;

    /** Storage Delete callback handles deletion of security material */
    ble_store_delete_fn *store_delete_cb;
It is not clear if there is a host-store API (and the comment is old) or if the store_read_cb and store_write_cb callback functions need to be implemented for persistent bonding to work.

Any help would be greatly appreciated.

Ian

ESP_Hrishi
Posts: 16
Joined: Fri Sep 28, 2018 3:06 am

Re: Persist Bonding Information with nimBLE

Postby ESP_Hrishi » Fri Nov 08, 2019 4:53 am

Hi @IanWhitehead,

Persistent bonding is supported in ESP-IDF for NimBLE host. Can you please enable bonding in the example configuration options `make menuconfig -> Example Configuration -> Use Bonding` which is disabled by default. Please give it a try and let us know if it helps. I just tested this and it seems to work fine at my end.

Feel free to raise an issue here in case of any problems

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Re: Persist Bonding Information with nimBLE

Postby IanWhitehead » Fri Nov 08, 2019 5:03 pm

Hi @ESP_Hrishi,

Thank you for the good news the persisting the bonding information is supported. I just need to figure out how to make it work!

I checked my configuration and "Use Bonding" is enabled.

To eliminate variables, and simplify reproducing the issue, I created a new project using the bleprph example and only changed the following items in menuconfig:
  • Example Configuration, I/O Capability = DISPLAY YESNO
  • Example Configuration, Use Bonding = Enabled
  • Example Configuration, MITM security = Enabled
  • Example Configuration, Use Secure Connection feature = Enabled
No changes were made to the source code. I can connected to the device (e.g. using LightBlue on iOS, or nRFConnect on Android).
When I access one of the characteristics I'm prompted to bond, and need to enter "key Y" on the console connection to complete the bonding. Disconnecting, then reconnecting looses the bonding information - I have to repeat the bonding process. On iOS I have to "Forget This Device" (under Settings -> Bluetooth) before I can rebond.

Are there any other configuration settings, or code changes that are required?

Ian

ESP_Prasad
Posts: 18
Joined: Tue Nov 12, 2019 7:46 am

Re: Persist Bonding Information with nimBLE

Postby ESP_Prasad » Tue Nov 12, 2019 9:01 am

@IanWhitehead, this is quite unusual, Can you please share the console logs and sdkconfig for this issue? Can you please also make sure that IDF_PATH is set correctly ? Ideally you should be able to see logs like below:
I (11254) NimBLE_BLE_PRPH: Accept or reject the passkey through console in this format -> key Y or key N
I (18894) You entered: key Y
I (18894) NimBLE_BLE_PRPH: ble_sm_inject_io result: 0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=xx our_id_addr_type=0 our_id_addr=xx peer_ota_addr_type=1 peer_ota_addr=xx peer_id_addr_type=1 peer_id_addr=xx conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=xx our_id_addr_type=0 our_id_addr=xx peer_ota_addr_type=1 peer_ota_addr=xx peer_id_addr_type=1 peer_id_addr=xx conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=xx our_id_addr_type=0 our_id_addr=xx peer_ota_addr_type=1 peer_ota_addr=xx peer_id_addr_type=1 peer_id_addr=xx conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=xx our_id_addr_type=0 our_id_addr=xx peer_ota_addr_type=1 peer_ota_addr=xx peer_id_addr_type=1 peer_id_addr=xx conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=xx our_id_addr_type=0 our_id_addr=xx peer_ota_addr_type=1 peer_ota_addr=xx peer_id_addr_type=1 peer_id_addr=xx conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Re: Persist Bonding Information with nimBLE

Postby IanWhitehead » Wed Nov 13, 2019 7:54 pm

Hi @ESP_Prasad,

Here is a complete console log, showing the repeat bonding:

Code: Select all

--- idf_monitor on COM6 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
       ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x3f (SPI_FAST_FLASets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6948
load:0x40078000,len:14044
load:0x40080400,len:4304
entry 0x400806e8
I (72) boot: Chip Revision: 1
I (72) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (40) boot: ESP-IDF v4.0-beta2-70-g0a03a55c1 2nd stage bootloader
I (40) boot: compile time 14:28:36
I (40) boot: Enabling RNG early entropy source...
I (46) boot: SPI Speed      : 40MHz
I (50) boot: SPI Mode       : DIO
I (54) boot: SPI Flash Size : 2MB
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (95) boot_comm: chip revision: 1, min. application chip revision: 0
I (102) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0dae0 ( 56032) map
I (132) esp_image: segment 1: paddr=0x0001db08 vaddr=0x3ffbdb60 size=0x02508 (  9480) load
I (136) esp_image: segment 2: paddr=0x00020018 vaddr=0x400d0018 size=0x50bec (330732) map
0x400d0018: _stext at ??:?

I (257) esp_image: segment 3: paddr=0x00070c0c vaddr=0x3ffc0068 size=0x0086c (  2156) load
I (258) esp_image: segment 4: paddr=0x00071480 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

I (264) esp_image: segment 5: paddr=0x00071888 vaddr=0x40080400 size=0x12f88 ( 77704) load
I (317) boot: Loaded app from partition at offset 0x10000
I (317) boot: Disabling RNG early entropy source...
I (317) cpu_start: Pro cpu up.
I (321) cpu_start: Application information:
I (326) cpu_start: Project name:     bleprph
I (330) cpu_start: App version:      v4.0-beta2-70-g0a03a55c1
I (337) cpu_start: Compile time:     Nov 13 2019 14:28:02
I (343) cpu_start: ELF file SHA256:  068ce1d332cde3f2...
I (349) cpu_start: ESP-IDF:          v4.0-beta2-70-g0a03a55c1
I (355) cpu_start: Starting app cpu, entry point is 0x400812a0
0x400812a0: call_start_cpu1 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/esp32/cpu_start.c:272

I (0) cpu_start: App cpu up.
I (366) heap_init: Initializing. RAM available for dynamic allocation:
I (373) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (379) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (385) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (391) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (397) heap_init: At 3FFC6080 len 00019F80 (103 KiB): DRAM
I (403) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (410) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (416) heap_init: At 40093388 len 0000CC78 (51 KiB): IRAM
I (422) cpu_start: Pro cpu start user code
I (441) spi_flash: detected chip: generic
I (441) spi_flash: flash io: dio
W (441) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (452) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (517) BTDM_INIT: BT controller compile version [d6bb204]
I (517) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (607) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
I (867) NimBLE_BLE_PRPH: BLE Host Task Started
I (867) uart: queue free spaces: 8
GAP procedure initiated: stop advertising.
Device Address: 4c:11:ae:6c:55:02
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

I (33097) NimBLE_BLE_PRPH: PASSKEY_ACTION_EVENT started

I (33097) NimBLE_BLE_PRPH: Passkey on device's display: 462787
I (33097) NimBLE_BLE_PRPH: Accept or reject the passkey through console in this format -> key Y or key N
I (46297) You entered: key Y
I (46297) NimBLE_BLE_PRPH: ble_sm_inject_io result: 0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=77:b3:3a:3d:02:4a peer_id_addr_type=1 peer_id_addr=77:b3:3a:3d:02:4a conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=7b:11:64:d7:27:18 peer_id_addr_type=1 peer_id_addr=7b:11:64:d7:27:18 conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=7b:11:64:d7:27:18 peer_id_addr_type=1 peer_id_addr=7b:11:64:d7:27:18 conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=0 authenticated=0 bonded=0

I (64577) NimBLE_BLE_PRPH: PASSKEY_ACTION_EVENT started

I (64577) NimBLE_BLE_PRPH: Passkey on device's display: 921319
I (64577) NimBLE_BLE_PRPH: Accept or reject the passkey through console in this format -> key Y or key N
I (76437) You entered: key Y
I (76437) NimBLE_BLE_PRPH: ble_sm_inject_io result: 0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=7b:11:64:d7:27:18 peer_id_addr_type=1 peer_id_addr=7b:11:64:d7:27:18 conn_itvl=6 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1

connection updated; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=7b:11:64:d7:27:18 peer_id_addr_type=1 peer_id_addr=7b:11:64:d7:27:18 conn_itvl=39 conn_latency=0 supervision_timeout=500 encrypted=1 authenticated=1 bonded=1
The sdkconfig file is attached.

For IDF_PATH, I get the following IDF parameters if I do a "set" command at the ESP-IDF Command Prompt:
IDF_GIT_DIR=C:\Program Files\Git\cmd
IDF_PATH=C:\Users\ian.whitehead\Desktop\esp\esp-idf
IDF_PYTHON_DIR=C:\Users\ian.whitehead\AppData\Local\Programs\Python\Python37\
IDF_PYTHON_ENV_PATH=C:\Users\ian.whitehead\.espressif\python_env\idf4.0_py3.7_env
IDF_TOOLS_PATH=C:\Users\ian.whitehead\.espressif
I hope you see something that is amiss!

Many thanks,

Ian
Attachments
sdkconfig.txt
sdkconfig, ".txt" suffix added to upload to forum.
(29.19 KiB) Downloaded 646 times

ESP_Prasad
Posts: 18
Joined: Tue Nov 12, 2019 7:46 am

Re: Persist Bonding Information with nimBLE

Postby ESP_Prasad » Thu Nov 14, 2019 6:24 am

@IanWhitehead , from the logs it can be observed that the `peer_id_addr` is changed. Now from the Bluetooth spec (Vol 6, Part B, section 1.3.2.1) :
If the static address of a device is changed, then the address stored in
peer devices will not be valid and the ability to reconnect using the old address
will be lost.
If the `peer_id_addr` is changed then this is treated as a new device, that is why you see the issue with bonding. Are you restarting your Android peer device before reconnection? Because I don't see any other reason for change in `peer_id_addr`.

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Re: Persist Bonding Information with nimBLE

Postby IanWhitehead » Thu Nov 14, 2019 4:35 pm

@ESP_Prasad your observation of the peer address changing, being the cause for the bonding not persisting, makes sense. I don't know why my Android device (Samsung Galaxy S9) would change addresses, I did not restart or reset it.

To explore further, I tried using my iPhone 7 and LightBlue, the console log follow ... the peer address does not change, but the bonding is not persisted, so there has to be something else going on:

Code: Select all

--- idf_monitor on COM6 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6980
load:0x40078000,len:14044
load:0x40080400,len:4304
entry 0x400806e8
I (71) boot: Chip Revision: 1
I (71) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot: ESP-IDF v4.0-beta2-70-g0a03a55c1 2nd stage bootloader
I (39) boot: compile time 10:03:02
I (39) boot: Enabling RNG early entropy source...
I (45) boot: SPI Speed      : 40MHz
I (50) boot: SPI Mode       : DIO
I (54) boot: SPI Flash Size : 2MB
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (95) boot_comm: chip revision: 1, min. application chip revision: 0
I (102) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0db00 ( 56064) map
I (131) esp_image: segment 1: paddr=0x0001db28 vaddr=0x3ffbdb60 size=0x024e8 (  9448) load
I (135) esp_image: segment 2: paddr=0x00020018 vaddr=0x400d0018 size=0x50bec (330732) map
0x400d0018: _stext at ??:?

I (256) esp_image: segment 3: paddr=0x00070c0c vaddr=0x3ffc0048 size=0x0088c (  2188) load
I (257) esp_image: segment 4: paddr=0x000714a0 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

I (263) esp_image: segment 5: paddr=0x000718a8 vaddr=0x40080400 size=0x12f88 ( 77704) load
I (316) boot: Loaded app from partition at offset 0x10000
I (316) boot: Disabling RNG early entropy source...
I (317) cpu_start: Pro cpu up.
I (320) cpu_start: Application information:
I (325) cpu_start: Project name:     bleprph
I (330) cpu_start: App version:      1
I (335) cpu_start: Compile time:     Nov 14 2019 10:34:23
I (341) cpu_start: ELF file SHA256:  5ee6e6edd5517063...
I (347) cpu_start: ESP-IDF:          v4.0-beta2-70-g0a03a55c1
I (353) cpu_start: Starting app cpu, entry point is 0x400812a0
0x400812a0: call_start_cpu1 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/esp32/cpu_start.c:272

I (0) cpu_start: App cpu up.
I (364) heap_init: Initializing. RAM available for dynamic allocation:
I (370) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (376) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (382) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (389) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (395) heap_init: At 3FFC6080 len 00019F80 (103 KiB): DRAM
I (401) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (407) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (414) heap_init: At 40093388 len 0000CC78 (51 KiB): IRAM
I (420) cpu_start: Pro cpu start user code
I (438) spi_flash: detected chip: generic
I (439) spi_flash: flash io: dio
W (439) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (449) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (515) BTDM_INIT: BT controller compile version [d6bb204]
I (515) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (605) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
I (855) NimBLE_BLE_PRPH: BLE Host Task Started
I (855) uart: queue free spaces: 8
GAP procedure initiated: stop advertising.
Device Address: 4c:11:ae:6c:55:02
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=43:21:28:b2:02:9e peer_id_addr_type=1 peer_id_addr=43:21:28:b2:02:9e conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=1 prevn=0 curn=0 previ=0 curi=1
I (41625) NimBLE_BLE_PRPH: PASSKEY_ACTION_EVENT started

I (41625) NimBLE_BLE_PRPH: Passkey on device's display: 60590
I (41625) NimBLE_BLE_PRPH: Accept or reject the passkey through console in this format -> key Y or key N
I (56375) You entered: key Y
I (56375) NimBLE_BLE_PRPH: ble_sm_inject_io result: 0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=43:21:28:b2:02:9e peer_id_addr_type=1 peer_id_addr=43:21:28:b2:02:9e conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=43:21:28:b2:02:9e peer_id_addr_type=1 peer_id_addr=43:21:28:b2:02:9e conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=43:21:28:b2:02:9e peer_id_addr_type=1 peer_id_addr=43:21:28:b2:02:9e conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=1 prevn=0 curn=0 previ=0 curi=1
I'm using release/v4.0 of ESP-IDF and running on an ESP32-WROOM-32D.

I wondered if the Example Configuration setting "Use Secure Connection Feature" was affecting the peer address changing, or the Bonding persistence, so turned the feature off. It had no effect on either the peer address changing (on Android), or the Bonding persistence but it did affect the I/O Capability - I had this set to DISPLAY YESNO in Menuconfig, but the image execute as if it were set to DISPLAY ONLY - I was prompted to enter a 6 digit code (123456) on the phone. Is this the intended result?

Any thoughts?

Ian

ESP_Prasad
Posts: 18
Joined: Tue Nov 12, 2019 7:46 am

Re: Persist Bonding Information with nimBLE

Postby ESP_Prasad » Thu Nov 14, 2019 6:58 pm

@IanWhitehead, Can you please confirm you did not get `BLE_GAP_EVENT_ENC_CHANGE` event after re-connection ? Can you please try `bleprph` example enabling bonding with "non address changing" device and provide me the complete log and sdkconfig file?
I wondered if the Example Configuration setting "Use Secure Connection Feature" was affecting the peer address changing, or the Bonding persistence, so turned the feature off. It had no effect on either the peer address changing (on Android), or the Bonding persistence but it did affect the I/O Capability - I had this set to DISPLAY YESNO in Menuconfig, but the image execute as if it were set to DISPLAY ONLY - I was prompted to enter a 6 digit code (123456) on the phone. Is this the intended result?
Secure connection is feature introduced from Bluetooth 4.2, if you disable it, it will be simply LE legacy pairing. In secure connection you get Numerical comparison association model which is not present in LE legacy when "DISPLAY YESNO" is selected, that is why you get "passkey display" after disabling the feature.

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Re: Persist Bonding Information with nimBLE

Postby IanWhitehead » Fri Nov 15, 2019 5:28 pm

@ESP_Prasad I have made some progress. The console trace below shows multiple connect/disconnect sequences with bonding persisting. I was using the iPhone 7 that used the same peer address each time. The main difference is that I disabled Security manager legacy pairing configuration option (Component -> Bluetooth -> NimBLE Options). Full sdkconfig file is attached.

Another thing that may have helped was erasing all of flash (idf.py -p PORT erase_flash). This presumably erased any previously stored bonding information. Does the ESP-IDF automatically handle recycling of NVS storage for saving bonding information (e.g. erasing oldest peer info when table is full)? Is there a mechanism for reading out the currently stored bonding info?

To answer your question about `BLE_GAP_EVENT_ENC_CHANGE` - Yes, the console log below shows one of these events for each connection.

I will continue to test the bonding persistence with the new configuration, and update with any new information.

Many thanks,

Ian

Code: Select all

--- idf_monitor on COM6 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0018,len:4
load:0x3fff001c,len:6980
load:0x40078000,len:14044
load:0x40080400,len:4304
entry 0x400806e8
I (71) boot: Chip Revision: 1
I (71) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (39) boot: ESP-IDF v4.0-beta2-70-g0a03a55c1 2nd stage bootloader
I (39) boot: compile time 10:03:02
I (39) boot: Enabling RNG early entropy source...
I (45) boot: SPI Speed      : 40MHz
I (49) boot: SPI Mode       : DIO
I (53) boot: SPI Flash Size : 2MB
I (58) boot: Partition Table:
I (61) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (83) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (95) boot_comm: chip revision: 1, min. application chip revision: 0
I (102) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x0d940 ( 55616) map
I (131) esp_image: segment 1: paddr=0x0001d968 vaddr=0x3ffbdb60 size=0x026a8 (  9896) load
I (135) esp_image: segment 2: paddr=0x00020018 vaddr=0x400d0018 size=0x4efb4 (323508) map
0x400d0018: _stext at ??:?

I (253) esp_image: segment 3: paddr=0x0006efd4 vaddr=0x3ffc0208 size=0x006cc (  1740) load
I (254) esp_image: segment 4: paddr=0x0006f6a8 vaddr=0x40080000 size=0x00400 (  1024) load
0x40080000: _WindowOverflow4 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

I (261) esp_image: segment 5: paddr=0x0006fab0 vaddr=0x40080400 size=0x12f88 ( 77704) load
I (313) boot: Loaded app from partition at offset 0x10000
I (314) boot: Disabling RNG early entropy source...
I (314) cpu_start: Pro cpu up.
I (318) cpu_start: Application information:
I (322) cpu_start: Project name:     bleprph
I (327) cpu_start: App version:      1
I (332) cpu_start: Compile time:     Nov 15 2019 09:50:34
I (338) cpu_start: ELF file SHA256:  fdb7aadd48f5f380...
I (344) cpu_start: ESP-IDF:          v4.0-beta2-70-g0a03a55c1
I (350) cpu_start: Starting app cpu, entry point is 0x400812a0
0x400812a0: call_start_cpu1 at C:/Users/ian.whitehead/Desktop/esp/esp-idf/components/esp32/cpu_start.c:272

I (0) cpu_start: App cpu up.
I (361) heap_init: Initializing. RAM available for dynamic allocation:
I (368) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (374) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (380) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (386) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (392) heap_init: At 3FFC6080 len 00019F80 (103 KiB): DRAM
I (398) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (405) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (411) heap_init: At 40093388 len 0000CC78 (51 KiB): IRAM
I (417) cpu_start: Pro cpu start user code
I (435) spi_flash: detected chip: generic
I (436) spi_flash: flash io: dio
W (436) spi_flash: Detected size(4096k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (447) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (481) BTDM_INIT: BT controller compile version [d6bb204]
I (491) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
I (591) phy: phy_version: 4102, 2fa7a43, Jul 15 2019, 13:06:06, 0, 0
I (831) NimBLE_BLE_PRPH: BLE Host Task Started
I (831) uart: queue free spaces: 8
GAP procedure initiated: stop advertising.
Device Address: 4c:11:ae:6c:55:02
GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=1 prevn=0 curn=0 previ=0 curi=1
I (30821) NimBLE_BLE_PRPH: PASSKEY_ACTION_EVENT started

I (30821) NimBLE_BLE_PRPH: Passkey on device's display: 296766
I (30821) NimBLE_BLE_PRPH: Accept or reject the passkey through console in this format -> key Y or key N
I (43371) You entered: key Y
I (43371) NimBLE_BLE_PRPH: ble_sm_inject_io result: 0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
connection established; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=0 authenticated=0 bonded=0

encryption change event; status=0 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

subscribe event; conn_handle=0 attr_handle=8 reason=3 prevn=0 curn=0 previ=0 curi=1
mtu update event; conn_handle=0 cid=4 mtu=256
subscribe event; conn_handle=0 attr_handle=8 reason=2 prevn=0 curn=0 previ=1 curi=0
disconnect; reason=531 handle=0 our_ota_addr_type=0 our_ota_addr=4c:11:ae:6c:55:02 our_id_addr_type=0 our_id_addr=4c:11:ae:6c:55:02 peer_ota_addr_type=1 peer_ota_addr=49:1b:80:bb:70:31 peer_id_addr_type=1 peer_id_addr=49:1b:80:bb:70:31 conn_itvl=24 conn_latency=0 supervision_timeout=72 encrypted=1 authenticated=1 bonded=1

GAP procedure initiated: advertise; disc_mode=2 adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=0 adv_itvl_max=0
Attachments
sdkconfig.txt
.txt suffix added to upload to forum
(29.23 KiB) Downloaded 695 times

IanWhitehead
Posts: 7
Joined: Wed Nov 06, 2019 8:58 pm

Re: Persist Bonding Information with nimBLE

Postby IanWhitehead » Sun Nov 17, 2019 6:57 pm

@ESP_Prasad After more testing I found that the iPhone will (also) try to connect using a different address - it seems to be time based
(e.g. If I disconnect, then wait 30 minutes before trying to reconnect, it will use a different address). My understanding is that this is typically behavior for BLE 4.2 (or greater), to enhance privacy. Presumably these addresses are Resolvable Private Addresses, that the host should be able to resolve using an IRK (Identity Resolving Key). Does privacy have to be enabled on the Peripheral, for peer addresses to be resolved? e.g.:

Code: Select all

    rc = ble_hs_id_infer_auto(1, &own_addr_type);
If I set the Default Log verbosity to DEBUG (in menuconfig) I can see bonding information being saved, then restored on a subsequent power-cycle or reset. The issue seems to be with the address resolving.

I appreciate any help you can offer to resolve (pun intended!) this.

Ian

Who is online

Users browsing this forum: karunt, ok-home and 71 guests