Created
March 22, 2021 07:50
-
-
Save KunYi/977cf0f489ff47575a6b8916706c50f4 to your computer and use it in GitHub Desktop.
Azure Device Agent running log for update success
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Mar 22 06:01:42 raspberrypi3 systemd[1]: Started ADU Client service.. | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7673Z [I] Agent (linux; 0.6.0-public-preview) starting. [main] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7674Z [I] Agent built with handlers: microsoft/swupdate. [main] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7678Z [I] Initalizing PnP components. [ADUC_PnP_Components_Create] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7678Z [I] ADUC agent started. Using IoT Hub Client SDK 1.6.0 [AzureDeviceUpdateCoreInterface_Create] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7679Z [I] Calling ADUC_Register [ADUC_MethodCall_Register] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7679Z [I] IoTHub Device Twin callback registered. [ADUC_DeviceClient_Create] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7683Z [W] Failed to pass connection string to DO, error: -1 [StartupAgent] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:42.7684Z [I] Agent running. [main] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: -> 06:01:43 CONNECT | VER: 4 | KEEPALIVE: 240 | FLAGS: 192 | USERNAME: AduTestHub.azure-devices.net/ADUOfficalDevice/?api-version=2020-09-30&DeviceClientT0 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: <- 06:01:44 CONNACK | SESSION_PRESENT: true | RETURN_CODE: 0x0 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:44.2277Z [D] IotHub connection status: 0, reason:6 [ADUC_ConnectionStatus_Callback] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: -> 06:01:44 SUBSCRIBE | PACKET_ID: 2 | TOPIC_NAME: $iothub/twin/res/# | QOS: 0 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: <- 06:01:44 SUBACK | PACKET_ID: 2 | RETURN_CODE: 0 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: -> 06:01:44 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/GET/?$rid=3 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: <- 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/200/?$rid=3 | PAYLOAD_LEN: 558 | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1300Z [I] Processing existing Device Twin data after agent started. [ADUC_PnPDeviceTwin_Callback] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1300Z [D] Notifies components that all callback are subscribed. [ADUC_PnPDeviceTwin_Callback] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1301Z [I] DeviceInformation component is ready - reporting properties [DeviceInfoInterface_Connected] | |
| Mar 22 06:01:45 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1303Z [I] Property manufacturer changed to UWINGS [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1304Z [I] Property model changed to raspberrypi3 [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1304Z [I] Property osName changed to Linux [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1305Z [I] Property swVersion changed to 4.19.88 [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1305Z [I] Property processorArchitecture changed to armv7l [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1474Z [I] Property processorManufacturer changed to ARM [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1475Z [I] Property totalMemory changed to 947772 [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1476Z [I] Property totalStorage changed to 1007860 [RefreshDeviceInfoInterfaceData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1479Z [I] No update content. Reporting Idle state. [ADUC_Workflow_HandleStartupWorkflowData] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1479Z [I] Setting UpdateState to Idle [ADUC_SetUpdateStateHelper] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1479Z [I] Reporting state: 0, Idle (0); HTTP 200; result 1, 0 [AzureDeviceUpdateCoreInterface_ReportStateAndResultAsync] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1480Z [I] UpdateAction: Idle. WorkflowId: 210322060145 [ADUC_MethodCall_Idle] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1481Z [I] Calling IdleCallback [ADUC_MethodCall_Idle] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:01:45.1481Z [I] Now idle. workflowId: 210322060145 [Idle] | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: -> 06:01:45 SUBSCRIBE | PACKET_ID: 4 | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/# | QOS: 0 | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: -> 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=5 | PAYLOAD_LEN: 226 | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: -> 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=6 | PAYLOAD_LEN: 99 | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: -> 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=7 | PAYLOAD_LEN: 231 | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: <- 06:01:45 SUBACK | PACKET_ID: 4 | RETURN_CODE: 0 | |
| Mar 22 06:01:46 raspberrypi3 AducIotAgent[354]: <- 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=5&$version=8 | PAYLOAD_LEN: 0 | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=7&$version=10 | PAYLOAD_LEN: 0 | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:01:45 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=6&$version=9 | PAYLOAD_LEN: 0 | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: -> 06:05:45 PINGREQ | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:05:45 PINGRESP | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: -> 06:09:45 PINGREQ | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:09:45 PINGRESP | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: -> 06:13:45 PINGREQ | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:13:45 PINGRESP | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: -> 06:17:45 PINGREQ | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:17:45 PINGRESP | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: -> 06:21:45 PINGREQ | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:21:45 PINGRESP | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: <- 06:24:18 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/?$version=2 | PAYLOAD_LEN:7 | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.5963Z [D] ComponentName:azureDeviceUpdateAgent, propertyName:service [ADUC_PnP_ComponentClient_PropertyUpdate_Callback] | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.5967Z [D] OrchestratorUpdateCallback received property JSON string ({"action":0,"updateManifest":"{\"manifestVersion\":\"2.0\",\"updat] | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6018Z [I] Processing 'Download' action [ADUC_Workflow_HandleUpdateAction] | |
| Mar 22 06:24:18 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6019Z [I] UpdateAction: Prepare - calling PrepareCallback [ADUC_MethodCall_Prepare] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6020Z [I] {210322060145} Received Metadata, UpdateType: microsoft/swupdate:1, UpdateTypeName: microsoft/swupdate, UpdateTypeVersion: 1] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6187Z [I] microsoft_swupdate_CreateFunc called. [microsoft_swupdate_CreateFunc] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6187Z [I] Prepare succeeded. [Prepare] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6187Z [I] UpdateAction: Download [ADUC_MethodCall_Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6188Z [I] Calling SandboxCreateCallback [ADUC_MethodCall_Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6191Z [I] Setting sandbox /tmp/aduc-dl-210322060145 [SandboxCreate] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6191Z [I] Using sandbox /tmp/aduc-dl-210322060145 [ADUC_MethodCall_Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6191Z [I] Setting UpdateState to DownloadStarted [ADUC_SetUpdateStateHelper] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6193Z [I] Calling DownloadCallback [ADUC_MethodCall_Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6193Z [I] Download thread started [DownloadCallback] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6196Z [D] Downloading 1 files to /tmp/aduc-dl-210322060145 [Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6197Z [I] OrchestratorPropertyUpdateCallback ended [OrchestratorUpdateCallback] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:18.6198Z [I] Downloading File 'adu-update-image-raspberrypi3-.4889.1.swu' from 'http://rpi3btest--adutest.b.nlu.dl.adu.microsoft.com/west] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: -> 06:24:18 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=8 | PAYLOAD_LEN: 315 | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: <- 06:24:19 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=8&$version=11 | PAYLOAD_LEN: 0 | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:46.4586Z [I] Validating file hash [Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0145Z [I] microsoft_swupdate_CreateFunc called. [microsoft_swupdate_CreateFunc] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0145Z [I] Download called - no-op for swupdate [Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0146Z [I] Content Handler Download resultCode: 1, extendedCode: 0 [Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0146Z [I] ProgressCallback: workflowId: 210322060145; Id 00000; State: Completed; Bytes: 106633728/106633728 [DownloadProgressCallback] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0147Z [I] Download resultCode: 1, extendedCode: 0 [Download] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0147Z [I] Action 'Download' complete. Result: 1, 0 [ADUC_Workflow_WorkCompletionCallback] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0147Z [I] WorkCompletionCallback: Download succeeded. Going to state DownloadSucceeded [ADUC_Workflow_WorkCompletionCallback] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0147Z [I] Setting UpdateState to DownloadSucceeded [ADUC_SetUpdateStateHelper] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:24:56.0148Z [I] Reporting state: DownloadSucceeded (2) [AzureDeviceUpdateCoreInterface_ReportStateAndResultAsync] | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: -> 06:24:56 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=9 | PAYLOAD_LEN: 59 | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: <- 06:24:56 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=9&$version=12 | PAYLOAD_LEN: 0 | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: <- 06:25:00 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/desired/?$version=3 | PAYLOAD_LEN:5 | |
| Mar 22 06:25:00 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1790Z [D] ComponentName:azureDeviceUpdateAgent, propertyName:service [ADUC_PnP_ComponentClient_PropertyUpdate_Callback] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1794Z [D] OrchestratorUpdateCallback received property JSON string ({"action":1,"updateManifest":"{\"manifestVersion\":\"2.0\",\"updat] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1845Z [I] Processing 'Install' action [ADUC_Workflow_HandleUpdateAction] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1846Z [I] UpdateAction: Install [ADUC_MethodCall_Install] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1846Z [I] Setting UpdateState to InstallStarted [ADUC_SetUpdateStateHelper] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1846Z [I] Calling InstallCallback [ADUC_MethodCall_Install] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1847Z [I] Install thread started [InstallCallback] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1849Z [I] Installing from /tmp/aduc-dl-210322060145 [Install] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1850Z [I] Installing image file: adu-update-image-raspberrypi3-.4889.1.swu [Install] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:25:00.1850Z [I] OrchestratorPropertyUpdateCallback ended [OrchestratorUpdateCallback] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: -> 06:25:00 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=10 | PAYLOAD_LEN: 27 | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: <- 06:25:00 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/res/204/?$rid=10&$version=13 | PAYLOAD_LEN: 0 | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:26:34.9131Z [I] Install succeeded [Install] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:26:34.9132Z [I] Action 'Install' complete. Result: 1, 0 [ADUC_Workflow_WorkCompletionCallback] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:26:34.9133Z [I] WorkCompletionCallback: Install succeeded. Going to state InstallSucceeded [ADUC_Workflow_WorkCompletionCallback] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:26:34.9133Z [I] Setting UpdateState to InstallSucceeded [ADUC_SetUpdateStateHelper] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: 2021-03-22T06:26:34.9133Z [I] Reporting state: InstallSucceeded (4) [AzureDeviceUpdateCoreInterface_ReportStateAndResultAsync] | |
| Mar 22 06:26:35 raspberrypi3 AducIotAgent[354]: -> 06:26:35 PUBLISH | IS_DUP: false | RETAIN: 0 | QOS: DELIVER_AT_MOST_ONCE | TOPIC_NAME: $iothub/twin/PATCH/properties/reported/?$rid=11 | PAYLOAD_LEN: 59 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment