NRF52840 NRF Connect desktop pairing / bonding issue

[swisst]

Good day

I use NRF52840 + SDK v17.0.2. My application relies on _gls example and mainly copies its security settings ( also uses peer manager ) except I use MITM protection for my characteristics and static pin code approach.

The root cause of issue is that behavior of NRF Connect for mobile (Android ) and for desktop differs. Our test app behaves correctly - I would say in the same way as NRF Connect for Android.

If shortly for Android ( NRF Connect app ) and iOS ( our test app ) during connection and bonding everything goes smoothly and I get expected result - I see pairing requests and system textbox for pin code input on both devices, after bonding is done I am able to connect without pin input.

The situation with NRF connect is different. It runs with 52840 usb dongle on Ubuntu, the version is 3.6.1 ( also tried 3.6.0 ). I tried both options: with automatic security response and manual - the result is the same - I can not get pin request on the screen thus device can not bond

Despite of MITM flag set in NRF Connect - anyway I get: Collector did not use MITM, disconnecting

Please advise what did I miss or what am I doing wrong. 2 log files are attached ( RTT output )

Thank you

Android /iOS - OK flow

Fullscreen 4747.Android_bonding_log.log Download

<info> app: Reset reason: 1
<info> app: Setting vector table to bootloader: 0x000F1000
<info> app: Setting vector table to main app: 0x00027000
<info> app: battery_service_init() completed: 0
<info> app: battery_service_init() completed
<info> app: Device id: 4fd1919f9a9b83a6
<info> app: MAC address: f0:7f:1e:fa:9a:08, type: -1
<info> app: dis_service_init() completed: 0
<error> app_serial: uart_event_handle(): APP_UART_COMMUNICATION_ERROR -> 4
<debug> nrf_ble_lesc: Initialized nrf_crypto.
<debug> nrf_ble_lesc: Initialized nrf_ble_lesc.
<debug> nrf_ble_lesc: Generating ECC key pair
<info> app_timer: RTC: initialized.
<info> app_adc: adc_init()
<info> app_indic: indicate INDICATE_IDLE = 0
<info> app_btn: button_configure: STATE_STARTUP
<info> app_twi_manager: twi_manager_init()
<info> app_pmic: global status 0x40
<info> app_pmic: ercflag 0x00
<info> app_state: set_ext_powered: FALSE, current state: STATE_ADVERTISING
<info> app_indic: indicate INDICATE_CHARGE_UNPLUGGED
<info> app_state: set_charging: FALSE
<info> app_pmic: charge status 0x00 0x00
<debug> nrf_ble_gatt: Requesting to update ATT MTU to 247 bytes on connection 0x0.
<debug> nrf_ble_gatt: Updating data length to 251 on connection 0x0.
<info> app_serial_srv: on_ble_event: BLE_GAP_EVT_CONNECTED
<info> peer_manager_handler: pm_handler_secure_on_connection: BLE_GAP_EVT_CONNECTED
<info> peer_manager_handler: Connected, securing connection. conn_handle: 0
<info> app: ble_evt_handler: BLE_GAP_EVT_CONNECTED
<info> app_state: state_set: STATE_CONNECTED
<info> app_indic: indicate INDICATE_CONNECTED
<info> app_btn: button_configure: STATE_CONNECTED
<info> app_pmic: pmic_ir_enable( TRUE )
<info> app_pmic: pmic_ir_enable(): err_code 0 
<info> app: pmic_ir_enable_callback
<info> app: Data len is set to 0xF4(244)
<debug> app: ATT MTU exchange completed. central 0xF7 peripheral 0xF7
<info> app_serial_srv: on_ble_event: 58
<info> peer_manager_handler: pm_handler_secure_on_connection: event 58
<info> app: ble_evt_handler: 58
<debug> nrf_ble_gatt: Data length updated to 251 on connection 0x0.
<debug> nrf_ble_gatt: max_rx_octets: 27
<debug> nrf_ble_gatt: max_tx_octets: 251
<debug> nrf_ble_gatt: max_rx_time: 328
<debug> nrf_ble_gatt: max_tx_time: 2120
<debug> app: ATT MTU exchange completed. central 0xF7 peripheral 0xF7
<info> app_serial_srv: on_ble_event: 36
<info> app: ble_evt_handler: 36
<info> app: pm_evt_handler(): 5
<info> app_serial_srv: on_ble_event: 18
<info> peer_manager_handler: pm_handler_secure_on_connection: event 18
<info> app: ble_evt_handler: BLE_GAP_EVT_CONN_PARAM_UPDATE
<info> app_serial_srv: on_ble_event: 18
<info> peer_manager_handler: pm_handler_secure_on_connection: event 18
<info> app: ble_evt_handler: BLE_GAP_EVT_CONN_PARAM_UPDATE
<info> app: pm_evt_handler(): 1
<info> app: pm_evt_handler(): 5
<info> app_serial_srv: on_ble_event: 19
<info> peer_manager_handler: pm_handler_secure_on_connection: event 19
<info> app: ble_evt_handler: BLE_GAP_EVT_SEC_PARAMS_REQUEST
<info> app_serial_srv: on_ble_event: 18
<info> peer_manager_handler: pm_handler_secure_on_connection: event 18
<info> app: ble_evt_handler: BLE_GAP_EVT_CONN_PARAM_UPDATE
<info> app_serial_srv: on_ble_event: 21
<info> peer_manager_handler: pm_handler_secure_on_connection: event 21
<info> app: ble_evt_handler: BLE_GAP_EVT_PASSKEY_DISPLAY
<info> app: Passkey: 123456
<info> app_serial_srv: on_ble_event: 26
<info> peer_manager_handler: pm_handler_secure_on_connection: event 26
<info> app: ble_evt_handler: 26
<info> peer_manager_handler: Connection secured: role: Peripheral, conn_handle: 0, procedure: Bonding
<info> app: pm_evt_handler(): PM_EVT_CONN_SEC_SUCCEEDED
<info> app: Link secured. Role: 1. conn_handle: 0, Procedure: 1
<info> app_serial_srv: on_ble_event: 25
<info> peer_manager_handler: pm_handler_secure_on_connection: event 25
<info> app: ble_evt_handler: BLE_GAP_EVT_AUTH_STATUS
<info> app:     status=0x0 bond=0x1 lv4: 0 kdist_own:0x3 kdist_peer:0x3
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app_serial_srv: on_ble_event: 53
<info> peer_manager_handler: pm_handler_secure_on_connection: event 53
<info> app: ble_evt_handler: 53
<info> app_serial_srv: on_ble_event: 54
<info> peer_manager_handler: pm_handler_secure_on_connection: event 54
<info> app: ble_evt_handler: 54
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app_serial_srv: on_ble_event: BLE_GATTS_EVT_WRITE
<info> peer_manager_handler: pm_handler_secure_on_connection: event 80
<info> app: ble_evt_handler: 80
<info> peer_manager_handler: Peer data updated in flash: peer_id: 0, data_id: Local database, action: Update
<info> app: PM_EVT_PEER_DATA_UPDATE_SUCCEEDED
<info> app: pm_evt_handler(): 14
<info> app_serial_srv: on_ble_event: 82
<info> peer_manager_handler: pm_handler_secure_on_connection: event 82
<info> app: ble_evt_handler: BLE_GATTS_EVT_SYS_ATTR_MISSING
> 

NRF connect for desktop - FAIL flow

Fullscreen 4786.PC_bonding_fail_log.log Download

<info> app: Reset reason: 1
<info> app: Setting vector table to bootloader: 0x000F1000
<info> app: Setting vector table to main app: 0x00027000
<info> app: battery_service_init() completed: 0
<info> app: battery_service_init() completed
<info> app: Device id: 4fd1919f9a9b83a6
<info> app: MAC address: f0:7f:1e:fa:9a:08, type: -1
<info> app: dis_service_init() completed: 0
<debug> nrf_ble_lesc: Initialized nrf_crypto.
<debug> nrf_ble_lesc: Initialized nrf_ble_lesc.
<debug> nrf_ble_lesc: Generating ECC key pair
<info> app_timer: RTC: initialized.
<info> app_adc: adc_init()
<info> app_indic: indicate INDICATE_IDLE = 0
<info> app_btn: button_configure: STATE_STARTUP
<info> app_pmic: global status 0x40
<info> app_pmic: ercflag 0x00
<info> app_state: set_ext_powered: FALSE, current state: STATE_ADVERTISING
<info> app_indic: indicate INDICATE_CHARGE_UNPLUGGED
<info> app_state: set_charging: FALSE
<info> app_pmic: charge status 0x00 0x00
<debug> nrf_ble_gatt: Requesting to update ATT MTU to 247 bytes on connection 0x0.
<debug> nrf_ble_gatt: Updating data length to 251 on connection 0x0.
<info> app_serial_srv: on_ble_event: BLE_GAP_EVT_CONNECTED
<info> peer_manager_handler: pm_handler_secure_on_connection: BLE_GAP_EVT_CONNECTED
<info> peer_manager_handler: Connected, securing connection. conn_handle: 0
<info> app: ble_evt_handler: BLE_GAP_EVT_CONNECTED
<info> app_state: state_set: STATE_CONNECTED
<info> app_indic: indicate INDICATE_CONNECTED
<info> app_btn: button_configure: STATE_CONNECTED
<info> app_pmic: pmic_ir_enable( TRUE )
<info> app_pmic: pmic_ir_enable(): err_code 0 
<info> app: pmic_ir_enable_callback
<debug> nrf_ble_gatt: ATT MTU updated to 247 bytes on connection 0x0 (response).
<info> app: Data len is set to 0xF4(244)
<debug> app: ATT MTU exchange completed. central 0xF7 peripheral 0xF7
<info> app_serial_srv: on_ble_event: 58
<info> peer_manager_handler: pm_handler_secure_on_connection: event 58
<info> app: ble_evt_handler: 58
<info> app: pm_evt_handler(): 5
<info> app: pm_evt_handler(): 1
<info> app: pm_evt_handler(): 5
<info> app_serial_srv: on_ble_event: 19
<info> peer_manager_handler: pm_handler_secure_on_connection: event 19
<info> app: ble_evt_handler: BLE_GAP_EVT_SEC_PARAMS_REQUEST
<info> app_serial_srv: on_ble_event: 26
<info> peer_manager_handler: pm_handler_secure_on_connection: event 26
<info> app: ble_evt_handler: 26
<info> peer_manager_handler: Connection secured: role: Peripheral, conn_handle: 0, procedure: Pairing
<info> app: pm_evt_handler(): PM_EVT_CONN_SEC_SUCCEEDED
<info> app: Collector did not use MITM, disconnecting
<info> app:     m_peer_to_be_deleted: 65535
<debug> app: Disconnected connection handle 0
<info> app_serial_srv: on_ble_event: 25
<info> peer_manager_handler: pm_handler_secure_on_connection: event 25
<info> app: ble_evt_handler: BLE_GAP_EVT_AUTH_STATUS
<info> app:     status=0x0 bond=0x0 lv4: 0 kdist_own:0x0 kdist_peer:0x0
<info> app: pm_whitelist_get returns 0 addr in whitelist and 0 irk whitelist
<info> app: on_adv_evt: BLE_ADV_EVT_FAST
<info> app_state: state_set: STATE_ADVERTISING
<info> app_indic: indicate INDICATE_ADVERTISING
<info> app_btn: button_configure: STATE_ADVERTISING
<info> app_serial_srv: on_ble_event: BLE_GAP_EVT_DISCONNECTED
<info> app: pmic_ir_disable_callback
> 

[Einar Thorsrud]

Hi,

I am not able to reproduce this. Using the unmodified GLS example from SDK 17.0.2 and nRF Connect 3.6.1 with BLE app 2.5.1 I connect and immediately pair with MITM.

nRF side log:

<info> app_timer: RTC: initialized.
<info> app: advdata size: 31
<info> app: srdata size: 0
<info> app: Glucose example started.
<info> app: Fast advertising
<info> app: Connected
<info> app: Passkey: 671717
<info> app: BLE_GAP_EVT_LESC_DHKEY_REQUEST
<info> nrf_ble_lesc: Calling sd_ble_gap_lesc_dhkey_reply on conn_handle: 0
<info> peer_manager_handler: Connection secured: role: Peripheral, conn_handle: 0, procedure: Pairing
<info> app: Link secured. Role: 1. conn_handle: 0, Procedure: 2
<info> app: BLE_GAP_EVT_AUTH_STATUS: status=0x0 bond=0x0 lv4: 1 kdist_own:0x0 kdist_peer:0x0

nRF Connect log:

2021-05-20T16_28_50.764Z-log.txt

Which version of the nRF Connect BLE app are you using? Could there be other factors here? Can you upload the log from nRF Connect?

[swisst]

Hi

Sorry for delayed reply

NRF Connect is recent one v3.6.1

Fullscreen NRF_Connect_log_autoresponse.log Download

# NRF PC DONGLE open device

2021-05-25T12:57:51.959Z INFO Device setup completed
2021-05-25T12:57:51.960Z INFO Connectivity firmware version: ble-connectivity 4.1.2+Jul-14-2020-05-48-48. SoftDevice API version: 5. Baud rate: 1000000.
2021-05-25T12:57:51.963Z INFO Opening adapter connected to /dev/ttyACM0
2021-05-25T12:57:52.902Z INFO Successfully opened /dev/ttyACM0. Baud rate: 1000000. Flow control: none. Parity: none.
2021-05-25T12:57:52.903Z DEBUG     1/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
2021-05-25T12:57:52.903Z DEBUG State change: STATE_START -> STATE_RESET
2021-05-25T12:57:52.903Z DEBUG        1 ->  [N/A] type:          RESERVED_5 reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:52.908Z INFO Reset performed on adapter /dev/ttyACM0
2021-05-25T12:57:53.203Z DEBUG State change: STATE_RESET -> STATE_UNINITIALIZED
2021-05-25T12:57:53.203Z DEBUG        2 ->  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
2021-05-25T12:57:53.204Z DEBUG     2/ 0 <-  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP]
2021-05-25T12:57:53.204Z DEBUG State change: STATE_UNINITIALIZED -> STATE_INITIALIZED
2021-05-25T12:57:53.204Z DEBUG        3 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.454Z DEBUG        4 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.603Z DEBUG     3/ 0 <-  [01 7e ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC]
2021-05-25T12:57:53.604Z DEBUG        5 ->  [02 7d ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:2 data_integrity:0 err_code:0x0 [SYNC_RESP]
2021-05-25T12:57:53.704Z DEBUG        6 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.705Z DEBUG     4/ 0 <-  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.705Z DEBUG        7 ->  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.955Z DEBUG        8 ->  [03 fc 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.955Z DEBUG     5/ 0 <-  [04 7b 11 ] type: LINK_CONTROL_PACKET reliable: no seq#:0 ack#:0 payload_length:3 data_integrity:0 err_code:0x0 [CONFIG_RESP [ sliding-window-size:1 out-of-frame:0 data-integrity-check-type:1 version-number:0 ]]
2021-05-25T12:57:53.955Z DEBUG State change: STATE_INITIALIZED -> STATE_ACTIVE
2021-05-25T12:57:54.001Z INFO Adapter connected to /dev/ttyACM0 opened
2021-05-25T12:57:54.004Z DEBUG        9 ->  [00 69 20 00 00 00 01 01 08 a0 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:0 payload_length:b data_integrity:1 header_checksum:82 err_code:0x0
2021-05-25T12:57:54.004Z DEBUG     6/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.005Z DEBUG     7/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:1 payload_length:6 data_integrity:1 header_checksum:ca err_code:0x0
2021-05-25T12:57:54.005Z DEBUG       10 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.005Z DEBUG       11 ->  [00 69 23 00 00 00 01 01 f7 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:1 payload_length:a data_integrity:1 header_checksum:89 err_code:0x0
2021-05-25T12:57:54.006Z DEBUG     8/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.006Z DEBUG     9/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:2 payload_length:6 data_integrity:1 header_checksum:c1 err_code:0x0
2021-05-25T12:57:54.006Z DEBUG       12 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.007Z DEBUG       13 ->  [00 69 01 00 00 00 01 0a ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:2 payload_length:8 data_integrity:1 header_checksum:a0 err_code:0x0
2021-05-25T12:57:54.007Z DEBUG    10/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.008Z DEBUG    11/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:3 payload_length:6 data_integrity:1 header_checksum:b8 err_code:0x0
2021-05-25T12:57:54.008Z DEBUG       14 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.008Z DEBUG       15 ->  [00 69 40 00 00 00 01 01 07 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:3 payload_length:a data_integrity:1 header_checksum:77 err_code:0x0
2021-05-25T12:57:54.009Z DEBUG    12/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.009Z DEBUG    13/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:4 payload_length:6 data_integrity:1 header_checksum:af err_code:0x0
2021-05-25T12:57:54.010Z DEBUG       16 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.010Z DEBUG       17 ->  [00 69 a0 00 00 00 01 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:4 payload_length:8 data_integrity:1 header_checksum:8e err_code:0x0
2021-05-25T12:57:54.011Z DEBUG    14/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.011Z DEBUG    15/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:5 payload_length:6 data_integrity:1 header_checksum:a6 err_code:0x0
2021-05-25T12:57:54.012Z DEBUG       18 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.012Z DEBUG       19 ->  [00 69 a1 00 00 00 01 80 05 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:5 payload_length:b data_integrity:1 header_checksum:55 err_code:0x0
2021-05-25T12:57:54.012Z DEBUG    16/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.013Z DEBUG    17/ 0 <-  [01 69 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:6 payload_length:6 data_integrity:1 header_checksum:9d err_code:0x0
2021-05-25T12:57:54.013Z DEBUG       20 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.014Z DEBUG       21 ->  [00 60 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:6 payload_length:2 data_integrity:1 header_checksum:dc err_code:0x0
2021-05-25T12:57:54.014Z DEBUG    18/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.014Z DEBUG    19/ 0 <-  [01 60 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:7 payload_length:6 data_integrity:1 header_checksum:94 err_code:0x0
2021-05-25T12:57:54.015Z DEBUG       22 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.057Z DEBUG       23 ->  [00 65 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:7 payload_length:3 data_integrity:1 header_checksum:c3 err_code:0x0
2021-05-25T12:57:54.058Z DEBUG    20/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.059Z DEBUG    21/ 0 <-  [01 65 00 00 00 00 09 59 00 a5 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:0 payload_length:b data_integrity:1 header_checksum:7b err_code:0x0
2021-05-25T12:57:54.060Z DEBUG       24 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.061Z DEBUG       25 ->  [00 7d 01 f8 00 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:0 payload_length:6 data_integrity:1 header_checksum:d2 err_code:0x0
2021-05-25T12:57:54.061Z DEBUG    22/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.061Z DEBUG    23/ 0 <-  [01 7d 00 00 00 00 01 05 00 6e 52 46 35 78 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:1 payload_length:e data_integrity:1 header_checksum:4a err_code:0x0
2021-05-25T12:57:54.061Z DEBUG       26 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.063Z DEBUG       27 ->  [00 6d 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:1 payload_length:3 data_integrity:1 header_checksum:f9 err_code:0x0
2021-05-25T12:57:54.064Z DEBUG    24/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.064Z DEBUG    25/ 0 <-  [01 6d 00 00 00 00 02 92 45 40 69 c0 f5 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:2 payload_length:d data_integrity:1 header_checksum:51 err_code:0x0
2021-05-25T12:57:54.064Z DEBUG       28 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:57:54.077Z DEBUG SoftDevice BLE stack enabled.


# GLUCOSE connect

2021-05-25T12:56:08.134Z INFO Connecting to device
2021-05-25T12:56:08.202Z DEBUG GAP_EVT_CONNECTED time:2021-05-25T12:56:08.178Z connHandle:0 peerAddr:[address:C0:07:D8:6A:75:08 type:randomStatic addrIdPeer:0] role:central connParams:[minConnInterval:11_25 maxConnInterval:11_25 slaveLatency:0 connSupTimeout:4000]
2021-05-25T12:56:08.231Z INFO Connected to device C0:07:D8:6A:75:08: interval: 11.25ms, timeout: 4000ms, latency: 0
2021-05-25T12:56:08.290Z DEBUG      423 ->  [00 8c 01 02 08 75 6a d8 07 c0 01 01 a0 00 50 00 14 00 01 09 00 09 00 00 00 90 01 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:3 payload_length:1c data_integrity:1 header_checksum:56 err_code:0x0
2021-05-25T12:56:08.290Z DEBUG   419/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.291Z DEBUG   420/ 0 <-  [01 8c 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:4 payload_length:6 data_integrity:1 header_checksum:af err_code:0x0
2021-05-25T12:56:08.291Z DEBUG      424 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.291Z DEBUG   421/ 0 <-  [02 10 00 00 00 02 08 75 6a d8 07 c0 02 09 00 09 00 00 00 90 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:4 payload_length:15 data_integrity:1 header_checksum:bd err_code:0x0
2021-05-25T12:56:08.292Z DEBUG      425 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.292Z DEBUG      426 ->  [00 94 00 00 01 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:5 payload_length:7 data_integrity:1 header_checksum:96 err_code:0x0
2021-05-25T12:56:08.292Z DEBUG   422/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.292Z DEBUG   423/ 0 <-  [01 94 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:5 payload_length:6 data_integrity:1 header_checksum:a5 err_code:0x0
2021-05-25T12:56:08.292Z DEBUG      427 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.318Z DEBUG GATTC_EVT_PRIM_SRVC_DISC_RSP time:2021-05-25T12:56:08.314Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:3 services:[[uuid:[uuid:6144 type:1 typeString:bleUuidTypeBle],handleRange:[startHandle:1 endHandle:9]],[uuid:[uuid:6145 type:1 typeString:bleUuidTypeBle],handleRange:[startHandle:10 endHandle:10]],[uuid:[uuid:6152 type:1 typeString:bleUuidTypeBle],handleRange:[startHandle:11 endHandle:19]]]
2021-05-25T12:56:08.319Z DEBUG   424/ 0 <-  [02 30 00 00 00 00 00 00 00 03 00 00 18 01 01 00 09 00 01 18 01 0a 00 0a 00 08 18 01 0b 00 13 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:5 payload_length:20 data_integrity:1 header_checksum:2 err_code:0x0
2021-05-25T12:56:08.319Z DEBUG      428 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.319Z DEBUG      429 ->  [00 94 00 00 14 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:7 payload_length:7 data_integrity:1 header_checksum:85 err_code:0x0
2021-05-25T12:56:08.320Z DEBUG   425/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.320Z DEBUG   426/ 0 <-  [01 94 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:6 payload_length:6 data_integrity:1 header_checksum:9b err_code:0x0
2021-05-25T12:56:08.320Z DEBUG      430 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.339Z DEBUG GATTC_EVT_PRIM_SRVC_DISC_RSP time:2021-05-25T12:56:08.337Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:2 services:[[uuid:[uuid:6159 type:1 typeString:bleUuidTypeBle],handleRange:[startHandle:20 endHandle:23]],[uuid:[uuid:6154 type:1 typeString:bleUuidTypeBle],handleRange:[startHandle:24 endHandle:65535]]]
2021-05-25T12:56:08.340Z DEBUG   427/ 0 <-  [02 30 00 00 00 00 00 00 00 02 00 0f 18 01 14 00 17 00 0a 18 01 18 00 ff ff ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:6 payload_length:19 data_integrity:1 header_checksum:71 err_code:0x0
2021-05-25T12:56:08.340Z DEBUG      431 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.420Z DEBUG      432 ->  [00 96 00 00 01 01 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:1 payload_length:9 data_integrity:1 header_checksum:94 err_code:0x0
2021-05-25T12:56:08.421Z DEBUG   428/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.421Z DEBUG   429/ 0 <-  [01 96 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:7 payload_length:6 data_integrity:1 header_checksum:99 err_code:0x0
2021-05-25T12:56:08.421Z DEBUG      433 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.454Z DEBUG GATTC_EVT_CHAR_DISC_RSP time:2021-05-25T12:56:08.438Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:3 chars:[[uuid:[uuid:10752 type:1 typeString:bleUuidTypeBle],charProps:[broadcast:false read:true writeWoResp:false write:true notify:false indicate:false authSignedWr:false],charExtProps:0,handleDecl:2,handleValue:3],[uuid:[uuid:10753 type:1 typeString:bleUuidTypeBle],charProps:[broadcast:false read:true writeWoResp:false write:false notify:false indicate:false authSignedWr:false],charExtProps:0,handleDecl:4,handleValue:5],[uuid:[uuid:10756 type:1 typeString:bleUuidTypeBle],charProps:[broadcast:false read:true writeWoResp:false write:false notify:false indicate:false authSignedWr:false],charExtProps:0,handleDecl:6,handleValue:7]]
2021-05-25T12:56:08.455Z DEBUG   430/ 0 <-  [02 32 00 00 00 00 00 00 00 03 00 00 2a 01 0a 00 02 00 03 00 01 2a 01 02 00 04 00 05 00 04 2a 01 02 00 06 00 07 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:7 payload_length:26 data_integrity:1 header_checksum:96 err_code:0x0
2021-05-25T12:56:08.455Z DEBUG      434 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.455Z DEBUG      435 ->  [00 96 00 00 01 07 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:3 payload_length:9 data_integrity:1 header_checksum:83 err_code:0x0
2021-05-25T12:56:08.456Z DEBUG   431/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.456Z DEBUG   432/ 0 <-  [01 96 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:0 payload_length:6 data_integrity:1 header_checksum:cf err_code:0x0
2021-05-25T12:56:08.456Z DEBUG      436 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.484Z DEBUG GATTC_EVT_CHAR_DISC_RSP time:2021-05-25T12:56:08.472Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:1 chars:[[uuid:[uuid:10918 type:1 typeString:bleUuidTypeBle],charProps:[broadcast:false read:true writeWoResp:false write:false notify:false indicate:false authSignedWr:false],charExtProps:0,handleDecl:8,handleValue:9]]
2021-05-25T12:56:08.484Z DEBUG   433/ 0 <-  [02 32 00 00 00 00 00 00 00 01 00 a6 2a 01 02 00 08 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:0 payload_length:14 data_integrity:1 header_checksum:ed err_code:0x0
2021-05-25T12:56:08.485Z DEBUG      437 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.485Z DEBUG      438 ->  [00 9a 00 00 03 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:5 payload_length:8 data_integrity:1 header_checksum:8a err_code:0x0
2021-05-25T12:56:08.485Z DEBUG   434/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.485Z DEBUG   435/ 0 <-  [01 9a 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:1 payload_length:6 data_integrity:1 header_checksum:c5 err_code:0x0
2021-05-25T12:56:08.485Z DEBUG      439 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.507Z DEBUG GATTC_EVT_READ_RSP time:2021-05-25T12:56:08.506Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:3 offset:0 len:14
2021-05-25T12:56:08.508Z DEBUG   436/ 0 <-  [02 36 00 00 00 00 00 00 00 03 00 00 00 0e 00 4e 6f 72 64 69 63 5f 47 6c 75 63 6f 73 65 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:1 payload_length:1d data_integrity:1 header_checksum:53 err_code:0x0
2021-05-25T12:56:08.508Z DEBUG      440 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.508Z DEBUG      441 ->  [00 9a 00 00 05 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:7 payload_length:8 data_integrity:1 header_checksum:79 err_code:0x0
2021-05-25T12:56:08.508Z DEBUG   437/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.509Z DEBUG   438/ 0 <-  [01 9a 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:2 payload_length:6 data_integrity:1 header_checksum:bb err_code:0x0
2021-05-25T12:56:08.509Z DEBUG      442 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.534Z DEBUG GATTC_EVT_READ_RSP time:2021-05-25T12:56:08.528Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:5 offset:0 len:2
2021-05-25T12:56:08.535Z DEBUG   439/ 0 <-  [02 36 00 00 00 00 00 00 00 05 00 00 00 02 00 00 04 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:2 payload_length:11 data_integrity:1 header_checksum:11 err_code:0x0
2021-05-25T12:56:08.535Z DEBUG      443 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.536Z DEBUG      444 ->  [00 9a 00 00 07 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:1 payload_length:8 data_integrity:1 header_checksum:a8 err_code:0x0
2021-05-25T12:56:08.536Z DEBUG   440/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.536Z DEBUG   441/ 0 <-  [01 9a 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:3 payload_length:6 data_integrity:1 header_checksum:b9 err_code:0x0
2021-05-25T12:56:08.537Z DEBUG      445 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.552Z DEBUG GATTC_EVT_READ_RSP time:2021-05-25T12:56:08.551Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:7 offset:0 len:8
2021-05-25T12:56:08.553Z DEBUG   442/ 0 <-  [02 36 00 00 00 00 00 00 00 07 00 00 00 08 00 08 00 50 00 00 00 90 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:3 payload_length:17 data_integrity:1 header_checksum:a7 err_code:0x0
2021-05-25T12:56:08.553Z DEBUG      446 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.554Z DEBUG      447 ->  [00 9a 00 00 09 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:3 payload_length:8 data_integrity:1 header_checksum:97 err_code:0x0
2021-05-25T12:56:08.554Z DEBUG   443/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.554Z DEBUG   444/ 0 <-  [01 9a 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:4 payload_length:6 data_integrity:1 header_checksum:af err_code:0x0
2021-05-25T12:56:08.555Z DEBUG      448 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.576Z DEBUG GATTC_EVT_READ_RSP time:2021-05-25T12:56:08.573Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:9 offset:0 len:1
2021-05-25T12:56:08.577Z DEBUG   445/ 0 <-  [02 36 00 00 00 00 00 00 00 09 00 00 00 01 00 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:4 payload_length:10 data_integrity:1 header_checksum:d err_code:0x0
2021-05-25T12:56:08.578Z DEBUG      449 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.632Z DEBUG GAP_EVT_SEC_REQUEST time:2021-05-25T12:56:08.584Z connHandle:0 bond:true mitm:true lesc:true keypress:false
2021-05-25T12:56:08.638Z DEBUG   446/ 0 <-  [02 1e 00 00 00 07 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:4 payload_length:6 data_integrity:1 header_checksum:ad err_code:0x0
2021-05-25T12:56:08.639Z DEBUG      450 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.639Z DEBUG      451 ->  [00 97 00 00 01 04 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:6 payload_length:9 data_integrity:1 header_checksum:6e err_code:0x0
2021-05-25T12:56:08.639Z DEBUG   447/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.639Z DEBUG   448/ 0 <-  [01 97 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:5 payload_length:6 data_integrity:1 header_checksum:a4 err_code:0x0
2021-05-25T12:56:08.640Z DEBUG      452 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.640Z DEBUG      453 ->  [00 7e 00 00 01 07 07 10 01 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:7 payload_length:a data_integrity:1 header_checksum:55 err_code:0x0
2021-05-25T12:56:08.640Z DEBUG   449/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.640Z DEBUG   450/ 0 <-  [01 7e 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:6 payload_length:6 data_integrity:1 header_checksum:9b err_code:0x0
2021-05-25T12:56:08.640Z DEBUG      454 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.654Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2021-05-25T12:56:08.652Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:5 descs:[[handle:4,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]],[handle:5,uuid:[uuid:10753 type:1 typeString:bleUuidTypeBle]],[handle:6,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]],[handle:7,uuid:[uuid:10756 type:1 typeString:bleUuidTypeBle]],[handle:8,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]]]
2021-05-25T12:56:08.655Z DEBUG   451/ 0 <-  [02 33 00 00 00 00 00 00 00 05 00 04 00 03 28 01 05 00 01 2a 01 06 00 03 28 01 07 00 04 2a 01 08 00 03 28 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:6 payload_length:24 data_integrity:1 header_checksum:c0 err_code:0x0
2021-05-25T12:56:08.655Z DEBUG      455 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.688Z DEBUG GAP_EVT_SEC_PARAMS_REQUEST time:2021-05-25T12:56:08.663Z connHandle:0 peerParams:[bond:true mitm:true lesc:true keypress:false ioCaps:bleGapIoCapsDisplayOnly oob:false minKeySize:0 maxKeySize:16 kdistOwn:[enc:true sign:false link:false] kdistPeer:[enc:true sign:false link:false]]
2021-05-25T12:56:08.703Z DEBUG   452/ 0 <-  [02 13 00 00 00 07 00 10 01 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:6 payload_length:a data_integrity:1 header_checksum:61 err_code:0x0
2021-05-25T12:56:08.703Z DEBUG      456 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.703Z DEBUG      457 ->  [00 97 00 00 01 06 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:2 payload_length:9 data_integrity:1 header_checksum:8c err_code:0x0
2021-05-25T12:56:08.703Z DEBUG   453/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.704Z DEBUG   454/ 0 <-  [01 97 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:7 payload_length:6 data_integrity:1 header_checksum:98 err_code:0x0
2021-05-25T12:56:08.704Z DEBUG      458 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.704Z DEBUG      459 ->  [00 7f 00 00 00 00 01 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 72 50 36 d6 bd 87 d7 57 fa 53 78 2d 02 13 7b da 00 2e 66 9b bd 28 2a e9 21 91 4d 7a 63 95 93 05 15 30 b7 55 4a be 78 6f 7e 4d 15 c9 85 c8 b5 c7 f5 78 b8 ea 52 f1 f1 e8 c3 1d ed 01 27 1f ec 82 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:3 payload_length:113 data_integrity:1 header_checksum:d2 err_code:0x0
2021-05-25T12:56:08.707Z DEBUG   455/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.707Z DEBUG   456/ 0 <-  [01 7f 00 00 00 00 01 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 72 50 36 d6 bd 87 d7 57 fa 53 78 2d 02 13 7b da 00 2e 66 9b bd 28 2a e9 21 91 4d 7a 63 95 93 05 15 30 b7 55 4a be 78 6f 7e 4d 15 c9 85 c8 b5 c7 f5 78 b8 ea 52 f1 f1 e8 c3 1d ed 01 27 1f ec 82 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:0 payload_length:113 data_integrity:1 header_checksum:ee err_code:0x0
2021-05-25T12:56:08.707Z DEBUG      460 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.708Z DEBUG ReplySecParams, secParams: null
2021-05-25T12:56:08.710Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2021-05-25T12:56:08.708Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:4 descs:[[handle:6,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]],[handle:7,uuid:[uuid:10756 type:1 typeString:bleUuidTypeBle]],[handle:8,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]],[handle:9,uuid:[uuid:10918 type:1 typeString:bleUuidTypeBle]]]
2021-05-25T12:56:08.711Z DEBUG   457/ 0 <-  [02 33 00 00 00 00 00 00 00 04 00 06 00 03 28 01 07 00 04 2a 01 08 00 03 28 01 09 00 a6 2a 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:0 payload_length:1f data_integrity:1 header_checksum:3d err_code:0x0
2021-05-25T12:56:08.711Z DEBUG      461 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.732Z DEBUG GAP_EVT_LESC_DHKEY_REQUEST time:2021-05-25T12:56:08.721Z connHandle:0 oobdReq:false pkPeer:[pk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]]
2021-05-25T12:56:08.739Z DEBUG   458/ 0 <-  [02 18 00 00 00 01 de 38 eb a4 01 72 d3 d8 b8 8d bb bb 92 b9 a7 5d b1 72 fc c5 86 d4 6f 0d c9 af 43 2d 81 dc 12 93 70 f8 92 3f 0c 23 1b d7 be b1 b2 8f 95 84 eb b2 80 e0 5a a7 d6 c1 c8 33 15 04 a9 b5 00 f5 82 fe 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:0 payload_length:47 data_integrity:1 header_checksum:b9 err_code:0x0
2021-05-25T12:56:08.740Z DEBUG      462 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.740Z DEBUG      463 ->  [00 97 00 00 01 08 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:6 payload_length:9 data_integrity:1 header_checksum:72 err_code:0x0
2021-05-25T12:56:08.740Z DEBUG   459/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.740Z DEBUG   460/ 0 <-  [01 97 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:1 payload_length:6 data_integrity:1 header_checksum:c4 err_code:0x0
2021-05-25T12:56:08.741Z DEBUG      464 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.741Z DEBUG      465 ->  [00 81 00 00 01 29 8b fd 0c be 70 4a 51 71 fe 7d 29 2b f9 aa d5 f9 61 83 ff de 3c 96 e8 63 d9 62 bf 5f 19 97 d8 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:7 payload_length:25 data_integrity:1 header_checksum:a7 err_code:0x0
2021-05-25T12:56:08.741Z DEBUG   461/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.741Z DEBUG   462/ 0 <-  [01 81 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:2 payload_length:6 data_integrity:1 header_checksum:bb err_code:0x0
2021-05-25T12:56:08.741Z DEBUG      466 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.742Z DEBUG      467 ->  [00 83 00 00 01 72 50 36 d6 bd 87 d7 57 fa 53 78 2d 02 13 7b da 00 2e 66 9b bd 28 2a e9 21 91 4d 7a 63 95 93 05 15 30 b7 55 4a be 78 6f 7e 4d 15 c9 85 c8 b5 c7 f5 78 b8 ea 52 f1 f1 e8 c3 1d ed 01 27 1f ec 82 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:0 payload_length:46 data_integrity:1 header_checksum:cc err_code:0x0
2021-05-25T12:56:08.742Z DEBUG   463/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.742Z DEBUG   464/ 0 <-  [01 83 00 00 00 00 01 02 92 45 40 69 c0 f5 a3 dc 5b 0f 55 0e d3 a8 51 f1 e9 3d 1d a9 c5 f3 63 d4 4f 28 eb 76 0b dc b7 6b ba 02 cb 22 ae 6a ] type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:3 payload_length:2e data_integrity:1 header_checksum:38 err_code:0x0
2021-05-25T12:56:08.742Z DEBUG      468 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.743Z DEBUG Own OOB data: {"addr":{"address":"F5:C0:69:40:45:92","type":"BLE_GAP_ADDR_TYPE_RANDOM_STATIC","addr_id_peer":0},"r":[163,220,91,15,85,14,211,168,81,241,233,61,29,169,197,243],"c":[99,212,79,40,235,118,11,220,183,107,186,2,203,34,174,106]}
2021-05-25T12:56:08.754Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2021-05-25T12:56:08.753Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:2 descs:[[handle:8,uuid:[uuid:10243 type:1 typeString:bleUuidTypeBle]],[handle:9,uuid:[uuid:10918 type:1 typeString:bleUuidTypeBle]]]
2021-05-25T12:56:08.755Z DEBUG   465/ 0 <-  [02 33 00 00 00 00 00 00 00 02 00 08 00 03 28 01 09 00 a6 2a 01 ] type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:3 payload_length:15 data_integrity:1 header_checksum:c8 err_code:0x0
2021-05-25T12:56:08.755Z DEBUG      469 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.779Z DEBUG      470 ->  [00 97 00 00 01 0a 00 09 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:2 payload_length:9 data_integrity:1 header_checksum:8f err_code:0x0
2021-05-25T12:56:08.779Z DEBUG   466/ 0 <-  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.779Z DEBUG   467/ 0 <-  [01 97 00 00 00 00 ] type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:4 payload_length:6 data_integrity:1 header_checksum:b0 err_code:0x0
2021-05-25T12:56:08.780Z DEBUG      471 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.843Z DEBUG   468/ 0 <-  [02 1a 00 00 00 21 10 ] type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:4 payload_length:7 data_integrity:1 header_checksum:9f err_code:0x0
2021-05-25T12:56:08.844Z DEBUG      472 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.845Z DEBUG GAP_EVT_CONN_SEC_UPDATE time:2021-05-25T12:56:08.843Z connHandle:0 connSec:[secMode:[sm:1 lv:2] encrKeySize:16]
2021-05-25T12:56:08.847Z INFO Security updated, mode:1, level:2 
2021-05-25T12:56:08.861Z DEBUG   469/ 0 <-  [02 19 00 00 00 00 0c 03 00 01 00 01 18 af fa 12 2d 06 2a b1 ef 9d 85 78 53 3a 77 c6 41 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 72 50 36 d6 bd 87 d7 57 fa 53 78 2d 02 13 7b da 00 2e 66 9b bd 28 2a e9 21 91 4d 7a 63 95 93 05 15 30 b7 55 4a be 78 6f 7e 4d 15 c9 85 c8 b5 c7 f5 78 b8 ea 52 f1 f1 e8 c3 1d ed 01 27 1f ec 82 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 01 de 38 eb a4 01 72 d3 d8 b8 8d bb bb 92 b9 a7 5d b1 72 fc c5 86 d4 6f 0d c9 af 43 2d 81 dc 12 93 70 f8 92 3f 0c 23 1b d7 be b1 b2 8f 95 84 eb b2 80 e0 5a a7 d6 c1 c8 33 15 04 a9 b5 00 f5 82 fe ] type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:4 payload_length:117 data_integrity:1 header_checksum:8d err_code:0x0
2021-05-25T12:56:08.861Z DEBUG      473 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.870Z DEBUG GAP_EVT_AUTH_STATUS time:2021-05-25T12:56:08.845Z connHandle:0 authStatus:0 authStatusName:bleGapSecStatusSuccess errorSrc:0 errorSrcName:bleGapSecStatusSourceLocal bonded:true sm1Levels:[lv1:true lv2:true lv3:false lv4:false] sm2Levels:[lv1:false lv2:false lv3:false lv4:false] kdistOwn:[enc:true sign:false link:false] kdistPeer:[enc:false sign:false link:false] lesc:true keyset:[keysOwn:[encKey:[encInfo:[ltk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]] auth:false ltkLen:16 lesc:true] masterId:[ediv:0 rand:[[],[],[],[],[],[],[],[]]]] idKey:[idInfo:[irk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]] idAddrInfo:[address:00:00:00:00:00:00 type:public addrIdPeer:0]] signKey:[csrk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]] pk:[pk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]]] keysPeer:[encKey:[encInfo:[ltk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]] auth:false ltkLen:0 lesc:false] masterId:[ediv:0 rand:[[],[],[],[],[],[],[],[]]]] idKey:[idInfo:[irk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]] idAddrInfo:[address:00:00:00:00:00:00 type:public addrIdPeer:0]] signKey:[csrk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]] pk:[pk:[[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[],[]]]]]
2021-05-25T12:56:08.881Z INFO Storing bond info for device C0:07:D8:6A:75:08
2021-05-25T12:56:08.882Z DEBUG Bond info: {}
2021-05-25T12:56:08.896Z DEBUG   470/ 0 <-  [02 11 00 00 00 13 ] type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:4 payload_length:6 data_integrity:1 header_checksum:ad err_code:0x0
2021-05-25T12:56:08.897Z DEBUG      474 ->  [N/A] type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0x0
2021-05-25T12:56:08.911Z DEBUG GAP_EVT_DISCONNECTED time:2021-05-25T12:56:08.876Z connHandle:0 reason:19 reasonName:remoteUserTerminatedConnection
2021-05-25T12:56:08.921Z INFO Disconnected from device C0:07:D8:6A:75:08, reason: BLE_HCI_REMOTE_USER_TERMINATED_CONNECTION

[Einar Thorsrud]

Hi,

Can you confirm that you reproduce this with an unmodified GLS example from SDK 17.0.2 as well as your custom app? If so, we need to look at your configuration in nRF Connect BLE. If you click on the gear icon, is "Auto reply security requests" checked or not? What is the configuration in "Security Parameters..."? When you initiate bonding, what parameters do you select? Screenshots would be good so that I can see that I match the exact same configuration on my side.

If this is not reproducible with the unmodified GLS app, then we need to look at your custom app and see if we see something there.

[swisst]

Hi,

thank you for quick reply and sorry for delay

For now lets focus on pca10056 board only - custom application relies on it so if I get result with glucose application I'll success with custom app

I've downloaded clear glucose example ( diifs were only in line endings ) and rebuild it - same result as above

The only changes I have in SDK are about verbosity with NRF_LOF_INFO in peer manager

Fullscreen peer_manager_handler.diff Download

peer_manager_handler.c
warning: LF will be replaced by CRLF in components/ble/peer_manager/peer_manager_handler.c.
The file will have its original line endings in your working directory.
diff --git a/components/ble/peer_manager/peer_manager_handler.c b/components/ble/peer_manager/peer_manager_handler.c
index 33f5b96..0d2d5d8 100644
--- a/components/ble/peer_manager/peer_manager_handler.c
+++ b/components/ble/peer_manager/peer_manager_handler.c
@@ -649,22 +649,24 @@ void pm_handler_disconnect_on_insufficient_sec(pm_evt_t const * p_pm_evt,
 
 void pm_handler_secure_on_connection(ble_evt_t const * p_ble_evt)
 {
-    switch (p_ble_evt->header.evt_id)
-    {
+    switch (p_ble_evt->header.evt_id) {
         case BLE_GAP_EVT_CONNECTED:
-            NRF_LOG_DEBUG("Connected, securing connection. conn_handle: %d", p_ble_evt->evt.gap_evt.conn_handle);
+            NRF_LOG_INFO("%s: BLE_GAP_EVT_CONNECTED", __FUNCTION__);
+            NRF_LOG_INFO("Connected, securing connection. conn_handle: %d", p_ble_evt->evt.gap_evt.conn_handle);
             conn_secure(p_ble_evt->evt.gap_evt.conn_handle, false);
             break;
 
 #if PM_HANDLER_SEC_DELAY_MS > 0
         case BLE_GAP_EVT_DISCONNECTED:
         {
+            NRF_LOG_INFO("%s: BLE_GAP_EVT_DISCONNECTED", __FUNCTION__);
             ret_code_t err_code = app_timer_stop(secure_delay_timer);
             APP_ERROR_CHECK(err_code);
         } break;
 #endif
 
         default:
+            NRF_LOG_INFO("%s: event %d", __FUNCTION__, p_ble_evt->header.evt_id );
             break;
     }
 }

Screenshot from NRF Connect but did try all option variants

[Einar Thorsrud]

Hi,

The issue here is the IO Capabilities you configure. You set "Display, no keyboard" in the nRF Connect BLE app, which is the same as the glucose application. When both peers support only display, no MITM is possible. You need to set "Keyboard and display" on nRF Connect. Then the combined IO capabilities will allow passkey display on the nRF device and passkey entry on nRF Connect.

[swisst]

Hi

Thanks a lot