Mender convert image does not connect to hosted.mender.io

General Discussions
, ,
1

Hi,

I’m testing out mender on a Pi Zero W. I have a mender convert image that I created from a golden image and it boots BUT the mender client does not connect to hosted.mender.io. I am using Wifi (and NetworkManager) to connect. I followed @drewmoseley suggestions in another ticket and moved my wifi connection to /data with a symbolic link. The Wifi connects fine but the mender client does not connect.

Here are my steps for image creation:

make image command taken from https://docs.mender.io/system-updates-debian-family/convert-a-mender-debian-image

sudo dd if=/dev/sdb of=golden-Nov-03-2020.img bs=1M conf=fdatasync

Mender Convert command
sudo MENDER_ARTIFACT_NAME=release-1 ./docker-mender-convert --disk-image ./golden-Nov-03-2020.img --config configs/raspberrypi0w_config --overlay ./rootfs_overlay_demo/

Write mender-convert image back to new SD card
zcat deploy/golden-Nov-03-2020-raspberrypi0w-mender.img.gz | sudo dd of=/dev/sdb bs=4M && sudo sync

System booted without issue and connected to Wifi (I can ssh into device). When mender-client makes an authorization request it gets a 401 unauthorized response. I have confirmed in the log file that my token matches what i got from my hosted.mender.io account

Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="handle authorize state" module=state
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:14:09 raspberrypi mender[309]: time="2020-11-23T19:14:09Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="got response: &{401 Unauthorized 401 HTTP/1.1 1 1 map[Vary:[Accept-Encoding] X-Authentication-Version:[unknown] X-Frame-Options:[SAMEORIGIN] Strict-Transport-Security:[max-age=31536000; includeSubdomains] Content-Type:[application/json; charset=utf-8] Date:[Mon, 23 Nov 2020 19:14:35 GMT] Connection:[keep-alive] Access-Control-Allow-Origin:[*] X-Xss-Protection:[1; mode=block] Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval'] Server:[openresty/1.13.6.2] X-Men-Requestid:[b5b926fa-e9df-400c-b95f-a32a5431d197] X-Content-Type-Options:[nosniff]] 0x2617c80 -1 [] false true map[] 0x248a780 0x2466720}" module=client_auth
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=error msg="authorize failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: Unauthorized" module=state
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="wait 2.588056809s before next authorization attempt" module=state```

I confirmed my date on the Pi is correct also.

Thanks in advance for your help
2

When mender-client makes an authorization request it gets a 401 unauthorized response

This is the expected behavior, and means that it was able to connect to the server, but it is not yet authorized to perform further actions.

It should appear here:

Mender

and you need to accept the device for it to become authorized.

More details on device authorization can be found in our docs, Device Authentication | Mender documentation

3

Thanks for the explanation. If that is the case then something in my setup is not correct as I never see the device show up in pending devices. The device has been online (Wifi) for 30+ minutes. I am running Mender client with debug flag. What logs can I provide to help troubleshoot this?

image
image1608×406 16.2 KB

4 
pi@raspberrypi:~ $ date
Tue 24 Nov 16:52:20 GMT 2020
pi@raspberrypi:~ $ timedatectl status
               Local time: Tue 2020-11-24 17:21:15 GMT
           Universal time: Tue 2020-11-24 17:21:15 UTC
                 RTC time: n/a
                Time zone: Europe/London (GMT, +0000)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no
pi@raspberrypi:~ $ echo | openssl s_client -connect hosted.mender.io:443 2>/dev/null | openssl x509 -noout -dates
notBefore=Oct 23 09:34:38 2020 GMT
notAfter=Jan 21 09:34:38 2021 GMT
pi@raspberrypi:~ $ echo | openssl s_client -connect hosted.mender.io:9000 2>/dev/null | openssl x509 -noout -dates
unable to load certificate
3069734928:error:0909006C:PEM routines:get_name:no start line:../crypto/pem/pem_lib.c:745:Expecting: TRUSTED CERTIFICATE

I tried to run some commands to troubleshoot the connection. I don’t seem to have a certificate for the storage proxy.

5

The storage proxy for our hosted platform is AWS S3 and we don’t use port 9000.
Do you have any devices in the “Rejected” tab?
Drew

6

No I just checked and there are none on that tab. I can send a complete log of the mender client but I can’t attach a text file.

7

Hi @martind I’m not sure why you can’t attach a file but if you want to email it to me at drew.moseley@northern.tech I’ll take a look.

@mirzak any idea about issues with attachments?

8

The system only allows image attachments like jpg, jpeg, png and yaml. I can’t upload a .txt file.

-- Logs begin at Mon 2020-09-14 22:43:39 BST, end at Mon 2020-11-23 19:27:06 GMT. --
-- Reboot --
Nov 23 19:12:46 raspberrypi systemd[1]: Started Mender OTA update service.
Nov 23 19:12:52 raspberrypi mender[309]: time="2020-11-23T19:12:52Z" level=debug msg="Reading Mender configuration from file /var/lib/mender/mender.conf" module=config
Nov 23 19:12:52 raspberrypi mender[309]: time="2020-11-23T19:12:52Z" level=info msg="Loaded configuration file: /var/lib/mender/mender.conf" module=config
Nov 23 19:12:52 raspberrypi mender[309]: time="2020-11-23T19:12:52Z" level=debug msg="Reading Mender configuration from file /etc/mender/mender.conf" module=config
Nov 23 19:12:52 raspberrypi mender[309]: time="2020-11-23T19:12:52Z" level=info msg="Loaded configuration file: /etc/mender/mender.conf" module=config
Nov 23 19:12:52 raspberrypi mender[309]: time="2020-11-23T19:12:52Z" level=debug msg="Merged configuration = &conf.MenderConfig{MenderConfigFromFile:conf.MenderConfigFromFile{ClientProtocol:\"\", ArtifactVerifyKey:\"\", HttpsClient:struct { Certificate string; Key string; SkipVerify bool }{Certificate:\"\", Key:\"\", SkipVerify:false}, RootfsPartA:\"/dev/mmcblk0p2\", RootfsPartB:\"/dev/mmcblk0p3\", DeviceTypeFile:\"/var/lib/mender/device_type\", UpdatePollIntervalSeconds:5, InventoryPollIntervalSeconds:5, RetryPollIntervalSeconds:30, StateScriptTimeoutSeconds:0, StateScriptRetryTimeoutSeconds:0, StateScriptRetryIntervalSeconds:0, ModuleTimeoutSeconds:0, ServerCertificate:\"\", ServerURL:\"https://hosted.mender.io/\", UpdateLogPath:\"\", TenantToken:\"MY TOKEN\", Servers:[]client.MenderServer{client.MenderServer{ServerURL:\"https://hosted.mender.io\"}}}, ModulesPath:\"/usr/share/mender/modules/v3\", ModulesWorkPath:\"/var/lib/mender/modules/v3\", ArtifactInfoFile:\"/etc/mender/artifact_info\", ArtifactScriptsPath:\"/var/lib/mender/scripts\", RootfsScriptsPath:\"/etc/mender/scripts\"}" module=config
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="Have U-Boot variable: mender_check_saveenv_canary=1" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="List of U-Boot variables:map[mender_check_saveenv_canary:1]" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="Have U-Boot variable: mender_saveenv_canary=1" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="List of U-Boot variables:map[mender_saveenv_canary:1]" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="Have U-Boot variable: mender_boot_part=2" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="List of U-Boot variables:map[mender_boot_part:2]" module=bootenv
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="Setting active partition from mount candidate: /dev/mmcblk0p2" module=partitions
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=info msg="Mender running on partition: /dev/mmcblk0p2" module=cli
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="block type: RSA PRIVATE KEY" module=keystore
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="ModuleTimeoutSeconds not set. Defaulting to 14400 seconds" module=modules
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=info msg="State transition: init [none] -> init [none]" module=mender
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="no state data stored" module=state
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=info msg="State transition: init [none] -> idle [Idle]" module=mender
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=info msg="State transition: idle [Idle] -> authorize-wait [Idle]" module=mender
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:12:53 raspberrypi mender[309]: time="2020-11-23T19:12:53Z" level=debug msg="handle authorize state" module=state
Nov 23 19:12:54 raspberrypi mender[309]: time="2020-11-23T19:12:54Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:12:54 raspberrypi mender[309]: time="2020-11-23T19:12:54Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*net.OpError)(0x25602a0)}" module=client_auth
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=error msg="authorization request error: dial tcp: lookup hosted.mender.io on 192.168.0.1:53: dial udp 192.168.0.1:53: connect: network is unreachable" module=client_auth
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: dial tcp: lookup hosted.mender.io on 192.168.0.1:53: dial udp 192.168.0.1:53: connect: network is unreachable" module=state
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:12:55 raspberrypi mender[309]: time="2020-11-23T19:12:55Z" level=debug msg="wait 27.757487s before next authorization attempt" module=state
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="wait complete" module=state
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="handle authorize state" module=state
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:14:08 raspberrypi mender[309]: time="2020-11-23T19:14:08Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:14:09 raspberrypi mender[309]: time="2020-11-23T19:14:09Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="got response: &{401 Unauthorized 401 HTTP/1.1 1 1 map[Vary:[Accept-Encoding] X-Authentication-Version:[unknown] X-Frame-Options:[SAMEORIGIN] Strict-Transport-Security:[max-age=31536000; includeSubdomains] Content-Type:[application/json; charset=utf-8] Date:[Mon, 23 Nov 2020 19:14:35 GMT] Connection:[keep-alive] Access-Control-Allow-Origin:[*] X-Xss-Protection:[1; mode=block] Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval'] Server:[openresty/1.13.6.2] X-Men-Requestid:[b5b926fa-e9df-400c-b95f-a32a5431d197] X-Content-Type-Options:[nosniff]] 0x2617c80 -1 [] false true map[] 0x248a780 0x2466720}" module=client_auth
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=error msg="authorize failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: Unauthorized" module=state
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:14:35 raspberrypi mender[309]: time="2020-11-23T19:14:35Z" level=debug msg="wait 2.588056809s before next authorization attempt" module=state
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="wait complete" module=state
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="handle authorize state" module=state
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:14:38 raspberrypi mender[309]: time="2020-11-23T19:14:38Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*errors.errorString)(0x240e030)}" module=client_auth
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=error msg="authorization request error: EOF" module=client_auth
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: EOF" module=state
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="handle authorize state" module=state
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:15:39 raspberrypi mender[309]: time="2020-11-23T19:15:39Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:15:40 raspberrypi mender[309]: time="2020-11-23T19:15:40Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="got response: &{401 Unauthorized 401 HTTP/1.1 1 1 map[Access-Control-Allow-Origin:[*] X-Xss-Protection:[1; mode=block] X-Frame-Options:[SAMEORIGIN] Strict-Transport-Security:[max-age=31536000; includeSubdomains] Date:[Mon, 23 Nov 2020 19:16:35 GMT] X-Men-Requestid:[3543f78b-9996-4dee-a6e6-5994e27d9180] Server:[openresty/1.13.6.2] Content-Type:[application/json; charset=utf-8] Vary:[Accept-Encoding] X-Authentication-Version:[unknown] X-Content-Type-Options:[nosniff] Connection:[keep-alive] Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval']] 0x2616db0 -1 [] false true map[] 0x248aa00 0x2466720}" module=client_auth
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=error msg="authorize failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: Unauthorized" module=state
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="handle authorize state" module=state
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:16:35 raspberrypi mender[309]: time="2020-11-23T19:16:35Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:16:36 raspberrypi mender[309]: time="2020-11-23T19:16:36Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*errors.errorString)(0x240e030)}" module=client_auth
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=error msg="authorization request error: EOF" module=client_auth
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: EOF" module=state
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="handle authorize state" module=state
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:17:36 raspberrypi mender[309]: time="2020-11-23T19:17:36Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:17:37 raspberrypi mender[309]: time="2020-11-23T19:17:37Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*errors.errorString)(0x240e030)}" module=client_auth
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=error msg="authorization request error: EOF" module=client_auth
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: EOF" module=state
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="handle authorize state" module=state
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:18:40 raspberrypi mender[309]: time="2020-11-23T19:18:40Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:18:41 raspberrypi mender[309]: time="2020-11-23T19:18:41Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*errors.errorString)(0x240e030)}" module=client_auth
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=error msg="authorization request error: EOF" module=client_auth
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: EOF" module=state
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="handle authorize state" module=state
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:19:42 raspberrypi mender[309]: time="2020-11-23T19:19:42Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:19:43 raspberrypi mender[309]: time="2020-11-23T19:19:43Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=debug msg="got response: &{401 Unauthorized 401 HTTP/1.1 1 1 map[X-Xss-Protection:[1; mode=block] Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval'] X-Content-Type-Options:[nosniff] Vary:[Accept-Encoding] X-Men-Requestid:[d4f09e67-e7cc-4587-8883-8e9efd7cf0fd] X-Authentication-Version:[unknown] Access-Control-Allow-Origin:[*] Content-Type:[application/json; charset=utf-8] Connection:[keep-alive] X-Frame-Options:[SAMEORIGIN] Strict-Transport-Security:[max-age=31536000; includeSubdomains] Server:[openresty/1.13.6.2] Date:[Mon, 23 Nov 2020 19:19:57 GMT]] 0x240d590 -1 [] false true map[] 0x248a800 0x2466720}" module=client_auth
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=error msg="authorize failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: Unauthorized" module=state
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:19:57 raspberrypi mender[309]: time="2020-11-23T19:19:57Z" level=debug msg="wait 15.084914162s before next authorization attempt" module=state
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=debug msg="wait complete" module=state
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=debug msg="handle authorize state" module=state
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:20:12 raspberrypi mender[309]: time="2020-11-23T19:20:12Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:20:13 raspberrypi mender[309]: time="2020-11-23T19:20:13Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=error msg="Failure occurred while executing authorization request: &url.Error{Op:\"Post\", URL:\"https://hosted.mender.io/api/devices/v1/authentication/auth_requests\", Err:(*errors.errorString)(0x240e030)}" module=client_auth
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=error msg="authorization request error: EOF" module=client_auth
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=error msg="authorize failed: transient error: authorization request failed: generic error occurred while executing authorization request: Post https://hosted.mender.io/api/devices/v1/authentication/auth_requests: EOF" module=state
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="wait 0s before next authorization attempt" module=state
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:20:55 raspberrypi mender[309]: time="2020-11-23T19:20:55Z" level=debug msg="handle authorize state" module=state
Nov 23 19:20:56 raspberrypi mender[309]: time="2020-11-23T19:20:56Z" level=debug msg="tenant token: MY TOKEN" module=auth
Nov 23 19:20:56 raspberrypi mender[309]: time="2020-11-23T19:20:56Z" level=debug msg="authorization data: {{\"mac\":\"MY MAC\"} MY TOKEN -----BEGIN PUBLIC KEY-----\MY KEY\n-----END PUBLIC KEY-----\n}" module=auth
Nov 23 19:20:56 raspberrypi mender[309]: time="2020-11-23T19:20:56Z" level=debug msg="making an authorization request () to server https://hosted.mender.io" module=client_auth
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=debug msg="got response: &{401 Unauthorized 401 HTTP/1.1 1 1 map[Content-Security-Policy:[default-src https: data: 'unsafe-inline' 'unsafe-eval'] Strict-Transport-Security:[max-age=31536000; includeSubdomains] X-Authentication-Version:[unknown] Access-Control-Allow-Origin:[*] X-Xss-Protection:[1; mode=block] Connection:[keep-alive] X-Content-Type-Options:[nosniff] X-Men-Requestid:[8588265c-bb4c-4423-9f63-ab1bdb74e537] X-Frame-Options:[SAMEORIGIN] Server:[openresty/1.13.6.2] Date:[Mon, 23 Nov 2020 19:21:05 GMT] Content-Type:[application/json; charset=utf-8] Vary:[Accept-Encoding]] 0x240d3e0 -1 [] false true map[] 0x248aa00 0x2466720}" module=client_auth
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=error msg="authorize failed: transient error: authorization request failed: (request_id: ): authentication request rejected server error message: Unauthorized" module=state
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=info msg="State transition: authorize [Sync] -> authorize-wait [Idle]" module=mender
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=debug msg="handle authorize wait state" module=state
Nov 23 19:21:05 raspberrypi mender[309]: time="2020-11-23T19:21:05Z" level=debug msg="wait 20.421902586s before next authorization attempt" module=state
Nov 23 19:21:25 raspberrypi mender[309]: time="2020-11-23T19:21:25Z" level=debug msg="wait complete" module=state
Nov 23 19:21:25 raspberrypi mender[309]: time="2020-11-23T19:21:25Z" level=info msg="State transition: authorize-wait [Idle] -> authorize [Sync]" module=mender
Nov 23 19:21:25 raspberrypi mender[309]: time="2020-11-23T19:21:25Z" level=debug msg="statescript: timeout for executing scripts is not defined; using default of 1h0m0s seconds" module=executor

I’m going to try and recreate my golden image and mender convert incase I missed a step.

I eventually got a simple mender client working using a .deb package but even then I couldn’t use the interactive method as I kept getting json errors. I used the non interactive script method and got my device to show up as pending eventually.

9

OK. Sounds like you at least have a workable solution. If you can post more details about the JSON error we can try and resolve that.

10

Thanks @drewmoseley I ended up recreating the image from scratch again and this time I did get it to successfully connect to hosted.mender.io

For anyone interested for a Raspberry Pi Zero W don’t follow the instructions in the Board Integration section and instead use the steps in the docs.mender.io Debian section.