Update reports successful but fails to change boot partition

[Shakta Exe]

I am implementing A/B update pattern. I have found that sometimes, my updates will report as successful but the boot partition will not get updated. When this happens, I re-run the update a second time and it succeeds and updates the boot partition correctly.

It surprises that SWUpdate is reporting the update as successful, but not updating the boot partition and I am seeking advice how to debug what the issue here.

Here is my SW description.

software = {
version = "@@MY_IMAGE_VERSION@@";

development : {
copy1 : {
images: (
{
filename = "@@MY_IMAGE_NAME@@-@@MACHINE@@.ext4.gz";
device = "/dev/mmcblk2p1";
type = "raw";
compressed = "zlib";
}
);
uboot: (
{
name = "mmcpart";
value = "1";
}
);
};
copy2 : {
images: (
{
filename = "@@MY_IMAGE_NAME@@-@@MACHINE@@.ext4.gz";
device = "/dev/mmcblk2p2";
type = "raw";
compressed = "zlib";
}
);
uboot: (
{
name = "mmcpart";
value = "2";
}
);
};
};
}

I run SWUpdate directly, using the following command. Where I use copy1/2 based on the output of the swupdate -g command.

swupdate -v -i /mnt/update/<imagename>.swu -e development,copy1

I have some observations to share. When the update succeeds (but doesn't update boot partition), the verbose output looks like this.

[INFO ] : SWUPDATE running :  [print_registered_bootloaders] : Registered bootloaders:
[INFO ] : SWUPDATE running :  [print_registered_bootloaders] :  uboot   loaded.
[INFO ] : SWUPDATE running :  [main] : Using default bootloader interface: uboot
[INFO ] : SWUPDATE running :  [print_registered_handlers] : Registered handlers:
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     dummy
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     archive
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     tar
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     uboot
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     bootloader
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     raw
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     rawfile
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     rawcopy
[INFO ] : SWUPDATE running :  [main] : software set: development mode: copy1
[TRACE] : SWUPDATE running :  [network_initializer] : Main loop daemon
[TRACE] : SWUPDATE running :  [listener_create] : creating socket at /tmp/swupdateprog
[TRACE] : SWUPDATE running :  [listener_create] : creating socket at /tmp/sockinstctrl
[TRACE] : SWUPDATE running :  [network_thread] : Incoming network request: processing...
[INFO ] : SWUPDATE started :  Software Update started !
[TRACE] : SWUPDATE running :  [network_initializer] : Software update started
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] : Found file
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] :   filename sw-description
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] :   size 582
[TRACE] : SWUPDATE running :  [get_common_fields] : Version 0.0.2
[TRACE] : SWUPDATE running :  [_parse_images] : Found compressed Image: <imagename>.ext4.gz in device : /dev/mmcblk2p1 for handler raw
[TRACE] : SWUPDATE running :  [_parse_bootloader] : Bootloader var: mmcpart = 1
[TRACE] : SWUPDATE running :  [extract_files] : Found file
[TRACE] : SWUPDATE running :  [extract_files] :         filename <imagename>.ext4.gz
[TRACE] : SWUPDATE running :  [extract_files] :         size 382965715 required
[TRACE] : SWUPDATE running :  [extract_padding] : Expecting 432 padding bytes at end-of-file
[TRACE] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH
[INFO ] : SWUPDATE running :  Installation in progress
[TRACE] : SWUPDATE running :  [install_single_image] : Found installer for stream b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz raw
[INFO ] : SWUPDATE running :  [endupdate] : SWUpdate was successful !

Let's compare this with output of the re-run of the update (immediately done after the run shown above). This is the update that actually succeeds and updates the boot partition.

[INFO ] : SWUPDATE running :  [print_registered_bootloaders] : Registered bootloaders:
[INFO ] : SWUPDATE running :  [print_registered_bootloaders] :  uboot   loaded.
[INFO ] : SWUPDATE running :  [main] : Using default bootloader interface: uboot
[INFO ] : SWUPDATE running :  [print_registered_handlers] : Registered handlers:
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     dummy
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     archive
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     tar
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     uboot
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     bootloader
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     raw
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     rawfile
[INFO ] : SWUPDATE running :  [print_registered_handlers] :     rawcopy
[INFO ] : SWUPDATE running :  [main] : software set: development mode: copy1
[TRACE] : SWUPDATE running :  [listener_create] : creating socket at /tmp/swupdateprog
[TRACE] : SWUPDATE running :  [network_initializer] : Main loop daemon
[TRACE] : SWUPDATE running :  [listener_create] : creating socket at /tmp/sockinstctrl
[TRACE] : SWUPDATE running :  [network_thread] : Incoming network request: processing...
[INFO ] : SWUPDATE started :  Software Update started !
[TRACE] : SWUPDATE running :  [network_initializer] : Software update started
[WARN ] : SWUPDATE running :  [swupdate_create_directory] : Directory scripts/ cannot be created due to : File exists
[WARN ] : SWUPDATE running :  [swupdate_create_directory] : Directory datadst/ cannot be created due to : File exists
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] : Found file
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] :   filename sw-description
[TRACE] : SWUPDATE running :  [extract_file_to_tmp] :   size 582
[TRACE] : SWUPDATE running :  [get_common_fields] : Version 0.0.2
[TRACE] : SWUPDATE running :  [_parse_images] : Found compressed Image: b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz in device : /dev/mmcblk2p1 for handler raw
[TRACE] : SWUPDATE running :  [_parse_bootloader] : Bootloader var: mmcpart = 1
[TRACE] : SWUPDATE running :  [extract_files] : Found file
[TRACE] : SWUPDATE running :  [extract_files] :         filename b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz
[TRACE] : SWUPDATE running :  [extract_files] :         size 382965715 required
[TRACE] : SWUPDATE running :  [extract_padding] : Expecting 432 padding bytes at end-of-file
[TRACE] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH
[INFO ] : SWUPDATE running :  Installation in progress
[TRACE] : SWUPDATE running :  [install_single_image] : Found installer for stream b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz raw
[INFO ] : SWUPDATE successful ! SWUPDATE successful !
[TRACE] : SWUPDATE running :  [network_initializer] : Main thread sleep again !
[INFO ] : No SWUPDATE running :  Waiting for requests...
[INFO ] : SWUPDATE running :  [endupdate] : SWUpdate was successful !

There are some differences to observe. First off, the warnings on the second run.

[WARN ] : SWUPDATE running :  [swupdate_create_directory] : Directory scripts/ cannot be created due to : File exists
[WARN ] : SWUPDATE running :  [swupdate_create_directory] : Directory datadst/ cannot be created due to : File exists

Secondly, we see that the successful update contains some info/traces that aren't present in the update that succeeded but failed to change the boot partition.

[INFO ] : SWUPDATE successful ! SWUPDATE successful !
[TRACE] : SWUPDATE running :  [network_initializer] : Main thread sleep again !

Lastly, I am noticing that certain images I create (boot2qt) fail more frequently than others (a custom extended version of core-image-minimal).

Any idea what is going on here?

- Shakta

[Stefano Babic]

Hi Shaktha,

On 02.11.23 15:56, Shakta Exe wrote:
> I am implementing A/B update pattern. I have found that sometimes, my
> updates will report as successful but the boot partition will not get
> updated. When this happens, I re-run the update a second time and it
> succeeds and updates the boot partition correctly.
>

First, I do not see *any* boot partition. You have just two partitions
for rootfs + U-Boot variables.

> It surprises that SWUpdate is reporting the update as successful, but
> not updating the boot partition and I am seeking advice how to debug
> what the issue here.

Ok, this phrase does not make sense.

You have run the same some seconds ago, directories are already there,
they are not created again. In fact, this is warning.

>
> Secondly, we see that the successful update contains some info/traces
> that aren't present in the update that succeeded but failed to change
> the boot partition.
>
> [INFO ] : SWUPDATE successful ! SWUPDATE successful !
> [TRACE] : SWUPDATE running :  [network_initializer] : Main thread sleep
> again !
>
> Lastly, I am noticing that certain images I create (boot2qt) fail more
> frequently than others (a custom extended version of core-image-minimal).
>
> Any idea what is going on here?

That probably you have a wrong interface with U-Boot environemt and you
have to test it before running SWUpdate. It is like you set redundancy,
but in a wrong way, and SWUpdate writes in a different place as what
U-Boot expects. You should first check that writing / reading the
environment perfectly works first. Just use fw_setenv / fw_getenv, and
reboot the board to check if U-Boot sees the same.

Best regards,
Stefano Babic

[Shakta Exe]

"First, I do not see *any* boot partition. You have just two partitions

for rootfs + U-Boot variables."

I am using the term boot partition incorrectly. Any where I say boot partition I mean the environment variable in u-boot that is used for what rootfs+kernel partition it boots to.

"That probably you have a wrong interface with U-Boot environemt and you
have to test it before running SWUpdate. It is like you set redundancy,
but in a wrong way, and SWUpdate writes in a different place as what
U-Boot expects. You should first check that writing / reading the
environment perfectly works first. Just use fw_setenv / fw_getenv, and
reboot the board to check if U-Boot sees the same."

Reading and writing uboot environment works as far as I can tell. I am able to switch between A/B file system partitions without issue by using fw_setenv to modify mmcpart, rebooting and checking if A or B using swupdate -g. I can do this many times without error. So, u-boot is seeing the same.

- Shakta

[Stefano Babic]

Hi Shakta,

On 02.11.23 17:47, Shakta Exe wrote:
> /"First, I do not see *any* boot partition. You have just two partitions
> /
> /for rootfs + U-Boot variables."/

>
> I am using the term boot partition incorrectly. Any where I say boot
> partition I mean the environment variable in u-boot that is used for
> what rootfs+kernel partition it boots to.
>

Ok

> /"That probably you have a wrong interface with U-Boot environemt and you

> have to test it before running SWUpdate. It is like you set redundancy,
> but in a wrong way, and SWUpdate writes in a different place as what
> U-Boot expects. You should first check that writing / reading the
> environment perfectly works first. Just use fw_setenv / fw_getenv, and

> reboot the board to check if U-Boot sees the same."/

>
> Reading and writing uboot environment works as far as I can tell. I am
> able to switch between A/B file system partitions without issue by using

> *fw_setenv* to modify *mmcpart*, rebooting and checking if A or B using

> swupdate -g. I can do this many times without error. So, u-boot is
> seeing the same.
>

Ok - but SWUpdate does not write itself to the environment, it uses the
libubootenv library that is used by fw_setenv, too. If it works with
fw_setenv, it works with SWUpdate, too. The only difference is to check
if the fw_env.config file is the same, that means if points to
/etc/fw_env.config and you have /etc/u-boot-initial/env.

Thes etwo files are set in SWUpdate with CONFIG_UBOOT_FWENV and
CONFIG_UBOOT_DEFAULTENV.

Which is the version of the library, that is which is the output of
"fw_setenv -v" ?

Best regards,
Stefano Babic

> --
> You received this message because you are subscribed to the Google
> Groups "swupdate" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to swupdate+u...@googlegroups.com
> <mailto:swupdate+u...@googlegroups.com>.
> To view this discussion on the web visit
> https://groups.google.com/d/msgid/swupdate/49ad2cd1-8a3d-488b-926c-063a17784c87n%40googlegroups.com <https://groups.google.com/d/msgid/swupdate/49ad2cd1-8a3d-488b-926c-063a17784c87n%40googlegroups.com?utm_medium=email&utm_source=footer>.

[Shakta Exe]

My bootloader support section from swupdate config.

#

# Bootloader support

#

#

# Bootloader Interfaces

#

# CONFIG_BOOTLOADER_NONE is not set

# CONFIG_BOOTLOADER_EBG is not set

CONFIG_UBOOT=y

CONFIG_UBOOT_FWENV="/etc/fw_env.config"

CONFIG_UBOOT_DEFAULTENV="/etc/u-boot-initial-env"

# CONFIG_BOOTLOADER_GRUB is not set

CONFIG_BOOTLOADER_DEFAULT_UBOOT=y

# CONFIG_BOOTLOADER_STATIC_LINKED is not set

CONFIG_UPDATE_STATE_CHOICE_BOOTLOADER=y

CONFIG_UPDATE_STATE_BOOTLOADER="ustate"

The output of fw_printenv -V is 0.3.2.

Don't think this is related but I just realized there is no ustate variable in my uboot environment.

- Shakta

[Shakta Exe]

I added a patch to swupdate to help myself get a better idea of what is (not) happening when this issue occurs.

diff --git a/bootloader/uboot.c b/bootloader/uboot.c

index a2f0794..800ab49 100644

--- a/bootloader/uboot.c

+++ b/bootloader/uboot.c

@@ -64,6 +64,7 @@ static int do_env_set(const char *name, const char *value)

struct uboot_ctx *ctx = NULL;

ret = bootloader_initialize(&ctx);

+ INFO("bootloader_initialize ret: %d for setting env var %s", ret, name);

if (!ret) {

libuboot.set_env(ctx, name, value);

ret = libuboot.env_store(ctx);

Here is a snippet of the output for an update that succeeds and sets the mmcpart environment variable.

[TRACE] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH

[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var recovery_status
[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var ustate

[INFO ] : SWUPDATE running :  Installation in progress
[TRACE] : SWUPDATE running :  [install_single_image] : Found installer for stream b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz raw

[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var recovery_status
[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var ustate

[INFO ] : SWUPDATE successful ! SWUPDATE successful !
[TRACE] : SWUPDATE running :  [network_initializer] : Main thread sleep again !
[INFO ] : No SWUPDATE running :  Waiting for requests...
[INFO ] : SWUPDATE running :  [endupdate] : SWUpdate was successful !

Here is a snippet of the output for an update that succeeds but doesn't set the mmcpart environment variable.

[TRACE] : SWUPDATE running :  [network_initializer] : Valid image found: copying to FLASH

[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var recovery_status
[INFO ] : SWUPDATE running :  [do_env_set] : bootloader_initialize ret: 0 for setting env var ustate

[INFO ] : SWUPDATE running :  Installation in progress
[TRACE] : SWUPDATE running :  [install_single_image] : Found installer for stream b2qt-embedded-qt6-image-imx8mp-var-dart.ext4.gz raw
[INFO ] : SWUPDATE running :  [endupdate] : SWUpdate was successful !

Comparing the two, it seems that when the issue occurs, SWUpdate is not setting environment variables after the installation finishes, at all.

- Shakta

[Shakta Exe]

Some additional useful info I think.

For the successful update where mmcpart environment variable gets updated, after the update, using fw_printenv I get...

• recovery_status=
• ustate=1

Compared to after an update where mmcpart environment variable does not get updated

• recovery_status=in_progress
• ustate=7

- shakta

[Shakta Exe]

I am starting to suspect the root cause of the issue is that something funky is going on in my yocto build. This issue seems to have recently arose when I removed signed update support from my layer, before that things were working well. The actual size of the .swu (378526720) is larger than the size expected by swupdate (378525673).

- Shakta

[Shakta Exe]

My size comparison is irrelevant. Even on builds before I removed update protection, that worked, the actual and expected sizes differ.

- Shakta