Bootloader DFU transport - transfer of init packet

[Matej]

Hi,

I'm implementing flashing modul, which will be running on external mcu. Therefore for the very 1st step, I have captured traffic while performing dfu on PCA10040 via nrf util from PC. Now I'm wondering of the meaning of transferred bytes, since it's not matching to decription in sdk.

First captured packet is: 0x09 0x01 0xc0; according to dfu transport shall be 0x02 0x00 0x01..

After response 0x60 0x09 0x01 0x01 0xc0, similar packet is sent 0x02 0x00 0x00 0xc0 and finally get response set prn success 0x60 0x02 0x01

Then Get MTU is following... and then I get a bit different response 0x60, 0x07, 0x01, 0x83, 0x00, 0xc0 --->how many bytes are use to represent MTU?

Now I'm wondering if there is any document/manual with detailed description of transfered bytes (somehow I didn't find it), or is there any existing code/library for performing dfu, that could be used for implementing flashing procedure on external mcu via uart.

Thank you in advance.

Best regards,

Matej

[Vidar Berg]

Hello Matej,

The DFU controller is starts by sending a ping request in your case.

Then Get MTU is following... and then I get a bit different response 0x60, 0x07, 0x01, 0x83, 0x00, 0xc0 --->how many bytes are use to represent MTU?

The MTU is represented with 2 bytes (uint16_t)

Best regards,

Vidar

[Matej]

Vidar, thank you, for your response.

I see, there are listed different OpCodes, for several requests. Is there any list of requests order (collected at one place), that needs to be sent for successful update? 

What is the timeout between request, before dfu is aborted? 

On "Get MTU" request 0x07, 0xC0, i get response:

• 0x60 (indicating response)
• 0x07 (get mtu rsp)
• 0x01, 0x83 (size)
• 0x00 status?
• 0xc0 (slip end)

while on ping req i get response i get 

• 0x60 (indicating response)
• 0x09 (ping request)
• 0x01 ping id
• 0x01 status?
• 0xc0 (slip end)

Now i'm wondering about bold status bytes? are those really status or something else? where can i find byte-to-byte overview?

Thank you in advance for additional support

Best regards,

Matej

[Matej]

Hello Vidar,

This is the case why I was wondering for protocol documentation and request sequence...

As mentioned I'm implementing dfu flashing on external MCU via UART. Therefore I'm interested in packets description at least a list of min required requests. 

I have checked about following commands; ping, get mtu, and set receipt notification and I think its everything clear...

Now I'm wondering of usage of select, create, write and execute... Could you please provide me a bit info how app/SD is selected, is there option to define also start address?

Thank you for support.

Best regards,

Matej

[Vidar Berg]

Hello Matej,

The content of the update is transparent to the sender. It is the bootloader that know where to place the image in flash based on the update type specified in the transferred init command (the *.dat file). The DFU controller cannot instruct the DFU target to place the image at a specific address.

Best regards,

Vidar

[Matej]

Hello Vidar,

I have managed to transfer image and it boots up if I have flashed only bootloader and softdevice. If I have also application, then always old application boots up.

If I refer to picture above - I'm at the state in the middle column... Is there any command that needs to be sent over to actually switch/replace old application with the new one?

Thank you and best regards,

Matej

[Vidar Berg]

Hello Matej,

The new app should be activated automatically after the last Execute request. I recommend you enable logging over RTT from the target bootloader to see if there are any errors reported during the pre- or post-validation step.

Best regards,

Vidar

[Matej]

Hi Vidar,

I was a bit to fast with reseting and didn't check for execute response; and then i noticed that there is hash error... now I have reworked quite some things... and when I'm sending 64 byte long chunks, now I'm getting an error that allocating buffer has failed.

Any idea? I'm attaching bootloader log:

<info> nrf_dfu_serial_uart: Allocated buffer 20000530
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (data)
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x0004EFC0, src=0x2000063C, len=64 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x0004EFC0, pending 0
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<info> nrf_dfu_serial_uart: Allocated buffer 20000638
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (data)
<error> nrf_dfu_req_handler: Write request too long
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x3
<warning> nrf_dfu_serial: DFU request completed with result: 0x3
<info> nrf_dfu_serial_uart: Allocated buffer 20000638
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_CRC_GET (data)
<debug> nrf_dfu_req_handler: Offset:8192, CRC:0x9C7914AB
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> nrf_dfu_serial: Sending Response: [0x3, 0x1]
<info> nrf_dfu_serial_uart: Allocated buffer 20000638
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_EXECUTE (data)
<debug> nrf_dfu_serial: Sending Response: [0x4, 0x1]
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> app: timer_stop (0x20000028)
<debug> app: timer_activate (0x20000028)
<info> nrf_dfu_serial_uart: Allocated buffer 20000638
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_SELECT (data)
<debug> nrf_dfu_req_handler: crc = 0x9C7914AB, offset = 0x2000, max_size = 0x1000
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> nrf_dfu_serial: Sending Response: [0x6, 0x1]
<info> nrf_dfu_serial_uart: Allocated buffer 20000638
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_CREATE (data)
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x0004F000, len=1 pages), queue usage: 1
<debug> nrf_dfu_flash: Flash erase success: addr=0x0004F000, pending 0
<debug> nrf_dfu_req_handler: Creating object with size: 4096. Offset: 0x00002000, CRC: 0x9C7914AB
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> nrf_dfu_serial: Sending Response: [0x1, 0x1]
<error> nrf_dfu_serial_uart: Failed to allocate buffer
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (data)
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x0004F000, src=0x2000063C, len=64 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x0004F000, pending 0
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<info> nrf_dfu_serial_uart: Allocated buffer 20001DF0
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_WRITE (data)
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x0004F040, src=0x2000063C, len=129 bytes), queue usage: 1
<error> app: Received a fault! id: 0x00004002, pc: 0x00000000, info: 0x2003FF48
<error> nrf_dfu_serial_uart: Failed to allocate buffer
<error> nrf_dfu_serial_uart: Failed to allocate buffer

Thank you in advance!

BR,
Matej

[Vidar Berg]

Hi Matej,

The error below suggests that the bootloader is receiving a packet that is too large:

Matej said:

<error> nrf_dfu_req_handler: Write request too long

There is also this one that indicates that it is receiving packets that are >64 bytes:

Matej said:

<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x0004F040, src=0x2000063C, len=129 bytes), queue usage: 1

Does your client verify that the reported CRC during DFU is correct?

BR,

Vidar

[Matej]

True, there was an error of sending one 64 byte to much within 4k chunks.

I made a bit of rework and I'm able to transffer image, but at the end of transfer when I send out execute cmd I have a bit weird situation:

• In case that image is not valid I receive a message that whole firmware image is received, but hash verfication failed - it seems ok, since hash is not matching
• In case that image is valid and sending algorithm is completly the same, I don't get a message that whole firmware is received and bootloader stops at 0xa80

Would you be please so kind and check attached logs? Where is the reason that I don't get any response on execute command in case that image transfer is valid? I have also performed readout and images are completly the same and in both cases I see with logic analyzer that execute cmd (0x04, 0xc0) is sent out.

Thank you for your support!

Best regards,

Matej

dfu_log_hangs.log

dfu_log_hash.log

[Vidar Berg]

Matej said:

In case that image is valid and sending algorithm is completly the same, I don't get a message that whole firmware is received and bootloader stops at 0xa80

0xA80 is the address of the mbr's reset handler, and the program should not hang there unless you have this breakpoint enabled in SES:

Have you tried to see what happens if you continue execution by pressing the 'play' button in SES? 

Best regards,

Vidar

[Matej]

Not completly sure (will perform detail test in afternoon), if I'm not wrong I have tried and it seems like reset occur and bootloader boots up normally like nothing happend an previous/old application is booted...

When I perform flash readout - the new image is stored at 0x4d000 and completely the same as was sent over, on 0x27000 is old application which boots up

I'm expecting at least a message like whole firmware image is received, but in this case nothing. Are there any differencies how last execute CMD is processed?

Any idea how to proceed?

BR,

Matej

[Matej]

Hi Vidar,

I have performed some additionall tests, also switched to single bank update and figured out that "no jump" or switching to new app happens in case that there is already valid application. And this shows up like at first need to perform one update to invalidate current image, the second round of updated it works properly...

Attaching part of logs 

1st round - "Invalidating" app

<info> nrf_dfu_serial_uart: Allocated buffer 200005B8
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_CRC_GET (data)
<debug> nrf_dfu_req_handler: Offset:155648, CRC:0x4D88F134
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> nrf_dfu_serial: Sending Response: [0x3, 0x1]

At this point stopping at mbr's reset handler 0xa80, pressing continue/play button as suggested

<info> app: Inside main
<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> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<info> app: No firmware to activate.
<info> app: Boot validation failed. No valid app to boot.
<debug> app: DFU mode because app is not valid.
<info> nrf_bootloader_wdt: WDT is not enabled
<debug> app: in weak nrf_dfu_init_user
<debug> app: timer_stop (0x20000028)
<debug> app: timer_activate (0x20000028)
<info> app: Entering DFU mode.
<debug> app: Initializing transports (found: 1)
<debug> nrf_dfu_serial_uart: serial_dfu_transport_init()
<debug> nrf_dfu_serial_uart: serial_dfu_transport_init() completed
<debug> nrf_dfu_flash: Initializing nrf_fstorage_nvmc backend.
<debug> nrf_dfu_validation: PB: Init packet data len: 64
<debug> app: Enter main loop

And nothing happens, app is not working, while performing same procedure once again, when I stop at at 0xa80, then I receive execute cmd response and app starts working...

<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_CRC_GET (data)
<debug> nrf_dfu_req_handler: Offset:155648, CRC:0x4D88F134
<debug> nrf_dfu_req_handler: Request handling complete. Result: 0x1
<debug> nrf_dfu_serial: Sending Response: [0x3, 0x1]

At this point stopping at mbr's reset handler 0xa80, pressing continue/play button as suggested

<info> nrf_dfu_serial_uart: Allocated buffer 200005B8
<debug> nrf_dfu_req_handler: Handle NRF_DFU_OP_OBJECT_EXECUTE (data)
<debug> nrf_dfu_req_handler: Whole firmware image received. Postvalidating.
<debug> nrf_dfu_validation: Hash verification. start address: 0x27000, size: 0x26000
<debug> nrf_dfu_validation: Invalidating old application in bank 0.
<debug> nrf_dfu_serial: Sending Response: [0x4, 0x1]
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FF000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FF000, len=1 pages), queue usage: 1
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FF000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FF000, src=0x20000A44, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FF000, pending 0
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FE000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FE000, len=1 pages), queue usage: 1
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FE000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FE000, src=0x200006C4, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FE000, pending 0
<debug> nrf_dfu_req_handler: All flash operations have completed. DFU completed.
<debug> app: Shutting down transports (found: 1)
<debug> app: Resetting bootloader.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> app: Inside main
<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> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<debug> app: Valid App
<debug> app: Enter nrf_dfu_app_continue
<debug> app: No copy needed
<debug> app: Setting app as valid
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FF000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FF000, len=1 pages), queue usage: 0
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FF000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FF000, src=0x20000A44, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FF000, pending 0
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Writing settings...
<debug> nrf_dfu_settings: Erasing old settings at: 0x000FE000
<debug> nrf_dfu_flash: nrf_fstorage_erase(addr=0x0x000FE000, len=1 pages), queue usage: 1
<debug> nrf_dfu_flash: Flash erase success: addr=0x000FE000, pending 0
<debug> nrf_dfu_flash: nrf_fstorage_write(addr=0x000FE000, src=0x200006C4, len=896 bytes), queue usage: 1
<debug> nrf_dfu_flash: Flash write success: addr=0x000FE000, pending 0
<debug> app: Resetting bootloader.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> app: Inside main
<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> nrf_dfu_settings: Using settings page.
<debug> nrf_dfu_settings: Copying forbidden parts from backup page.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Enter nrf_bootloader_fw_activate
<info> app: No firmware to activate.
<debug> app: App is valid
<warning> nrf_dfu_settings: No additional data erased
<info> nrf_dfu_settings: Backing up settings page to address 0xFE000.
<debug> nrf_dfu_settings: Destination settings are identical to source, write not needed. Skipping.
<debug> app: Running nrf_bootloader_app_start with address: 0x00001000
<debug> app: Disabling interrupts. NVIC->ICER[0]: 0x0

Any idea? In both cases same length and crc are calculated.

Thank you for additional inputs.

Best regards,

Matej