Client error 401 Unauthorized while requesting configuration file via c8y_configuration_plugin

[bjoernsauer]

Describe the bug

Requesting a configuration file via cumulocity fails with the error reason "HTTP status client error (401 Unauthorized) for url (https://xxx)".

The log file of the c8y_configuration_plugin:

2022-11-07T11:11:40.013424418Z  INFO c8y_configuration_plugin::config: Reading the config file from /etc/tedge/c8y/c8y-configuration-plugin.toml
2022-11-07T11:11:40.051588345Z ERROR c8y_configuration_plugin::upload: The configuration upload for 'tedge.toml' failed.

To Reproduce

Connect a device to cumulocity. Wait some time (several hours, sorry for no precise duration). Try to retrieve a configuration file from the device.

Expected behavior

the configuration file should be received.

Screenshots

Details of the cumulocity operation:

{
  "delivery": {
    "log": [
      {
        "time": "2022-11-07T11:11:39.983Z",
        "status": "PENDING"
      },
      {
        "time": "2022-11-07T11:11:39.997Z",
        "status": "SEND"
      }
    ],
    "time": "2022-11-07T11:11:40.022Z",
    "status": "DELIVERED"
  },
  "creationTime": "2022-11-07T11:11:39.945Z",
  "deviceId": "36214",
  "deviceName": "axcf3152-test1",
  "failureReason": "HTTP status client error (401 Unauthorized) for url (https://xxx.eu-latest.cumulocity.com/event/events/)",
  "self": "http://xxx",
  "id": "xxx",
  "status": "FAILED",
  "description": "Retrieve tedge.toml configuration snapshot from device axcf3152-test1",
  "c8y_UploadConfigFile": {
    "type": "tedge.toml"
  }
}

Environment (please complete the following information):

• OS: Custom yocto build, glibc 2.35, gcc 11.2
• Phoenix Contact AXC F 3152, Custom embedded hardware x86_64 Intel(R) Atom(TM) Processor E3930
• System-Architecture: Linux axcf3152 5.4.161-rt66-pxc # 1 SMP PREEMPT_RT Tue Jul 19 13:05:03 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
• thin-edge.io version 0.8.0

[bjoernsauer]

Here is the plugin configuration file c8y-configuration-plugin.toml

# Add the configurations to be managed by c8y-configuration-plugin

files = [
    { path = '/etc/tedge/tedge.toml', user = 'tedge', group = 'tedge', type = 'tedge.toml' },
    { path = '/etc/tedge/mosquitto-conf/c8y-bridge.conf', type = 'c8y-bridge.conf' },
    { path = '/etc/tedge/mosquitto-conf/tedge-mosquitto.conf', type = 'tedge-mosquitto.conf' },
    { path = '/etc/mosquitto/mosquitto.conf', type = 'mosquitto.conf' },
    { path = '/etc/tedge/c8y/c8y-log-plugin.toml', type = 'c8y-log-plugin.toml' }
]

[reubenmiller]

It sounds like that the token is not being refreshed before the plugin tries to communicate with Cumulocity via the REST API.

@bjoernsauer How long as the agent service/s been running for? A few minutes, or much longer (e.g. a day or more)?

[bjoernsauer]

I reconnected the thin-edge.io agent at approx 2022-11-07T07:14:05.285Z this morning. That's what cumulocity shows me for "last actualization" time in the device info dashboard.

[didier-wenzek]

A 401 unauthorized response is due to the plugin using a JWT token that is expired. This can happen for two reasons:

• Cumulocity avoid to create too many tokens and re-use the same as long as valid. The counterpart is that the plugin might get a token with a lifetime not long enough. The fix here is simple: one just have to get a fresher token. This is really unlikely though.
• Several thin-edge processes require JWT tokens and are concurrently requesting tokens, but each token is published to all the processes filling their subscription queue. So a process requesting a fresh token might be fooled and pick from its queue a token that has been returned for another process hours ago. This is the most likely root cause of the observed 401 unauthorized responses. One solution to fix that is to open a fresh clean connection for each token. Another one is to consume all the tokens received on the c8y/s/dat subscriptions even when not requested by the process itself.

So to reproduce the issue:

1. Launch the c8y_configuration_plugin but don't use it
2. Use other thin-edge services that require JWT tokens (log management or software management).
3. Wait at least an hour - the JWT token issued by Cumulocity having one hour to live.
4. Trigger a configuration upload request
5. => Observe the unexpected 401 due to the configuration plugin using the token sent an hour ago to the other services.

One way to reproduce the issue in a test environment is to publish fake tokens. Despite proper tokens being published on demand the plugin will try to use first the fake ones :-(.

1. Launch the c8y_configuration_plugin but don't use it
2. Generate several fake tokens using tedge mqtt pub c8y/s/dat '71,fake-expired-token'
3. Trigger a configuration upload request
4. => Observe the unexpected 401 due to the configuration plugin using the fake tokens.

[didier-wenzek]

A fix has been merged: https://github.com/thin-edge/thin-edge.io/pull/1586. The build is https://github.com/thin-edge/thin-edge.io/actions/runs/3478607077.

@gligorisaev please see my previous comment to test it.

[gligorisaev]

Tested and it is fine

[reubenmiller]

Will be included in the next release. 0.8.2