Hosted Mender Connect Remote Terminal Forbidden

I am trying to stand up some test machines running Debian 11 and installing the mender-client and mender-connect deb packages using the docs form the APT repo.

I have successful installed the mender-client, mender-connect, and mender-configure deb packages and I am able to register my test machines in the mender ui using a basic demo config.

I have also paid for the configure and troubleshooting add-ons for my account.

When attempting to Remote terminal from the Mender Hosted UI I get a forbidden.

Watching the debug logs on the mender client show no errors, however watching a trace output from the mender-connect logs show the following

I did find some references in previous posts to running a dbus-send command to check if the JWT was being provided by the localhost endpoint. I can confirm that is it and the server in the logs of the mender-connect matches the server returned by the dbus-send command.

Otherwise I can find no other errors in either the mender-connect or mender-client logs and am wondering what is going on.

Hello @vhbgraham,

Is the mender-connect service running?

$ systemctl status mender-connect

The mender client is run by systemd, meaning, it uses root permissions, while if you run the mender-connect as a regular user probably that is the reason it is not working as it is not able to get access to the credentials the mender-client has. If you don’t want to use it as a regular systemd service, at least you need to run it with sudo or the root user.

Best regards,
Luis

Both are run as systemd services as that is how the .deb sets them up

mender-client.service

root@ip-172-31-1-10:/var/lib/systemd# cat /lib/systemd/system/mender-client.service
[Unit]
Description=Mender OTA update service
Wants=network-online.target
After=systemd-resolved.service network-online.target mender.service mender-client-data-dir.service data.mount
Conflicts=mender.service

[Service]
Type=idle
User=root
Group=root
ExecStart=/usr/bin/mender daemon
Restart=on-abort

[Install]
WantedBy=multi-user.target

mender-connect.service

root@ip-172-31-1-10:/var/lib/systemd# cat /lib/systemd/system/mender-connect.service
[Unit]
Description=Mender Connect service
Wants=network-online.target
After=systemd-resolved.service network-online.target mender-client.service
Requires=mender-client.service

[Service]
Type=idle
User=root
Group=root
ExecStart=/usr/bin/mender-connect daemon
Restart=on-abort

[Install]
WantedBy=multi-user.target
root@ip-172-31-1-10:/var/lib/systemd# systemctl status mender-client
● mender-client.service - Mender OTA update service
     Loaded: loaded (/lib/systemd/system/mender-client.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-07-15 01:47:50 UTC; 9min ago
   Main PID: 575 (mender)
      Tasks: 11 (limit: 1112)
     Memory: 40.7M
        CPU: 2.031s
     CGroup: /system.slice/mender-client.service
             └─575 /usr/bin/mender daemon
root@ip-172-31-1-10:/var/lib/systemd# systemctl status mender-connect
● mender-connect.service - Mender Connect service
     Loaded: loaded (/lib/systemd/system/mender-connect.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-07-15 01:47:50 UTC; 10min ago
   Main PID: 576 (mender-connect)
      Tasks: 10 (limit: 1112)
     Memory: 21.1M
        CPU: 128ms
     CGroup: /system.slice/mender-connect.service
             └─576 /usr/bin/mender-connect daemon

Here is a fresh restart of mender-connect with --trace turned on

● mender-connect.service - Mender Connect service
     Loaded: loaded (/lib/systemd/system/mender-connect.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2022-07-15 02:00:36 UTC; 15s ago
   Main PID: 1456 (mender-connect)
      Tasks: 11 (limit: 1112)
     Memory: 5.4M
        CPU: 22ms
     CGroup: /system.slice/mender-connect.service
             └─1456 /usr/bin/mender-connect --trace daemon

Jul 15 02:00:36 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:36Z" level=trace msg="messageLoop: starting"
Jul 15 02:00:36 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:36Z" level=trace msg="messageLoop: posting event: reconnect-req; waiting for response"
Jul 15 02:00:36 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:36Z" level=trace msg="needsReconnect: got event: reconnect-req"
Jul 15 02:00:36 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:36Z" level=trace msg="dbusEventLoop: daemon needs to reconnect"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateCha>
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="(dbusEventLoop) posting Event: reconnect"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="eventLoop: got event: reconnect"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=info msg="eventLoop: Connection established with http://localhost:46299"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="messageLoop: got response: {event:connected data: id:}"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="messageLoop: calling readMessage"
Jul 15 02:00:57 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:57Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:00:46 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:46Z" level=trace msg="messageLoop: calling readMessage"
Jul 15 02:00:57 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:00:57Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:01:08 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:08Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:01:19 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:19Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:01:30 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:30Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:01:40 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:40Z" level=debug msg="ping message"
Jul 15 02:01:40 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:40Z" level=debug msg="PongHandler called"
Jul 15 02:01:41 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:41Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:01:52 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:01:52Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:02:03 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:02:03Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:02:14 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:02:14Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:02:25 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:02:25Z" level=trace msg="dbusEventLoop: WaitForJwtTokenStateChange [], err timeout waiting for signal JwtTokenStateChange"
Jul 15 02:02:34 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:02:34Z" level=debug msg="ping message"
Jul 15 02:02:34 ip-172-31-1-10 mender-connect[1456]: time="2022-07-15T02:02:34Z" level=debug msg="PongHandler called"

What is interesting and that file uploads and download work fine and that uses the mender-connect daemon I believe

Log after a successful upload

Jul 15 02:25:22 ip-172-31-1-10 mender-connect[1550]: time="2022-07-15T02:25:22Z" level=info msg="session: accepting new session with ID: 8a60b59c-c29c-4980-a4db-7526723fa817"
Jul 15 02:25:22 ip-172-31-1-10 mender-connect[1550]: time="2022-07-15T02:25:22Z" level=info msg="session: closed 8a60b59c-c29c-4980-a4db-7526723fa817"

Log after successful download

Jul 15 02:28:13 ip-172-31-1-10 mender-connect[1550]: time="2022-07-15T02:28:13Z" level=info msg="session: accepting new session with ID: 624524e6-8a63-423f-b859-1132d3e26310"
Jul 15 02:28:13 ip-172-31-1-10 mender-connect[1550]: time="2022-07-15T02:28:13Z" level=info msg="session: closed 624524e6-8a63-423f-b859-1132d3e26310"

Let me also note the the installation enviroment is as follows

  1. QEMU Virtual machine, X86-64 running Debian 11 (bullseye) net-install/minimal installation with not extra packages selected, and mender is deployed following

https://docs.mender.io/client-installation/install-with-debian-package – using the script to install the client, and then apt-get install mender-connect mender-configure.

mender setup is using hosted and mender-connect.conf is a follows

{
  "ShellCommand": "/bin/bash",
  "User": "root"
}

Update from my end. I tried using mender-cli which did work. I am able to upload, download, port-forward, and terminal into my device for the CLI running on a local machine to me.

So this seems to be an issues with the hosted.mender.io web interface – Still an issue as that is part of the troubleshoot offering, but at least some progress.

Hello @vhbgraham

Thank you for using Mender. Could we try two things?

  1. reload without cache (command/control+r in some browsers), and/or use incognito/private window/tab?

  2. could you open developer tools and show me both the console and the network tabs when you try to open the terminal?

best regards,
peter

Load the page with both Cache Disabled in Dev tools, and in Incognito Modes results in the same error – below is a screen shot of the dev tools network during the Incognito Run – tried connecting 3 times

Here is output from a “normal” browser session (its the same result as the above attempt)

Here is the output from one of the connect in the network log (I am excluding cookies since there is a secret in there)

Here are the cookies that aren’t the JWT
grav-site-8c069df=6e4d692979579274335dbd080f3a1a9c; _ga=GA1.2.857832636.1658154050; _gid=GA1.2.1618402795.1658154050; _gat=1

Seems I am getting a 400 due to an error in the websocket handshake

Bumping this as I am still having this issue on the webui side