2024-03-06T09:41:25.9972Z 1276[1276] [D] IotHub connection status: 1, reason: 0 [IoTHub_CommunicationManager_ConnectionStatus_Callback:219] 2024-03-06T09:41:26.0979Z 1276[1276] [I] Refreshing the handle for the PnP channels. [ADUC_PnP_Components_HandleRefresh:474] 2024-03-06T09:41:26.3761Z 1276[1276] [I] Attempting to create connection to IotHub using type: ADUC_ConnType_Module [ADUC_DeviceClient_Create:327] 2024-03-06T09:41:26.3761Z 1276[1276] [I] IotHub Protocol: MQTT [GetIotHubProtocolFromConfig:265] 2024-03-06T09:41:26.3762Z 1276[1276] [I] IoTHub Device Twin callback registered. [ADUC_DeviceClient_Create:430] 2024-03-06T09:41:26.3762Z 1276[1276] [I] Refreshing the handle for the PnP channels. [ADUC_PnP_Components_HandleRefresh:474] 2024-03-06T09:41:26.3762Z 1276[1276] [I] Successfully re-authenticated the IoT Hub connection. [ADUC_Refresh_IotHub_Connection_SAS_Token:690] 2024-03-06T09:41:26.5226Z 1276[1276] [I] The connection is currently broken. Will try to authenticate in 17 seconds. [Connection_Maintenance:781] -> 09:41:26 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: xxx-xxx-iot-hub.azure-devices.net/device-name/AducIotAgent/?api-version=2020-09-> <- 09:41:26 CONNACK | SESSION_PRESENT: true | RETURN_CODE: 0x0 2024-03-06T09:41:26.7340Z 1276[1276] [D] IotHub connection status: 0, reason: 6 [IoTHub_CommunicationManager_ConnectionStatus_Callback:219] -> 09:41:26 SUBSCRIBE | PACKET_ID: 2 | TOPIC_NAME: $iothub/twin/res/# | QOS: 0 <- 09:41:26 SUBACK | PACKET_ID: 2 | RETURN_CODE: 0 -> 09:41:27 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/GET/?$rid=3 <- 09:41:27 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/200/?$rid=3 | PAYLOAD_LEN: 7234 2024-03-06T09:41:27.1378Z 1276[1276] [D] ComponentName:deviceUpdate, propertyName:service [ADUC_PnP_ComponentClient_PropertyUpdate_Callback:536] 2024-03-06T09:41:27.1380Z 1276[1276] [D] Update Action info string ({"workflow":{"action":3,"id":"6409ddb9d8ce39ade510df4a-20242685040"},"updateManifest":"{\"manifestVersion> 2024-03-06T09:41:27.1383Z 1276[1276] [D] Processing deployment 6409ddb9d8ce39ade510df4a-20242685040 ... [OrchestratorUpdateCallback:446] 2024-03-06T09:41:27.1384Z 1276[1276] [D] Queueing message (t:0, c:0xff3f8290, m:{"deviceUpdate":{"__t":"c","agent":{"lastInstallResult":{"stepResults":null,"resultCode":1,"e> 2024-03-06T09:41:27.1388Z 1276[1276] [E] stat path '/var/lib/adu/downloads/6409ddb9d8ce39ade510df4a-20242685040/rootkeypackage-1.json' failed: 2 [SystemUtils_IsFile:734] 2024-03-06T09:41:27.1389Z 1276[1276] [D] Attempting download of 'http://xxx-xxx-instance--xxx-xxx-adu.b.nlu.dl.adu.microsoft.com/WestEurope/rootkeypackages/rootk> 2024-03-06T09:41:27.1389Z 1276[1276] [I] Downloading File 'http://xxx-xxx-instance--xxx-xxx-adu.b.nlu.dl.adu.microsoft.com/WestEurope/rootkeypackages/rootkeypack> 2024-03-06T09:41:32.1617Z 1276[1276] [I] Download rc: 1, erc: 0x00000000 [DownloadRootKeyPkg_DO:51] 2024-03-06T09:41:32.1643Z 1276[1276] [D] No root key change. [RootKeyWorkflow_UpdateRootKeys:172] 2024-03-06T09:41:32.1679Z 1276[1276] [D] set prop '_workFolder' to '/var/lib/adu/downloads/6409ddb9d8ce39ade510df4a-20242685040' [workflow_set_string_property:1683] 2024-03-06T09:41:32.1679Z 1276[1276] [D] cancellationType(0) => None [ADUC_Workflow_HandleUpdateAction:667] 2024-03-06T09:41:32.1679Z 1276[1276] [D] Ignoring duplicate deployment 6409ddb9d8ce39ade510df4a-20242685040, action 3 [ADUC_Workflow_HandleUpdateAction:714] 2024-03-06T09:41:32.1679Z 1276[1276] [D] PropertyUpdated event handler completed. [ADUC_Workflow_HandlePropertyUpdate:638] 2024-03-06T09:41:32.1680Z 1276[1276] [D] Queueing message (t:1, c:0xff3f1c40, m:{"deviceUpdate":{"__t":"c","service":{"value":{"workflow":{"action":3,"id":"6409ddb9d8ce39ade> 2024-03-06T09:41:32.1682Z 1276[1276] [I] OrchestratorPropertyUpdateCallback ended [OrchestratorUpdateCallback:517] 2024-03-06T09:41:32.1684Z 1276[1276] [D] Sending D2C message (t:0, retries:0). [ProcessMessage:390] 2024-03-06T09:41:32.1684Z 1276[1276] [D] Sending D2C message: {"deviceUpdate":{"__t":"c","agent":{"lastInstallResult":{"stepResults":null,"resultCode":1,"extendedResultCodes":"00000000","resultDetails":null},"state":6,"workflow":{"acti> 2024-03-06T09:41:32.1685Z 1276[1276] [D] Sending D2C message (t:1, retries:0). [ProcessMessage:390] 2024-03-06T09:41:32.1685Z 1276[1276] [D] Sending D2C message: {"deviceUpdate":{"__t":"c","service":{"value":{"workflow":{"action":3,"id":"6409ddb9d8ce39ade510df4a-20242685040"},"updateManifest":"{\"manifestVersion\":\"5\",\"updateId\":> 2024-03-06T10:29:27.4863Z 1276[1276] [E] IoTHub connection is broken. [IoTHub_CommunicationManager_ConnectionStatus_Callback:234] -> 09:41:32 SUBSCRIBE | PACKET_ID: 4 | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/# | QOS: 0 <- 09:41:32 SUBACK | PACKET_ID: 4 | RETURN_CODE: 0 -> 09:41:32 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=5 | PAYLOAD_LEN: 226 -> 09:41:32 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=6 | PAYLOAD_LEN: 1680 <- 09:41:32 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=6&$version=27 | PAYLOAD_LEN: 0 2024-03-06T09:41:32.7726Z 1276[1276] [D] context:0xd0492d50 [DefaultIoTHubSendReportedStateCompletedCallback:205] 2024-03-06T09:41:32.7726Z 1276[1276] [D] D2C message processed successfully (t:1, r:0, content:0xff418410 ) [DefaultIoTHubSendReportedStateCompletedCallback:233] 2024-03-06T09:41:32.7726Z 1276[1276] [D] Send message completed (status:3) [OnUpdateResultD2CMessageCompleted:64] <- 09:41:32 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=5&$version=26 | PAYLOAD_LEN: 0 2024-03-06T09:41:32.7727Z 1276[1276] [D] context:0xd0492ca8 [DefaultIoTHubSendReportedStateCompletedCallback:205] 2024-03-06T09:41:32.7728Z 1276[1276] [D] D2C message processed successfully (t:0, r:0, content:0xff3ff480 ) [DefaultIoTHubSendReportedStateCompletedCallback:233] 2024-03-06T09:41:32.7728Z 1276[1276] [D] Send message completed (status:3) [OnUpdateResultD2CMessageCompleted:64] -> 09:45:32 PINGREQ