ADU deviceupdate-agnet 1.0.2 is unable to connect to the IoT Hub, Connection Not Accepted: 0x5: Not Authorized

[FinitelyFailed]

Expected Behavior

deviceupdate-agent should connect to the IoT hub, using the azure identity service to get a connection string.

Current Behavior

This happened on one of our test devices. We have multiple devices running, the other ones work fine. But this one stopped working about a week ago.
deviceupdate-agent can not connect to the IoT hub as it gets a "Connection Not Accepted" error.

Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: .c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:33 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:33 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:33.4330Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:33 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:37 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:37 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:37.4011Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:37 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:45 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:45 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:45.4150Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:45 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:58:01 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:58:01 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:58:01.4152Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:58:01 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:58:32 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:58:32 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:58:32.4416Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:58:32 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:59:02 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscom2024-10-02T05:59:02.4834Z 335[335] [E] IoTHub connection is broken for 418419 seconds (will retry in 455 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:32 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:59:32.4069Z 335[335] [E] IoTHub connection is broken for 418449 seconds (will retry in 425 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:00:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:00:02.4371Z 335[335] [E] IoTHub connection is broken for 418479 seconds (will retry in 395 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:00:32 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:00:32.4771Z 335[335] [E] IoTHub connection is broken for 418509 seconds (will retry in 365 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:01:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:01:02.4203Z 335[335] [E] IoTHub connection is broken for 418539 seconds (will retry in 335 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]

Device Information

• Host OS: Linux built with a Yocto Dunfell pipeline
• Architecture: arm64
• Provisioning Method: AIS
• DU Agent Version: 1.0.2

Logs

Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: .c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:33 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:33 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:33.4330Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:33 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:37 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:37 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:37.4011Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:37 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:57:45 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:57:45 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:57:45.4150Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:57:45 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:58:01 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:58:01 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:58:01.4152Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:58:01 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:58:32 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscomiotedgehubtest.azure-devices.net/e6dc8d96-50a0-4eaf-bb9b-4ba6fff80658-gptedge/DeviceUpdate/?api-version=2020-09-30&DeviceClientType=iothubclient%2f1.9.0%20(native%3b%20Linux%3b%20aarch64)>
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: <- 05:58:32 CONNACK | SESSION_PRESENT: false | RETURN_CODE: 0x5
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:58:32.4416Z 335[335] [D] IotHub connection status: 1, reason: 2 [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: Error: Time:Wed Oct  2 05:58:32 2024 File:/usr/src/debug/azure-iot-sdk-c/1.0+gitAUTOINC+7329f70906-r0/git/iothub_client/src/iothubtransport_mqtt_common.c Func:mqttOperationCompleteCallback Line:2072 Connection Not Accepted: 0x5: Not Authorized
Oct 02 05:59:02 raspberrypi4-64 AducIotAgent[335]: -> 05:59:02 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: syscom2024-10-02T05:59:02.4834Z 335[335] [E] IoTHub connection is broken for 418419 seconds (will retry in 455 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 05:59:32 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T05:59:32.4069Z 335[335] [E] IoTHub connection is broken for 418449 seconds (will retry in 425 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:00:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:00:02.4371Z 335[335] [E] IoTHub connection is broken for 418479 seconds (will retry in 395 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:00:32 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:00:32.4771Z 335[335] [E] IoTHub connection is broken for 418509 seconds (will retry in 365 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]
Oct 02 06:01:02 raspberrypi4-64 AducIotAgent[335]: 2024-10-02T06:01:02.4203Z 335[335] [E] IoTHub connection is broken for 418539 seconds (will retry in 335 seconds) [IoTHub_CommunicationManager_ConnectionStatus_Callback]

Additional Information

I have rebooted the computer, restarted the deviceupdate-agent, with no change in behavior.

The deviceupdate-agent is setup as a "Module Identity" on the device in the IoT hub.

# cat /etc/aziot/identityd/config.d/adu.toml 
[[principal]]
uid = 800
name = "DeviceUpdate"

We have a parallel connection to the device in the IoT hub for our software, which is able to connect to the IoT hub without an problems.

[FinitelyFailed]

I'm still having this issue. It this repo abandoned? Should I look for answers elsewhere?

[jw-msft]

Seems like the version of azure-iot-sdk-c is 1.9 from the hash in the logs providerd, 7329f70906, which is not an LTS release.

The version of azure-iot-sdk for c supported by iot-hub-device-update ver 1.0.2 was the older LTS_07_2021_Ref01 as can be seen here: https://github.com/Azure/iot-hub-device-update/blob/2d1f03671d45be1e55b89c940514ffe91b3227e0/scripts/install-deps.sh#L46C15-L46C32

Was the DU agent installed from 1.2 debian package, or built from sources?

Anyways, this is error 0x5 Not Authorized coming back from iot-hub MQTT server in the CONACK MQTT packet, so whatever cred received from AIS and sent to the MQTT server is not considered authorized by iothub MQTT server

Is this use of AIS based on symmetric keys or x509.certs? If the former, something may be going on with the token generation in AIS, or a bug in the version of the iothub sdk.

This is troubleshooting issue with AIS and iot-hub-sdk-for-c, so you could get faster support opening an issue at https://github.com/Azure/azure-iot-sdk-c/issues and/or https://github.com/Azure/iot-identity-service

[FinitelyFailed]

Hi,

Thanks for your answer!

Seems like the version of azure-iot-sdk-c is 1.9 from the hash in the logs providerd, 7329f70906, which is not an LTS release.

The version of azure-iot-sdk for c supported by iot-hub-device-update ver 1.0.2 was the older LTS_07_2021_Ref01 as can be seen here: https://github.com/Azure/iot-hub-device-update/blob/2d1f03671d45be1e55b89c940514ffe91b3227e0/scripts/install-deps.sh#L46C15-L46C32

Was the DU agent installed from 1.2 debian package, or built from sources?

We build from source. As we build our own Linux based OS with the help of Yocto, we use recepices from https://github.com/GaiaSystem/meta-azure-device-update (which is a fork of https://github.com/Azure/meta-azure-device-update). We have OS:s based on Dunfell and Kirkstone at the moment, both seems to be running 1.0.2 of ADU.
It seems that we use code from this repo from the commits:

• Kirkstone: 79ce3ba
• Dunfell: 33554d2

Anyways, this is error 0x5 Not Authorized coming back from iot-hub MQTT server in the CONACK MQTT packet, so whatever cred received from AIS and sent to the MQTT server is not considered authorized by iothub MQTT server

Is this use of AIS based on symmetric keys or x509.certs? If the former, something may be going on with the token generation in AIS, or a bug in the version of the iothub sdk.

This is troubleshooting issue with AIS and iot-hub-sdk-for-c, so you could get faster support opening an issue at https://github.com/Azure/azure-iot-sdk-c/issues and/or https://github.com/Azure/iot-identity-service

We use symmetric keys.
And we use AIS to get credentials to connect our own software to the IoT hub, which is seems to be very stable. I do not think that AIS is the problem.

The problem is that we do not know which version of ADU (in our case which commit) that should be used. I find it hard to find any info about LTS versions etc.

And what is bit worrying is that I can't get our device to work. The one which got the "error 0x5 Not Authorized" error. If I could clear some cache, restart something etc. etc. to get DU on device to work again I would feel a bit better, as we have a bunch of devices in production running the same version of DU.

[FinitelyFailed]

Hi,

I would love some answers to my questions.

Is development around ADU ongoing? It seems a bit dead to be honest.

[eshashah-msft]

Hi @FinitelyFailed , the latest ADU Yocto recipes and meta layers are based on the Scarthgap release of Yocto as it is current LTS version. The main branch will be snapped to the Scarthgap version by end of the week as well. Our recommendation would be to use these layers and recipes. Any bug fixes and changes will be incorporated here. Additionally, these recipes have been tested with AIS and use the 1.1.0 commits of the ADU agent.

Separately, it looks like your ADU AIS config.toml file is missing idtype = ["module"] that is required to allow auth of ADU as module for the Edge device. Documentation here This may be causing the connection not authorized error.

[FinitelyFailed]

Hi @eshashah-msft ,

Thanks for your answer. We will try to move our version of ADU to the same version as the one that Scarthgap points. I guess that the meta iot hub device update delta will be fixed as well? As it doesn't seem to have a finished Scarthgap branch (I guess that user/nox-msft/scarthgap is somekind of work branch)?

The AIS config file for ADU actually looke like this:

[[principal]]
uid = 800
name = "DeviceUpdate"
idtype = ["module"]

The last line doesn't end with a newline, which made me miss that line when I copied it the first time ... Sorry.

We flashed our faulty device, and now it works. Both its deviceupdate-agent and our software connects to the IoT Hub without any problems. Which makes me think that the error is in the deviceupdate-agent. And that something is cached, or similar on the device's disk. As a restart of the device, deviceupdate-agent, or AIS services doesn't do anything.
I would love some input on what kind of files that are created by deviceupdate-agent or AIS. So I can test to remove any such files, restart affected services and make the device work again. As we do have some remote access to the devices in production, and very limited physical access. So a re-flash of the affected devices is somewhat a headache for us.

We got the same problem on an other device in our test environment as well ... Which is a bit concerning. As far as we know the problem hasn't happened in production, yet.

BTW: When I was looking around I saw that you seem to have a typo here: https://github.com/Azure/iot-hub-device-update-yocto/blob/568515f2f160189398907bdb5d69080c0ee1d4f6/azurepipelines/build-template.yml#L36