Remote terminal connection failed

Piocky · February 18, 2021, 10:29am

Hi,

I updated my Mender Open-Source server to 2.6 as we wanted to test the new remote terminal feature, but it doesn’t work so far.

We use Raspberry Pi 3 model A+ in our project, with Yocto image and Mender system update (everything work fine apart from this new feature), I added mender-connect to the image following those guidelines, I do see the remote terminal connection button for the device updated with the new image, but when I click on it, I see the terminal open and close very fast, with a “Connection died with the device” message at the bottom.

This is the result of systemctl status mender-connect command on my device:

[[0;1;32m●[[0m mender-connect.service - Mender Connect service
Loaded: loaded (/lib/systemd/system/mender-connect.service; enabled; vendor preset: enabled)
Active: [[0;1;32mactive (running)[[0m since Thu 2021-02-18 11:01:17 CET; 19min ago
Main PID: 283 (mender-connect)
Tasks: 12 (limit: 413)
CGroup: /system.slice/mender-connect.service
└─283 /usr/bin/mender-connect daemon

Feb 18 11:01:17 Alto systemd[1]: Started Mender Connect service.
Feb 18 11:01:17 Alto mender-connect[283]: time=“2021-02-18T11:01:17+01:00” level=info msg=“Loaded configuration file: /etc/mender/mender-connect.conf”
Feb 18 11:01:18 Alto mender-connect[283]: time=“2021-02-18T11:01:18+01:00” level=warning msg=“call to GetJWTToken on the Mender D-Bus API failed: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name io.mender.AuthenticationManager was not provided by any .serv
ice files”
Feb 18 11:01:18 Alto mender-connect[283]: time=“2021-02-18T11:01:18+01:00” level=info msg=“waiting for JWT token (waitForJWTToken)”
Feb 18 11:01:19 Alto mender-connect[283]: time=“2021-02-18T11:01:19+01:00” level=info msg=“loadServerTrust loading certificate from /etc/mender/server.crt”
Feb 18 11:01:19 Alto mender-connect[283]: time=“2021-02-18T11:01:19+01:00” level=info msg=“API Gateway certificate (in PEM format): […]”
Feb 18 11:01:19 Alto mender-connect[283]: time=“2021-02-18T11:01:19+01:00” level=info msg=“Issuer: [], Valid from: 2020-10-27 12:06:34 +0000 UTC, Valid to: 2030-10-25 12:06:34 +0000 UTC”

I guess this is related to the JWT warning message, but I don’t know how to fix this.
This is the content of the mender-connect.conf:

{
“ClientProtocol”: “https”,
“ServerCertificate”: “/etc/mender/server.crt”,
“ServerURL”: “***”,
“User”: “root”,
“ShellCommand”: “/bin/sh”,
“Terminal”: {
“Height”: 24,
“Width”: 128
},
“Sessions”: {
“StopExpired”: false,
“ExpireAfter”: 255,
“ExpireAfterIdle”: 16,
“MaxPerUser”: 4
}
}

Any help would be very appreciated.

Yoann

tranchitella · February 18, 2021, 10:31am

Hello @Piocky, which version of the Mender client you are running? You need the latest stable version, which provides the D-Bus API that mender-connect consumes.

Piocky · February 18, 2021, 10:44am

Hi @tranchitella,

I’m using the last commit on Dunfell branch, but i’m not sure to use the last stable version of mender-client. Where should I specify which version to use?
It seems to be the 2.5.0 version of mender-client, I don’t have the PREFERRED_VERSION_pn-mender-client variable set in my local.conf file, so the build should use the latest stable version right?

kacf · February 18, 2021, 11:02am

@Piocky: It is not necessary to set PREFERRED_VERSION, it should select the latest version automatically. What does your client log say?

journalctl -u mender-client

Piocky · February 18, 2021, 11:04am

[[0;1;32m●[[0m mender-client.service - Mender OTA update service
-- Logs begin at Wed 2021-02-17 18:43:30 CET, end at Thu 2021-02-18 11:28:23 CET. --
-- Logs begin at Wed 2021-02-17 18:43:30 CET, end at Thu 2021-02-18 11:28:23 CET. --
-- Logs begin at Wed 2021-02-17 18:43:30 CET, end at Thu 2021-02-18 11:28:23 CET. --
-- Logs begin at Wed 2021-02-17 18:43:30 CET, end at Thu 2021-02-18 11:28:23 CET. --
Feb 17 19:37:37 Alto systemd[1]: Started Mender OTA update service.
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="Loaded configuration file: /var/lib/mender/mender.conf"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="Loaded configuration file: /etc/mender/mender.conf"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="Mender running on partition: /dev/mmcblk0p2"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="State transition: init [none] -> init [none]"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="State transition: init [none] -> idle [Idle]"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Feb 18 11:01:18 Alto mender[282]: time="2021-02-18T11:01:18+01:00" level=warning msg="Inventory tool /usr/share/mender/inventory/mender-inventory-geo wait failed: exit status 3"
Feb 18 11:01:19 Alto mender[282]: time="2021-02-18T11:01:19+01:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Feb 18 11:01:19 Alto mender[282]: time="2021-02-18T11:01:19+01:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Feb 18 11:01:19 Alto mender[282]: time="2021-02-18T11:01:19+01:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"

kacf · February 19, 2021, 8:13am

I can’t see anything wrong in there. What is the output of:

cat /usr/share/dbus-1/system.d/io.mender.AuthenticationManager.conf

Piocky · February 19, 2021, 3:12pm

It works now! I can’t tell you what it was exactly, but the freelance who deployed the server tell me that he made some manual changes in production/config/prod.yml at the time there were problems with group and deploy. He changed back to normal and we restart the dockers, now the Rmote Terminal works well.
Thanks a lot for your help and reactivity!

zainmehdi · June 11, 2021, 6:54am

Hi, I have been trying to run sudo command in the remote terminal using hosted mender server. It keeps asking me for password and when I enter my device’s password its not accepting it. Is there any default password I can use ?

Thanks alot

tranchitella · June 11, 2021, 7:08am

Hello @zainmehdi , the remote terminal feature in Mender does not configure authentication in any custom way. If you run sudo, it works as it would work when connecting over ssh or serial console. I suggest checking the configuration of your device (/etc/sudoers).

zainmehdi · June 11, 2021, 7:45am

@tranchitella thanks alot for the reply. But I checked my sudoers file and everything looked normal

nobody@NanoPi-NEO4:/home/pi$ sudo rm -rf frame.raw 
[sudo] password for nobody: 
Sorry, try again.
[sudo] password for nobody:

Its showing nobody as username which is quite strange

tranchitella · June 11, 2021, 7:48am

@zainmehdi you are connected as “nobody”, which is probably not part of the sudoers.
Please check your configuration in /etc/mender/mender-connect.conf and, eventually, change the User setting to “pi” if you are running on a RaspberryPI.

zainmehdi · June 11, 2021, 7:59am

@tranchitella thanks alot. That solves the issue

joseph · June 17, 2021, 5:35pm

Hey guys,

Got a question for you all. So been using the remote terminal and there have been a few instances that have been occurring, more and more often, where the remote terminal is unavailable and this message is visible on the GUI:
“The Remote terminal add-on does not seem to be enabled on this device.
Please see the documentation for a description on how it works and how to enable it.”

When using ‘journalctl -f -u mender-client’ I get this output:

time="2021-06-17T13:15:07-04:00" level=error msg="Authorize failed: transient error: authorization request failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: dev auth: unauthorized"

To confirm, the device is authroized and I would be able to create a deployment for that device no problem. The only thing effected here is the Remote Terminal.

I’ve also seen the below error that originally started this post:

“waiting for JWT token (waitForJWTToken)”

Please let me know your thoughts as this is starting to turn into a big blocker since there is randomly no connection to the device.

Looking forward to your replies, thanks!

drewmoseley · June 21, 2021, 2:31pm

@tranchitella @lluiscampos any thoughts here?

tranchitella · June 21, 2021, 4:17pm

Hello @joseph,

From the message you posted, it looks like the device is not authorized (Authorize: failed), and in this case the remote terminal cannot work. Can you please provide the full logs from the Mender Client? Are you sure your device identity data is stable and not changing? Do you see additional pending devices?

joseph · June 24, 2021, 1:19pm

Hey guys,

Thanks for getting back to me. At the moment it is difficult to provide additional logs because the issue is not a constant issue. There are times when a unit will have full access and remote terminal is completely working, but there are some rare occasions that I’ve noted where the remote terminal is unavailable and the only way to get a connection back is to reboot the unit. Mind you everything else mender works, so i can still create a deployment and I can see that the unit is online and communicating with Mender. A few days ago as an example, I was working through the remote terminal on a remote unit, and the shell disconnected and I was unable to bring up a new one (i could click remote terminal but the shell never properly came up, it was a black screen), so informed the unit owner to reboot the unit. At that time though after reboot, the logs were cleared and I was unavailable to grab anything useful, once back in the unit.

I can confirm that the unit is authorized, the device identity is working with the defaulted device ID that mender uses, and there are no additional pending devices with the same MAC address/device ID.

I will monitor the devices and try to grab logs from a device that is experiencing this issue. As it is not constant on all units all the time though, does anyone have any additional thoughts as to why this may be occurring?

joseph · June 28, 2021, 9:13pm

Hey all,

Had another remote terminal failure. Please find the logs below.

mender client:

Jun 25 15:54:34 VirtualBox systemd[1]: Started Mender OTA update service.
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="Loaded configuration file: /var/lib/mender/mender.conf"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="Loaded configuration file: /etc/mender/mender.conf"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="Mender running on partition: ******"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="State transition: init [none] -> init [none]"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="State transition: init [none] -> idle [Idle]"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Jun 25 15:54:34 VirtualBox mender[1151]: time="2021-06-25T15:54:34-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 25 15:54:35 VirtualBox mender[1151]: time="2021-06-25T15:54:35-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 25 15:54:35 VirtualBox mender[1151]: time="2021-06-25T15:54:35-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 25 15:54:35 VirtualBox mender[1151]: time="2021-06-25T15:54:35-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 25 15:54:39 VirtualBox mender[1151]: time="2021-06-25T15:54:39-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 25 15:54:40 VirtualBox mender[1151]: time="2021-06-25T15:54:40-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 25 15:54:40 VirtualBox mender[1151]: time="2021-06-25T15:54:40-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 25 15:54:40 VirtualBox mender[1151]: time="2021-06-25T15:54:40-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 25 15:54:44 VirtualBox mender[1151]: time="2021-06-25T15:54:44-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 25 15:54:45 VirtualBox mender[1151]: time="2021-06-25T15:54:45-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 25 15:54:45 VirtualBox mender[1151]: time="2021-06-25T15:54:45-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 25 15:54:45 VirtualBox mender[1151]: time="2021-06-25T15:54:45-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 25 15:54:49 VirtualBox mender[1151]: time="2021-06-25T15:54:49-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 25 15:54:50 VirtualBox mender[1151]: time="2021-06-25T15:54:50-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 25 15:54:50 VirtualBox mender[1151]: time="2021-06-25T15:54:50-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 25 15:54:50 VirtualBox mender[1151]: time="2021-06-25T15:54:50-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"

Please find below the logs of mender connect:

Jun 25 15:54:34 VirtualBox systemd[1]: Started Mender Connect service.
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=info msg="Loaded configuration file: /etc/mender/mender-connect.conf"
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=warning msg="call to GetJWTToken on the Mender D-Bus API failed: GDBus.Error:org.freedesktop.DBus.Error.Service
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=info msg="waiting for JWT token (waitForJWTToken)"
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=info msg="loadServerTrust loading certificate from /etc/mender/server.crt"
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=info msg="API Gateway certificate (in PEM format): **********************
Jun 25 15:54:34 VirtualBox mender-connect[1152]: time="2021-06-25T15:54:34-04:00" level=info msg="Issuer: [], Valid from: 2020-12-11 10:18:31 +0000 UTC, Valid to: 2030-12-09 10:18:31 +0000 UTC"
Jun 25 15:54:44 VirtualBox systemd[1]: Stopping Mender Connect service...
Jun 25 15:54:45 VirtualBox systemd[1]: Stopped Mender Connect service.

At this point the only solution I have found is either getting the user to manually reboot the device or restart the service.

Please let me know your thoughts, thanks!

joseph · June 29, 2021, 3:03pm

More logs from yesterday:

I can confirm that Mender sees the unit and I can do a deployment onto the unit.
One fix that i thought of was calling to restart the mender-connect.service and that fixed the problem, thought not a viable solution on a remote device. For this one device, the Remote Terminal has been unavailable for the last few days and the fix i mentioned above solved the issue. I would also like to point out that in the mender-client log it says that there is no host at the specified address, when there is, and the device received an OTA from that server, and it is currently checked-in.

Please find below logs from mender-connect and mender-client for the same time period.

Mender-connect:

Jun 28 12:10:10 VirtualBox mender-connect[3513]: time="2021-06-28T12:10:10-04:00" level=info msg="Issuer: [], Valid from: 2020-12-11 10:18:31 +0000 UTC, Valid to: 2030-12-09 10:18:31 +0000 UTC"
Jun 28 19:31:41 VirtualBox systemd[1]: Started Mender Connect service.
Jun 28 19:31:41 VirtualBox mender-connect[1226]: time="2021-06-28T19:31:41-04:00" level=info msg="Loaded configuration file: /etc/mender/mender-connect.conf"
Jun 28 19:31:41 VirtualBox mender-connect[1226]: time="2021-06-28T19:31:41-04:00" level=warning msg="call to GetJWTToken on the Mender D-Bus API failed: GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown: The name io.mender.AuthenticationManager was not provided by any .service files"
Jun 28 19:31:41 VirtualBox mender-connect[1226]: time="2021-06-28T19:31:41-04:00" level=info msg="waiting for JWT token (waitForJWTToken)"
Jun 28 19:31:41 VirtualBox mender-connect[1226]: time="2021-06-28T19:31:41-04:00" level=info msg="loadServerTrust loading certificate from /etc/mender/server.crt"
Jun 28 19:31:41 VirtualBox mender-connect[1226]: time="2021-06-28T19:31:41-04:00" level=info msg="API Gateway certificate (in PEM format): \n-----BEGIN CERTIFICATE-----\n****************\n-----END CERTIFICATE-----\n-----BEGIN CERTIFICATE-----\n****************\n-----END CERTIFICATE-----\n"

Mender-client:

Jun 28 12:09:54 VirtualBox systemd[1]: Started Mender OTA update service.
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="Loaded configuration file: /var/lib/mender/mender.conf"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="Loaded configuration file: /etc/mender/mender.conf"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="Mender running on partition: *******"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: init [none] -> init [none]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: init [none] -> idle [Idle]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Failed to submit inventory data: Put \"**********/api/devices/v1/inventory/device/attributes\": dial tcp: lookup **********************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Failed to submit inventory data: Put \"**************/api/devices/v1/inventory/device/attributes\": dial tcp: lookup **********************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="inventory submit failed: Put \"**************************/api/devices/v1/inventory/device/attributes\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=warning msg="Failed to refresh inventory: failed to submit inventory data: inventory submit failed: Put \"******************************/api/devices/v1/inventory/device/attributes\": dial tcp: lookup ***************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="inventory submit failed: Put \"******************************/api/devices/v1/inventory/device/attributes\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=warning msg="Failed to refresh inventory: failed to submit inventory data: inventory submit failed: Put \"******************************/api/devices/v1/inventory/device/attributes\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Error receiving scheduled update data: POST update check request failed: Post \"******************************/api/devices/v1/deployments/device/deployments/next\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Update check failed: transient error: POST update check request failed: Post \"******************************/api/devices/v1/deployments/device/deployments/next\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Error receiving scheduled update data: POST update check request failed: Post \"******************************/api/devices/v1/deployments/device/deployments/next\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=error msg="Update check failed: transient error: POST update check request failed: Post \"******************************/api/devices/v1/deployments/device/deployments/next\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: update-check [Sync] -> error [Error]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="Handling error state, current error: transient error: POST update check request failed: Post \"******************************/api/devices/v1/deployments/device/deployments/next\": dial tcp: lookup ******************************: no such host"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: error [Error] -> idle [Idle]"
Jun 28 12:09:54 VirtualBox mender[1195]: time="2021-06-28T12:09:54-04:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Jun 28 12:09:59 VirtualBox mender[1195]: time="2021-06-28T12:09:59-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:09:59 VirtualBox mender[1195]: time="2021-06-28T12:09:59-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:09:59 VirtualBox mender[1195]: time="2021-06-28T12:09:59-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:09:59 VirtualBox mender[1195]: time="2021-06-28T12:09:59-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:04 VirtualBox mender[1195]: time="2021-06-28T12:10:04-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:09 VirtualBox mender[1195]: time="2021-06-28T12:10:09-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:09 VirtualBox mender[1195]: time="2021-06-28T12:10:09-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:14 VirtualBox mender[1195]: time="2021-06-28T12:10:14-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:14 VirtualBox mender[1195]: time="2021-06-28T12:10:14-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:14 VirtualBox mender[1195]: time="2021-06-28T12:10:14-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:14 VirtualBox mender[1195]: time="2021-06-28T12:10:14-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:15 VirtualBox mender[1195]: time="2021-06-28T12:10:15-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:19 VirtualBox mender[1195]: time="2021-06-28T12:10:19-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:19 VirtualBox mender[1195]: time="2021-06-28T12:10:19-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:19 VirtualBox mender[1195]: time="2021-06-28T12:10:19-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:20 VirtualBox mender[1195]: time="2021-06-28T12:10:20-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:24 VirtualBox mender[1195]: time="2021-06-28T12:10:24-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:24 VirtualBox mender[1195]: time="2021-06-28T12:10:24-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:24 VirtualBox mender[1195]: time="2021-06-28T12:10:24-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:25 VirtualBox mender[1195]: time="2021-06-28T12:10:25-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:29 VirtualBox mender[1195]: time="2021-06-28T12:10:29-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:29 VirtualBox mender[1195]: time="2021-06-28T12:10:29-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:29 VirtualBox mender[1195]: time="2021-06-28T12:10:29-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:30 VirtualBox mender[1195]: time="2021-06-28T12:10:30-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:34 VirtualBox mender[1195]: time="2021-06-28T12:10:34-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:34 VirtualBox mender[1195]: time="2021-06-28T12:10:34-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 12:10:34 VirtualBox mender[1195]: time="2021-06-28T12:10:34-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 12:10:35 VirtualBox mender[1195]: time="2021-06-28T12:10:35-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 12:10:39 VirtualBox mender[1195]: time="2021-06-28T12:10:39-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 12:10:39 VirtualBox mender[1195]: time="2021-06-28T12:10:39-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"

Jun 28 19:31:41 VirtualBox systemd[1]: Started Mender OTA update service.
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="Loaded configuration file: /var/lib/mender/mender.conf"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="Loaded configuration file: /etc/mender/mender.conf"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="Mender running on partition: ********"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: init [none] -> init [none]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: init [none] -> idle [Idle]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 19:31:41 VirtualBox mender[1220]: time="2021-06-28T19:31:41-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 19:31:46 VirtualBox mender[1220]: time="2021-06-28T19:31:46-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 19:31:46 VirtualBox mender[1220]: time="2021-06-28T19:31:46-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 19:31:46 VirtualBox mender[1220]: time="2021-06-28T19:31:46-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 19:31:46 VirtualBox mender[1220]: time="2021-06-28T19:31:46-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 19:31:51 VirtualBox mender[1220]: time="2021-06-28T19:31:51-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 19:31:56 VirtualBox mender[1220]: time="2021-06-28T19:31:56-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"
Jun 28 19:31:56 VirtualBox mender[1220]: time="2021-06-28T19:31:56-04:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jun 28 19:31:56 VirtualBox mender[1220]: time="2021-06-28T19:31:56-04:00" level=info msg="State transition: update-check [Sync] -> check-wait [Idle]"
Jun 28 19:31:56 VirtualBox mender[1220]: time="2021-06-28T19:31:56-04:00" level=info msg="State transition: check-wait [Idle] -> inventory-update [Sync]"
Jun 28 19:31:57 VirtualBox mender[1220]: time="2021-06-28T19:31:57-04:00" level=info msg="State transition: inventory-update [Sync] -> check-wait [Idle]"

Let me know your thoughts, thanks guys!

joseph · June 30, 2021, 7:52pm

Hey guys,

While digging through the community, I found this issue that someone else was having a couple months ago. It seems to be similar if not the exact same issue.

Has this been resolved or is still persistent in 2.7?