Cannot send inventory

bender · December 27, 2021, 1:43pm

Hello all,

we tried a deployment to a group of devices and got a failure with no option for log output.
Reading the journal from that device we repeatedly see these lines:

Dec 27 13:30:17 hostname mender[283]: time="2021-12-27T13:30:17Z" level=info msg="State transition: update-retry-report [none] -> update-status-report [none]"
Dec 27 13:30:20 hostname mender[283]: time="2021-12-27T13:30:20Z" level=error msg="Got unexpected HTTP status when uploading log: 400"
Dec 27 13:30:20 hostname mender[283]: time="2021-12-27T13:30:20Z" level=error msg="error uploading logs: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 13:30:20 hostname mender[283]: time="2021-12-27T13:30:20Z" level=error msg="Failed to report deployment logs: transient error: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 13:30:20 hostname mender[283]: time="2021-12-27T13:30:20Z" level=error msg="Failed to send deployment logs to server: transient error: failed to send deployment logs: transient error: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 13:30:20 hostname mender[283]: time="2021-12-27T13:30:20Z" level=info msg="State transition: update-status-report [none] -> update-retry-report [none]"

We had an older mender artifact on site so we performed a manual mender install artifact.mender, all went well, rebooted to new partition, committed successfully but same errors appear and mender cloud still reports previous version.

The command echo string | nc hosted.mender.io 443 reports correctly 400 Bad Request as it should. Also nslookup seems fine:

nslookup hosted.mender.io
Server:    8.8.8.8
Address 1: 8.8.8.8 dns.google

Name:      hosted.mender.io
Address 1: 3.217.79.33 ec2-3-217-79-33.compute-1.amazonaws.com
Address 2: 54.162.248.127 ec2-54-162-248-127.compute-1.amazonaws.com

Any idea how we can get out of this?

bender · December 27, 2021, 2:24pm

Something possibly timed-out and did send correct inventory to server so we retried another manual install with that same old artifact and it did reboot ok and committed and updated the server fine but once we started another cloud based deployment we got an instant failure and journal reported this:

Dec 27 14:17:21 hostname mender[284]: time="2021-12-27T14:17:21Z" level=info msg="Forced wake-up from sleep"
Dec 27 14:17:21 hostname mender[284]: time="2021-12-27T14:17:21Z" level=info msg="Forcing state machine to: update-check"
Dec 27 14:17:21 hostname mender[284]: time="2021-12-27T14:17:21Z" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Dec 27 14:17:22 hostname mender[284]: time="2021-12-27T14:17:22Z" level=info msg="Correct request for getting image from: https://s3.amazonaws.com/hosted-mender-artifacts/5f4cabcfxxx200f34/ad9051f8-1ce1-4b9xxxafb052b?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAQWI2xxxLMYE2%2F20xxx227%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20211227T141722Z&X-Amz-Expires=86400&X-Amz-SignedHeaders=host&response-content-type=application%2Fvnd.mender-artifact&X-Amz-Signature=ee2a1984dxxx98f7e8e60e385a7c8bd0c467c3a2e2774e [name: base-1.0.0; devices: [ds-pi]]"
Dec 27 14:17:22 hostname mender[284]: time="2021-12-27T14:17:22Z" level=info msg="State transition: update-check [Sync] -> update-fetch [Download_Enter]"
Dec 27 14:17:22 hostname mender[284]: time="2021-12-27T14:17:22Z" level=info msg="State transition: update-fetch [Download_Enter] -> update-status-report [none]"
Dec 27 14:17:29 hostname mender[284]: time="2021-12-27T14:17:29Z" level=error msg="Got unexpected HTTP status when uploading log: 400"
Dec 27 14:17:29 hostname mender[284]: time="2021-12-27T14:17:29Z" level=error msg="error uploading logs: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 14:17:29 hostname mender[284]: time="2021-12-27T14:17:29Z" level=error msg="Failed to report deployment logs: transient error: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 14:17:29 hostname mender[284]: time="2021-12-27T14:17:29Z" level=error msg="Failed to send deployment logs to server: transient error: failed to send deployment logs: transient error: (request_id: ): uploading logs failed, bad status 400 server error message: no messages: invalid deployment log"
Dec 27 14:17:29 hostname mender[284]: time="2021-12-27T14:17:29Z" level=info msg="State transition: update-status-report [none] -> update-retry-report [none]"

So we are still stuck… Please help

oleorhagen · December 28, 2021, 8:03am

Hi @bender

Just to start out, can you have a look at the deployment log files on the device?

These should be stored in /var/lib/mender/ and look like deployment.<time>.log.

bender · December 28, 2021, 9:02am

Nothing found from the recent attempts. Actually only one log which seems to be when the problem started (but gone unnoticed until now) a few months ago:

# cat deployments.0002.47333005-770d-4522-bcde-3f562418a2ea.log 
{"level":"info","message":"Running Mender client version: 2.3.0-dirty","timestamp":"2021-07-12T11:26:38Z"}
{"level":"info","message":"State transition: update-fetch [Download_Enter] -\u003e update-store [Download_Enter]","timestamp":"2021-07-12T11:26:43Z"}
{"level":"info","message":"Installer: authenticated digital signature of artifact","timestamp":"2021-07-12T11:26:44Z"}
{"level":"error","message":"Cannot check update or update inventory while in update-after-store state","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-store [Download_Enter] -\u003e update-after-store [Download_Leave]","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-after-store [Download_Leave] -\u003e update-install [ArtifactInstall]","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-install [ArtifactInstall] -\u003e reboot [ArtifactReboot_Enter]","timestamp":"2021-07-12T11:48:14Z"}
{"level":"info","message":"Rebooting device(s)","timestamp":"2021-07-12T11:48:15Z"}
{"level":"info","message":"Running Mender client version: 2.3.0-dirty","timestamp":"2021-07-12T11:49:16Z"}
{"level":"info","message":"State transition: init [none] -\u003e after-reboot [ArtifactReboot_Leave]","timestamp":"2021-07-12T11:49:16Z"}
{"level":"info","message":"State transition: after-reboot [ArtifactReboot_Leave] -\u003e after-reboot [ArtifactReboot_Leave]","timestamp":"2021-07-12T11:49:17Z"}
{"level":"info","message":"State transition: after-reboot [ArtifactReboot_Leave] -\u003e update-commit [ArtifactCommit_Enter]","timestamp":"2021-07-12T11:49:17Z"}
{"level":"info","message":"State transition: update-commit [ArtifactCommit_Enter] -\u003e update-after-first-commit [none]","timestamp":"2021-07-12T11:51:34Z"}
{"level":"info","message":"State transition: update-after-first-commit [none] -\u003e update-after-commit [ArtifactCommit_Leave]","timestamp":"2021-07-12T11:51:35Z"}
{"level":"info","message":"State transition: update-after-commit [ArtifactCommit_Leave] -\u003e cleanup [none]","timestamp":"2021-07-12T11:51:35Z"}
{"level":"info","message":"State transition: cleanup [none] -\u003e update-status-report [none]","timestamp":"2021-07-12T11:51:35Z"}

I have just completed downloading manually the mender artifact and will proceed to manually install it…

oleorhagen · December 28, 2021, 9:57am

Alright, interesting indeed.

How much space is left on your data partition?

bender · December 28, 2021, 10:20am

There were about 200MB free.
Manual installation seemed to “fix” the problem, unfortunately without understanding the root cause.
Any extra troubleshooting you may need, I’ll be happy to help for the rest of the day as my holidays start tomorrow

oleorhagen · December 28, 2021, 11:11am

I don’t see anything in the logs, which tells me anything other than that it did not have any deployment logs to upload, which is odd.

If you can get me a full log from an old deployment, the log from the passing one, and all the log files present in your data partition that would be a nice start

bender · December 28, 2021, 1:35pm

That puzzled me too… there aren’t any other logs:

root@hostname:~ # date
Tue Dec 28 13:23:41 UTC 2021
root@hostname:~ # ls -l /var/lib/mender/*.log
-rw------- 1 root root  107 Dec 28 06:24 /var/lib/mender/deployments.0001.7a3a5a3d-a94b-4a46-ae9a-8d8d83488dbb.log
-rw------- 1 root root 2244 Jul 12 11:51 /var/lib/mender/deployments.0002.47333005-770d-4522-bcde-3f562418a2ea.log
root@hostname:~ # cat /var/lib/mender/deployments.0001.7a3a5a3d-a94b-4a46-ae9a-8d8d83488dbb.log
{"level":"info","message":"Running Mender client version: 2.3.0-dirty","timestamp":"2021-12-28T06:24:42Z"}
root@hostname:~ # cat /var/lib/mender/deployments.0002.47333005-770d-4522-bcde-3f562418a2ea.log
{"level":"info","message":"Running Mender client version: 2.3.0-dirty","timestamp":"2021-07-12T11:26:38Z"}
{"level":"info","message":"State transition: update-fetch [Download_Enter] -\u003e update-store [Download_Enter]","timestamp":"2021-07-12T11:26:43Z"}
{"level":"info","message":"Installer: authenticated digital signature of artifact","timestamp":"2021-07-12T11:26:44Z"}
{"level":"error","message":"Cannot check update or update inventory while in update-after-store state","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-store [Download_Enter] -\u003e update-after-store [Download_Leave]","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-after-store [Download_Leave] -\u003e update-install [ArtifactInstall]","timestamp":"2021-07-12T11:48:13Z"}
{"level":"info","message":"State transition: update-install [ArtifactInstall] -\u003e reboot [ArtifactReboot_Enter]","timestamp":"2021-07-12T11:48:14Z"}
{"level":"info","message":"Rebooting device(s)","timestamp":"2021-07-12T11:48:15Z"}
{"level":"info","message":"Running Mender client version: 2.3.0-dirty","timestamp":"2021-07-12T11:49:16Z"}
{"level":"info","message":"State transition: init [none] -\u003e after-reboot [ArtifactReboot_Leave]","timestamp":"2021-07-12T11:49:16Z"}
{"level":"info","message":"State transition: after-reboot [ArtifactReboot_Leave] -\u003e after-reboot [ArtifactReboot_Leave]","timestamp":"2021-07-12T11:49:17Z"}
{"level":"info","message":"State transition: after-reboot [ArtifactReboot_Leave] -\u003e update-commit [ArtifactCommit_Enter]","timestamp":"2021-07-12T11:49:17Z"}
{"level":"info","message":"State transition: update-commit [ArtifactCommit_Enter] -\u003e update-after-first-commit [none]","timestamp":"2021-07-12T11:51:34Z"}
{"level":"info","message":"State transition: update-after-first-commit [none] -\u003e update-after-commit [ArtifactCommit_Leave]","timestamp":"2021-07-12T11:51:35Z"}
{"level":"info","message":"State transition: update-after-commit [ArtifactCommit_Leave] -\u003e cleanup [none]","timestamp":"2021-07-12T11:51:35Z"}
{"level":"info","message":"State transition: cleanup [none] -\u003e update-status-report [none]","timestamp":"2021-07-12T11:51:35Z"}
root@hostname:~ #

Additionally there was no option for the log on the deployment page (also something I haven’t seen before):

oleorhagen · December 28, 2021, 3:04pm

The reason there is no log in the UI is because the client does not upload any logs to the UI, and the deployments service returns the error No Messages.

But this is odd. And I’m not sure what to make of it right now, I will take a closer look at the client in the meantime.

Topic		Replies	Views
Failed to report status: EOF General Discussions	14	862	September 30, 2021
Client can not update inventory General Discussions	10	337	September 3, 2021
Deployment doesn't deploy General Discussions	9	719	March 7, 2024
Deployment fails because of 500 Internal Server Error from hosted.mender.io General Discussions	2	357	November 22, 2022
Issue: mender-deployments SerializationError General Discussions issue , mender-server , deployment , production , integration	29	2144	July 23, 2021

Cannot send inventory

Related Topics