#849 Golden demos: compensation lands AFTER the 5s event, inverting BRANCH_B/PHASE2B vs BRANCH_C/PHASE3 in both expected files
Description
EditEARS SPEC:
- When a task with TimeoutPolicy(3s) fails by timeout and has an on_failure compensation task, the Highway engine shall run that compensation promptly enough that it precedes a sibling parallel branch gated on a 5-second sleep, as the golden demos assert.
- If compensation latency after a timeout legitimately exceeds the sibling branch time, then the golden expected files shall be corrected DELIBERATELY and the new ordering justified - not quietly updated to match observed output.
- The Highway golden demos shall be re-run and exact-matched after every engine change.
EVIDENCE (2026-08-03):
demo/v2.py expected: ...PHASE2A::PHASE2B_TIMEOUT_COMPENSATED::PHASE3_EVENT_RECEIVED::PHASE4...
actual: ...PHASE2A::PHASE3_EVENT_RECEIVED::PHASE2B_TIMEOUT_COMPENSATED::PHASE4...
demo/disaster_recovery_simulation.py expected: ::BRANCH_A_SUCCESS / ::BRANCH_B_COMPENSATION_SUCCESS / ::BRANCH_C_EVENT_RECEIVED
actual: ::BRANCH_A_SUCCESS / ::BRANCH_C_EVENT_RECEIVED / ::BRANCH_B_COMPENSATION_SUCCESS
Same class of difference in both. Same set of phases - ORDER ONLY. Everything else matches exactly.
BY CONSTRUCTION the expected order is the correct one: v2 Branch B sleeps 10s under TimeoutPolicy(timeout=3s) so it fails at ~3s and its on_failure compensation should follow immediately; Branch C sleeps 5s before emitting the event that unblocks the PHASE3 writer. Compensation at ~3s must therefore precede PHASE3 at >=5s. Observed compensation is landing later than 5s, i.e. more than 2s after the timeout fires.
NOT CAUSED BY THE 2026-08-03 CHANGES - attributed, not assumed. I checked the highway-core submodule out at bb616ff (the commit BEFORE #843/#845/#836 landed), rebuilt the image, redeployed, and ran v2 twice: byte-identical inverted ordering on the pre-change engine. Then restored main (7145fe6) and rebuilt. So this is pre-existing drift, not a regression from the pool/replay/metrics work.
The expected files are stale: demo/v2_expected_result.txt last touched 2025-11-11 (b4d2f82 "demo v2 works"), ~9 months and several engine releases ago (#825 cooperative cancel, #826 lock scope, #827-832 audit fixes, #833 replay side-effect freeze all landed since).
TIMEOUT DETECTION NOTE: TimeoutService scans every 30s, but these runs complete in ~8s total, so the 3s TimeoutPolicy is enforced inline by tools.shell.run - the executor passes timeout into the shell kwargs. So the delay is in the failure-handling / on_failure spawn path, not in the background sweeper.
TWO POSSIBLE RESOLUTIONS, OPERATOR DECIDES - I deliberately did NOT rewrite the golden files, because updating an expected result to match observed output turns a golden test into a tautology:
(a) There is a real latency regression in the timeout -> on_failure compensation path introduced somewhere between 2025-11-11 and now. Investigate and fix; expected files stay.
(b) Cross-branch write ordering into a shared append-only file is inherently timing-dependent and should never have been asserted as a total order. Then the demos should assert per-branch content and a partial order, not a byte-exact interleaving - and the expected files are corrected with that rationale recorded.
I lean (a) is worth ruling out first: the ordering was STABLE across 6 runs on both engines, so this is a consistent ~2s+ shift, not a flapping race.
WHAT DID MATCH EXACTLY (so the scope of this ticket is clear):
- disaster recovery: all other 14 lines byte-exact, INCLUDING "While loop iteration 0" / "While loop iteration 1" - the operator changed by #845 - plus the switch case, the foreach Processing/Validating pairs, sync gate and WORKFLOW_END.
- ultimate_correctness: self-verifying, counter=30, 35 unique audit entries, FINAL_VERIFICATION_PASSED.
- native_operators: OPERATORS_START -> task -> activity -> 7s wait -> OPERATORS_DONE, correct.
Comments
Loading comments...
Context
Loading context...
Audit History
View AllLoading audit history...