Mender deployment error Expected \"upgrade_available\" flag to be true but it was false

Hi,

I am using mender server version 2.1.0.
when I do deployment, its get successful.I can see my device gets booted with new version. Mender server also shows updated version for my device. But it shows deployment status as “Failure”.

@mirzak
@drewmoseley any idea what will be the issue here?

Deployment logs:

{“level”:“info”,“message”:“Running Mender client version: b6dfc02”,“timestamp”:“2020-11-02T04:15:16-05:00”}
{“level”:“info”,“message”:“State transition: update-fetch [Download_Enter] -\u003e update-store [Download_Enter]”,“timestamp”:“2020-11-02T04:15:17-05:00”}
{“level”:“info”,“message”:“No public key was provided for authenticating the artifact”,“timestamp”:“2020-11-02T04:15:17-05:00”}
{“level”:“info”,“message”:“Opening device “/dev/sda2” for writing”,“timestamp”:“2020-11-02T04:15:17-05:00”}
{“level”:“info”,“message”:“Native sector size of block device /dev/sda2 is 512 bytes. Mender will write in chunks of 1048576 bytes”,“timestamp”:“2020-11-02T04:15:17-05:00”}
{“level”:“info”,“message”:“All bytes were successfully written to the new partition”,“timestamp”:“2020-11-02T04:59:31-05:00”}
{“level”:“info”,“message”:“The optimized block-device writer wrote a total of 27868 frames, where 18480 frames did need to be rewritten (i.e., skipped)”,“timestamp”:“2020-11-02T04:59:31-05:00”}
{“level”:“info”,“message”:“Wrote 29220802560/29220802560 bytes to the inactive partition”,“timestamp”:“2020-11-02T04:59:32-05:00”}
{“level”:“info”,“message”:“State transition: update-store [Download_Enter] -\u003e update-after-store [Download_Leave]”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“State transition: update-after-store [Download_Leave] -\u003e update-install [ArtifactInstall]”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Enabling partition with new image installed to be a boot candidate: 2”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Probing the Bootloader environment for which separator to use”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:"Writing map[mender_uboot_separator:1] to the U-Boot environment, using separator: ",“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:"Writing map[mender_uboot_separator:] to the U-Boot environment, using separator: ",“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:"Writing map[upgrade_available:1 bootcount:0 mender_boot_part:2 mender_boot_part_hex:2] to the U-Boot environment, using separator: ",“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“State transition: update-install [ArtifactInstall] -\u003e reboot [ArtifactReboot_Enter]”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Rebooting device(s)”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Mender rebooting from active partition: /dev/sda3”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“error”,“message”:“Error rebooting device: signal: terminated”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Shutting down.”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Running Mender client version: 251fa42”,“timestamp”:“2020-11-02T05:00:32-05:00”}
{“level”:“info”,“message”:“State transition: init [none] -\u003e after-reboot [ArtifactReboot_Leave]”,“timestamp”:“2020-11-02T05:00:32-05:00”}
{“level”:“info”,“message”:“State transition: after-reboot [ArtifactReboot_Leave] -\u003e after-reboot [ArtifactReboot_Leave]”,“timestamp”:“2020-11-02T05:00:32-05:00”}
{“level”:“info”,“message”:“State transition: after-reboot [ArtifactReboot_Leave] -\u003e update-commit [ArtifactCommit_Enter]”,“timestamp”:“2020-11-02T05:00:32-05:00”}
{“level”:“error”,“message”:“transient error: update commit failed: Reboot to the new update failed. Expected “upgrade_available” flag to be true but it was false. Either the switch to the new partition was unsuccessful, or the bootloader rolled back”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“State transition: update-commit [ArtifactCommit_Enter] -\u003e rollback [ArtifactRollback]”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“Performing rollback”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“No update available, so no rollback needed.”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“State transition: rollback [ArtifactRollback] -\u003e rollback-reboot [ArtifactRollbackReboot_Enter]”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“Rebooting device(s) after rollback”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“Mender rebooting from inactive partition: /dev/sda2”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“error”,“message”:“Error rebooting device: signal: terminated”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“Shutting down.”,“timestamp”:“2020-11-02T05:00:33-05:00”}
{“level”:“info”,“message”:“Running Mender client version: 251fa42”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“Mender shut down in state: rollback-reboot”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“State transition: init [none] -\u003e verify-rollback-reboot [ArtifactRollbackReboot_Leave]”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“State transition: verify-rollback-reboot [ArtifactRollbackReboot_Leave] -\u003e after-rollback-reboot [ArtifactRollbackReboot_Leave]”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“State transition: after-rollback-reboot [ArtifactRollbackReboot_Leave] -\u003e update-error [ArtifactFailure]”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“State transition: update-error [ArtifactFailure] -\u003e cleanup [Error]”,“timestamp”:“2020-11-02T05:01:29-05:00”}
{“level”:“info”,“message”:“State transition: cleanup [Error] -\u003e update-status-report [none]”,“timestamp”:“2020-11-02T05:01:29-05:00”}

Hi @Rohita83 it seems that something is causing an extra reboot on the client. This part of the log seems to indicate this:

{“level”:“info”,“message”:“Rebooting device(s)”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“info”,“message”:“Mender rebooting from active partition: /dev/sda3”,“timestamp”:“2020-11-02T04:59:33-05:00”}
{“level”:“error”,“message”:“Error rebooting device: signal: terminated”,“timestamp”:“2020-11-02T04:59:33-05:00”}

We would need logging from the client to be able to understand why this happened. Can you provide full console logs as well as the output from “journalctl -u mender-client”?

Drew

I have the same problem.
I believe the problem is because Mender is configured to use ttyS0, and som other tty connections. What these are used for, I haven’t been able to find out, but in my case after I removed ttyS0 from:
MENDER_GRUB_KERNEL_BOOT_ARGS="console=tty0,115200n8 console=ttyO0,115200n8 console=ttyAMA0,115200n8"
Then the update fails with the responds
2021-07-28 04:10:46 +0000 UTC error: transient error: Reboot to the new update failed. Expected “upgrade_available” flag to be true but it was false. Either the switch to the new partition was unsuccessful, or the bootloader rolled back

Any knowlagde to why mender-client needs ttyS0? @mirzak
@drewmoseley

No clue. Perhaps @lramirez can help here.

Drew

Got it to work.

Seems to be an problem with creating artifacts using the snapshot method, since creating artifacts over ssh works fine.