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]

I added more logging and have determined the issue is with the tlv magic. I added a log statement there to see what the difference is.

[00:00:22.004,516] <err> mcuboot: tlv magic is wrong! expected 0x6907 but got 0x0000

[Simon]

I can see that boot_validate_slot() is called several times from different places, but if I've concluded correctly the call from context_boot_go() is the one that is leading to this error. This means that the update is already done, and the image previously located in the secondary slot (external flash), now residing in the primary slot is being validated.

I am not sure why it can't find IMAGE_TLV_PROT_INFO_MAGIC. I'll talk to a developer on Monday.

Maybe you could try to print out the offset, it should be equal to the size of the binary (app_update.bin) if I understand it correctly

bootutil_tlv_iter_begin(..){
 ..
 ..
 off_ = BOOT_TLV_OFF(hdr);
 //Add the line below
 printk("offset %d | image size: %d | header size: %d \n", off_, hdr->ih_img_size, hdr->ih_hdr_size);
    if (flash_area_read(fap, off_, &info, sizeof(info))) {
        return -1;
    }

    if (info.it_magic == IMAGE_TLV_PROT_INFO_MAGIC) {
    ..

Best regards,

Simon

[Simon]

I've talked to a developer internally and got some insight. I think the reason for this issue is that the write alignment in the spi_nor driver is not set to 4 bytes. As you can see in Zephyr issue 26729, it is not possible to write to the mx25r64 if the minimum write size is less than 4, I believe it's the same with your mx25r32. The qpsi_nor driver has been modified to take this into account. The two links below points to the code that will handle writes smaller than 4 bytes:

• qspi_nor_write()
• write_sub_word()

If you look inside write_sub_word(), it will handle cases where less than 4 bytes is written to flash. E.g. if you write 2 bytes, then you need to read out 4 bytes and store it into a buffer, put your 2 bytes into the same buffer, before writing all the 4 bytes into the flash. This is to preserve unchanged data.

Could you try to modify spi_nor_write() to do the same?

Please ask if anything is unclear.

Best regards,

Simon