DFU from external flash using SPI NOR

[dhump3]

Hi,

I am attempting to get the zephyr usb dfu sample located at ncs/zephyr/samples/usb/dfu to work using external flash. I am using the nrf52833 on a custom board in combination with mx25r32 flash chip on ncs version 2.4.0.

Firstly, I have been able to get the dfu working with no issues when I don't configure the project to use external flash. I build the project with the default usb device name, flash it and see that it shows up as a usb device. Then I change the name, rebuild the project and use dfu-util to send app_update.bin to the image 1 slot of the device. I reboot the device, it swaps in the new image and I see my newly named usb device show up. Unfortunately, I need the extra internal flash space as my application is larger than 250 kb.

I then make the following changes to the prj.conf file located at ncs/bootloader/mcuboot/boot/zephyr/prj.conf

CONFIG_MULTITHREADING=y
CONFIG_SPI=y
CONFIG_SPI_NOR=y
CONFIG_SPI_NOR_FLASH_LAYOUT_PAGE_SIZE=4096
CONFIG_PM_EXTERNAL_FLASH=y
CONFIG_PM_EXTERNAL_FLASH_DEV_NAME="MX25R32"
CONFIG_PM_EXTERNAL_FLASH_BASE=0
CONFIG_PM_EXTERNAL_FLASH_SIZE=0x73000

I then make the following change to the pm.yml located at the same place

mcuboot_secondary:
    region: external_flash
    size: CONFIG_PM_EXTERNAL_FLASH_SIZE

I also add the following to the prj.conf file in the usb dfu sample

CONFIG_SPI=y
CONFIG_SPI_NOR=y
CONFIG_SPI_NOR_FLASH_LAYOUT_PAGE_SIZE=4096
CONFIG_PM_EXTERNAL_FLASH=y
CONFIG_PM_EXTERNAL_FLASH_DEV_NAME="MX25R32"
CONFIG_PM_EXTERNAL_FLASH_BASE=0
CONFIG_PM_EXTERNAL_FLASH_SIZE=0x73000

Once I make these changes, everything builds fine and I see the new application size is basically doubled, which to me means that it is in fact configured correctly for storing the secondary image on external flash. I repeat the steps to get a new image on the device just as a I did before and everything seems to work fine. However, when I reboot the device the new usb device is never seen. I see the bootloader try to swap the new image in but it then says that there is no valid firmware image in the primary slot.

I also run into the same issue when I use SMP over BLE. The image is successfully added and the mcumgr image list command even shows that there are two firmware images on the device. But when I reboot, the bootloader tries to swap in the new image but then fails to validate it. 

Am I doing something wrong or is this only supposed to work with QSPI?

The external flash works fine on its own as I have the NVS system stored there and I am able to use it without any issues.

[dhump3]

Hi Simon,

For some reason I there was no reply button so am just replying to my original question. I have been able to add log statements and read the flash out. I will go through each step I have done.

I start by flashing an image of version 0.1.0 normally. I then use the command mcumgr image upload -e my_image.bin to upload an image of version 0.2.0. After this I ran a mcumgr image list and get the following output:

Images:
 image=0 slot=0
    version: 0.1.0
    bootable: true
    flags: active confirmed
    hash: f225666061fb89f3b354c0a68024125f754ba19bc04bff8de96d3272fe2e8fe4
 image=0 slot=1
    version: 0.2.0
    bootable: true
    flags: 
    hash: 9b79b38d0ef3d0aef9540ca3544714abcfe5949c7c980fea1d8246fa48ded321

This seems to be working properly. I then reset the device without testing the image in order to read the image_1 flash area on boot using the following code:

flash_area_open(FLASH_AREA_ID(image_1), &fap);
uint32_t data = 0;
flash_area_read(fap, 0, &data, sizeof(data));
LOG_INF("IMAGE-1 Magic = 0x%08X", data);
flash_area_close(fap);

This gives me the following log output

[00:00:01.796,783] <inf> app: IMAGE-1 Magic = 0x96f3b83d

I believe it is reversed because I stored it in a uint32_t rather than reading into a uint8_t buffer, so the magic seems fine. I then proceed and run the command mcumgr image test 9b79b38d0ef3d0aef9540ca3544714abcfe5949c7c980fea1d8246fa48ded321. This gives me the expected output of:

Images:
 image=0 slot=0
    version: 0.1.0
    bootable: true
    flags: active confirmed
    hash: f225666061fb89f3b354c0a68024125f754ba19bc04bff8de96d3272fe2e8fe4
 image=0 slot=1
    version: 0.2.0
    bootable: true
    flags: pending
    hash: 9b79b38d0ef3d0aef9540ca3544714abcfe5949c7c980fea1d8246fa48ded321

I then reset the device once again and the bootloader does the swap and fails as usual. Here is the output with some extra logging I added:

[00:00:00.253,601] <inf> mcuboot: Starting bootloader
[00:00:00.254,333] <inf> mcuboot: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
[00:00:00.254,333] <inf> mcuboot: Boot source: none
[00:00:00.254,974] <inf> mcuboot: Swap type: test
[00:00:00.254,974] <inf> mcuboot: Header is valid!
[00:00:00.254,974] <inf> mcuboot: Inside bootutil_img_validate()
[00:00:01.040,039] <inf> mcuboot: bootutil_img_validate() successful!
[00:00:01.040,069] <inf> mcuboot: Inisde boot_perform_update()
[00:00:21.213,592] <inf> mcuboot: Header is valid!
[00:00:21.213,592] <inf> mcuboot: Inside bootutil_img_validate()
[00:00:21.537,841] <err> mcuboot: bootutil_tlv_iter_begin failed with error -1
[00:00:21.537,841] <err> mcuboot: Failed to validate the image!
[00:00:21.537,872] <err> mcuboot: Image in the primary slot is not valid!
[00:00:21.537,872] <err> mcuboot: Unable to find bootable image

Each "Header is valid!" is printed after the function boot_is_header_valid() completes successfully. I determined that the failure is occurring in the function boot_img_validate() after the swap occurs, which can be seen in the logs. I added logs inside of that function to determine where its failing and it seems to be failing here. The function bootutil_tlv_iter_begin() returns -1 in numerous different cases, I can add more logging there to try to narrow it down if that helps.

After this failure to validate the image, I have to flash a new image normally. I flash an image of version 0.3.0 and then run mcumgr image list and get this output:

Images:
 image=0 slot=0
    version: 0.3.0
    bootable: true
    flags: active confirmed
    hash: cc631d7dc18337d07b7c17e72f8d1e08f8a9beceab361fa46bb84075cc77fd34
 image=0 slot=1
    version: 0.2.0
    bootable: true
    flags: 
    hash: 9b79b38d0ef3d0aef9540ca3544714abcfe5949c7c980fea1d8246fa48ded321

The 0.2.0 image is still there. Also the output for the magic remains unchanged.

[Simon]

Try to add some unique logging before each return statement inside bootutil_tlv_iter_begin() to figure out exactly where it fails. E.g. printk("bootutil_tlv_iter_begin() no 1\n"), printk("bootutil_tlv_iter_begin() no 2\n") and so on.

[dhump3]

Yes, I see that folder. Anything in here I should be looking for?

[Simon]

No, I was just wondering if it was present (added as a child image). I'm happy you found a working solution. I think I have to do some testing myself to see exactly when/how the PM partitions/dts applies or not.

[embeddedER]

Hi Simon,

Did you get more insights on this problem? I've an exactly the same issue and I see the same error:

info.it_magic(0x0) != IMAGE_TLV_INFO_MAGIC (0x6907)

I am using Winbond flash and nrf52832 with ncs version 1.8.0.

So, after downloading the image, it fails to validate the image and then doesn't switch to the new firmware. Anything that I need to take care of with ncs v1.8.0?

TIA!

[Simon]

Take a look at this PR https://github.com/nrfconnect/sdk-mcuboot/pull/200, which I think is related to you issue. The fix for this issue is merged into NCS v2.0.0.

You can see how the function boot_write_magic() has changed:

NCS v1.8.0: https://github.com/nrfconnect/sdk-mcuboot/blob/v1.7.99-ncs4/boot/bootutil/src/bootutil_public.c#L316-L332 

NCS v2.0.0: https://github.com/nrfconnect/sdk-mcuboot/blob/v1.9.99-ncs1/boot/bootutil/src/bootutil_public.c#L326-L361 

Best regards,

Simon

[embeddedER]

Thanks, Simon!