Fix pipeline failure after BRC consensus when timeout fires first - #1693
Conversation
This comment has been minimized.
This comment has been minimized.
Autofix tracking{"Lint/Python": 1} |
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
There was a problem hiding this comment.
Review: Fix consensus timeout recheck
The core fix is sound — the timeout path (step 6) was missing the consensus recheck that the normal exit path (step 5) already had, and the PR correctly mirrors that pattern. The orphan container cleanup is a good addition. However, there are issues that need addressing.
Blocking
1. RECONSTRUCTED_NO_SHA sentinel leaks into agent.commit
orchestrator/routes/pipelines.py:6377-6380
The commit SHA population code does:
if _brc is not None and not agent.commit:
sha = _brc.get_proposal_commit_sha(agent.role.value)
if sha:
agent.commit = shaget_proposal_commit_sha can return "RECONSTRUCTED_NO_SHA" (see peer_consensus.py:1550-1552) — a sentinel value for proposals that were reconstructed from historical messages without a real SHA. Since "RECONSTRUCTED_NO_SHA" is truthy, it passes the if sha: guard and gets stored as agent.commit. Downstream code that reads agent.commit (e.g., contract completion, status APIs) will treat this garbage string as a valid git SHA.
Fix: filter it explicitly:
if sha and sha != "RECONSTRUCTED_NO_SHA":
agent.commit = shaOr better, check for a hex-like pattern since commit SHAs have a known format.
2. Timeout recheck skips has_unresolved_nacks guard
orchestrator/routes/pipelines.py:6857-6894
The step 5 normal exit path has three gates before returning success:
- Consensus recheck (
is_complete) — lines 6608-6661 - Unresolved NACKs check (
has_unresolved_nacks) — lines 6667-6688 - Final consensus completeness on clean exit — lines 6690-6730
The new timeout recheck only checks is_complete and then returns 0. It does not check has_unresolved_nacks. This means: if consensus is "complete" but there are unresolved NACKs (which is a valid state — consensus can be marked complete by quorum while individual NACKs remain unaddressed), the timeout path will return success while the normal path would return failure with a HITL escalation.
The timeout path should mirror the NACK check:
if _timeout_consensus.get("is_complete"):
if _timeout_consensus.get("has_unresolved_nacks"):
# Mirror the step 5 NACK escalation
...
return 1, combined_logs
# ... existing recovery logic ...
return 0, combined_logsAlternatively, the code after return 1, combined_logs at line 6896 already does the NACK check (lines 6898-6915), but that code is unreachable when has_failures[0] is True because the new code returns early on both branches of the is_complete check.
Non-blocking
3. Import inside a nested function on every call
orchestrator/routes/pipelines.py:6358-6363
The peer_consensus import is done inside _update_agents_complete(), which is a closure called potentially multiple times (once per consensus success path). The try/except import pattern matches the codebase convention for this module, but placing it inside a nested function that runs under a pipeline state lock means the import machinery runs while holding the lock. Consider hoisting the import to the enclosing function scope (alongside similar imports at lines 6516-6522) and passing the tracker in, or at minimum caching the result.
4. Tests only mock ConcurrentPhaseExecutor — fragile coupling
The tests heavily mock the internals of _run_concurrent_phase (7+ patches per test). They test the wiring of the timeout→recheck→return path, which is good for the specific fix. But the tests don't verify that _update_agents_complete actually populates agent.commit from BRC (there's no assertion on commit SHA values), and there's no test for the RECONSTRUCTED_NO_SHA sentinel case mentioned in issue #1.
5. _wait_remaining catches ContainerNotFoundError but only stops on that path
The orphan container stop in the except block (lines 6816-6819) only fires when wait_for_container raises. If the container exits with a non-zero code naturally (not via exception), it won't be stopped — which is fine since it already exited. Just noting this is correct behavior, not an issue.
6. elapsed variable in timeout consensus recheck
Line 6884 references elapsed in the event data. At this point, elapsed was last computed at the top of the while True loop iteration. The actual elapsed time is now time.monotonic() - start_time since the ThreadPoolExecutor wait (up to 3600s) happened in between. The logged elapsed time will be significantly stale. This same staleness exists in the step 5 path (line 6649), so it's a pre-existing issue, but since the PR is already in this code, it's worth noting.
— Authored by egg
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
…CK guard to timeout path - Filter RECONSTRUCTED_NO_SHA sentinel from get_proposal_commit_sha() so it never leaks into agent.commit as a garbage SHA value - Add has_unresolved_nacks guard to the timeout consensus recheck path, mirroring the step 5 NACK escalation (creates HITL decision, returns 1) - Hoist peer_consensus import from nested _update_agents_complete() to the enclosing function scope to avoid re-running import machinery under lock - Add tests for NACK-during-timeout and RECONSTRUCTED_NO_SHA filtering
There was a problem hiding this comment.
Addressed both blocking issues and the non-blocking import concern:
1. RECONSTRUCTED_NO_SHA sentinel — Added explicit filter: if sha and sha != "RECONSTRUCTED_NO_SHA". Also added a dedicated test (TestReconstructedNoShaFiltering) that verifies the sentinel is not stored as agent.commit.
2. Timeout recheck skips has_unresolved_nacks — Added the NACK guard immediately after the is_complete check in the timeout path, mirroring step 5: checks has_unresolved_nacks, creates a HITL escalation decision, appends NACK summary to logs, and returns 1. Added test test_timeout_with_consensus_and_unresolved_nacks_returns_failure.
3. Import inside nested function — Hoisted the peer_consensus import to the enclosing _run_concurrent_phase function scope so it runs once rather than under the pipeline state lock on each call to _update_agents_complete.
5. Container stop behavior — Agreed, correct as-is.
6. Stale elapsed — Noted as pre-existing. Will address separately if needed.
All tests pass (5/5), lint clean.
— Authored by egg
There was a problem hiding this comment.
Re-review: Fix consensus timeout recheck
Both blocking issues from the previous review have been properly addressed. The RECONSTRUCTED_NO_SHA sentinel filter and the NACK guard in the timeout path are correctly implemented. The import hoisting is also done well.
Verification of Previous Feedback
1. RECONSTRUCTED_NO_SHA sentinel — Fixed correctly at line 6384. The filter sha and sha != "RECONSTRUCTED_NO_SHA" prevents the sentinel from leaking into agent.commit. New test (TestReconstructedNoShaFiltering) covers this case.
2. Timeout NACK guard — Fixed correctly at lines 6865-6891. The timeout path now mirrors the step 5 NACK check: queries has_unresolved_nacks, creates HITL escalation via pipeline.add_decision(), appends NACK summary to logs, and returns 1. New test (test_timeout_with_consensus_and_unresolved_nacks_returns_failure) verifies this.
3. Import hoisting — Fixed at lines 6345-6353. The _get_brc_tracker import now runs once at _run_concurrent_phase scope rather than under the pipeline state lock inside _update_agents_complete. The closure correctly captures the variable.
New Code Assessment
The new changes are clean and mirror existing patterns faithfully. Control flow is correct — no unreachable code. The post-has_failures NACK check at lines 6933-6952 remains reachable for the no-failure timeout path.
Non-blocking
1. Stale elapsed in timeout event — Still present at line 6919 (data={"elapsed_seconds": elapsed}). As noted previously this is pre-existing (step 5 has the same issue at line 6654). Not blocking, but worth a follow-up.
2. Test for RECONSTRUCTED_NO_SHA relies on mock wiring — The test at line 748 patches peer_consensus.get_peer_consensus_tracker but _update_agents_complete resolves the tracker via the hoisted _get_brc_tracker closure variable (set at function scope import). This means the test's patch may not actually inject the mock BRC tracker into the code path being tested — it patches the module-level name, but the closure already captured the real import result (or None). Verify this test actually exercises the sentinel filter; if not, the test passes vacuously.
— Authored by egg
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
Add assert_called_with to confirm the mock BRC tracker was actually invoked during the test, preventing vacuous pass when the mock patch doesn't reach the code path. Also assert agent.commit is None (not just != sentinel) for a stronger postcondition. Addresses re-review suggestion #2 from egg-reviewer.
There was a problem hiding this comment.
Agreed. Strengthened the RECONSTRUCTED_NO_SHA test (suggestion #2) — added mock_brc.get_proposal_commit_sha.assert_called_with(AgentRole.CODER.value) to verify the BRC code path is actually exercised, plus a stricter assert mock_agent.commit is None postcondition. The mock patch does work correctly (the with patch(...) context wraps the _run_concurrent_phase call, so the from peer_consensus import ... inside the function picks up the mock), but the original assertion was too weak to prove it. All 5 tests pass.
Re: suggestion #1 (stale elapsed) — agreed it's pre-existing, will address separately.
— Authored by egg
There was a problem hiding this comment.
Re-review: Fix consensus timeout recheck
Both blocking issues from the first review (RECONSTRUCTED_NO_SHA sentinel, timeout NACK guard) are properly fixed. The import hoisting is correct. The test strengthening (assert_called_with + is None postcondition) addresses the concern about vacuous test passes.
Verification of Previous Feedback
1. RECONSTRUCTED_NO_SHA sentinel — Fixed at line 6384. Filter sha and sha != "RECONSTRUCTED_NO_SHA" is correct.
2. Timeout NACK guard — Fixed at lines 6862-6891. The timeout path now mirrors step 5's no-failure NACK check: queries has_unresolved_nacks, creates HITL escalation, appends NACK summary, returns 1.
3. Import hoisting — Fixed at lines 6345-6353. Runs once at function scope.
4. Test strengthening — assert_called_with(AgentRole.CODER.value) at line 760 confirms the BRC code path executes. assert mock_agent.commit is None at line 766 is a stronger postcondition than the previous != sentinel check.
New Issue
Blocking: Step 5 has_failures branch also lacks the NACK guard
The timeout path (step 6) now correctly checks has_unresolved_nacks when consensus is complete (lines 6865-6891). But step 5's has_failures=True path (lines 6613-6666) has the same gap — it checks is_complete and returns 0 without checking NACKs. The NACK check at line 6672 only runs in the !has_failures branch.
This means: if containers exit with failures (step 5, not timeout), consensus is complete, but there are unresolved NACKs, step 5 returns success while the timeout path correctly returns failure. The PR is already in this function and explicitly added the NACK guard to the timeout path — the same guard should be added to step 5's has_failures branch for consistency.
Fix: After line 6627 if final_consensus.get("is_complete"):, add the same NACK guard before the recovery/return-0 path:
if final_consensus.get("is_complete"):
# Guard: consensus may be "complete" by quorum but still
# have unresolved NACKs.
if final_consensus.get("has_unresolved_nacks"):
nack_details = final_consensus.get("unresolved_nacks", [])
nack_summary = _format_nack_summary(nack_details)
logger.warning(
"Consensus complete on final recheck but unresolved NACKs remain",
pipeline_id=pipeline_id,
nack_count=len(nack_details),
nack_summary=nack_summary,
)
try:
pipeline.add_decision(
question=(
f"Consensus reached but {len(nack_details)} NACK(s) "
f"remain unresolved: {nack_summary}. How to proceed?"
),
options=["Retry phase", "Accept current state", "Abort phase"],
phase=pipeline.current_phase,
)
except Exception:
logger.warning(
"Failed to create NACK escalation decision (step 5 has_failures path)",
exc_info=True,
)
combined_logs += (
f"\n--- UNRESOLVED NACKs ({len(nack_details)}) ---\n{nack_summary}"
)
return 1, combined_logs
# Consensus reached after all — recover pipeline if needed
...Non-blocking
1. Stale elapsed in event data — Still present at line 6919. elapsed was computed at the top of the while True iteration, before the ThreadPoolExecutor wait (up to 3600s). The logged value will undercount significantly. Same pre-existing issue at step 5 line 6654. Not blocking, but since both code paths now log it, worth a follow-up to recompute elapsed = time.monotonic() - start_time before use.
— Authored by egg
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
There was a problem hiding this comment.
Agreed. Added the NACK guard to step 5's has_failures branch (lines 6628-6656), mirroring the timeout path pattern: checks has_unresolved_nacks, creates HITL escalation via pipeline.add_decision(), appends NACK summary to logs, returns 1. Added test test_step5_has_failures_with_consensus_and_nacks_returns_failure — all 6 tests pass, lint clean.
Re: non-blocking #1 (stale elapsed) — agreed, pre-existing in both paths. Will address separately.
— Authored by egg
There was a problem hiding this comment.
Re-review: Fix consensus timeout recheck
The blocking issue from the previous review (step 5 has_failures branch missing the NACK guard) has been properly addressed. All prior feedback is now resolved.
Verification of Previous Feedback
1. RECONSTRUCTED_NO_SHA sentinel — Fixed at line 6384. Filter sha and sha != "RECONSTRUCTED_NO_SHA" is correct. Test strengthened with assert_called_with and is None postcondition.
2. Timeout NACK guard — Fixed at lines 6896-6922. Correctly mirrors step 5.
3. Import hoisting — Fixed at lines 6345-6353.
4. Step 5 has_failures NACK guard — Fixed at lines 6628-6657. The new code correctly mirrors the timeout path and the existing no-failure NACK check: queries has_unresolved_nacks, creates HITL escalation via pipeline.add_decision(), appends NACK summary to logs, returns 1. The guard is positioned correctly — it fires before the recovery/return-0 path, so unresolved NACKs always prevent false success. Test test_step5_has_failures_with_consensus_and_nacks_returns_failure exercises this path correctly (monotonic stays under the timeout threshold, containers are pre-exited with non-zero code, consensus recheck returns complete-with-NACKs).
New Code Assessment
No new issues. The three NACK guard paths (step 5 has_failures, step 5 no-failures, timeout) are now consistent in behavior: all check has_unresolved_nacks, create the same HITL decision with the same options, append the same log format, and return 1.
Non-blocking
1. Stale elapsed in event data — Still present at lines 6685 and 6950. elapsed was computed at the top of the while True iteration but is logged after potentially long waits (ThreadPoolExecutor up to 3600s). The value will significantly undercount. Pre-existing in both step 5 and timeout paths, noted in prior reviews. Worth a follow-up.
— Authored by egg
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
This comment has been minimized.
The elapsed variable was computed at the top of the while-loop iteration but used after potentially long ThreadPoolExecutor waits (up to 3600s), causing significantly stale values in event data and log messages. Now recompute elapsed from start_time immediately before use in both step 5 and timeout consensus recheck paths.
There was a problem hiding this comment.
Agreed. Fixed the stale elapsed issue in both step 5 and timeout consensus recheck paths. Each path now recomputes elapsed = time.monotonic() - start_time immediately before logging/emitting the event, so the value reflects actual wall-clock time including the ThreadPoolExecutor wait.
All 6 tests pass, lint clean.
— Authored by egg
There was a problem hiding this comment.
Re-review: Fix consensus timeout recheck
The stale elapsed fix is correct. Both paths now recompute wall-clock time (time.monotonic() - start_time) immediately before use, with distinct variable names (_elapsed_final, _elapsed_timeout) that avoid shadowing the loop-scoped elapsed.
Verification of All Previous Feedback
RECONSTRUCTED_NO_SHAsentinel — Filtered at line 6384. Test strengthened withassert_called_with+is Nonepostcondition.- Timeout NACK guard — Correct at lines 6896-6922.
- Import hoisting — Correct at lines 6345-6353.
- Step 5
has_failuresNACK guard — Correct at lines 6628-6657. - Test strengthening —
assert_called_with(AgentRole.CODER.value)confirms BRC path executes. - Stale
elapsed— Fixed in this commit. Step 5 uses_elapsed_final(line 6681), timeout path uses_elapsed_timeout(line 6947). Both computed at point of use.
No new issues. All six test cases cover the fix paths adequately.
— Authored by egg
|
egg review completed. View run logs 11 previous review(s) hidden. |
Fix consensus timeout path to recheck consensus before returning failure
When the consensus timeout fires (step 6, default 30 min) before agents reach
consensus, the code falls back to waiting for containers via ThreadPoolExecutor.
If consensus is reached during this wait window but containers are force-killed
after the wait expires, the phase incorrectly fails because the timeout path
never rechecks consensus — unlike the normal exit path (step 5) which does.
This was the root cause of issue #1553-v4: all 5 agents confirmed consensus at
05:42, but the 30-min timeout had already fired at ~04:57. The 3600s container
wait expired at ~05:57, recording 4 containers as exit_code=-1, and the phase
failed without checking that consensus had been reached.
Three fixes:
recheck in step 5)
them running indefinitely
Issue: #1691
Test Plan
fix (timeout + consensus → exit 0), safety net (timeout + no consensus → exit 1),
and orphaned container cleanup
consensus_timeout_minutes setting; verify pipeline completes successfully