Skip to content

e2e: fix RouteMessageL3LeafToL4Module by waiting for nested deployment reconcile - #7523

Merged
kodiakhq[bot] merged 6 commits into
mainfrom
jlian/nested-e2e-l4-repro
Jul 14, 2026
Merged

e2e: fix RouteMessageL3LeafToL4Module by waiting for nested deployment reconcile#7523
kodiakhq[bot] merged 6 commits into
mainfrom
jlian/nested-e2e-l4-repro

Conversation

@jlian

@jlian jlian commented Jul 7, 2026

Copy link
Copy Markdown
Member

Summary

Fixes the consistently failing RouteMessageL3LeafToL4Module nested end-to-end test. The failure is a test race: the AMQP test group starts before the L4/L5 deployment has finished reconciling, so the L4 edgeHub restart triggered by that deployment lands in the middle of the test.

The core change is a reconcile-wait guard after set-modules. It also keeps two supporting changes that made the failure debuggable and the repro reliable.

Root cause

The RouteMessageL3LeafToL4Module timeout is caused by a missing synchronization step in the test pipeline, not by a network fault.

After the MQTT tests, the pipeline calls az iot edge set-modules for L5 and L4 and then starts the AMQP tests immediately. set-modules only updates the desired twin; it does not wait for edgeAgent to apply the deployment. The L4 deployment changes the upstream protocol, edgeHub configuration/routes, and modules, so L4 edgeHub restarts after the AMQP tests have already started. L3 loses its parent connection for about 15 seconds during that restart, and the in-flight device-to-module message is delayed long enough to miss the test's 300-second receive window.

Verified in run 171488751: L3 lost its parent at 03:11:37.193 and reconnected at 03:11:52.212, a 15.018-second outage coinciding with the L4 edgeHub restart. The iotedgeApiProxy / IoTEdgeAPIProxy casing difference between the MQTT and AMQP deployment files adds reconciliation churn, but it is not the complete cause; any deployment change that restarts edgeHub would expose the same missing wait. Normalizing the casing is not the fix.

RouteMessageL3LeafToL4Module is the second AMQP test. The first, QuickstartCerts, runs immediately after set-modules and acts as an unintended buffer while the L4 reconcile completes in the background. Whether RouteMessage passes comes down to a race between that buffer and the L4 reconcile/edgeHub-restart, both of which vary run to run depending on the test agents' state (for example how long modules take to reach the running state, which depends on image-cache warmth). This is why the test is timing-sensitive rather than deterministically broken.

Is this masking a 1.6 product regression?

No. This was the first thing we checked, since the test began failing around the 1.6 timeframe and a test-only fix would be wrong if it hid a product regression. The decisive evidence is a controlled comparison of the same binary and commit run at different times:

Test Run Date Commit / CI artifact Pre-RouteMessage buffer RouteMessage
20260529.1 2026-05-29 b3531a737 / 20260528.1 78.6s pass, 21.7s
20260710.12 2026-07-10 b3531a737 / 20260528.1 33.1s timeout, 300s

Identical bits, identical commit, identical parameters, clean identity namespace: it passed in May and times out today. A binary cannot regress against itself, so the change is environmental/timing (the buffer shrank relative to the reconcile), not a code regression in 1.6.

Supporting data across a range of runs (all AMQP full-suite, on main unless noted):

Build Date Commit / CI artifact Buffer RouteMessage result
161293998 04-22 621ff98b / 20260420.1 30.4s pass 29.5s
162168027 04-29 621ff98b / 20260427.1 30.3s pass 29.5s
166045060 05-29 b3531a737 / 20260528.1 78.6s pass 21.7s
170483773 07-01 36d6c426 / 20260629.1 48.1s timeout 300s
171767938 07-10 36d6c426 / 20260706.1 58.2s timeout 300s
171795768 07-10 b3531a737 / 20260528.1 33.1s timeout 300s

The outcome does not track a clean buffer threshold (April passed with a 30s buffer; a July run timed out with a 58s buffer), which is expected for a race where both the buffer and the concurrent reconcile time vary. The point the table establishes is narrower and solid: a known-good pre-1.6 binary that passed now times out, so the recent failures are timing/environmental, not a 1.6 product regression.

The guard removes the dependency on that accidental buffer entirely by waiting for the actual reconcile, so it is the correct fix regardless of the exact timing.

Some earlier runs (for example 166823784, 06-04) failed fast on DeviceAlreadyExists from a leaf identity orphaned by a prior aborted run, a separate issue addressed by the idempotent-identity change below, not the timeout this PR targets.

Separate, out-of-scope product improvement

A ~15s parent restart can strand an in-flight message for minutes because the edgeHub SDK connection-status callback is disabled and edgeHub falls back to slow connectivity polling. That is a genuine product improvement, tracked separately as Fix B in #7527, and is out of scope here. This PR fixes the test race that makes the failure reproduce in CI.

Changes

  1. Reconcile-wait guard (the fix). Adds a guard to the shared nested-deploy-config.yaml template, applied to L5 then L4. After set-modules, it reads the desired edgeAgent $version and polls reported.lastDesiredVersion plus lastDesiredStatus.code, continuing only when the exact desired version reports status 200. On a 300-second timeout it prints lastDesiredStatus.description and reported module states so the two failure modes (deploy never picked up vs picked up but reported non-200) are distinguishable from the pipeline log.

  2. Collect L4/L5 support bundles. Adds Collect_Nested_Bundles to publish support bundles and raw module logs from L3, L4, and L5. The existing pipeline only preserved L3 evidence, which is why the parent (L4) edgeHub restart was invisible in earlier investigations. Kept because per-level evidence is broadly useful for nested-edge test debugging.

  3. Idempotent leaf-identity creation. Deletes and recreates a leaf device identity orphaned when a prior run dies before teardown (the pipeline's identity cleanup only removes the L4/L5 parent devices, not the test-created leaf). Prevents a spurious DeviceAlreadyExistsException on the shared hub.

Validation

Build Harness RouteMessage
171795530 with guard pass 26.8s (full AMQP suite 25/25)
171618229 with guard pass 21.7s (full AMQP suite 25/25)
171795768 no guard timeout 300s

With the guard, RouteMessage runs only after the L4/L5 deployment has reconciled, so the edgeHub restart no longer lands mid-test.

jlian added 4 commits July 7, 2026 15:59
… 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.
…dle 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.
CreateDeviceIdentityAsync now deletes+recreates on DeviceAlreadyExists so an
orphaned identity from a prior killed run doesn't block the RouteMessage repro.
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.
@jlian jlian changed the title [TEMP investigation, do not merge] Nested E2E: minimal RouteMessage repro + collect L4/L5 support bundles e2e: fix RouteMessageL3LeafToL4Module by waiting for nested deployment reconcile Jul 11, 2026
@jlian
jlian marked this pull request as ready for review July 11, 2026 05:07
@jlian
jlian requested a review from damonbarry July 11, 2026 05:07
Comment thread builds/e2e/templates/nested-deploy-config.yaml Outdated
Comment thread builds/e2e/nested-e2e.yaml Outdated
Comment thread builds/e2e/nested-e2e.yaml Outdated
- 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.
@jlian
jlian force-pushed the jlian/nested-e2e-l4-repro branch from 1fdfbce to a6df062 Compare July 13, 2026 19:54
@jlian

jlian commented Jul 14, 2026

Copy link
Copy Markdown
Member Author

Closing and reopening to try to trigger the license check

@jlian jlian closed this Jul 14, 2026
@jlian jlian reopened this Jul 14, 2026
@kodiakhq
kodiakhq Bot merged commit fbc5c7b into main Jul 14, 2026
15 checks passed
@kodiakhq
kodiakhq Bot deleted the jlian/nested-e2e-l4-repro branch July 14, 2026 19:13
kodiakhq Bot pushed a commit that referenced this pull request Jul 20, 2026
This update cherry-picks changes to build/test code from main:
- b3531a7 Fix docker host mismatch (#7506)
- e6d15bf [PARTIAL] Address PR comments in end-to-end tests (#7518)
- c29aabe Use Ubuntu 24.04 artifacts in ARM64 ISA95 smoke tests (#7519)
- fbc5c7b e2e: fix RouteMessageL3LeafToL4Module by waiting for nested deployment reconcile (#7523)
- 33a21bb Increase cleanup timeouts in nested end-to-end pipeline (#7531)
- 314983e [PARTIAL] Prepare for release 1.6.0 (#7530)

Confirmed the following pipelines pass:
- [x] CI Build
- [x] End-to-end tests
- [x] Nested end-to-end tests
- [x] ISA95 smoke tests
- [x] Service deployment tests

## Azure IoT Edge PR checklist:
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants