Adu-agent 1.1.0 failed to process PPR base deployment string

[GauravChoube]

I am facing the problem when device with version 0.8.1 or lower get update to latest adu-agent[1.1.0].

Found the problem in deployment string missing with parameter of 'rootkeypackage' url.
As this parameter mandatory for latest agent which get fail to report completion of deployment from PPR to GA.

Below is logs clearly showing error 0x80300011

Oct 1 15:55:13 vetscan AducIotAgent[5027]: 2024-10-01T15:55:13.6316Z 5027[5027] [I] ADU-Custom: Main : workflow.action: 3 [ADUC_PnP_ComponentClient_PropertyUpdate_Callback:559] Oct 1 15:55:13 vetscan AducIotAgent[5027]: 2024-10-01T15:55:13.6318Z 5027[5027] [I] ADU-Custom: OTAhealthcheck : Version[2024.10.1] not found [Is_entry_OTAHealthCheckup_File:389] Oct 1 15:55:13 vetscan AducIotAgent[5027]: 2024-10-01T15:55:13.6320Z 5027[5027] [D] Update Action info string ({"workflow":{"action":3,"id":"1aac00a9-ab06-4987-a73a-77832ceecce7"},"updateManifest":"{\"manifestVersion\":\"5\",\"updateId\":{\"provider\":\"Zoetis\",\"name\":\"Hub\",\"version\":\"2024.10.1\"},\"compatibility\":[{\"manufacturer\":\"Zoetis\",\"model\":\"Hub\"}],\"instructions\":{\"steps\":[{\"type\":\"reference\",\"detachedManifestFileId\":\"f09eaaf591e5c2d10\"},{\"type\":\"reference\",\"detachedManifestFileId\":\"fe2e28d7b8449c3f7\"}]},\"files\":{\"f09eaaf591e5c2d10\":{\"fileName\":\"zoetis.vetscan-hub.1.3.0.1727787352.updatemanifest5.json\",\"sizeInBytes\":1004,\"hashes\":{\"sha256\":\"d45tzDljvS5mD68fGS2309NXNikG\/5XbyXJG0XpcJkc=\"}},\"fe2e28d7b8449c3f7\":{\"fileName\":\"zoetis.vetscan-opticell.1.1.2.1727787352.updatemanifest5.json\",\"sizeInBytes\":1037,\"hashes\":{\"sha256\":\"FoQP8k+Ddl0+COOvOfxPcgVqjt4MQ6dOggEzWt8eRbE=\"}}},\"createdDateTime\":\"2024-09-30T12:57:59Z\"}","updateManifestSignature":null,"fileUrls":null}), property version (3) [OrchestratorUpdateCallback:433] Oct 1 15:55:13 vetscan AducIotAgent[5027]: 2024-10-01T15:55:13.6322Z 5027[5027] [E] Parse failed for unprotected properties, erc: 0x80300011[OrchestratorUpdateCallback:439] Oct 1 15:55:13 vetscan AducIotAgent[5027]: 2024-10-01T15:55:13.6323Z 5027[5027] [I] OrchestratorPropertyUpdateCallback ended [OrchestratorUpdateCallback:537]

Step to recreate

1. Install agent with 0.8.1 on device
2. Create deployment with latest agent 1.1.0[in my case]
3. Trigger deployment and wait till get completed
4. After restart device, update to latest code, above error will be generated

Note: I am using script handler type update to install firmware file into partition.

[jw-msft]

That error is ADUC_ERC_UTILITIES_UPDATE_DATA_PARSER_EMPTY_OR_MISSING_ROOTKEY_PKG_URL

iot-hub-device-update/src/inc/aduc/result.h

Line 1665 in b96895b

* @brief ADUC_ERC_UTILITIES_UPDATE_DATA_PARSER_EMPTY_OR_MISSING_ROOTKEY_PKG_URL, ERC Value: 2150629393 (0x80300011)

That extended result code (ERC) is set when the "rootkeyPackageUrl" JSON Property is empty or missing in the C2D message(Cloud to Device) as can be seen here:

iot-hub-device-update/src/utils/workflow_utils/src/workflow_utils.c

Line 770 in b96895b

result.ExtendedResultCode = ADUC_ERC_UTILITIES_UPDATE_DATA_PARSER_EMPTY_OR_MISSING_ROOTKEY_PKG_URL;

The C2D message is clearly missing the "rootkeyPackageUrl" property, which should not occur.

'''json
{
"workflow": {
"action": 3,
"id": "1aac00a9-ab06-4987-a73a-77832ceecce7"
},
"updateManifest": "{"manifestVersion":"5","updateId":{"provider":"Zoetis","name":"Hub","version":"2024.10.1"},"compatibility":[{"manufacturer":"Zoetis","model":"Hub"}],"instructions":{"steps":[{"type":"reference","detachedManifestFileId":"f09eaaf591e5c2d10"},{"type":"reference","detachedManifestFileId":"fe2e28d7b8449c3f7"}]},"files":{"f09eaaf591e5c2d10":{"fileName":"zoetis.vetscan-hub.1.3.0.1727787352.updatemanifest5.json","sizeInBytes":1004,"hashes":{"sha256":"d45tzDljvS5mD68fGS2309NXNikG/5XbyXJG0XpcJkc="}},"fe2e28d7b8449c3f7":{"fileName":"zoetis.vetscan-opticell.1.1.2.1727787352.updatemanifest5.json","sizeInBytes":1037,"hashes":{"sha256":"FoQP8k+Ddl0+COOvOfxPcgVqjt4MQ6dOggEzWt8eRbE="}}},"createdDateTime":"2024-09-30T12:57:59Z"}",
"updateManifestSignature": null,
"fileUrls": null
}

@GauravChoube Could you confirm which endpoint URL it is hitting after having updated to 1.1.0 from the du agent logs or via a packet sniffer, or can provide the logs?


@josephmsft or @xinanqiu 
Would you be able to determine why the `"rootkeyPackageUrl"` property is missing for the request when 2 detached manifests are present in C2D message? Also, why are there 2 detached update manifests in the "updateManifest" ?

[xinanqiu]

@GauravChoube, could you please share the twin of your agent?

[GauravChoube]

@jw-msft
As i mentioned above we have been upgrading from devices runnning with adu version( 0.8.x or below) to adu with version 1.1.0.
We have some mechanism to do this job where we put all device those running with PPR version( 0.8.x or below) into one group, let say name PPR-Group. But we also have device running with GA version(1.0.0) which put into GA-Group.
Our device are connected with some not internet sub-device , we are using multi-manifest deployment OTA update where one manifest for self device and another manifest for connect sub-devce , this is reason for 2 detached manifests.

We created new deployment for PPR-Group as well as GA-Group and which mean both group has different deployment OTA with same firmware version but targeting devices are different.

@GauravChoube Could you confirm which endpoint URL it is hitting after having updated to 1.1.0 from the du agent logs or via a packet sniffer, or can provide the logs?
I not sure about endpoint url, what are you looking here.

@xinanqiu
i am afraid that i dont have twins for that device.

[xinanqiu]

@GauravChoube, which model id did the agent report to? If you don't know about it, could you please share me ADU account & instance id and the test device id?

[eshashah-msft]

Hi @GauravChoube,
can you please confirm if this issue is still persisting for you? And if you can capture the device twin, model twin from the twin, when the issue repros for future investigation?

[GauravChoube]

@eshashah-msft
Yes, issue is still there.
I will try to recreate and update the same.

[GauravChoube]

@eshashah-msft @jw-msft
Attaching the details after recreating the issue.

0.8.1

1. Device running with ppr version 0.8.1 and got trigger of OTA where Adu version is 1.1.0
   

2. Device twins updated with device information
   

3. Received the deployment string as single file update[ we are using script handler]
   

4. Adu-agent completed download, install , apply action and started rebooting
   

1.1.0

5. Device start with new firmware with adu-agent version 1.1.0 and DPS connected
   

6. Updated twins
   

7. Received the PPR Deployment string again. Its get failed while parsing as throw below error
   Nov 20 09:39:39 vetscan AducIotAgent[5174]: 2024-11-20T09:39:39.2306Z 5174[5174] [D] Update Action info string ({"workflow":{"action":3,"id":"3b417eed-d282-40ba-b7a9-80217a13fca3"},"updateManifest":"{\"manifestVersion\":\"4\",\"updateId\":{\"provider\":\"Zoetis\",\"name\":\"Hub\",\"version\":\"1111.4.16\"},\"compatibility\":[{\"deviceManufacturer\":\"Zoetis\",\"deviceModel\":\"Hub\"}],\"instructions\":{\"steps\":[{\"handler\":\"microsoft\/script:1\",\"files\":[\"fe075ff2477f9b863\"],\"handlerProperties\":{\"scriptFileName\":\"master_script.sh\",\"arguments\":\"--firmware-file vetscan-hub_1111.4.16 --restart-to-apply --component-name --component-name-val --component-group --component-group-val --component-prop path --component-prop-val path\",\"installedCriteria\":\"1111.4.16\"}}]},\"files\":{\"fe075ff2477f9b863\":{\"fileName\":\"vetscan-hub_1111.4.16.tar.gz.aes\",\"sizeInBytes\":1112691312,\"hashes\":{\"sha256\":\"G5hR+KmjhJbqNpmhuYEQ0OrKlh+WwcCZp2j3dLL3Rpg=\"}}},\"createdDateTime\":\"2024-11-15T14:56:46Z\"}","updateManifestSignature":null,"fileUrls":null}), property version (4) [OrchestratorUpdateCallback:439] Nov 20 09:39:39 vetscan AducIotAgent[5174]: 2024-11-20T09:39:39.2322Z 5174[5174] [E] Parse failed for unprotected properties, erc: 0x80300011 [OrchestratorUpdateCallback:445] Nov 20 09:39:39 vetscan AducIotAgent[5174]: 2024-11-20T09:39:39.2708Z 5174[5174] [E] Manifest signature validation failed with result: 'InvalidRootKid' (7). ERC: ADUC_COMPONENT_JWS_UPDATE_MANIFEST_VALIDATION [workflow_validate_update_manifest_signature:932] Nov 20 09:39:39 vetscan AducIotAgent[5174]: 2024-11-20T09:39:39.2710Z 5174[5174] [E] Failed to init workflow handle. result:0 (erc:0xF0200007) [workflow_init:2899]
   

Below screenshot of twins after upgrade to 1.1.0

{
  "deviceId": "M309WESA0C",
  "etag": "AAAAAAAAAAc=",
  "deviceEtag": "NDY1OTY0Njgw",
  "status": "enabled",
  "statusUpdateTime": "0001-01-01T00:00:00Z",
  "connectionState": "Connected",
  "lastActivityTime": "2024-11-20T09:39:40.0512126Z",
  "cloudToDeviceMessageCount": 0,
  "authenticationType": "sas",
  "x509Thumbprint": {
    "primaryThumbprint": null,
    "secondaryThumbprint": null
  },
  "modelId": "dtmi:azure:iot:deviceUpdateModel;3",
  "version": 66,
  "tags": {
    "ADUGroup": "GA-Group"
  },
  "properties": {
    "desired": {
      "deviceUpdate": {
        "__t": "c"
      },
      "$metadata": {
        "$lastUpdated": "2024-11-20T09:39:50.2938336Z",
        "$lastUpdatedVersion": 6,
        "deviceUpdate": {
          "$lastUpdated": "2024-11-20T09:39:50.2938336Z",
          "$lastUpdatedVersion": 6,
          "__t": {
            "$lastUpdated": "2024-11-20T09:39:50.2938336Z",
            "$lastUpdatedVersion": 6
          }
        }
      },
      "$version": 6
    },
    "reported": {
      "deviceInformation": {
        "__t": "c",
        "manufacturer": "Zoetis",
        "model": "Hub",
        "osName": "Debian GNU/Linux",
        "swVersion": "12 (bookworm)",
        "processorArchitecture": "x86_64",
        "processorManufacturer": "GenuineIntel",
        "totalMemory": 7966704,
        "totalStorage": 38137396,
        "hubVersion": "1111.4.16"
      },
      "deviceUpdate": {
        "__t": "c",
        "agent": {
          "deviceProperties": {
            "manufacturer": "Zoetis",
            "model": "Hub",
            "contractModelId": "dtmi:azure:iot:deviceUpdateContractModel;3",
            "aduVer": "DU;agent/1.1.0",
            "doVer": "DU;lib/v0.7.0+20220726.155753,DU;agent/v0.7.0+20220726.155459,DU;plugin-apt/v0.5.0+20220726.160208"
          },
          "compatPropertyNames": "manufacturer,model",
          "lastInstallResult": {
            "resultCode": 0,
            "extendedResultCode": 0,
            "extendedResultCodes": "80300000"
          },
          "state": 255,
          "workflow": {
            "action": 3,
            "id": "3b417eed-d282-40ba-b7a9-80217a13fca3"
          }
        },
        "service": {
          "value": {
            "workflow": {
              "action": 3,
              "id": "3b417eed-d282-40ba-b7a9-80217a13fca3"
            },
            "updateManifest": "{\"manifestVersion\":\"4\",\"updateId\":{\"provider\":\"Zoetis\",\"name\":\"Hub\",\"version\":\"1111.4.16\"},\"compatibility\":[{\"deviceManufacturer\":\"Zoetis\",\"deviceModel\":\"Hub\"}],\"instructions\":{\"steps\":[{\"handler\":\"microsoft/script:1\",\"files\":[\"fe075ff2477f9b863\"],\"handlerProperties\":{\"scriptFileName\":\"master_script.sh\",\"arguments\":\"--firmware-file vetscan-hub_1111.4.16 --restart-to-apply --component-name --component-name-val --component-group --component-group-val --component-prop path --component-prop-val path\",\"installedCriteria\":\"1111.4.16\"}}]},\"files\":{\"fe075ff2477f9b863\":{\"fileName\":\"vetscan-hub_1111.4.16.tar.gz.aes\",\"sizeInBytes\":1112691312,\"hashes\":{\"sha256\":\"G5hR+KmjhJbqNpmhuYEQ0OrKlh+WwcCZp2j3dLL3Rpg=\"}}},\"createdDateTime\":\"2024-11-15T14:56:46Z\"}"
          },
          "ac": 200,
          "ad": "",
          "av": 4
        }
      },
      "customStatus": {
        "OTA": "DOWNLOAD_STARTED"
      },
      "$metadata": {
        "$lastUpdated": "2024-11-20T09:40:09.1960719Z",
        "deviceInformation": {
          "$lastUpdated": "2024-11-20T09:39:39.8257493Z",
          "__t": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "manufacturer": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "model": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "osName": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "swVersion": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "processorArchitecture": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "processorManufacturer": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "totalMemory": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "totalStorage": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          },
          "hubVersion": {
            "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
          }
        },
        "deviceUpdate": {
          "$lastUpdated": "2024-11-20T09:39:40.8891479Z",
          "__t": {
            "$lastUpdated": "2024-11-20T09:39:40.8891479Z"
          },
          "agent": {
            "$lastUpdated": "2024-11-20T09:39:40.8891479Z",
            "deviceProperties": {
              "$lastUpdated": "2024-11-20T09:39:39.8257493Z",
              "manufacturer": {
                "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
              },
              "model": {
                "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
              },
              "contractModelId": {
                "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
              },
              "aduVer": {
                "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
              },
              "doVer": {
                "$lastUpdated": "2024-11-20T09:23:02.8781982Z"
              }
            },
            "compatPropertyNames": {
              "$lastUpdated": "2024-11-20T09:39:39.8257493Z"
            },
            "lastInstallResult": {
              "$lastUpdated": "2024-11-20T09:39:40.8891479Z",
              "resultCode": {
                "$lastUpdated": "2024-11-20T09:39:40.8891479Z"
              },
              "extendedResultCode": {
                "$lastUpdated": "2024-11-20T09:26:08.0177128Z"
              },
              "extendedResultCodes": {
                "$lastUpdated": "2024-11-20T09:39:40.8891479Z"
              }
            },
            "state": {
              "$lastUpdated": "2024-11-20T09:39:40.8891479Z"
            },
            "workflow": {
              "$lastUpdated": "2024-11-20T09:26:08.0177128Z",
              "action": {
                "$lastUpdated": "2024-11-20T09:26:08.0177128Z"
              },
              "id": {
                "$lastUpdated": "2024-11-20T09:26:08.0177128Z"
              }
            }
          },
          "service": {
            "$lastUpdated": "2024-11-20T09:39:39.7476139Z",
            "value": {
              "$lastUpdated": "2024-11-20T09:39:39.7476139Z",
              "workflow": {
                "$lastUpdated": "2024-11-20T09:39:39.7476139Z",
                "action": {
                  "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
                },
                "id": {
                  "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
                }
              },
              "updateManifest": {
                "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
              }
            },
            "ac": {
              "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
            },
            "ad": {
              "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
            },
            "av": {
              "$lastUpdated": "2024-11-20T09:39:39.7476139Z"
            }
          }
        },
        "customStatus": {
          "$lastUpdated": "2024-11-20T09:26:09.0177907Z",
          "OTA": {
            "$lastUpdated": "2024-11-20T09:26:09.0177907Z"
          }
        }
      },
      "$version": 59
    }
  },
  "configurations": {
    "adu-3b417eed-d282-40ba-b7a9-80217a13fca3-38e7f11d1afbf8adf220d5f9be00a476c2c893cd": {
      "status": "Applied"
    },
    "adu-nodeployment": {
      "status": "Applied"
    }
  },
  "capabilities": {
    "iotEdge": false
  }
}

[eshashah-msft]

Hi @xinanqiu, can you take a look at the issue above and deployment sent to the 1.1.0 device?

[jw-msft]

The 1.1.0 agent unlike previous versions requires the "rootkeyPackageUrl" to be in the C2D message alongside the "workflow" and "updateManifest" / "UpdateManifestSignature / "fileUrles" top-level properties (see the code search here), but it looks like the service may not be providing it in the C2D message pushed to the device agent.

It is catching the error on this line:

iot-hub-device-update/src/agent/adu_core_interface/src/adu_core_interface.c

Line 378 in 18e98a9

Log_Error("Parse failed for unprotected properties, erc: 0x%08x", tmpResult.ExtendedResultCode);

Based on data provided, it is getting:

Manifest signature validation failed with result: 'InvalidRootKid' (7). ERC: ADUC_COMPONENT_JWS_UPDATE_MANIFEST_VALIDATION 

This corresponds to this line in the JWSResult VerifySJWK(const char* sjwk) function where it is verifying the Signed JSON Web Key:

iot-hub-device-update/src/utils/jws_utils/src/jws_utils.c

Line 360 in 18e98a9

retval = JWSResult_InvalidRootKid;

and it's failing for reasons other than:

• ADUC_ERC_UTILITIES_ROOTKEYUTIL_SIGNING_ROOTKEY_IS_DISABLED
• or ADUC_ERC_UTILITIES_ROOTKEYUTIL_NO_ROOTKEY_FOUND_FOR_KEYID

which means it is failing when loading the rootkey store from disk:

iot-hub-device-update/src/utils/root_key_utils/src/root_key_util.c

Line 723 in 18e98a9

RootKeyUtility_LoadPackageFromDisk(&s_localStore, rootKeyStorePath, true /* validateSignatures */);

specifically at this line:

iot-hub-device-update/src/utils/root_key_utils/src/root_key_util.c

Line 727 in 18e98a9

result = loadResult;

Unfortunately, it is not logging the details about the loading, parsing, verification of rootkey package integrity in

iot-hub-device-update/src/utils/root_key_utils/src/root_key_util.c

Line 503 in 18e98a9

ADUC_Result RootKeyUtility_LoadPackageFromDisk(

so it is hard to know what went wrong specifically.

Action Items

1. I will send a PR to add additional logging to help with future troubleshooting.
2. @xinanqiu, Could you provide the latest or expected rootkey package url that should have been included in the C2D message? Then, we can run validation code against it to see if it is issue with rootkey package or not.

Note: I did not see "rootkeyPackageUrl" in the C2D message logged, but I am assuming it was there since otherwise it would have failed earlier with:

iot-hub-device-update/src/utils/workflow_utils/src/workflow_utils.c

Line 770 in 18e98a9

result.ExtendedResultCode = ADUC_ERC_UTILITIES_UPDATE_DATA_PARSER_EMPTY_OR_MISSING_ROOTKEY_PKG_URL;

[jw-msft]

Added more logging with PR: #676