I had a few Raspberry pi3 which were deployed a few months back. I m trying to update the pi with new artifact but the pi is stuck at the black screen & the hosted mender show rebooting status forever.
Below are the failed deployment logs:
2020-01-31 10:11:54 +0000 UTC info: Running Mender version 2.0.1 2020-01-31 10:11:54 +0000 UTC debug: handle update fetch state 2020-01-31 10:11:54 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:11:56 +0000 UTC debug: Received fetch update response &{200 OK 200 HTTP/1.1 1 1 map[X-Amz-Request-Id:[204E88CC6190A87F] Etag:["cd0c5275077bbe440b17e4114d755a6a"] Content-Length:[375175168] Server:[AmazonS3] X-Amz-Id-2:[09NHgIU5lRHm+0gp24xLYovJhIUd42YZfNjkh1tjTeSQRIwwo/DfzljHKASt48CibCipzGj0MFg=] Last-Modified:[Fri, 31 Jan 2020 09:03:45 GMT] X-Amz-Tagging-Count:[1] Accept-Ranges:[bytes] Content-Type:[application/vnd.mender-artifact] Date:[Fri, 31 Jan 2020 10:11:56 GMT]] 0x29bd580 375175168 [] false false map[] 0x2b94a00 0x2c4bda0}+ 2020-01-31 10:11:56 +0000 UTC info: State transition: update-fetch [Download_Enter] -> update-store [Download_Enter] 2020-01-31 10:11:56 +0000 UTC debug: handle update install state 2020-01-31 10:11:56 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:11:56 +0000 UTC debug: Read data from device manifest file: device_type=raspberrypi3 2020-01-31 10:11:56 +0000 UTC debug: Current manifest data: raspberrypi3 2020-01-31 10:11:56 +0000 UTC info: no public key was provided for authenticating the artifact 2020-01-31 10:11:56 +0000 UTC debug: checking if device [raspberrypi3] is on compatibile device list: [raspberrypi3] 2020-01-31 10:11:56 +0000 UTC debug: installer: processing script: ArtifactReboot_Enter_00_restore_dns_leases 2020-01-31 10:11:56 +0000 UTC debug: installer: successfully read artifact [name:xxx; version: 3; compatible devices: [raspberrypi3]] 2020-01-31 10:11:56 +0000 UTC debug: Trying to install update of size: 1895825408 2020-01-31 10:11:56 +0000 UTC debug: Active partition: /dev/mmcblk0p2 2020-01-31 10:11:56 +0000 UTC debug: Detected inactive partition /dev/mmcblk0p3, based on active partition /dev/mmcblk0p2 2020-01-31 10:11:56 +0000 UTC info: native sector size of block device /dev/mmcblk0p3 is 512, we will write in chunks of 1048576 2020-01-31 10:11:57 +0000 UTC info: opening device /dev/mmcblk0p3 for writing 2020-01-31 10:11:57 +0000 UTC info: partition /dev/mmcblk0p3 size: 1895825408 2020-01-31 10:23:33 +0000 UTC info: wrote 1895825408/1895825408 bytes of update to device /dev/mmcblk0p3 2020-01-31 10:23:36 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:23:36 +0000 UTC info: State transition: update-store [Download_Enter] -> update-after-store [Download_Leave] 2020-01-31 10:23:36 +0000 UTC info: State transition: update-after-store [Download_Leave] -> update-install [ArtifactInstall] 2020-01-31 10:23:36 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:36 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:36 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:23:36 +0000 UTC debug: Inactive partition: /dev/mmcblk0p3 2020-01-31 10:23:36 +0000 UTC debug: Marking inactive partition (/dev/mmcblk0p3) as the new boot candidate. 2020-01-31 10:23:36 +0000 UTC info: Enabling partition with new image installed to be a boot candidate: 3 2020-01-31 10:23:36 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1 2020-01-31 10:23:36 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1] 2020-01-31 10:23:36 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1 2020-01-31 10:23:36 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1] 2020-01-31 10:23:36 +0000 UTC debug: Marking inactive partition as a boot candidate successful. 2020-01-31 10:23:36 +0000 UTC info: State transition: update-install [ArtifactInstall] -> reboot [ArtifactReboot_Enter] 2020-01-31 10:23:36 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:36 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:36 +0000 UTC debug: start executing script: ArtifactReboot_Enter_00_restore_dns_leases 2020-01-31 10:23:37 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:23:37 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:23:37 +0000 UTC debug: handling reboot state 2020-01-31 10:23:37 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:23:37 +0000 UTC info: rebooting device(s) 2020-01-31 10:23:37 +0000 UTC info: Mender rebooting from active partition: /dev/mmcblk0p2 2020-01-31 10:23:53 +0000 UTC info: Running Mender version 2.0.1 2020-01-31 10:23:54 +0000 UTC info: State transition: init [none] -> after-reboot [ArtifactReboot_Leave] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: upgrade_available=0 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:0] 2020-01-31 10:23:54 +0000 UTC error: transient error: Reboot to new update failed. Expected "upgrade_available" flag to be true but it was false 2020-01-31 10:23:54 +0000 UTC info: State transition: after-reboot [ArtifactReboot_Leave] -> rollback [ArtifactRollback] 2020-01-31 10:23:54 +0000 UTC debug: transitioning to error state 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC info: performing rollback 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: upgrade_available=0 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:0] 2020-01-31 10:23:54 +0000 UTC debug: will try to rollback reboot the device 2020-01-31 10:23:54 +0000 UTC info: State transition: rollback [ArtifactRollback] -> rollback-reboot [ArtifactRollbackReboot_Enter] 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC info: rebooting device(s) after rollback 2020-01-31 10:23:54 +0000 UTC info: Mender rebooting from inactive partition: /dev/mmcblk0p2 2020-01-31 10:23:53 +0000 UTC info: Running Mender version 2.0.1 2020-01-31 10:23:53 +0000 UTC info: Update was interrupted in state: rollback-reboot 2020-01-31 10:23:53 +0000 UTC info: State transition: init [none] -> verify-rollback-reboot [ArtifactRollbackReboot_Leave] 2020-01-31 10:23:53 +0000 UTC debug: transitioning to error state 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_check_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_check_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: mender_saveenv_canary=1 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[mender_saveenv_canary:1] 2020-01-31 10:23:54 +0000 UTC debug: Have U-Boot variable: upgrade_available=0 2020-01-31 10:23:54 +0000 UTC debug: List of U-Boot variables:map[upgrade_available:0] 2020-01-31 10:23:54 +0000 UTC info: State transition: verify-rollback-reboot [ArtifactRollbackReboot_Leave] -> after-rollback-reboot [ArtifactRollbackReboot_Leave] 2020-01-31 10:23:54 +0000 UTC debug: handling state after rollback reboot 2020-01-31 10:23:54 +0000 UTC info: State transition: after-rollback-reboot [ArtifactRollbackReboot_Leave] -> update-error [ArtifactFailure] 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: handle update error state 2020-01-31 10:23:54 +0000 UTC info: State transition: update-error [ArtifactFailure] -> cleanup [Error] 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: Handling Cleanup state 2020-01-31 10:23:54 +0000 UTC info: State transition: cleanup [Error] -> update-status-report [none] 2020-01-31 10:23:54 +0000 UTC debug: statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds 2020-01-31 10:23:54 +0000 UTC debug: handle update status report state 2020-01-31 10:23:54 +0000 UTC error: failed to report status: Put https://hosted.mender.io/api/devices/v1/deployments/device/deployments/577b8807-84b9-417a-a4c1-d218334b0a46/status: dial tcp: lookup hosted.mender.io on 127.0.0.1:53: server misbehaving 2020-01-31 10:23:54 +0000 UTC error: error reporting update status: reporting status failed: Put https://hosted.mender.io/api/devices/v1/deployments/device/deployments/577b8807-84b9-417a-a4c1-d218334b0a46/status: dial tcp: lookup hosted.mender.io on 127.0.0.1:53: server misbehaving 2020-01-31 10:23:54 +0000 UTC error: failed to send status to server: transient error: reporting status failed: Put https://hosted.mender.io/api/devices/v1/deployments/device/deployments/577b8807-84b9-417a-a4c1-d218334b0a46/status: dial tcp: lookup hosted.mender.io on 127.0.0.1:53: server misbehaving 2020-01-31 10:23:54 +0000 UTC info: State transition: update-status-report [none] -> update-retry-report [none] 2020-01-31 10:29:32 +0000 UTC debug: wait complete 2020-01-31 10:29:32 +0000 UTC info: State transition: update-retry-report [none] -> update-status-report [none] 2020-01-31 10:29:32 +0000 UTC debug: handle update status report state 2020-01-31 10:29:33 +0000 UTC debug: status reported, response 204 No Content 2020-01-31 10:29:33 +0000 UTC debug: attempting to upload deployment logs for failed update
The artifact is made by the mender-convert 1.2.1 and mender-artifact 3.2.0
The deployment fails after the raspberry pi is rebooted manually.
The line
2020-01-31 10:23:54 +0000 UTC error: transient error: Reboot to new update failed. Expected “upgrade_available” flag to be true but it was false
makes the raspberry pi3 rollback to the previous boot patitiion