From 1a9eb6e33dcbc7d01d9f210ff1d84df26c0e0347 Mon Sep 17 00:00:00 2001 From: John Lian Date: Tue, 7 Jul 2026 15:59:50 -0700 Subject: [PATCH 1/5] [TEMP investigation] Nested E2E: minimal RouteMessage repro + collect L4/L5 support bundles Not for merge. Two temporary changes to investigate the consistently-failing RouteMessageL3LeafToL4Module nested-e2e test (AMQP-only): 1. e2e-run.yaml: narrow the nestededge_amqp filter to the smallest set that reproduces the failure (Module + Metrics + IoTEdgeCheck + RouteMessage), derived from PR #7521's bisection (run 20260701.8 first-failing subset). 2. nested-e2e.yaml: add a Collect_Nested_Bundles job that captures support bundles + raw module logs from ALL levels (L3/L4/L5) after the test stage. The default pipeline only collects the L3 bundle, so the L4 relayer/edgeHub logs that explain the 4-minute store-and-forward stall are never captured. --- builds/e2e/nested-e2e.yaml | 44 +++++++++++++++++++++++++++++++ builds/e2e/templates/e2e-run.yaml | 4 +++ 2 files changed, 48 insertions(+) diff --git a/builds/e2e/nested-e2e.yaml b/builds/e2e/nested-e2e.yaml index eb82081e697..ffc17a90498 100644 --- a/builds/e2e/nested-e2e.yaml +++ b/builds/e2e/nested-e2e.yaml @@ -152,8 +152,52 @@ stages: - LockAgents - RunNestedTests jobs: + # TEMP (investigation, not for merge): capture support bundles from ALL levels (L3/L4/L5) + # after the test stage, so the L4/L5 edgeHub/relayer logs are available to debug + # RouteMessageL3LeafToL4Module. Runs before Clean_images so containers/logs still exist. + - job: Collect_Nested_Bundles + displayName: Collect nested support bundles + condition: always() + strategy: + matrix: + L3: + level: 3 + L4: + level: 4 + L5: + level: 5 + pool: + name: $(pool.name) + demands: + - agent-group -equals $(agent.group) + - Agent.OS -equals Linux + - Agent.OSArchitecture -equals X64 + - status -equals locked_$(Build.BuildId)_L$(level) + steps: + - bash: | + set +e + out="$(Build.ArtifactStagingDirectory)/nested-bundle-L$(level)" + mkdir -p "$out" + echo "Collecting support bundle on L$(level) ($(hostname))" + sudo iotedge support-bundle --output "$out/support_bundle_L$(level).zip" || echo "support-bundle failed on L$(level)" + # Also grab raw module logs as a fallback in case support-bundle errors + for m in edgeHub edgeAgent relayer1; do + sudo docker logs "$m" > "$out/$m-L$(level).log" 2>&1 || true + done + ls -la "$out" || true + displayName: 'Generate support bundle (L$(level))' + condition: always() + - task: PublishBuildArtifacts@1 + displayName: 'Publish nested bundle (L$(level))' + condition: always() + inputs: + PathtoPublish: '$(Build.ArtifactStagingDirectory)/nested-bundle-L$(level)' + ArtifactName: 'nested-support-bundles' + - job: Clean_images displayName: Clean up Docker images + dependsOn: Collect_Nested_Bundles + condition: always() strategy: matrix: L3: diff --git a/builds/e2e/templates/e2e-run.yaml b/builds/e2e/templates/e2e-run.yaml index 7426f3f347c..611b7787508 100644 --- a/builds/e2e/templates/e2e-run.yaml +++ b/builds/e2e/templates/e2e-run.yaml @@ -67,6 +67,10 @@ steps: # Below tests were disabled and marked for re-enable when a blocking item was resolved. # When it was resolved the tests were never enabled. We need to re-enable these. $filter += '&FullyQualifiedName!~Provisioning&FullyQualifiedName!~SasOutOfScope&FullyQualifiedName!~X509ManualProvision&FullyQualifiedName!~AuthorizationPolicyUpdateTest&FullyQualifiedName!~AuthorizationPolicyExplicitPolicyTest' + # TEMP (investigation, not for merge): narrow to the smallest set that reproduces + # RouteMessageL3LeafToL4Module. Metrics + IoTEdgeCheck must run before RouteMessage + # to provoke the AMQP upstream blip (derived from PR #7521 bisection, run 20260701.8). + $filter += '&(FullyQualifiedName~Microsoft.Azure.Devices.Edge.Test.Module|FullyQualifiedName~Microsoft.Azure.Devices.Edge.Test.Metrics|FullyQualifiedName~IoTEdgeCheck|FullyQualifiedName~RouteMessageL3LeafToL4Module)' } elseif ($test_type -eq 'nestededge_isa95') { From b67b480ab9d329d7bfddd0dd8f883f3e143f69e3 Mon Sep 17 00:00:00 2001 From: John Lian Date: Wed, 8 Jul 2026 12:16:36 -0700 Subject: [PATCH 2/5] Remove test filter to run full unperturbed suite (keep only L4/L5 bundle collection) The temporary category filter narrowed and reordered the nested suite, causing RouteMessage to run first before relayer1 was deployed on L4 (a different failure than the original 15s upstream blip). Revert the filter so the full suite runs with RouteMessage in its normal late position; keep only the Collect_Nested_Bundles job so L4/L5 evidence is captured without perturbing the test flow. --- builds/e2e/templates/e2e-run.yaml | 4 ---- 1 file changed, 4 deletions(-) diff --git a/builds/e2e/templates/e2e-run.yaml b/builds/e2e/templates/e2e-run.yaml index 611b7787508..7426f3f347c 100644 --- a/builds/e2e/templates/e2e-run.yaml +++ b/builds/e2e/templates/e2e-run.yaml @@ -67,10 +67,6 @@ steps: # Below tests were disabled and marked for re-enable when a blocking item was resolved. # When it was resolved the tests were never enabled. We need to re-enable these. $filter += '&FullyQualifiedName!~Provisioning&FullyQualifiedName!~SasOutOfScope&FullyQualifiedName!~X509ManualProvision&FullyQualifiedName!~AuthorizationPolicyUpdateTest&FullyQualifiedName!~AuthorizationPolicyExplicitPolicyTest' - # TEMP (investigation, not for merge): narrow to the smallest set that reproduces - # RouteMessageL3LeafToL4Module. Metrics + IoTEdgeCheck must run before RouteMessage - # to provoke the AMQP upstream blip (derived from PR #7521 bisection, run 20260701.8). - $filter += '&(FullyQualifiedName~Microsoft.Azure.Devices.Edge.Test.Module|FullyQualifiedName~Microsoft.Azure.Devices.Edge.Test.Metrics|FullyQualifiedName~IoTEdgeCheck|FullyQualifiedName~RouteMessageL3LeafToL4Module)' } elseif ($test_type -eq 'nestededge_isa95') { From ab62ebce0a04d963e27dcdab2a74be8ad7129dde Mon Sep 17 00:00:00 2001 From: John Lian Date: Wed, 8 Jul 2026 19:22:01 -0700 Subject: [PATCH 3/5] test: make leaf device identity creation idempotent for nested-e2e repro CreateDeviceIdentityAsync now deletes+recreates on DeviceAlreadyExists so an orphaned identity from a prior killed run doesn't block the RouteMessage repro. --- .../IotHub.cs | 14 +++++++++++++- 1 file changed, 13 insertions(+), 1 deletion(-) diff --git a/test/Microsoft.Azure.Devices.Edge.Test.Common/IotHub.cs b/test/Microsoft.Azure.Devices.Edge.Test.Common/IotHub.cs index 80b02d384ac..ec01cd88c1a 100644 --- a/test/Microsoft.Azure.Devices.Edge.Test.Common/IotHub.cs +++ b/test/Microsoft.Azure.Devices.Edge.Test.Common/IotHub.cs @@ -97,7 +97,19 @@ public Task GetDeviceIdentityAsync(string deviceId, CancellationToken to public async Task CreateDeviceIdentityAsync(Device device, CancellationToken token) { - return await this.RegistryManager.AddDeviceAsync(device, token); + try + { + return await this.RegistryManager.AddDeviceAsync(device, token); + } + catch (DeviceAlreadyExistsException) + { + // A prior test run can leave an orphaned identity behind (for example when the + // job is killed during artifact upload before cleanup runs). Remove the stale + // identity and recreate so the repro run isn't blocked by leftover state. + Log.Warning($"Device identity '{device.Id}' already exists; deleting orphaned identity and recreating."); + await this.RegistryManager.RemoveDeviceAsync(device.Id, token); + return await this.RegistryManager.AddDeviceAsync(device, token); + } } public async Task CreateEdgeDeviceIdentityAsync(string deviceId, Option parentDeviceId, AuthenticationType authType, X509Thumbprint x509Thumbprint, CancellationToken token) From 08529e0c465ecb11baf35be06329af78082fc333 Mon Sep 17 00:00:00 2001 From: John Lian Date: Thu, 9 Jul 2026 14:08:32 -0700 Subject: [PATCH 4/5] e2e: gate nested deploy on edgeAgent reconcile with diagnostic timeout Wait for edgeAgent to report the desired version reconciled (version match + lastDesiredStatus.code 200) after set-modules, before returning from the deploy step. Without this barrier tests can start while a parent layer is still reconciling (edgeHub restart), dropping a leaf's upstream link mid-test and causing the ~4min RouteMessageL3LeafToL4Module stall. On timeout, dump full lastDesiredStatus.description + reported module states and distinguish 'never picked up version' (agent/connectivity) from 'version matched but stuck non-200' (unhealthy module) so a genuine stuck reconcile is diagnosable from the pipeline log. Validated end-to-end on a standalone device (docpilot-iot-hub): guard correctly held through the edgeHub restart and released 10s after edgeHub came back up; confirmed the stale-200 and transient-500-during-restart cases are handled. --- .../e2e/templates/nested-deploy-config.yaml | 49 +++++++++++++++++++ 1 file changed, 49 insertions(+) diff --git a/builds/e2e/templates/nested-deploy-config.yaml b/builds/e2e/templates/nested-deploy-config.yaml index f31c37be9c2..5126b7ea6a7 100644 --- a/builds/e2e/templates/nested-deploy-config.yaml +++ b/builds/e2e/templates/nested-deploy-config.yaml @@ -47,3 +47,52 @@ steps: # 5/22/2024 - Temporary work around the issue where the az cli command cannot authorize itself within *.sh script using the service principal's service connection deployment_working_file="$(Agent.HomeDirectory)/../working/deployment.json" az iot edge set-modules --auth-type login --device-id "${{ parameters.deviceId }}" --hub-name "$(iotHubName)" --content ${deployment_working_file} --output none + + # Wait for the device's edgeAgent to finish reconciling this deployment before + # returning. set-modules only writes the desired twin; the device applies it + # asynchronously (which restarts edgeHub). Without this barrier the next test + # group can start while a parent is still reconciling, dropping a leaf's upstream + # link mid-test (see RouteMessageL3LeafToL4Module ~4min stall). Gate on edgeAgent's + # reported lastDesiredStatus.code == 200 (Success) for the desired version. + deviceId="${{ parameters.deviceId }}" + hubName="$(iotHubName)" + desiredVersion=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.desired."$version"' --output tsv) + echo "Waiting for edgeAgent on $deviceId to reconcile desired version $desiredVersion ..." + reconcileTimeoutSecs=300 + reconcilePollSecs=5 + elapsed=0 + while true; do + reportedVersion=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredVersion' --output tsv 2>/dev/null) + reportedCode=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredStatus.code' --output tsv 2>/dev/null) + echo " [$elapsed s] reported version=$reportedVersion status=$reportedCode (want version=$desiredVersion status=200)" + if [ "$reportedVersion" = "$desiredVersion" ] && [ "$reportedCode" = "200" ]; then + echo "edgeAgent on $deviceId reconciled desired version $desiredVersion successfully." + break + fi + if [ "$elapsed" -ge "$reconcileTimeoutSecs" ]; then + # Pull the full status description and reason so a stuck reconcile is diagnosable + # from the pipeline log instead of just a bare code. Two distinct failure modes: + # - reportedVersion never reached desiredVersion => edgeAgent never picked up the + # deployment (twin write lost, agent down, or hub connectivity issue). + # - reportedVersion matched but code stayed non-200 => deployment applied but a + # module is unhealthy (bad image ref, crash loop, pull failure). + reportedDescription=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredStatus.description' --output tsv 2>/dev/null) + echo "----- edgeAgent reconcile timeout diagnostics for $deviceId -----" + echo "desired version : $desiredVersion" + echo "reported version: $reportedVersion" + echo "reported status : $reportedCode" + echo "status detail : $reportedDescription" + if [ "$reportedVersion" != "$desiredVersion" ]; then + echo "diagnosis : edgeAgent never picked up desired version $desiredVersion (still on $reportedVersion) - check agent connectivity/liveness" + else + echo "diagnosis : deployment applied (version matched) but stuck at status $reportedCode - a module is likely unhealthy (bad image, crash loop, or pull failure)" + fi + echo "reported module states:" + az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.modules' --output json 2>/dev/null || true + echo "----------------------------------------------------------------" + echo "##vso[task.logissue type=error]edgeAgent on $deviceId did not reconcile desired version $desiredVersion within ${reconcileTimeoutSecs}s (last reported version=$reportedVersion status=$reportedCode: $reportedDescription)" + exit 1 + fi + sleep "$reconcilePollSecs" + elapsed=$((elapsed + reconcilePollSecs)) + done From a6df062a038b7164a7744defff00b5f3d7d6a66e Mon Sep 17 00:00:00 2001 From: John Lian Date: Mon, 13 Jul 2026 12:49:52 -0700 Subject: [PATCH 5/5] e2e: address review feedback on nested repro PR - Collapse the three per-poll 'az iot hub module-twin show' calls in the reconcile-wait loop into a single call. az emits the array query as three tsv lines (one per element), so read them into an array via mapfile rather than one 'az' call per field (fewer invocations / failure points per poll). Verified against a live edgeAgent twin. - Drop L3 from Collect_Nested_Bundles; the existing per-test teardown already publishes L3 support bundles, so only L4/L5 are new here. - Remove the 'TEMP (investigation, not for merge)' label now that the bundle-collection job is intended to stay. --- builds/e2e/nested-e2e.yaml | 10 ++++----- .../e2e/templates/nested-deploy-config.yaml | 22 ++++++++++++++----- 2 files changed, 22 insertions(+), 10 deletions(-) diff --git a/builds/e2e/nested-e2e.yaml b/builds/e2e/nested-e2e.yaml index ffc17a90498..0466f2a8325 100644 --- a/builds/e2e/nested-e2e.yaml +++ b/builds/e2e/nested-e2e.yaml @@ -152,16 +152,16 @@ stages: - LockAgents - RunNestedTests jobs: - # TEMP (investigation, not for merge): capture support bundles from ALL levels (L3/L4/L5) - # after the test stage, so the L4/L5 edgeHub/relayer logs are available to debug - # RouteMessageL3LeafToL4Module. Runs before Clean_images so containers/logs still exist. + # Capture support bundles from the upper nested levels (L4/L5) after the test stage, + # so the L4/L5 edgeHub/relayer logs are available to debug nested routing failures + # (for example RouteMessageL3LeafToL4Module). The existing per-test teardown already + # publishes L3, so L3 is intentionally omitted here. Runs before Clean_images so + # containers/logs still exist. - job: Collect_Nested_Bundles displayName: Collect nested support bundles condition: always() strategy: matrix: - L3: - level: 3 L4: level: 4 L5: diff --git a/builds/e2e/templates/nested-deploy-config.yaml b/builds/e2e/templates/nested-deploy-config.yaml index 5126b7ea6a7..5c18e842a0f 100644 --- a/builds/e2e/templates/nested-deploy-config.yaml +++ b/builds/e2e/templates/nested-deploy-config.yaml @@ -62,21 +62,33 @@ steps: reconcilePollSecs=5 elapsed=0 while true; do - reportedVersion=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredVersion' --output tsv 2>/dev/null) - reportedCode=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredStatus.code' --output tsv 2>/dev/null) + # Single twin read per poll: az emits the array query as three lines (one per + # element) with --output tsv, so read them into an array. Fewer az invocations + # than one call per field = fewer potential failure points per iteration. + mapfile -t twin < <( + az iot hub module-twin show \ + --auth-type login \ + --device-id "$deviceId" \ + --module-id '$edgeAgent' \ + --hub-name "$hubName" \ + --query '[properties.reported.lastDesiredVersion, properties.reported.lastDesiredStatus.code, properties.reported.lastDesiredStatus.description]' \ + --output tsv \ + 2>/dev/null + ) + reportedVersion="${twin[0]}" + reportedCode="${twin[1]}" + reportedDescription="${twin[2]}" echo " [$elapsed s] reported version=$reportedVersion status=$reportedCode (want version=$desiredVersion status=200)" if [ "$reportedVersion" = "$desiredVersion" ] && [ "$reportedCode" = "200" ]; then echo "edgeAgent on $deviceId reconciled desired version $desiredVersion successfully." break fi if [ "$elapsed" -ge "$reconcileTimeoutSecs" ]; then - # Pull the full status description and reason so a stuck reconcile is diagnosable - # from the pipeline log instead of just a bare code. Two distinct failure modes: + # Two distinct failure modes, both diagnosable from the values already read above: # - reportedVersion never reached desiredVersion => edgeAgent never picked up the # deployment (twin write lost, agent down, or hub connectivity issue). # - reportedVersion matched but code stayed non-200 => deployment applied but a # module is unhealthy (bad image ref, crash loop, pull failure). - reportedDescription=$(az iot hub module-twin show --auth-type login --device-id "$deviceId" --module-id '$edgeAgent' --hub-name "$hubName" --query 'properties.reported.lastDesiredStatus.description' --output tsv 2>/dev/null) echo "----- edgeAgent reconcile timeout diagnostics for $deviceId -----" echo "desired version : $desiredVersion" echo "reported version: $reportedVersion"