Signature verification fails for custom SPI Flash DFU Bootloader

[brooksp]

Hi everyone,

I'm working on a custom bootloader for nrf52840-based board. The bootloader needs to support DFU from an external SPI Flash and also BLE. I was working on this a few months ago and was able to get a proof-of-concept working. You can see my previous topic here:

devzone.nordicsemi.com/.../need-help-with-a-custom-dfu-transport

I'm now trying to productize this work so we can use it in production. Unfortunately I'm now running into an issue where signature validation always fails with images in my external SPI Flash, but succeeds over BLE (with the same images). Here's a log of the bootloader:

Fullscreen

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

20

21

<info> app: Inside main

<info> app: Memory Regions:

<info> app: MBR: address [0x00000000, 0x00001000), size: 0x00001000 (4096)

<info> app: SoftDevice: address [0x00001000, 0x00026000), size: 0x00025000 (151552)

<info> app: Application: address [0x00026000, 0x000E0000), size: 0x000BA000 (761856)

<info> app: Bootloader: address [0x000E0000, 0x000FE000), size: 0x0001E000 (122880)

<info> app: MBR Settings: address [0x000FE000, 0x000FF000), size: 0x00001000 (4096)

<info> app: Bootloader Settings: address [0x000FF000, 0x00100000), size: 0x00001000 (4096)

<debug> app: In nrf_bootloader_init

<debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...

<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.

<debug> app: Enter nrf_bootloader_fw_activate

<info> app: No firmware to activate.

<debug> app: Enter nrf_dfu_app_is_valid

<debug> app: Return true. App was valid

<debug> app: DFU mode requested via WA DFU.

<info> nrf_bootloader_wdt: WDT is not enabled

<debug> app: in weak nrf_dfu_init_user

<info> app_timer: RTC: initialized.

<info> app: Entering DFU mode.

<debug> app: dfu_observer() event: NRF_DFU_EVT_DFU_INITIALIZED

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

<info> app: Inside main
<info> app: Memory Regions:
<info> app:                  MBR: address [0x00000000, 0x00001000), size: 0x00001000 (4096)
<info> app:           SoftDevice: address [0x00001000, 0x00026000), size: 0x00025000 (151552)
<info> app:          Application: address [0x00026000, 0x000E0000), size: 0x000BA000 (761856)
<info> app:           Bootloader: address [0x000E0000, 0x000FE000), size: 0x0001E000 (122880)
<info> app:         MBR Settings: address [0x000FE000, 0x000FF000), size: 0x00001000 (4096)
<info> app:  Bootloader Settings: address [0x000FF000, 0x00100000), size: 0x00001000 (4096)
<debug> app: In nrf_bootloader_init
<debug> nrf_dfu_settings: Calling nrf_dfu_settings_init()...
<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
<debug> app: Enter nrf_bootloader_fw_activate
<info> app: No firmware to activate.
<debug> app: Enter nrf_dfu_app_is_valid
<debug> app: Return true. App was valid
<debug> app: DFU mode requested via WA DFU.
<info> nrf_bootloader_wdt: WDT is not enabled
<debug> app: in weak nrf_dfu_init_user
<info> app_timer: RTC: initialized.
<info> app: Entering DFU mode.
<debug> app: dfu_observer() event: NRF_DFU_EVT_DFU_INITIALIZED
<debug> app: Initializing transports (found: 2)
<debug> nrf_dfu_ble: Initializing BLE DFU transport
<debug> nrf_dfu_ble: Setting up vector table: 0x000E0000
<debug> nrf_dfu_ble: Enabling SoftDevice.
<debug> nrf_dfu_ble: Configuring BLE stack.
<debug> nrf_dfu_ble: Enabling the BLE stack.
<debug> nrf_dfu_ble: No advertising name found
<debug> nrf_dfu_ble: Using default advertising name
<debug> nrf_dfu_ble: Advertising...
<debug> nrf_dfu_ble: BLE DFU transport initialized.
<debug> wa_dfu_transport: Initializing WA DFU transport...
<debug> wa_dfu_transport: Initializing WA DFU transport... done
<debug> nrf_dfu_flash: Initializing nrf_fstorage_sd backend.
<debug> app: Enter nrf_dfu_app_is_valid
<debug> app: Return true. App was valid
<debug> wa_dfu_transport: { wa_dfu_main, force dfu: 0
<debug> app: dfu_observer() event: NRF_DFU_EVT_TRANSPORT_ACTIVATED
<debug> wa_dfu_req_handler: { wa_dfu_req_set_prn
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_RECEIPT_NOTIF_SET
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> wa_dfu_req_handler: { set_prn_callback
<debug> wa_dfu_req_handler: } set_prn_callback
<debug> wa_dfu_req_handler: prn: 0
<debug> wa_dfu_req_handler: } wa_dfu_req_set_prn
<debug> wa_dfu_req_handler: { wa_dfu_req_set_mtu
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_MTU_GET
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> wa_dfu_req_handler: { set_mtu_callback
<debug> wa_dfu_req_handler: } set_mtu_callback
<debug> wa_dfu_req_handler: mtu size: 4096
<debug> wa_dfu_req_handler: } wa_dfu_req_set_mtu
<debug> wa_dfu_transport: { do_dfu
<debug> wa_dfu_req_handler: { wa_dfu_req_object_select
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_SELECT (command)
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> wa_dfu_req_handler: { object_select_callback
<debug> wa_dfu_req_handler: } object_select_callback
<debug> wa_dfu_req_handler: type: 1, crc: 0x00000000, offset: 0, max size: 256
<debug> wa_dfu_req_handler: } wa_dfu_req_object_select
<debug> wa_dfu_transport: { read_from_flash_and_write_object
<debug> wa_dfu_transport: index: 0, remaining size: 141, read size: 141, read addr: 0x00001000
<debug> wa_dfu_req_handler: { wa_dfu_req_object_create
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_CREATE (command)
<debug> app: dfu_observer() event: NRF_DFU_EVT_DFU_STARTED
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> wa_dfu_req_handler: { object_create_callback
<debug> wa_dfu_req_handler: } object_create_callback
<debug> wa_dfu_req_handler: object create: type: 1, size: 141
<debug> wa_dfu_req_handler: } wa_dfu_req_object_create
<debug> wa_dfu_req_handler: { wa_dfu_req_object_write
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (command)
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> wa_dfu_req_handler: { object_write_callback
<debug> wa_dfu_req_handler: } object_write_callback
<debug> wa_dfu_req_handler: object write: data: 0x2000A510, size: 141
<debug> wa_dfu_req_handler: } wa_dfu_req_object_write
<debug> wa_dfu_req_handler: { wa_dfu_req_object_execute
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_EXECUTE (command)
<debug> nrf_dfu_validation: PB: Init packet data len: 64
<info> nrf_dfu_validation: Signature required. Checking signature.
<info> nrf_dfu_validation: Calculating init packet hash (init packet len: 64)
<info> nrf_dfu_validation: Verify signature
<error> nrf_dfu_validation: Signature failed (err_code: 0x8542)
<debug> nrf_dfu_validation: Signature:
<debug> nrf_dfu_validation:  00 00 10 00 00 00 00 00|........
<debug> nrf_dfu_validation:  00 00 00 04 00 02 05 00|........
<debug> nrf_dfu_validation:  10 00 20 00 00 00 00 00|.. .....
<debug> nrf_dfu_validation:  00 00 00 00 00 00 04 00|........
<debug> nrf_dfu_validation:  00 01 10 00 00 00 00 00|........
<debug> nrf_dfu_validation:  00 00 00 00 00 00 10 00|........
<debug> nrf_dfu_validation:  00 00 00 08 00 00 08 00|........
<debug> nrf_dfu_validation:  00 00 02 12 00 00 00 44|.......D
<debug> nrf_dfu_validation: Hash:
<debug> nrf_dfu_validation:  B8 3E EC B3 63 AC 52 44|.>..c.RD
<debug> nrf_dfu_validation:  E6 B5 2B BA D2 D2 BE 4D|..+....M
<debug> nrf_dfu_validation:  D3 91 BA AA 19 05 54 D8|......T.
<debug> nrf_dfu_validation:  0A 5B CC 65 30 7C 6A A5|.[.e0|j.
<debug> nrf_dfu_validation: Public Key:
<debug> nrf_dfu_validation:  78 5C FC 6E C6 E0 58 11|x\.n..X.
<debug> nrf_dfu_validation:  49 AD CF 57 16 D0 CE 1C|I..W....
<debug> nrf_dfu_validation:  E7 6F 4F C6 B6 60 F4 99|.oO..`..
<debug> nrf_dfu_validation:  CE 74 1A FA D8 C7 0B 5F|.t....._
<debug> nrf_dfu_validation:  0B 52 11 06 0F CC C9 D6|.R......
<debug> nrf_dfu_validation:  82 97 5D 80 4A F4 31 80|..].J.1.
<debug> nrf_dfu_validation:  12 2E 1F F6 7C C6 99 6C|....|..l
<debug> nrf_dfu_validation:  26 11 96 88 EE F0 2C 37|&.....,7
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x5
<debug> wa_dfu_req_handler: { object_execute_callback
<error> wa_dfu_req_handler: Request 4 returned error 5!
<debug> wa_dfu_req_handler: } object_execute_callback
<debug> app: dfu_observer() event: NRF_DFU_EVT_DFU_FAILED
<debug> wa_dfu_req_handler: } wa_dfu_req_object_execute
<error> wa_dfu_transport: Error: DFU failed while requesting object execute!
<debug> wa_dfu_transport: } read_from_flash_and_write_object, ret_val: 5h
<debug> wa_dfu_transport: } do_dfu, ret_val: 5h
<debug> app: dfu_observer() event: NRF_DFU_EVT_TRANSPORT_DEACTIVATED
<debug> wa_dfu_transport: } wa_dfu_main, ret_val: 5h
<debug> app: Enter main loop

At line 81 is where the signature verification fails.

Some questions and comments:

• I'm using NRF5 SDK 15.0.0 so that I have the same versions of the softdevice/SDK as Mbed 5.15
• I'm using nrfutil 6.1 to generate my packages. I can't remember what version I was using previously where I got my proof-of-concept to work. I see that version 6.0 has issues; are they fixed in 6.1? Should I revert to 5.2?
• In the bootloader, when the SPI Flash DFU fails, it starts up the BLE DFU, and I can *successfully* use the same DFU package over BLE that failed on SPI Flash. This makes me think the DFU package is OK, and it's something else in my code.

Is there a way to further debug the DFU process, especially around the signature validation? Or, does anything else stand out as an issue?

Also, let me know if any additional information would be helpful. Thank you in advance!