MCUboot not confirm image when using 'west flash'

[nandojve]

Describe the bug
When an App uses MCUboot as bootloader it needs confirm any "clean/new" image at first boot. This always worked on Zephyr until pre-2.5.0 version. Now, it was detected that an image flashed using OpenOCD is not confirming images anymore. This was detected with frdm-k64f, nrf52840dk_nrf52840 and nucleo-f767zi. One possible consequence is an infinite loop that tries boot the board.

To Reproduce
Steps to reproduce the behavior:

1. git checkout master

2. git fetch upstream

3. git rebase upstream/master

4. west update

5. cd ..

6. ls
   bootloader modules net-tools tools zephyr

7. west build -b frdm_k64f -d build/mcuboot-frdm_k64f bootloader/mcuboot/boot/zephyr

8. west flash -d build/mcuboot-frdm_k64f

9. west build -b frdm_k64f -d build/app zephyr/samples/subsys/mgmt/updatehub

10. west sign -t imgtool -d build/app --no-hex -- --version 1.0.0 --pad --key bootloader/mcuboot/root-rsa-2048.pem

11. west flash -d build/app --bin-file build/app/zephyr/zephyr.signed.bin

12. see error

Expected behavior
The recent flashed Image confirm at first boot.

Impact
At least stop development with newer Zephyr versions.

Logs and console output

*** Booting Zephyr OS build zephyr-v2.5.0-2840-g363af20fc4a6  ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: primary slot
I: Swap type: none
I: Bootloader chainload address offset: 0x20000
I: Jumping to the first image slot
*** Booting Zephyr OS build zephyr-v2.5.0-2840-g363af20fc4a6  ***


[00:00:03.001,000] <inf> eth_mcux: ETH_0 enabled 100M full-duplex mode.
[00:00:03.002,000] <inf> main: UpdateHub sample app started
[00:00:03.002,000] <inf> main: Confirming the boot image
[00:00:03.002,000] <err> main: Error to confirm the image
[00:00:03.002,000] <inf> main: Network disconnected
uart:~$ 
[00:00:11.006,000] <inf> main: Network connected
[00:00:11.006,000] <inf> main: Starting UpdateHub polling mode
[00:00:11.006,000] <inf> updatehub: SHA-256 verification on download and from flash
[00:00:11.006,000] <err> updatehub: The current image is not confirmed
[00:00:11.006,000] <err> updatehub: Image is unconfirmed. Rebooting to revert back to previousconfirmed image.*** Booting Zephyr OS build zephyr-v2.5.0-2840-g363af20fc4a6  ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: primary slot
I: Swap type: none
I: Bootloader chainload address offset: 0x20000
I: Jumping to the first image slot
*** Booting Zephyr OS build zephyr-v2.5.0-2840-g363af20fc4a6  ***


[00:00:03.001,000] <inf> eth_mcux: ETH_0 enabled 100M full-duplex mode.
[00:00:03.002,000] <inf> main: UpdateHub sample app started
[00:00:03.002,000] <inf> main: Confirming the boot image
[00:00:03.002,000] <err> main: Error to confirm the image
[00:00:03.002,000] <inf> main: Network disconnected
uart:~$ 

Environment (please complete the following information):

• OS: Linux
• Toolchain Zephyr SDK 0.12.3
• Zephyr version: 2.5.99 (mainline)

Additional context
All variants that UpdateHub uses are working at b0bd14b. This includes proper boot, network and upgrades. I hope we can find a solution or a possible missing config to re-enable the feature.

[nandojve]

To make it easy to reproduce:

git checkout master
git fetch upstream
git rebase upstream/master
west update

Apply this diff

diff --git a/samples/hello_world/prj.conf b/samples/hello_world/prj.conf
index b2a4ba5910..2db4bd6f2c 100644
--- a/samples/hello_world/prj.conf
+++ b/samples/hello_world/prj.conf
@@ -1 +1,7 @@
-# nothing here
+CONFIG_LOG=y
+CONFIG_BOOTLOADER_MCUBOOT=y
+CONFIG_MCUBOOT_IMG_MANAGER=y
+CONFIG_FLASH=y
+CONFIG_REBOOT=y
+CONFIG_IMG_MANAGER=y
+CONFIG_MPU_ALLOW_FLASH_WRITE=y
diff --git a/samples/hello_world/src/main.c b/samples/hello_world/src/main.c
index 6c5c8a27dc..a00464c3ba 100644
--- a/samples/hello_world/src/main.c
+++ b/samples/hello_world/src/main.c
@@ -5,9 +5,21 @@
  */
 
 #include <zephyr.h>
-#include <sys/printk.h>
+#include <dfu/mcuboot.h>
+
+#define LOG_LEVEL CONFIG_LOG_LEVEL_INFO
+#include <logging/log.h>
+LOG_MODULE_REGISTER(hello_world);
 
 void main(void)
 {
-       printk("Hello World! %s\n", CONFIG_BOARD);
+       LOG_INF("Hello MCUboot World!");
+
+       if (boot_write_img_confirmed() < 0) {
+               LOG_ERR("Error to confirm the image");
+       }
+
+       if (boot_is_img_confirmed()) {
+               LOG_INF("Everything is working.");
+       }
 }

Move out Zephyr dir:

cd ..

For frdm-k64f

west build -b frdm_k64f -d build/mcuboot-frdm_k64f bootloader/mcuboot/boot/zephyr
west flash -d build/mcuboot-frdm_k64f

west build -b frdm_k64f -d build/app zephyr/samples/hello_world
west sign -t imgtool -d build/app --no-hex -- --version 1.0.0 --pad --key bootloader/mcuboot/root-rsa-2048.pem
west flash -d build/app --bin-file build/app/zephyr/zephyr.signed.bin

*** Booting Zephyr OS build zephyr-v2.5.0-3527-g89ec3d82adf1  ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: primary slot
I: Swap type: none
I: Bootloader chainload address offset: 0x20000
I: Jumping to the first image slot0*** Booting Zephyr OS build zephyr-v2.5.0-3527-g89ec3d82adf1  ***
[00:00:00.005,000] <inf> hello_world: Hello MCUboot World!
[00:00:00.005,000] <err> hello_world: Error to confirm the image

[nandojve]

For nrf52840dk_nrf52840

west build -b nrf52840dk_nrf52840 -d build/nrf52840dk_nrf52840 bootloader/mcuboot/boot/zephyr
west flash -d build/nrf52840dk_nrf52840

west build -b nrf52840dk_nrf52840 -d build/app zephyr/samples/hello_world
west sign -t imgtool -d build/app -- --version 1.0.0 --pad --key bootloader/mcuboot/root-rsa-2048.pem
west flash -d build/app --hex-file build/app/zephyr/zephyr.signed.hex

*** Booting Zephyr OS build zephyr-v2.5.0-3321-g126da28620d7  ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: primary slot
I: Swap type: none
I: Bootloader chainload address offset: 0xc000
I: Jumping to the first image slot
*** Booting Zephyr OS build zephyr-v2.5.0-3321-g126da28620d7  ***
[00:00:00.005,737] <inf> hello_world: Hello MCUboot World!
[00:00:00.005,798] <err> hello_world: Error to confirm the image

[nandojve]

For nucleo_f767zi

west build -b nucleo_f767zi -d build/nucleo_f767zi bootloader/mcuboot/boot/zephyr
west flash -d build/nucleo_f767zi

west build -b nucleo_f767zi -d build/app zephyr/samples/hello_world
west sign -t imgtool -d build/app -- --version 1.0.0 --pad --key bootloader/mcuboot/root-rsa-2048.pem
west flash -d build/app --hex-file build/app/zephyr/zephyr.signed.hex

*** Booting Zephyr OS build zephyr-v2.5.0-3321-g126da28620d7  ***
I: Starting bootloader
I: Primary image: magic=good, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Scratch: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
I: Boot source: primary slot
I: Swap type: none
I: Bootloader chainload address offset: 0x40000
I: Jumping to the first image slot
*** Booting Zephyr OS build zephyr-v2.5.0-3321-g126da28620d7  ***
[00:00:00.005,000] <inf> hello_world: Hello MCUboot World!
[00:00:00.005,000] <err> hello_world: Error to confirm the image

[nandojve]

CC: @nvlsianpu , @de-nordic , @utzig

[MaureenHelm]

The title of this issue suggests the problem is related to OpenOCD, but I don't think that's the case since you've reproduced it on frdm_k64 (pyocd), nrf52840dk_nrf52840 (jlink), and nucleo_f767zi (openocd). Reassigning to the DFU subsystem maintainer.