Raspberry Pi 4 update failed

Hi,
I’m new to mender. I installed a production server as described in https://docs.mender.io/2.3/administration/production-installation. I also generate a image for the Raspberry Pi 4 as described in Raspberry Pi 4 Model B + Raspbian

The server is working and the raspberry is recognized as device in the server.

Then I created a new artifact (only adding some files and folders for testing) and uploaded it to the mender server.
Then I create a deployment on the server and added the raspberry.

After starting the deployment the download to the raspberry begin and after rebooting the update failed and the raspberry boot from /dev/mmcblk0p2.

The log file looks like this:
2020-04-24 13:10:19 +0000 UTC info: Running Mender version 2.2.0
2020-04-24 13:10:19 +0000 UTC debug: handle update fetch state
2020-04-24 13:10:19 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:10:19 +0000 UTC debug: Received fetch update response &{200 OK 200 HTTP/1.1 1 1 map[Content-Length:[585492992] Server:[openresty/1.13.6.2] Accept-Ranges:[bytes] X-Frame-Options:[DENY] X-Amz-Request-Id:[1608C38292D8C735] Strict-Transport-Security:[max-age=63072000; includeSubdomains; preload] Connection:[keep-alive] Content-Security-Policy:[block-all-mixed-content] Last-Modified:[Fri, 24 Apr 2020 11:14:33 GMT] Vary:[Origin] X-Xss-Protection:[1; mode=block] X-Content-Type-Options:[nosniff] Date:[Fri, 24 Apr 2020 13:10:34 GMT] Content-Type:[application/vnd.mender-artifact] Etag:[“a308f56a5683f089805bbc76495b20c7”]] 0x22b09e0 585492992 [] false false map[] 0x20b4a00 0x208f6e0}+
2020-04-24 13:10:19 +0000 UTC info: State transition: update-fetch [Download_Enter] -> update-store [Download_Enter]
2020-04-24 13:10:19 +0000 UTC debug: handle update install state
2020-04-24 13:10:19 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:10:19 +0000 UTC debug: Read data from device manifest file: device_type=raspberrypi4
2020-04-24 13:10:19 +0000 UTC debug: Current manifest data: raspberrypi4
2020-04-24 13:10:19 +0000 UTC info: no public key was provided for authenticating the artifact
2020-04-24 13:10:19 +0000 UTC debug: checking if device [raspberrypi4] is on compatible device list: [raspberrypi4]
2020-04-24 13:10:19 +0000 UTC debug: installer: successfully read artifact [name: release-2; version: 3; compatible devices: [raspberrypi4]]
2020-04-24 13:10:19 +0000 UTC debug: Active partition: /dev/mmcblk0p2
2020-04-24 13:10:19 +0000 UTC debug: Detected inactive partition /dev/mmcblk0p3, based on active partition /dev/mmcblk0p2
2020-04-24 13:10:19 +0000 UTC info: opening device /dev/mmcblk0p3 for writing
2020-04-24 13:10:19 +0000 UTC debug: Open block-device for installing update of size: 2338209792
2020-04-24 13:10:19 +0000 UTC debug: Device: /dev/mmcblk0p3 is a ubi device: false
2020-04-24 13:10:19 +0000 UTC info: native sector size of block device /dev/mmcblk0p3 is 512, we will write in chunks of 1048576
2020-04-24 13:10:19 +0000 UTC debug: Opening device: /dev/mmcblk0p3 for writing with flag: 2
2020-04-24 13:20:15 +0000 UTC info: 0 bytes remaining to be written
2020-04-24 13:20:15 +0000 UTC info: The optimized block-device writer wrote a total of 2230 frames, where 23 frames did need to be rewritten
2020-04-24 13:20:15 +0000 UTC info: Wrote 2338209792/2338209792 bytes to the inactive partition
2020-04-24 13:20:15 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:20:15 +0000 UTC info: State transition: update-store [Download_Enter] -> update-after-store [Download_Leave]
2020-04-24 13:20:15 +0000 UTC info: State transition: update-after-store [Download_Leave] -> update-install [ArtifactInstall]
2020-04-24 13:20:15 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:15 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:15 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:20:15 +0000 UTC debug: Inactive partition: /dev/mmcblk0p3
2020-04-24 13:20:15 +0000 UTC debug: Marking inactive partition (/dev/mmcblk0p3) as the new boot candidate.
2020-04-24 13:20:15 +0000 UTC info: Enabling partition with new image installed to be a boot candidate: 3
2020-04-24 13:20:15 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1
2020-04-24 13:20:15 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1]
2020-04-24 13:20:15 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1
2020-04-24 13:20:15 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1]
2020-04-24 13:20:15 +0000 UTC debug: Marking inactive partition as a boot candidate successful.
2020-04-24 13:20:15 +0000 UTC info: State transition: update-install [ArtifactInstall] -> reboot [ArtifactReboot_Enter]
2020-04-24 13:20:15 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:15 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:15 +0000 UTC debug: handling reboot state
2020-04-24 13:20:15 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:20:15 +0000 UTC info: rebooting device(s)
2020-04-24 13:20:15 +0000 UTC info: Mender rebooting from active partition: /dev/mmcblk0p2
2020-04-23 12:17:09 +0000 UTC info: Running Mender version 2.2.0
2020-04-23 12:17:09 +0000 UTC info: State transition: init [none] -> after-reboot [ArtifactReboot_Leave]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: upgrade_available=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:1]
2020-04-23 12:17:09 +0000 UTC info: State transition: after-reboot [ArtifactReboot_Leave] -> after-reboot [ArtifactReboot_Leave]
2020-04-23 12:17:09 +0000 UTC debug: handling state after reboot
2020-04-23 12:17:09 +0000 UTC info: State transition: after-reboot [ArtifactReboot_Leave] -> update-commit [ArtifactCommit_Enter]
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC debug: handle update commit state
2020-04-23 12:17:09 +0000 UTC error: transient error: update commit failed: statescript: The statescript version file is missing. This file needs to be present and contain a single number representing which version of the statescript support the client is using in order to successfully run statescripts on the client
2020-04-23 12:17:09 +0000 UTC info: State transition: update-commit [ArtifactCommit_Enter] -> rollback [ArtifactRollback]
2020-04-23 12:17:09 +0000 UTC debug: transitioning to error state
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC info: performing rollback
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: upgrade_available=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:1]
2020-04-23 12:17:09 +0000 UTC debug: Active partition: /dev/mmcblk0p3
2020-04-23 12:17:09 +0000 UTC debug: Detected inactive partition /dev/mmcblk0p2, based on active partition /dev/mmcblk0p3
2020-04-23 12:17:09 +0000 UTC debug: Marking inactive partition (/dev/mmcblk0p2) as the new boot candidate.
2020-04-23 12:17:09 +0000 UTC info: setting partition for rollback: 2
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1
2020-04-23 12:17:09 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1]
2020-04-23 12:17:09 +0000 UTC debug: Marking inactive partition as a boot candidate successful.
2020-04-23 12:17:09 +0000 UTC debug: will try to rollback reboot the device
2020-04-23 12:17:09 +0000 UTC info: State transition: rollback [ArtifactRollback] -> rollback-reboot [ArtifactRollbackReboot_Enter]
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-23 12:17:09 +0000 UTC info: rebooting device(s) after rollback
2020-04-23 12:17:09 +0000 UTC info: Mender rebooting from inactive partition: /dev/mmcblk0p3
2020-04-24 13:20:26 +0000 UTC info: Running Mender version 2.2.0
2020-04-24 13:20:26 +0000 UTC info: Update was interrupted in state: rollback-reboot
2020-04-24 13:20:26 +0000 UTC info: State transition: init [none] -> verify-rollback-reboot [ArtifactRollbackReboot_Leave]
2020-04-24 13:20:26 +0000 UTC debug: transitioning to error state
2020-04-24 13:20:26 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1
2020-04-24 13:20:26 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1]
2020-04-24 13:20:26 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1
2020-04-24 13:20:26 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1]
2020-04-24 13:20:26 +0000 UTC debug: Have U-Boot variable: upgrade_available=0
2020-04-24 13:20:26 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:0]
2020-04-24 13:20:26 +0000 UTC info: State transition: verify-rollback-reboot [ArtifactRollbackReboot_Leave] -> after-rollback-reboot [ArtifactRollbackReboot_Leave]
2020-04-24 13:20:26 +0000 UTC debug: handling state after rollback reboot
2020-04-24 13:20:26 +0000 UTC info: State transition: after-rollback-reboot [ArtifactRollbackReboot_Leave] -> update-error [ArtifactFailure]
2020-04-24 13:20:26 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:26 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:26 +0000 UTC debug: handle update error state
2020-04-24 13:20:26 +0000 UTC info: State transition: update-error [ArtifactFailure] -> cleanup [Error]
2020-04-24 13:20:26 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:26 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:26 +0000 UTC debug: Handling Cleanup state
2020-04-24 13:20:26 +0000 UTC info: State transition: cleanup [Error] -> update-status-report [none]
2020-04-24 13:20:26 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds
2020-04-24 13:20:26 +0000 UTC debug: handle update status report state
2020-04-24 13:20:26 +0000 UTC error: failed to report status: Put https://deployment.xxx.com/api/devices/v1/deployments/device/deployments/c428e28a-8076-4893-a19e-e1a98134c267/status: dial tcp: lookup deployment.xxx.com on [fd00::464e:6dff:fe56:8825]:53: dial udp [fd00::464e:6dff:fe56:8825]:53: connect: network is unreachable
2020-04-24 13:20:26 +0000 UTC error: error reporting update status: reporting status failed: Put https://deployment.xxx.com/api/devices/v1/deployments/device/deployments/c428e28a-8076-4893-a19e-e1a98134c267/status: dial tcp: lookup deployment.xxx.com on [fd00::464e:6dff:fe56:8825]:53: dial udp [fd00::464e:6dff:fe56:8825]:53: connect: network is unreachable
2020-04-24 13:20:26 +0000 UTC error: failed to send status to server: transient error: reporting status failed: Put https://deployment.xxx.com/api/devices/v1/deployments/device/deployments/c428e28a-8076-4893-a19e-e1a98134c267/status: dial tcp: lookup deployment.xxx.com on [fd00::464e:6dff:fe56:8825]:53: dial udp [fd00::464e:6dff:fe56:8825]:53: connect: network is unreachable
2020-04-24 13:20:26 +0000 UTC info: State transition: update-status-report [none] -> update-retry-report [none]
2020-04-24 13:21:37 +0000 UTC debug: wait complete
2020-04-24 13:21:37 +0000 UTC info: State transition: update-retry-report [none] -> update-status-report [none]
2020-04-24 13:21:37 +0000 UTC debug: handle update status report state
2020-04-24 13:21:37 +0000 UTC debug: status reported, response 204 No Content
2020-04-24 13:21:37 +0000 UTC debug: attempting to upload deployment logs for failed update

I also tried to insert a script “ArtifactReboot_Leave_00” to /var/lib/mender/scripts to wait for wi-fi network - but the effect is the same.

If I mount mmcblk0p3 manually and have a look on it, the files and folders I stored in the artifact exist.

But the raspberry don’t switch the rootfs and don’t mount from mmcblk0p3.

Has anyone an idea, what I can do, to recognize the problem and fix it?

Hm, strange. This is the error that is causing it to rollback.

Then I created a new artifact (only adding some files and folders for testing) and uploaded it to the mender server.

How did you create the new Artifact?

I use mender-convert. I copied some files to the directory “rootfs_overlay_demo” and start a new conversion with “release-2”.

The new .mender file I uploaded to the server.

Hi @walterp it looks like mender-convert is not creating the state script version file. I have submitted a fix for that issue here: https://github.com/mendersoftware/mender-convert/pull/196

Drew

Thank you for the quick fix. Now the update run successfully.