Mender update fails at 99%

anishmonachan · August 24, 2020, 2:31pm

Description

I was updating a group of devices with the mender update. The update of 4 of the 5 devices failed. The update process were stuck at 99% for a while and failed. These groups of devices run the same image of yocto mender. I don’t understand why this fails. The following is the log. Can someone help please?

deployments.0001.ea87551f-f69e-4dbb-a427-daf12f19fd42.log deployments.0002.27b07dea-b847-4bd3-8e59-b929ddfca2be.log root@j140-tx2:/data/mender# cat deployments.0001.ea87551f-f69e-4dbb-a427-daf12f19fd42.log {"level":"info","message":"Running Mender version 2.2.0b1","timestamp":"2020-08-24T14:11:26Z"} {"level":"debug","message":"handle update fetch state","timestamp":"2020-08-24T14:11:26Z"} {"level":"debug","message":"status reported, response 204 No Content","timestamp":"2020-08-24T14:11:26Z"} {"level":"debug","message":"Received fetch update response \u0026{200 OK 200 HTTP/1.1 1 1 map[Accept-Ranges:[bytes] Content-Length:[741602816] Content-Type:[application/vnd.mender-artifact] Date:[Mon, 24 Aug 2020 14:11:28 GMT] Etag:[\"8e17d4e41e35e415e4d1909aa67b5885-71\"] Expires:[Mon, 24 Aug 2020 12:07:02 GMT] Last-Modified:[Mon, 24 Aug 2020 11:57:03 GMT] Server:[AmazonS3] X-Amz-Id-2:[ml4lIoUBFa6UxxWsnODXF2Zs2n+HqttC+8o3Q6y5ykWURYb0LbS5Ry+dmHC6+L4DUlkCcHLFxS8=] X-Amz-Request-Id:[B537E9A51521247D]] 0x4000346b60 741602816 [] false false map[] 0x4000580200 0x40000a44d0}+","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"State transition: update-fetch [Download_Enter] -\u003e update-store [Download_Enter]","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"handle update install state","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"status reported, response 204 No Content","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Read data from device manifest file: device_type=j140-tx2","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Current manifest data: j140-tx2","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"no public key was provided for authenticating the artifact","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"Update Module path \"/usr/share/mender/modules/v3\" could not be opened (open /usr/share/mender/modules/v3: no such file or directory). Update modules will not be available","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"checking if device [j140-tx2] is on compatible device list: [j140-tx2]\n","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"installer: processing script: ArtifactReboot_Enter_50","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"installer: successfully read artifact [name: lab-test-2; version: 3; compatible devices: [j140-tx2]]","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Active partition: /dev/mmcblk0p1","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Detected inactive partition /dev/mmcblk0p30, based on active partition /dev/mmcblk0p1","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"opening device /dev/mmcblk0p30 for writing","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Open block-device for installing update of size: 3078619136","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Device: /dev/mmcblk0p30 is a ubi device: false","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"native sector size of block device /dev/mmcblk0p30 is 512, we will write in chunks of 1048576","timestamp":"2020-08-24T14:11:27Z"} {"level":"debug","message":"Opening device: /dev/mmcblk0p30 for writing with flag: 2","timestamp":"2020-08-24T14:11:27Z"} {"level":"info","message":"Running Mender version 2.2.0b1","timestamp":"2020-08-24T14:13:23Z"} {"level":"error","message":"Update was interrupted in state: update-store","timestamp":"2020-08-24T14:13:23Z"} {"level":"info","message":"Update Module path \"/usr/share/mender/modules/v3\" could not be opened (open /usr/share/mender/modules/v3: no such file or directory). Update modules will not be available","timestamp":"2020-08-24T14:13:23Z"} {"level":"info","message":"State transition: init [none] -\u003e cleanup [Error]","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"transitioning to error state","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"Handling Cleanup state","timestamp":"2020-08-24T14:13:23Z"} {"level":"info","message":"State transition: cleanup [Error] -\u003e update-status-report [none]","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"handle update status report state","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"status reported, response 204 No Content","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"attempting to upload deployment logs for failed update","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"logs uploaded, response \u0026{204 No Content 204 HTTP/1.1 1 1 map[Cache-Control:[no-cache, no-store] Connection:[keep-alive] Content-Encoding:[gzip] Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval'] Content-Type:[application/json; charset=utf-8] Date:[Mon, 24 Aug 2020 14:13:23 GMT] Pragma:[no-cache] Referrer-Policy:[strict-origin] Server:[openresty/1.13.6.2] Strict-Transport-Security:[max-age=31536000; includeSubdomains] Vary:[Accept-Encoding] X-Content-Type-Options:[nosniff] X-Deployments-Version:[unknown] X-Frame-Options:[SAMEORIGIN] X-Men-Requestid:[dc3b9a55-b76f-4325-88bb-9a6b5130439c] X-Xss-Protection:[1; mode=block]] 0x400032d660 0 [] false false map[] 0x40004a0300 0x40000b2370}","timestamp":"2020-08-24T14:13:23Z"} {"level":"debug","message":"reporting complete","timestamp":"2020-08-24T14:13:23Z"} root@j140-tx2:/data/mender# date Mon Aug 24 14:19:37 UTC 2020

drewmoseley · August 24, 2020, 3:14pm

This is strange from your log:

{“level”:“debug”,“message”:“Detected inactive partition /dev/mmcblk0p30, based on active partition /dev/mmcblk0p1”,“timestamp”:“2020-08-24T14:11:27Z”} {“level”:“info”,“message”:“opening device /dev/mmcblk0p30 for writing”,“timestamp”:“2020-08-24T14:11:27Z”} {“level”:“debug”,“message”:“Open block-device for installing update of size: 3078619136”,“timestamp”:“2020-08-24T14:11:27Z”} {“level”:“debug”,“message”:"Device: /dev/mmcblk0p30 is a ubi device:

Is /dev/mmcblk0p30 really your passive root filesystem dev node? That seems awfully high. Also the fact that it is a “ubi” device seems to conflict with it being mmcblk0.

Drew

anishmonachan · August 25, 2020, 12:31pm

I’m not sure about it. I am using jetson-tx2. I let the mender default rootfs variables stay.
What is the best approach to choose rootfs partitions?

drewmoseley · August 25, 2020, 1:59pm

I can’t imagine that’s correct. But I have no experience with that board/integration. @dwalkes do you have any feedback on this issue?
Drew

anishmonachan · August 25, 2020, 2:04pm

This is the o/p of lsblk . I hope that I’m using correct partitions for the rootfs. Infact, not all the device updates are failing

drewmoseley · August 25, 2020, 3:52pm

That does seem like a lot of partitions but I’ve seen similar setups on systems that primarily run Android.

The comment in the logs about UBI seems awfully strange and incorrect though. You may want to investigate that a bit further.

dwalkes · August 26, 2020, 3:27pm

Yes this is correct. There are lots of reserved partitions on tegra setups. See https://github.com/mendersoftware/meta-mender-community/blob/zeus/meta-mender-tegra/recipes-bsp/tegra-binaries/mender-custom-flash-layout/tegra186/flash_mender.xml for the TX2 default layout on Zeus.

Also the fact that it is a “ubi” device seems to conflict with it being mmcblk0.

I think the print is actually stating that it’s not a ubi device if I understand it correctly.

github.com

mendersoftware/mender/blob/3f242846b17a43377c22f6a727c68821dc00a2e0/installer/block_device.go#L94


      
          		err = syscall.Unmount(device, 0)
          		if err != nil {
          			log.Errorf("Error unmounting partition %s",
          				device)
          			return nil, err
          		}
          	}
          
          	typeUBI := system.IsUbiBlockDevice(device)
          
          	log.Debugf("Device: %s is a ubi device: %t", device, typeUBI)
          
          	var flag int
          
          	if typeUBI {
          		// UBI block devices are not prefixed with /dev due to the fact
          		// that the kernel root= argument does not handle UBI block
          		// devices which are prefixed with /dev
          		//
          		// Kernel root= only accepts:
          		// - ubi0_0

@anishmonachan are you using the zeus branch? Have you tried mender -install from the command line yet?

anishmonachan · August 26, 2020, 3:40pm

I’m using using Mender ‘warrior’. I haven’t tried to install mender file from command line. Is there a way to do it?

Also to add, the print is stating the device seems ubi= false. Also the output log is printed Is same for a successful update

dellgreen · August 26, 2020, 7:31pm

mender -install <path_to_local_file>
mender -install <http_path_to_file>

anishmonachan · August 27, 2020, 11:21am

I had copied the mender artifact to the jetson. I used above command to install the mender file.
Following are the logs

INFO[0000] Loaded configuration file: /var/lib/mender/mender.conf module=config INFO[0000] Loaded configuration file: /etc/mender/mender.conf module=config ERRO[0000] Failed to read the current active partition: No match between boot and root partitions.: exec: "fw_printenv": executable file not found in $PATH module=cli INFO[0000] Start updating from local image file: [.] module=standalone Installing Artifact of size 4096... INFO[0000] no public key was provided for authenticating the artifact module=installer INFO[0000] Update Module path "/usr/share/mender/modules/v3" could not be opened (open /usr/share/mender/modules/v3: no such file or directory). Update modules will not be available module=modules ERRO[0000] Reading headers failed: installer: failed to read Artifact: reader: can not read version file: readNext: Failed to get next header: reader: error reading archive: read .: is a directory module=standalone ERRO[0000] installer: failed to read Artifact: reader: can not read version file: readNext: Failed to get next header: reader: error reading archive: read .: is a directory module=main

I’m using mender warrior

Update

I had fixed the conflict with the similar mender file name. Then the manual installation seems to be working. Is their any particular way to download mender artifact directly from hosted.mender.io using commandline?

drewmoseley · August 27, 2020, 6:16pm

No, the artifacts are not directly available outside the scope of an OTA deployment. At least not easily. You can from the web ui download them and presumably you could do that on the target device but it would require having your login credentials stored on the device to be able to access the API gateway and generate a JWT.

anishmonachan · August 27, 2020, 6:28pm

That’s clear.
Thank you very much for your response.

Anish

Topic		Replies	Views
Failure updating with Mender General Discussions yocto	5	861	January 22, 2022
System update stuck at 99% General Discussions raspberry-pi-3 , mender-artifact	19	986	July 23, 2020
Mender rootfs group update issue General Discussions	6	395	October 16, 2020
Mender-Artifact deployment error General Discussions yocto , sumo , rocko , thud	11	2457	September 11, 2019
Downgrade from yocto zeus to thud and state version incompatibilty General Discussions	3	440	May 4, 2020

Mender update fails at 99%

Description

Update

Related topics