Update check request failed: transient error: authorization request failed

Hello,

I hope you’re all doing well. I’m writing to seek some guidance and assistance with a problem I’ve encountered while trying to connect a device. Despite my best efforts, the device fails to appear after running the given command.

Upon investigating the issue further, I checked the logs and discovered the following information:

Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="Device unauthorized; attempting reauthorization"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/identity/mender-device-identity\": using interface /sys/class/net/eth0"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=error msg="Failure occurred while executing authorization request: Method: Post, URL: https://xxxxxxx.org/api/devices/v1/authentication/auth_requests"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=error msg="Failed to authorize with \"https://xxxxxxx.org\": Unknown url.Error type: depth zero self-signed certificate, openssl verify rc: 18 server cert file: "
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=warning msg="Reauthorization failed with error: transient error: authorization request failed"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=error msg="Error receiving scheduled update data: update check request failed: transient error: authorization request failed"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=error msg="Update check failed: transient error: update check request failed: transient error: authorization request failed"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="State transition: update-check [Sync] -> error [Error]"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="Handling error state, current error: transient error: update check request failed: transient error: authorization request failed"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="State transition: error [Error] -> idle [Idle]"
Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=info msg="State transition: idle [Idle] -> check-wait [Idle]"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=info msg="State transition: check-wait [Idle] -> update-check [Sync]"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=info msg="Device unauthorized; attempting reauthorization"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/identity/mender-device-identity\": using interface /sys/class/net/eth0"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=error msg="Failure occurred while executing authorization request: Method: Post, URL: https://xxxxxxx.org/api/devices/v1/authentication/auth_requests"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=error msg="Failed to authorize with \"https://xxxxxxx.org\": Unknown url.Error type: depth zero self-signed certificate, openssl verify rc: 18 server cert file: "
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=warning msg="Reauthorization failed with error: transient error: authorization request failed"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=error msg="Error receiving scheduled update data: update check request failed: transient error: authorization request failed"
Jul 14 12:36:49 raspberrypi mender[24915]: time="2023-07-14T12:36:49+02:00" level=error msg="Update check failed: transient error: update check request failed: transient error: authorization request failed"

It appears that the authentication process is failing. To my surprise, when I went to review the authentication logs on the server, I found them to be strangely empty:

time="2023-07-14T09:46:59Z" level=info msg="migration to version 1.10.0 skipped" db=deviceauth file=migrator_simple.go func="migrate.(*SimpleMigrator).Apply" line=125
time="2023-07-14T09:46:59Z" level=info msg="migration to version 1.11.0 skipped" db=deviceauth file=migrator_simple.go func="migrate.(*SimpleMigrator).Apply" line=125
time="2023-07-14T09:46:59Z" level=info msg="DB migrated to version 1.11.0" db=deviceauth file=migrator_simple.go func="migrate.(*SimpleMigrator).Apply" line=140
time="2023-07-14T09:46:59Z" level=info msg="Device Authentication Service starting up" file=main.go func=main.cmdServer line=225
time="2023-07-14T09:46:59Z" level=info msg="setting up prod middleware" file=middleware.go func=main.SetupMiddleware line=87
time="2023-07-14T09:46:59Z" level=info msg="listening on :8080"

I’m quite puzzled by this situation and would greatly appreciate it if someone could point me in the right direction. Is there any relevant documentation or resources you could recommend that could help me troubleshoot this problem? If anyone has experienced a similar issue or has any insights to offer, I would be extremely grateful for your assistance.

Thank you in advance for your time and support!

Best regards,
Richard

Hi @Ries,

Just guessing:

Jul 14 12:06:49 raspberrypi mender[24915]: time="2023-07-14T12:06:49+02:00" level=error msg="Failed to authorize with \"https://xxxxxxx.org\": Unknown url.Error type: depth zero self-signed certificate, openssl verify rc: 18 server cert file: "

tells you that the certificate in itself on the device is not trustworthy, and hence no connection is even established. Hence, silence on the server.

You can temporarily disable certificate checking on the client by adding the snippet

    "HttpsClient": {
        "SkipVerify": true
    },

to your /etc/mender/mender.conf file and check if that gets things going in your test environment.

DISCLAIMER: THIS IS NOT SUITABLE FOR ANY KIND OF PRODUCTION OR REMOTELY ACCESSIBLE DEVICE

Greetz,
Josef

1 Like

Hi @TheYoctoJester ,

Thank you for your suggestion. I tried adding the snippet you provided to the mender.conf file (/etc/mender/mender.conf), but unfortunately, it didn’t seem to have any effect. The error message I’m receiving still indicates that the certificate on the device is not trusted, resulting in a failed authorization with the server.

Jul 14 13:58:29 raspberrypi mender[678]: time="2023-07-14T13:58:29+02:00" level=info msg="Wait 30s before next inventory update attempt in 59.999995185s"
Jul 14 13:58:59 raspberrypi mender[678]: time="2023-07-14T13:58:59+02:00" level=info msg="State transition: inventory-update-retry-wait [Sync] -> inventory-update [Sync]"
Jul 14 13:59:00 raspberrypi mender[678]: time="2023-07-14T13:59:00+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/inventory/mender-inventory-mender-configure\": An authentication token could not be obtained over DBus."
Jul 14 13:59:00 raspberrypi mender[678]: time="2023-07-14T13:59:00+02:00" level=warning msg="Inventory tool /usr/share/mender/inventory/mender-inventory-mender-configure wait failed: exit status 1"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=info msg="Device unauthorized; attempting reauthorization"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/identity/mender-device-identity\": using interface /sys/class/net/eth0"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=error msg="Failure occurred while executing authorization request: Method: Post, URL: https://xxxxx.org/api/devices/v1/authentication/auth_requests"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=error msg="Failed to authorize with \"https://xxxxx.org\": Unknown url.Error type: depth zero self-signed certificate, openssl verify rc: 18 server cert file: "
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=warning msg="Reauthorization failed with error: transient error: authorization request failed"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=error msg="Failed to submit inventory data: transient error: authorization request failed"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=error msg="inventory submit failed: transient error: authorization request failed"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=warning msg="Failed to refresh inventory: failed to submit inventory data: inventory submit failed: transient error: authorization request failed"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=info msg="State transition: inventory-update [Sync] -> inventory-update-retry-wait [Sync]"
Jul 14 13:59:01 raspberrypi mender[678]: time="2023-07-14T13:59:01+02:00" level=info msg="Handle update inventory retry state: not the time yet; 28s/28.882750887s remaining."

I’m open to any other suggestions or ideas you might have to resolve this problem. Thank you for your assistance!

Best regards,
Ries

@Ries can you drop your full mender.conf in here?

1 Like
{
    "HttpsClient": {
        "SkipVerify": true
    },
    "Security": {},
    "Connectivity": {},
    "RootfsPartA": "/dev/mmcblk0p2",
    "RootfsPartB": "/dev/mmcblk0p3",
    "DeviceTypeFile": "/var/lib/mender/device_type",
    "DBus": {
        "Enabled": true
    },
    "UpdateControlMapExpirationTimeSeconds": 90,
    "UpdateControlMapBootExpirationTimeSeconds": 45,
    "UpdatePollIntervalSeconds": 5,
    "InventoryPollIntervalSeconds": 5,
    "RetryPollIntervalSeconds": 30,
    "Servers": [
        {
            "ServerURL": "https://xxxxx.org"
        }
    ]
}

And it works when you use Hosted Mender?

1 Like

It shows up in the pending tab on hosted unlike when tried on a self hosted server.

the errors still show up in the log however. So the errors are unrelated to the problem?

Jul 14 14:30:30 raspberrypi mender[31975]: time="2023-07-14T14:30:30+02:00" level=info msg="Handle update inventory retry state: not the time yet; 28s/28.902199074s remaining."
Jul 14 14:30:58 raspberrypi mender[31975]: time="2023-07-14T14:30:58+02:00" level=info msg="State transition: inventory-update-retry-wait [Sync] -> inventory-update [Sync]"
Jul 14 14:30:59 raspberrypi mender[31975]: time="2023-07-14T14:30:59+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/inventory/mender-inventory-mender-configure\": An authentication token could not be obtained over DBus."
Jul 14 14:30:59 raspberrypi mender[31975]: time="2023-07-14T14:30:59+02:00" level=warning msg="Inventory tool /usr/share/mender/inventory/mender-inventory-mender-configure wait failed: exit status 1"
Jul 14 14:30:59 raspberrypi mender[31975]: time="2023-07-14T14:30:59+02:00" level=info msg="Device unauthorized; attempting reauthorization"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/identity/mender-device-identity\": using interface /sys/class/net/eth0"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=error msg="Failed to authorize with \"https://eu.hosted.mender.io\": authentication request rejected server error message: dev auth: unauthorized"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=warning msg="Reauthorization failed with error: transient error: authorization request failed"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=error msg="Failed to submit inventory data: transient error: authorization request failed"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=error msg="inventory submit failed: transient error: authorization request failed"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=warning msg="Failed to refresh inventory: failed to submit inventory data: inventory submit failed: transient error: authorization request failed"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="State transition: inventory-update [Sync] -> inventory-update-retry-wait [Sync]"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="Handle update inventory retry state try: 1"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/inventory/mender-inventory-mender-configure\": An authentication token could not be obtained over DBus."
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=warning msg="Inventory tool /usr/share/mender/inventory/mender-inventory-mender-configure wait failed: exit status 1"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="Device unauthorized; attempting reauthorization"
Jul 14 14:31:00 raspberrypi mender[31975]: time="2023-07-14T14:31:00+02:00" level=info msg="Output (stderr) from command \"/usr/share/mender/identity/mender-device-identity\": using interface /sys/class/net/eth0"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=error msg="Failed to authorize with \"https://eu.hosted.mender.io\": authentication request rejected server error message: dev auth: unauthorized"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=warning msg="Reauthorization failed with error: transient error: authorization request failed"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=error msg="Failed to submit inventory data: transient error: authorization request failed"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=error msg="inventory submit failed: transient error: authorization request failed"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=warning msg="Failed to refresh inventory: failed to submit inventory data: inventory submit failed: transient error: authorization request failed"
Jul 14 14:31:01 raspberrypi mender[31975]: time="2023-07-14T14:31:01+02:00" level=info msg="Wait 30s before next inventory update attempt in 59.999994852s"

Hi @Ries ,

“Unauthorized” means “Pending”, e.g. “not yet accepted” in this context. I know the wording is a bit misleading.

But as you can see the SSL error is gone, and as such the device can connect to the server for the authentication request.

At the moment I don’t have another idea where to look in detail, but as far as I can tell it is related to the HTTPS certification, so you need to figure out injecting your self-signed certificate into the device and trusting it, or getting your server signed by a trusted root.

Greetz,
Josef

1 Like

If you are creating the self certificate yourself, it’s worth checking how you are creating your self-signed certificate, as there are ways to generate the errors you are seeing depending on how you fill in the metadata contained within it. Maybe you didn’t set the common name to ‘xxxxx.org

1 Like

@TheYoctoJester thanks for the help. I successfully added the certificate into the device and ensured it is trusted. It’s now working as expected. Thanks for your guidance! I’ll work on getting the server signed.

1 Like