Skip to content

fix: race between probe-pod TTL GC and _wait_for_probe_pod poll - #2700

Merged
jwbron merged 3 commits into
mainfrom
egg/integration-test-default-timeout-90
May 13, 2026
Merged

fix: race between probe-pod TTL GC and _wait_for_probe_pod poll#2700
jwbron merged 3 commits into
mainfrom
egg/integration-test-default-timeout-90

Conversation

@jwbron

@jwbron jwbron commented May 13, 2026

Copy link
Copy Markdown
Owner

Summary

Two flake fixes for validate-network-isolation integration tests:

1. Probe-pod TTL race (root cause of #2700's first red CI)

test_probe_runs_and_returns_expected_shape intermittently saw the route return the probe_timeout shape instead of the happy-path result. The probe Job set ttlSecondsAfterFinished=0, which races _wait_for_probe_pod's 1Hz poll:

  1. Probe pod completes → phase=Succeeded (or Failed via activeDeadlineSeconds)
  2. Job marked Complete → ttlSecondsAfterFinished=0 → TTL controller cascade-deletes the Job/pod within milliseconds
  3. Wait loop's next 1s poll finds no pods matching the selector (not "Failed")
  4. Loop never observes a terminal phase → keeps polling until 75s ceiling → returns probe_timeout

Evidence from Actions run 25817353877:

  • Orchestrator log durations were bimodal: 9-12s (happy path) or 75-76s (full ceiling), no middle ground.
  • The route's finally _delete_probe_job got 404 on the hung calls: "(404) Reason: Not Found" — the Job was already gone, GC'd by ttl=0.
  • The pod's k8s events stop at Started; no DeadlineExceeded, no Killing — the pod completed normally and was reaped before the poll observed it.

Fix: bump ttlSecondsAfterFinished from 0 to 30. The route's try/finally remains the primary cleanup path; 30s is the backstop that guarantees both:

  • _wait_for_probe_pod sees the terminal phase before GC
  • _read_probe_log can still read the pod's stdout after _wait_for_probe_pod returns

2. _post() helper default timeout (60s90s)

PR #2699 raised the route's _wait_for_probe_pod from 30s → 75s. The integration helper _post() still defaulted to timeout=60, leaving any test that proceeds past the CNI gate (valid labels → probe launches) structurally underweight against the route's 75s ceiling.

Surfaced by #2689 comment 4443847011. test_pipeline_id_regex_valid_at_boundaries_pass had the same latent bug across 4 parametrize cases. 90s matches the explicit timeout=90 already used in test_probe_runs_and_returns_expected_shape, the concurrency test, and the JSON-validity test.

Files

  • orchestrator/routes/deployment.pyttlSecondsAfterFinished 0 → 30 with explanatory comment
  • orchestrator/tests/test_deployment_routes.py — matching unit-test assertion
  • orchestrator/mcp_tools.py — tool description text
  • integration_tests/test_deployment_validation_logic.py_post() default timeout 60 → 90; TestProbeJobCleanup docstring + failure message updated to reference ttl=30

Test plan

  • Integration Tests / Integration Tests job passes (the run that revealed Phase 1: Repository setup and CI infrastructure #2 still passing on the rerun).
  • test_probe_runs_and_returns_expected_shape consistently observes the terminal phase (no more bimodal hangs).
  • test_no_orphan_probe_jobs_after_call still passes — the route's explicit finally cleanup runs before the test polls, so ttl=30 is invisible to it on the happy path.
  • test_default_pipeline_id_and_role_pass_label_validation and test_pipeline_id_regex_valid_at_boundaries_pass (4 parametrize cases) pass with the bumped default _post() timeout.

Closes

This PR root-causes the probe hang that was opened as #2701; that issue can be closed when this lands.

…on probe path

PR #2699 raised the route's probe-pod wait to 75s, leaving the
_post() helper's 60s default too tight for any test that proceeds
past the CNI gate (probe launches → wait can approach the route's
75s ceiling).

Surfaced by #2689 comment 4443847011:
test_default_pipeline_id_and_role_pass_label_validation hit a 60s
read-timeout while the sibling test_probe_runs_and_returns_expected_shape
ran 10s later and passed with its explicit timeout=90.

test_pipeline_id_regex_valid_at_boundaries_pass has the same latent
bug (4 parametrize cases of valid labels that launch the probe with
the default 60s).

Bumping the default to 90s matches the explicit timeout already used
in test_probe_runs_and_returns_expected_shape, the concurrency test,
and the JSON-validity test, and sits at the route's 90s HTTP-timeout
ceiling. 400-path tests (label rejections) return fast and are
unaffected.
@james-in-a-box

This comment has been minimized.

@james-in-a-box

Copy link
Copy Markdown
Contributor

Check Failure: Integration Tests / Integration Tests

What's failing: test_probe_runs_and_returns_expected_shape — the route returned the probe_timeout shape ({'error': 'probe_timeout', 'probe_id': 'dcb7da2be765'}), tripping the explicit pytest.fail(...) at integration_tests/test_deployment_validation_logic.py:447.

Root cause: This is the same _wait_for_probe_pod timeout #2699 was meant to address. The route's internal probe wait is currently 75.0s at orchestrator/routes/deployment.py:1273. On this run the k3s probe pod again exceeded that budget, so the route returned the probe_timeout envelope before the probe completed. Pre-existing flake, not caused by this PR.

Why this PR doesn't fix it: This PR only changes the test-side default _post() timeout (60s → 90s). The failing test already passes timeout=90 explicitly at integration_tests/test_deployment_validation_logic.py:437, so the diff is a no-op for this case. The failure is on the route's k3s wait, not on the HTTP client timeout.

Evidence it's a flake, not a PR-introduced regression:

  • 376 passed / 1 failed / 24 skipped.
  • Sibling test_default_pipeline_id_and_role_pass_label_validation (the exact test this PR's bump is meant to fix) passed at the new 90s default.
  • The 4 parametrize cases of test_pipeline_id_regex_valid_at_boundaries_pass also passed.
  • Another branch (egg/issue-2629-push-after-populate-contract) passed integration tests around the same time.

What needs to be done:

  • Retry the Integration Tests job to confirm this is the same probe flake. If it passes on retry, this PR can merge.
  • If the flake recurs, the durable fix is a follow-up that bumps _wait_for_probe_pod past 75s and the corresponding test HTTP timeouts past 90s to keep the headroom invariant. That's a route + test change, deliberately out of scope for this PR (which is a one-line test-side default bump).

Suggestion: Retry first. The autofixer is not the right place to add probe-wait headroom — that change touches orchestrator/routes/deployment.py and would expand this PR beyond its stated test-only scope.

— Authored by egg

@james-in-a-box

Copy link
Copy Markdown
Contributor
Autofix tracking
{"Test/Integration Tests / Integration Tests": 1}

@james-in-a-box

This comment has been minimized.

@egg-reviewer egg-reviewer Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Verdict: Approve

Tiny, well-motivated change. The 60s default was structurally below the server-side 75s _wait_for_probe_pod ceiling that #2699 just established, and several tests in the same file already work around it with explicit timeout=90. Bumping the default closes that gap. No security, correctness, or regression risk.

Verified

  • orchestrator/routes/deployment.py:1273 calls _wait_for_probe_pod(..., timeout=75.0); the inline comment at line 1271 explicitly anchors 75s under "the route's 90s HTTP-timeout ceiling." Old 60s client default → guaranteed ReadTimeout whenever the probe path is exercised and scheduling drifts past 60s.
  • The new 90s default matches the existing explicit overrides in this file (test_probe_runs_and_returns_expected_shape:437, test_concurrent_validate_network_isolation_calls_get_distinct_probe_ids:518, test_validation_routes_reject_invalid_json:638,647, test_no_orphan_probe_jobs_after_call:710). The helper now matches its callers' de-facto convention.
  • The 400-path tests (test_invalid_pipeline_id_returns_400, test_invalid_role_returns_400, test_pipeline_id_regex_boundary_violations_return_400[*]) reject at the label-validator before reaching the CNI gate and return in milliseconds — bumping the upper bound has no effect on them. Confirmed by inspection.
  • CI on this branch (run 25817353877) shows the stated targets now pass:
    • test_default_pipeline_id_and_role_pass_label_validation PASSED
    • test_pipeline_id_regex_valid_at_boundaries_pass[single-char | max-length-63 | middle-dot-underscore-hyphen | uppercase-allowed] — all 4 PASSED

Non-blocking note

The "Integration Tests job passes on this branch" checkbox in the test plan won't be satisfied by this change alone. CI run 25817353877 still has one failure:

FAILED test_probe_runs_and_returns_expected_shape -
  Failed: probe pod did not complete before route timeout:
  {'error': 'probe_timeout', 'probe_id': 'dcb7da2be765'}

That test already had timeout=90 pre-PR, so it's untouched by this diff. The failure shape is the server-side _wait_for_probe_pod returning the probe_timeout 200-response — i.e. the probe pod did not become observable within the server's 75s deadline. The 90s client ceiling is irrelevant here; the client cleanly received an HTTP 200 with a probe_timeout payload well before 90s.

So the residual flake is at a different layer than this PR addresses — it's the same class of issue #2699 was hardening against (probe-pod scheduling on the k3s integration cluster occasionally exceeding the server-side deadline), not a client-timeout problem. Not in scope to fix here, but worth knowing: if this recurs, the next bump is on the server-side _wait_for_probe_pod timeout, not on _post.

— Authored by egg

@james-in-a-box

This comment has been minimized.

@james-in-a-box

This comment has been minimized.

@james-in-a-box

Copy link
Copy Markdown
Contributor

Review feedback disposition

Thanks for the review. The PR is APPROVED by egg-reviewer[bot] and the only item in the review body is a non-blocking informational note. No code changes are needed; per-item disposition below.

Items

  1. Non-blocking note: residual test_probe_runs_and_returns_expected_shape CI failure (server-side _wait_for_probe_pod timeout at orchestrator/routes/deployment.py:1273)disagree (reviewer explicitly scoped this as out-of-PR).

    Reviewer's own words: "the residual flake is at a different layer than this PR addresses ... Not in scope to fix here, but worth knowing: if this recurs, the next bump is on the server-side _wait_for_probe_pod timeout, not on _post." The autofix analysis on this same PR also concluded: "the autofixer is not the right place to add probe-wait headroom — that change touches orchestrator/routes/deployment.py and would expand this PR beyond its stated test-only scope. Suggestion: Retry first."

    This PR is a deliberate one-line test-side default bump (_post() 60s → 90s) to match the route's 90s HTTP-timeout ceiling and the existing explicit timeout=90 callers in the same file. The failing test (test_probe_runs_and_returns_expected_shape) already passes timeout=90 explicitly, so this PR is a no-op for it; the failure shape ({'error': 'probe_timeout', ...}) is the server-side route returning its probe_timeout envelope at the 75s deadline well before any 90s client ceiling. Expanding this PR to bump server-side _wait_for_probe_pod past 75s and tests past 90s in lockstep would change the PR's scope from "client default catches up to the route ceiling" to "raise the whole headroom invariant" — a different change with a different review surface, and one the reviewer has clearly indicated belongs in a separate PR if/when the flake recurs. Reserving disagree here per the feedback contract: the reviewer is not asking me to fix it (no explicit follow-up ask either), they're flagging the next layer to bump if the flake comes back.

Summary

No commits added. Branch HEAD is still 344bf1c (the change the reviewer already approved). Ready to merge from this end.

— Authored by egg

@james-in-a-box

This comment has been minimized.

Root cause of the test_probe_runs_and_returns_expected_shape flake on
PR #2700 CI: the probe Job set ttlSecondsAfterFinished=0, which races
_wait_for_probe_pod's 1Hz poll. The probe Job/pod could transition to
Succeeded (or Failed via activeDeadlineSeconds), then be GC'd by the
TTL-after-finished controller before the next poll observed the
terminal phase. The wait loop would then scan an empty list until its
75s ceiling and return probe_timeout.

Evidence (Actions run 25817353877):
- Orchestrator log durations were bimodal: 9-12s (happy) or 75-76s
  (full ceiling), no middle ground.
- The route's finally _delete_probe_job got 404 on the hung calls:
  "(404) Reason: Not Found" — Job was already gone, GC'd by ttl=0.
- The pod's k8s events stop at Started; no DeadlineExceeded, no
  Killing — the pod completed normally but was reaped before the poll
  observed it.

Fix: bump ttlSecondsAfterFinished from 0 to 30. The route's
try/finally remains the primary cleanup path; 30s is the backstop
that also gives the 1Hz poll a guaranteed observation window and
ensures _read_probe_log can still read the pod's stdout after
_wait_for_probe_pod returns.

Also bumps integration helper _post() default timeout from 60s to
90s. PR #2699 raised the route's probe-pod wait to 75s, leaving the
helper's 60s default structurally too tight for any test that lets
the route proceed past the CNI gate. The bot caught
test_default_pipeline_id_and_role_pass_label_validation on #2689
comment 4443847011; test_pipeline_id_regex_valid_at_boundaries_pass
had the same latent bug across 4 parametrize cases. 90s matches the
explicit timeout already used in the probe-result/concurrency/JSON
tests.

Files:
- orchestrator/routes/deployment.py: ttlSecondsAfterFinished 0 → 30
- orchestrator/tests/test_deployment_routes.py: matching assertion
- orchestrator/mcp_tools.py: tool description text
- integration_tests/test_deployment_validation_logic.py: _post()
  default timeout 60 → 90; TestProbeJobCleanup docstring + failure
  message updated to reference ttl=30
@jwbron jwbron changed the title test: bump _post default timeout 60s→90s for probe path fix: race between probe-pod TTL GC and _wait_for_probe_pod poll May 13, 2026

@egg-reviewer egg-reviewer Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Verdict: Approve

The new commit (559a06b) addresses the residual probe_timeout flake my previous review flagged as out-of-scope. The expanded scope is justified — the PR description's bimodal-distribution evidence from run 25817353877 is convincing, and Integration Tests now pass on this commit.

Verified the race hypothesis

Traced the full flow in orchestrator/routes/deployment.py:

  • _wait_for_probe_pod (lines 1115-1130) polls list_namespaced_pod at 1Hz against the egg.io/probe-id selector, returning only on phase in {Succeeded, Failed}.
  • With ttlSecondsAfterFinished=0, the TTL-after-finished controller cascade-deletes the Job + pod within sub-second of Job completion — narrower than the 1Hz poll window. The 404 on the finally _delete_probe_job calls in the failure run confirms the Job was gone by the time the route reached finally.
  • ttlSecondsAfterFinished=30 gives the 1Hz poll ~30 attempts to observe terminal phase. Combined with activeDeadlineSeconds=30, max time from Job submit to pod GC is bounded at ~60s, safely under the 75s wait ceiling.
  • _read_probe_log (lines 1133-1161) runs immediately after _wait_for_probe_pod returns — the 30s window leaves ample headroom for the log read before TTL fires. Existing try/except already covers GC-during-read.
  • _delete_probe_job uses propagation_policy="Background" (line 1174) and never raises, so the route's explicit cleanup is unaffected by the bumped TTL.

Consistency check

All 5 references to ttlSecondsAfterFinished for the probe Job now read 30:

  • orchestrator/routes/deployment.py:1034 — manifest value
  • orchestrator/tests/test_deployment_routes.py:969 — unit-test assertion
  • orchestrator/mcp_tools.py:1115 — MCP tool description
  • integration_tests/test_deployment_validation_logic.py:685,717,749 — docstring + comment + failure message

Other ttlSecondsAfterFinished references in the repo (e.g. startup_reconciliation.py:210, agent-Job default of 600s) are unrelated and correctly left alone.

Stricter cleanup test as a side benefit

test_no_orphan_probe_jobs_after_call is now strictly stronger than before. With the old ttl=0, a silent finally failure could be masked by the TTL controller cleaning up within the test's 15s window. With ttl=30, the 15s deadline is below the TTL fire time, so the test now fails on any finally regression. The updated comment captures this:

15s + the ~10s probe runtime still sits well under ttl + GC sync

Minor nit (non-blocking): the comment is mildly awkward — the 15s is deliberately below ttl=30 so the test catches finally regressions rather than relying on the TTL backstop. Reading it as "the headroom lets TTL fire if finally failed" would be wrong. Not worth respinning.

CI

  • Integration Tests / Integration Tests: ✅ (the run that motivated this fix now passes)
  • Unit Tests: ✅
  • All other required checks: ✅

— Authored by egg

@james-in-a-box

This comment has been minimized.

@james-in-a-box

This comment has been minimized.

The previous wording read as if the 15s window existed so the
ttlSecondsAfterFinished=30 backstop could fire during the test. That
inverts the intent: 15s is deliberately below ttl=30 so a regression
in the route's try/finally path surfaces as a test failure here
instead of being masked by the TTL controller sweeping the orphan
inside the poll window.

No behavior change; comment-only.
@james-in-a-box

Copy link
Copy Markdown
Contributor

Review feedback disposition

Latest review (egg-reviewer[bot] on 559a06b) is APPROVED. It contains one minor non-blocking nit, which I've fixed in-PR rather than carry the misleading wording forward.

Items

  1. Minor nit (non-blocking): TestProbeJobCleanup deadline comment is misleading — reads as if the 15s window exists so ttlSecondsAfterFinished=30 can fire during the test, when actually 15s is deliberately below ttl=30 so a finally-path regression surfaces as a test failure rather than being masked by the TTL controller sweeping the orphan inside the poll window.fixed-in-PR (commit 6156c6e).

    Rewrote the comment block at integration_tests/test_deployment_validation_logic.py:714-719 to spell out the intent explicitly:

    # The route's try/finally _delete_probe_job is the primary
    # cleanup path, so the Job should be gone within milliseconds
    # of the route returning. The 15s deadline is deliberately
    # below ttlSecondsAfterFinished=30: a finally-path regression
    # must surface as a test failure here, not get masked by the
    # TTL controller sweeping the orphan inside the poll window.

    Reviewer said "not worth respinning," but the wording was a correctness hazard for a future maintainer reading the test as documentation of the cleanup invariant — and the fix is one comment block. Comment-only change; no behavior delta, no test re-run required (purely test-file comment text).

Summary

  • 1 commit added: 6156c6e — clarify the TestProbeJobCleanup deadline comment.
  • Branch HEAD now at 6156c6e (was 559a06b when reviewed).
  • The substantive changes the reviewer already approved (probe-Job ttlSecondsAfterFinished 0 → 30, _post() default timeout 60 → 90, and the matching unit-test assertion / MCP tool description) are unchanged.

— Authored by egg

@james-in-a-box

This comment has been minimized.

@egg-reviewer egg-reviewer Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Verdict: Approve

The single new commit (6156c6e) is a comment-only change that correctly addresses the non-blocking nit I raised on 559a06b. No behavior delta; the substantive changes (ttlSecondsAfterFinished 0→30, _post() default timeout 60→90, and matching unit-test + MCP tool description updates) are unchanged and remain approved.

Verified the comment is now accurate

Traced the timing for test_no_orphan_probe_jobs_after_call:

  • orchestrator/routes/deployment.py:1034 — probe Job sets ttlSecondsAfterFinished=30 and activeDeadlineSeconds=30.
  • TTL countdown starts at Job-Finished, which on the normal path is ~probe-runtime (~10s) into route execution.
  • The route's finally _delete_probe_job runs immediately after _wait_for_probe_pod returns, then the route returns to the client.
  • integration_tests/test_deployment_validation_logic.py:720deadline = time.time() + 15 starts after _post returns.
  • Effective TTL fire time (normal probe completion path): ~Job-Finished + 30s, i.e. ~30s after the route returned.
  • 15s poll window < 30s TTL window → the TTL controller cannot mask a finally-path regression by sweeping the orphan inside the poll window.

The new wording captures that intent directly:

The 15s deadline is deliberately below ttlSecondsAfterFinished=30: a finally-path regression must surface as a test failure here, not get masked by the TTL controller sweeping the orphan inside the poll window.

This is the correct framing. The old wording read as if the 15s window was for the TTL backstop to fire during the test, which would have required a window > 30s; the new version makes the invariant explicit.

Scope of delta

  • git diff 559a06b..HEAD is one comment block in integration_tests/test_deployment_validation_logic.py. Nothing else.
  • No new tests, no production code changes, no CI surface change. The previously green Integration Tests / Unit Tests result on 559a06b carries over.

— Authored by egg

@james-in-a-box

Copy link
Copy Markdown
Contributor

egg review completed. View run logs

8 previous review(s) hidden.

@jwbron
jwbron merged commit 53860b8 into main May 13, 2026
23 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant