DFU fails with "Cannot read property 'instanceId' of undefined"

[kobyatom]

running DFU example from <SDK 15.3>\examples\dfu\secure_dfu_test_images\ble\nrf52840, and attempting a DFU update of:

sd_s140_bootloader_buttonless_with_setting_page_dfu_secure_ble_debug_without_bonds.hex

to

hrs_application_s140.zip.

The DFU is performed on the nRF52840 DK, using this procedure:

1. I burn the .hex image via the J-Link drive on a Windows PC, by copying it there.
2. I connect to the device via nRF-Connect on the Windows PC, and start the DFU process, selecting the .zip image.

Mostly, the DFU is successful, and Nordic_HRM becomes the device' name.

Sometimes, the DFU fails with "Cannot read property 'instanceId' of undefined".

I have the failure logs, of both the RTT log of the device 

# SEGGER J-Link RTT Viewer V6.44f Terminal Log File
# Compiled: 17:18:21 on Apr 12 2019
# Logging started @ 17 Apr 2019 15:14:31

 

 
<00> info> app: Inside main
00> 
<00> debug> app: In nrf_bootloader_init
00> 
<00> debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
00> 
<00> debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
00> 
<00> debug> nrf_dfu_settings: Using settings page.
00> 
<00> debug> nrf_dfu_settings: Copying forbidden parts from backup page.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Enter nrf_bootloader_fw_activate
00> 
<00> info> app: No firmware to activate.
00> 
<00> debug> app: App is valid
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Running nrf_bootloader_app_start with address: 0x00001000
00> 
<00> debug> app: Disabling interrupts. NVIC->ICER[0]: 0x0
00> 

 
<00> info> app: Inside main
00> 
<00> debug> app: In nrf_bootloader_init
00> 
<00> debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
00> 
<00> debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
00> 
<00> info> nrf_dfu_settings: Restoring settings from backup since the settings page contents are invalid (CRC error).
00> 
<00> info> nrf_dfu_settings: Old settings page detected. Upgrading info.
00> 
<00> debug> nrf_dfu_settings: Writing settings...
00> 
<00> debug> nrf_dfu_settings: Erasing old settings at: 0x000FF000
00> 
<00> debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FF000, len=1 pages), queue usage: 0
00> 
<00> debug> nrf_dfu_flash: Flash erase success: addr=0x000FF000, pending 0
00> 
<00> debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FF000, src=0x20007D90, len=896 bytes), queue usage: 1
00> 
<00> debug> nrf_dfu_flash: Flash write success: addr=0x000FF000, pending 0
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Writing settings...
00> 
<00> debug> nrf_dfu_settings: Erasing old settings at: 0x000FE000
00> 
<00> debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FE000, len=1 pages), queue usage: 1
00> 
<00> debug> nrf_dfu_flash: Flash erase success: addr=0x000FE000, pending 0
00> 
<00> debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FE000, src=0x20008110, len=896 bytes), queue usage: 1
00> 
<00> debug> nrf_dfu_flash: Flash write success: addr=0x000FE000, pending 0
00> 
<00> debug> app: Enter nrf_bootloader_fw_activate
00> 
<00> info> app: No firmware to activate.
00> 
<00> debug> app: App is valid
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Running nrf_bootloader_app_start with address: 0x00001000
00> 
<00> debug> app: Disabling interrupts. NVIC->ICER[0]: 0x0
00> 
<00> info> app: Inside main
00> 
<00> debug> app: In nrf_bootloader_init
00> 
<00> debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
00> 
<00> debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
00> 
<00> debug> nrf_dfu_settings: Using settings page.
00> 
<00> debug> nrf_dfu_settings: Copying forbidden parts from backup page.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Enter nrf_bootloader_fw_activate
00> 
<00> info> app: No firmware to activate.
00> 
<00> debug> app: App is valid
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Running nrf_bootloader_app_start with address: 0x00001000
00> 
<00> debug> app: Disabling interrupts. NVIC->ICER[0]: 0x0
00> 

 
<00> info> app: Inside main
00> 
<00> debug> app: In nrf_bootloader_init
00> 
<00> debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
00> 
<00> debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
00> 
<00> debug> nrf_dfu_settings: Using settings page.
00> 
<00> debug> nrf_dfu_settings: Copying forbidden parts from backup page.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
00> 
<00> debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
00> 
<00> debug> app: Enter nrf_bootloader_fw_activate
00> 
<00> info> app: No firmware to activate.
00> 
<00> debug> app: App is valid
00> 
<00> debug> app: DFU mode requested via GPREGRET.
00> 
<00> info> nrf_bootloader_wdt: WDT is not enabled
00> 
<00> debug> app: in weak nrf_dfu_init_user
00> 
<00> debug> app: timer_stop (0x200057D4)
00> 
<00> debug> app: timer_activate (0x200057D4)
00> 
<00> info> app: Entering DFU mode.
00> 
<00> debug> app: Initializing transports (found: 1)
00> 
<00> debug> nrf_dfu_ble: Initializing BLE DFU transport
00> 
<00> debug> nrf_dfu_ble: Setting up vector table: 0x000F1000
00> 
<00> debug> nrf_dfu_ble: Enabling SoftDevice.
00> 
<00> debug> nrf_dfu_ble: Configuring BLE stack.
00> 
<00> debug> nrf_dfu_ble: Enabling the BLE stack.
00> 
<00> debug> nrf_dfu_ble: No advertising name found
00> 
<00> debug> nrf_dfu_ble: Using default advertising name
00> 
<00> debug> nrf_dfu_ble: Advertising...
00> 
<00> debug> nrf_dfu_ble: BLE DFU transport initialized.
00> 
<00> debug> nrf_dfu_flash: Initializing nrf_fstorage_sd backend.
00> 
<00> debug> app: Enter main loop
00> 

# Logging stopped @ 17 Apr 2019 15:24:16

and the nRF Connect log:

2019-04-17T12:22:50.770Z DEBUG 10061/ 0 <-  [02 32 00 00 00 0a 01 10 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:7 payload_length:b data_integrity:1 header_checksum:4a err_code:0
2019-04-17T12:22:50.770Z DEBUG    10063 ->  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:50.770Z DEBUG GATTC_EVT_CHAR_DISC_RSP time:2019-04-17T12:22:50.771Z connHandle:0 gattStatus:266 gattStatusName:atterrAttributeNotFound errorHandle:16 count:0 chars:[]
2019-04-17T12:22:50.771Z DEBUG    10064 ->  [00 97 00 00 01 11 00 ff ff ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:1 payload_length:9 data_integrity:1 header_checksum:93 err_code:0
2019-04-17T12:22:50.774Z DEBUG 10062/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:50.774Z DEBUG 10063/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:0 payload_length:6 data_integrity:1 header_checksum:d1 err_code:0
2019-04-17T12:22:50.774Z DEBUG    10065 ->  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:50.972Z DEBUG 10064/ 0 <-  [02 33 00 00 00 00 00 00 00 01 00 11 00 02 29 01 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:0 payload_length:10 data_integrity:1 header_checksum:2f err_code:0
2019-04-17T12:22:50.972Z DEBUG    10066 ->  []
               type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:50.972Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:50.972Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 count:1 descs:[[handle:17,uuid:[uuid:10498 type:1 typeString:bleUuidTypeBle]]]
2019-04-17T12:22:50.973Z DEBUG    10067 ->  [00 97 00 00 01 12 00 ff ff ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:3 payload_length:9 data_integrity:1 header_checksum:8a err_code:0
2019-04-17T12:22:50.976Z DEBUG 10065/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:50.976Z DEBUG 10066/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:1 payload_length:6 data_integrity:1 header_checksum:c7 err_code:0
2019-04-17T12:22:50.976Z DEBUG    10068 ->  []
               type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.170Z DEBUG 10067/ 0 <-  [02 33 00 00 00 0a 01 12 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:1 payload_length:b data_integrity:1 header_checksum:76 err_code:0
2019-04-17T12:22:51.170Z DEBUG    10069 ->  []
               type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.170Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:51.171Z connHandle:0 gattStatus:266 gattStatusName:atterrAttributeNotFound errorHandle:18 count:0 descs:[]
2019-04-17T12:22:51.171Z DEBUG    10070 ->  [00 9a 00 00 11 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:5 payload_length:8 data_integrity:1 header_checksum:89 err_code:0
2019-04-17T12:22:51.174Z DEBUG 10068/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.174Z DEBUG 10069/ 0 <-  [01 9a 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:2 payload_length:6 data_integrity:1 header_checksum:bd err_code:0
2019-04-17T12:22:51.174Z DEBUG    10071 ->  []
               type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.371Z DEBUG 10070/ 0 <-  [02 36 00 00 00 00 00 00 00 11 00 00 00 02 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:2 payload_length:11 data_integrity:1 header_checksum:b err_code:0
2019-04-17T12:22:51.371Z DEBUG    10072 ->  []
               type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.371Z DEBUG GATTC_EVT_READ_RSP time:2019-04-17T12:22:51.371Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:17 offset:0 len:2
2019-04-17T12:22:51.371Z DEBUG findCharacteristic: Did not find characteristic ID. Error Error: Unable to find characteristic 8EC90004F3154F609FB8838830DAEA50 for service FE59 on device D4:D5:F6:7C:B1:8C.0
2019-04-17T12:22:51.372Z DEBUG    10073 ->  [00 97 00 00 01 04 00 09 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:7 payload_length:9 data_integrity:1 header_checksum:68 err_code:0
2019-04-17T12:22:51.375Z DEBUG 10071/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.375Z DEBUG 10072/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:3 payload_length:6 data_integrity:1 header_checksum:b3 err_code:0
2019-04-17T12:22:51.375Z DEBUG    10074 ->  []
               type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.572Z DEBUG 10073/ 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#:3 payload_length:24 data_integrity:1 header_checksum:d8 err_code:0
2019-04-17T12:22:51.572Z DEBUG    10075 ->  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.572Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:51.573Z 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]]]
2019-04-17T12:22:51.573Z DEBUG    10076 ->  [00 97 00 00 01 06 00 09 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:1 payload_length:9 data_integrity:1 header_checksum:97 err_code:0
2019-04-17T12:22:51.575Z DEBUG 10074/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.575Z DEBUG 10075/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:4 payload_length:6 data_integrity:1 header_checksum:b1 err_code:0
2019-04-17T12:22:51.575Z DEBUG    10077 ->  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.871Z DEBUG 10076/ 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#:2 ack#:4 payload_length:1f data_integrity:1 header_checksum:1f err_code:0
2019-04-17T12:22:51.871Z DEBUG    10078 ->  []
               type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.871Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:51.871Z 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]]]
2019-04-17T12:22:51.871Z DEBUG    10079 ->  [00 97 00 00 01 08 00 09 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:3 payload_length:9 data_integrity:1 header_checksum:86 err_code:0
2019-04-17T12:22:51.875Z DEBUG 10077/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:51.875Z DEBUG 10078/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:5 payload_length:6 data_integrity:1 header_checksum:a7 err_code:0
2019-04-17T12:22:51.875Z DEBUG    10080 ->  []
               type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.071Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:52.071Z 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]]]
2019-04-17T12:22:52.071Z DEBUG 10079/ 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#:4 ack#:5 payload_length:15 data_integrity:1 header_checksum:b5 err_code:0
2019-04-17T12:22:52.071Z DEBUG    10081 ->  []
               type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.071Z DEBUG    10082 ->  [00 97 00 00 01 0a 00 09 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:5 payload_length:9 data_integrity:1 header_checksum:75 err_code:0
2019-04-17T12:22:52.075Z DEBUG 10080/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.075Z DEBUG 10081/ 0 <-  [01 97 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:6 payload_length:6 data_integrity:1 header_checksum:9d err_code:0
2019-04-17T12:22:52.075Z DEBUG    10083 ->  []
               type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.370Z DEBUG 10082/ 0 <-  [02 33 00 00 00 01 01 0a 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:6 payload_length:b data_integrity:1 header_checksum:4c err_code:0
2019-04-17T12:22:52.370Z DEBUG    10084 ->  []
               type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.370Z DEBUG GATTC_EVT_DESC_DISC_RSP time:2019-04-17T12:22:52.371Z connHandle:0 gattStatus:257 gattStatusName:atterrInvalidHandle errorHandle:10 count:0 descs:[]
2019-04-17T12:22:52.370Z DEBUG findCharacteristic: Found characteristic ID D4:D5:F6:7C:B1:8C.0.22.43
2019-04-17T12:22:52.370Z DEBUG Found unbonded buttonless characteristic: D4:D5:F6:7C:B1:8C.0.22.43
2019-04-17T12:22:52.371Z DEBUG    10085 ->  [00 9c 00 00 01 01 00 11 00 00 00 02 00 01 02 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:7 payload_length:10 data_integrity:1 header_checksum:f3 err_code:0
2019-04-17T12:22:52.373Z DEBUG 10083/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.373Z DEBUG 10084/ 0 <-  [01 9c 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:7 payload_length:6 data_integrity:1 header_checksum:93 err_code:0
2019-04-17T12:22:52.373Z DEBUG    10086 ->  []
               type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.571Z DEBUG 10085/ 0 <-  [02 38 00 00 00 00 00 00 00 11 00 01 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:7 payload_length:10 data_integrity:1 header_checksum:f9 err_code:0
2019-04-17T12:22:52.571Z DEBUG    10087 ->  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.571Z DEBUG GATTC_EVT_WRITE_RSP time:2019-04-17T12:22:52.571Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:17 writeOp:1 offset:0 len:0
2019-04-17T12:22:52.571Z INFO Attribute value changed, handle: 0x11, value (0x): 02-00
2019-04-17T12:22:52.572Z DEBUG    10088 ->  [00 9c 00 00 01 01 00 10 00 00 00 01 00 01 01 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:1 payload_length:f data_integrity:1 header_checksum:33 err_code:0
2019-04-17T12:22:52.574Z DEBUG 10086/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.574Z DEBUG 10087/ 0 <-  [01 9c 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:0 payload_length:6 data_integrity:1 header_checksum:d1 err_code:0
2019-04-17T12:22:52.574Z DEBUG    10089 ->  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.770Z DEBUG 10088/ 0 <-  [02 38 00 00 00 00 00 00 00 10 00 01 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:0 payload_length:10 data_integrity:1 header_checksum:2f err_code:0
2019-04-17T12:22:52.770Z DEBUG    10090 ->  []
               type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.770Z DEBUG GATTC_EVT_WRITE_RSP time:2019-04-17T12:22:52.771Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:16 writeOp:1 offset:0 len:0
2019-04-17T12:22:52.770Z INFO Attribute value changed, handle: 0x10, value (0x): 01
2019-04-17T12:22:52.772Z DEBUG 10089/ 0 <-  [02 39 00 00 00 00 00 00 00 10 00 02 03 00 20 01 01 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:3 ack#:0 payload_length:11 data_integrity:1 header_checksum:1e err_code:0
2019-04-17T12:22:52.772Z DEBUG    10091 ->  []
               type:                 ACK reliable: no seq#:0 ack#:4 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.772Z DEBUG GATTC_EVT_HVX time:2019-04-17T12:22:52.773Z connHandle:0 gattStatus:0 gattStatusName:success errorHandle:0 handle:16 type:2 len:3
2019-04-17T12:22:52.772Z INFO Attribute value changed, handle: 0x10, value (0x): 20-01-01
2019-04-17T12:22:52.773Z DEBUG    10092 ->  [00 9d 00 00 10 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:4 payload_length:6 data_integrity:1 header_checksum:b2 err_code:0
2019-04-17T12:22:52.773Z DEBUG Waiting for target device to disconnect.
2019-04-17T12:22:52.776Z DEBUG 10090/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:52.776Z DEBUG 10091/ 0 <-  [01 9d 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:4 ack#:1 payload_length:6 data_integrity:1 header_checksum:c6 err_code:0
2019-04-17T12:22:52.776Z DEBUG    10093 ->  []
               type:                 ACK reliable: no seq#:0 ack#:5 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:56.970Z DEBUG 10092/ 0 <-  [02 11 00 00 00 08 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:5 ack#:1 payload_length:6 data_integrity:1 header_checksum:c5 err_code:0
2019-04-17T12:22:56.970Z DEBUG    10094 ->  []
               type:                 ACK reliable: no seq#:0 ack#:6 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:56.970Z DEBUG GAP_EVT_DISCONNECTED time:2019-04-17T12:22:56.970Z connHandle:0 reason:8 reasonName:connectionTimeout
2019-04-17T12:22:56.970Z DEBUG Received disconnection event for target device.
2019-04-17T12:22:56.970Z DEBUG New address for DFU target: D4:D5:F6:7C:B1:8D
2019-04-17T12:22:56.970Z DEBUG Connecting to address: D4:D5:F6:7C:B1:8D, type: BLE_GAP_ADDR_TYPE_RANDOM_STATIC.
2019-04-17T12:22:56.973Z DEBUG    10095 ->  [00 8c 01 02 8d b1 7c f6 d5 d4 01 01 a0 00 50 00 14 00 01 06 00 06 00 00 00 90 01 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:6 payload_length:1b data_integrity:1 header_checksum:50 err_code:0
2019-04-17T12:22:56.977Z DEBUG 10093/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:56.977Z DEBUG 10094/ 0 <-  [01 8c 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:6 ack#:2 payload_length:6 data_integrity:1 header_checksum:bc err_code:0
2019-04-17T12:22:56.977Z DEBUG    10096 ->  []
               type:                 ACK reliable: no seq#:0 ack#:7 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:57.000Z DEBUG GAP_EVT_CONNECTED time:2019-04-17T12:22:56.999Z connHandle:0 peerAddr:[address:D4:D5:F6:7C:B1:8D type:randomStatic addrIdPeer:0] role:central connParams:[minConnInterval:7_5 maxConnInterval:7_5 slaveLatency:0 connSupTimeout:4000]
2019-04-17T12:22:57.005Z DEBUG 10095/ 0 <-  [02 10 00 00 00 02 8d b1 7c f6 d5 d4 02 06 00 06 00 00 00 90 01 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:7 ack#:2 payload_length:15 data_integrity:1 header_checksum:ca err_code:0
2019-04-17T12:22:57.005Z DEBUG    10097 ->  []
               type:                 ACK reliable: no seq#:0 ack#:0 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:57.005Z DEBUG    10098 ->  [00 94 00 00 01 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:2 ack#:0 payload_length:7 data_integrity:1 header_checksum:c0 err_code:0
2019-04-17T12:22:57.009Z DEBUG 10096/ 0 <-  []
               type:                 ACK reliable: no seq#:0 ack#:3 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:57.009Z DEBUG 10097/ 0 <-  [01 94 00 00 00 00 ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:0 ack#:3 payload_length:6 data_integrity:1 header_checksum:ba err_code:0
2019-04-17T12:22:57.009Z DEBUG    10099 ->  []
               type:                 ACK reliable: no seq#:0 ack#:1 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:57.039Z DEBUG 10098/ 0 <-  [02 11 00 00 00 3e ]
               type:     VENDOR_SPECIFIC reliable:yes seq#:1 ack#:3 payload_length:6 data_integrity:1 header_checksum:b9 err_code:0
2019-04-17T12:22:57.039Z DEBUG    10100 ->  []
               type:                 ACK reliable: no seq#:0 ack#:2 payload_length:0 data_integrity:0 err_code:0
2019-04-17T12:22:57.039Z DEBUG GAP_EVT_DISCONNECTED time:2019-04-17T12:22:57.039Z connHandle:0 reason:62 reasonName:connFailedToBeEstablished
2019-04-17T12:22:57.039Z DEBUG Did not find service changed. Error: Error: Device disconnected
2019-04-17T12:22:57.040Z DEBUG Destroying DFU transport.
2019-04-17T12:22:57.040Z ERROR DFU failed with error: Cannot read property 'instanceId' of undefined.

After such a failure message, I can try to the DFU again, and sometimes it will succeed.

[Edvin]

Hello,

I haven't tried this example, but have you seen the "getting started with DFU" guide written by my colleague?

https://devzone.nordicsemi.com/b/blog/posts/getting-started-with-nordics-secure-dfu-bootloader

It explains quite good how to perform a DFU from scratch. Can you try to follow this guide, and let me know if it doesn't work?

My suspision is that you don't erase the nRF in between your tries now, which may cause some undefined behavior (with old bootloader settings and a new image).

Can you test the guide and see if that works? I know it is written for an older SDK, but the method in the current SDK (SDK15.3.0) is the same.

Best regards,

Edvin

[gaminn]

I have exactly same issue. Sometimes it fails with this error. It seems it only happens where my device runs my application and is restarted to DFU mode using nrf connect on Win10. I didn't see this error when my device is already in dfu mode. What this error means? I also noticed that after some time nrf connect became very slow in updating firmware (0.35 kB/s). After restarting nrf connect the speed normalized around 1.5 kB/s.

[Edvin]

gaminn:

Are you running the tutorial that I linked in my previous reply, or did you modify the bootloader? Are you using bonding, either in your application or your bootloader?

[gaminn]

I modified the bootloader to support AES encryption of the firmware.

My device uses bonding, but bonds sharing between app and bootloader is not enabled.

[Edvin]

gaminn:

Please create a new ticket where you describe what changes you did, and what your symptoms are. It doesn't look like this is "exactly the same issue". It is related to DFU, but that is about it