[fecolinhares]

Fixes #850

What happens

After a replay hands a step to the executor and the executor settles it without acting, the staged trace records endWaitMs from the last replayed action. The interval before staging contains the failed replay's own wait and the executor's turn; both get counted again on the next recording. That causes endWaitMs to grow on repeated hand-offs until it reaches MAX_TRACE_END_WAIT_MS (120 s).

The replay excludes the executor turn from the app-settling budget when the executor records no action. When it does act, settling is measured from that last action, so a slow app response after the action remains in the recording.

Measured

The fake-clock regression test replays and heals the same entry three times. I measured both versions with the current main runtime and this branch's runtime, using the same test harness:

runtime	entry	run 1	run 2	run 3
main (13da94b)	200	28,000	42,000	56,000
this branch	200	10,000	10,000	10,000

With main, each run adds the replay wait and executor turn. With the fix, the silent hand-off measures from the agent's verdict. A separate action-failed regression verifies that when the executor acts, the app's post-action settling time is preserved.

The assertions catch both unbounded growth and a stable-but-inflated wait; reverting the runtime change makes the regression fail with expected 42000 to be less than or equal to 28000.

Verified

Ran locally on top of current main 1b92a6d:

• pnpm check — passed end-to-end: lint, dead-code, typecheck, error-code docs, peer ranges, install scripts, build validation and broken links.
• pnpm --filter e2e exec vitest run tests/unit/step-cache.test.ts — 60 passed.
• pnpm test — passed: e2e 245 files / 3,064 passed / 2 skipped; web 56 / 507 passed / 1 skipped; mobile 12 / 232 passed; GitHub 4 / 32 passed; kernel 1 / 15 passed; EAS 1 / 35 passed; decision 5 / 88 passed; scripts 15 passed.

The full suite includes local Chromium integration tests; the end-wait measurements remain deterministic fake-clock unit tests and use no live model or benchmark service. The rebase resolves main's step-cache.ts overlap while preserving keyedBy, hand-off detail, and the correct completion-vs-last-action baseline.

Versions

e2e 0.17.0 @ 13da94b, Node 22.

[cubic-dev-ai]

All reported issues were addressed across 3 files

<sub>Reply with feedback, questions, or to request a fix.

Re-trigger cubic</sub>

[fecolinhares]

Addressed in 4343971 (fix(cache): exclude executor time from healed wait). On a replay hand-off, conclude() now captures executor completion and staging measures app settling only from that point; ordinary runs still use the last action. The regression test now requires each post-warm-up recording to be no larger than its predecessor. Verified: pnpm check and pnpm --filter e2e run test:unit (172 files, 2450 passed, 2 skipped); focused step-cache suite: 58 passed.

[fecolinhares]

Addressed in 4343971 (fix(cache): exclude executor time from healed wait). Tightened the stability assertion to compare each post-warm-up endWaitMs directly with the preceding value, rejecting any increase. Verified with the full unit suite (172 files, 2450 passed, 2 skipped) and focused step-cache suite (58 passed).

[cubic-dev-ai]

All reported issues were addressed across 1 file (changes from recent commits).

<sub>Tip: Review your code locally with the cubic CLI to iterate faster.

Re-trigger cubic</sub>

[okwasniewski]

[claude-opus-5-5] responding on behalf of okwasniewski

Thanks, the bug is real and the fix direction is right: after a hand-off, endWaitMs measured from the last replayed action soaks up the failed replay's own wait and the executor's turn. A few things before merge:

1. Don't drop the settle time when the executor acted after the hand-off.
Math.max(lastActionAtMs, executorCompletedMs ?? handedOffMs) always picks the executor's completion, so when the executor did act (the usual heal), endWaitMs collapses to the 10 s margin and loses how long the app took after the executor's last action (a slow save or report). The next replay then hands off on that step. Use the completion baseline only when the executor recorded nothing after the hand-off, and measure from its last action otherwise, like any live recording:

const actedAfter = this.handedOffMs !== undefined && (recorder.lastActionAtMs ?? 0) > this.handedOffMs;
const from =
  this.handedOffMs === undefined || actedAfter
    ? (recorder.lastActionAtMs ?? this.startedMs)
    : (this.executorCompletedMs ?? this.handedOffMs);

Please add a test for "hand-off, then the executor acts" next to the existing one.

2. Simpler test clock.
withClock and the holdLastPath/remainingMs parameters on the shared helpers make the harness harder to follow. trace-replay.test.ts already runs on vi.useFakeTimers() with vi.setTimerTickMode('nextTimerAsync') (#816), which lets timers fire as awaits arm them, so the race loop shouldn't be needed. A dedicated host for this test would keep makeHost/recordingSession unchanged.

3. Heads-up on overlap with #805.
#805 restructures the handOff/stage area of step-cache.ts and adds withChangeWait to the test makeHost. The conflict is mechanical; whichever lands second rebases. #805 does not change how endWaitMs is measured, so this fix is still needed on top of it.

4. PR body.
## Verified appears twice and has no Ran it locally: line. A live run would make the case: a step that hands off on the web benchmark, re-run twice in read-write, showing endWaitMs in the written entry before and after.

[fecolinhares]

Addressed the actionable items in ba84e67 and updated the PR body (single ## Verified, with the exact local commands and a note that no live benchmark was run). The end-wait baseline is now the executor’s last action when it acted after hand-off, or executor completion when it did not; the regression test’s fake-clock driver now uses Vitest nextTimerAsync, and the settling-budget assertion has both lower and upper bounds. #805 is still open and touches the same two files; the current main tip (371706e) does not include it, so a later landing may still require another rebase. I have not completed a reliable dedicated test for the executor-acted branch yet, so I am leaving that specific request open rather than claiming it covered.

[fecolinhares]

Thanks for the review — items 2, 3 and 4 are in (ba84e67 drops withClock for setTimerTickMode('nextTimerAsync'), and the duplicated ## Verified is gone). Item 1 is applied as you wrote it.

The test for it is the part I can't deliver, and I think the reason is in conclude() rather than in the test.

After an end-mismatch hand-off, passed reads:

if (this.repairedAfterEndMismatch(recorder)) await this.evict();
else if (this.replayedWhole) { /* keep */ }
else if (!(await this.stage(recorder, verdictSummary)) && this.readEntryHit) await this.evict();

repairedAfterEndMismatch is true exactly when the executor recorded something after the hand-off — the same condition as your actedAfter. So when the executor acts after a hand-off, the entry is evicted and no endWaitMs is ever written for that path. That rule predates this PR; repairedAfterEndMismatch is unchanged on main.

What I measured in the unit harness, recording a tap after the hand-off and reading the staged result:

trace in the entry	stopReason	staged
endAnchors that the host shows	end-mismatch	evict
no end anchors	end-mismatch	evict
endPath only	end-mismatch	evict
end anchors that never appear	end-mismatch	evict
a tap/fill the host cannot resolve	—	entry rejected, no replay

Every shape that hands off lands on the evict branch, so there is no endWaitMs on it to assert — the Math.max that regresses settling time is only reachable when the executor records nothing after the hand-off, which is the case re-records no longer end wait than the entry it healed already covers.

So one of these is true and I'd rather you tell me which:

• The regressing path is a different one than the one I found (name it and I'll pin it), or
• the guard is still worth having as insurance on the entry-staging path, in which case I'll add the test you asked for on stage() itself rather than on a session that evicts, or
• you saw this fail in a real run, in which case the endWaitMs you saw came from a different session and I'd like the log.

I'd rather not ship a test I can't make fail before the fix.

[fecolinhares]

Correction to my previous reply and to the claim that every executor action after hand-off necessarily evicts: I found a non-end-mismatch path where replay runs one action and the next replay action fails (action-failed). In that path actionsAtEndMismatch is unset, so the executor’s later action is staged and the baseline matters. Added keeps app settling time after an executor action following an action-failed hand-off in 05cdf69; it asserts the post-action app settling interval remains in the recorded wait, excluding the executor turn. The test is not a hypothetical duplicate of the no-action case: it takes the actual action-failed hand-off branch. Verification after this addition: pnpm check passed; pnpm --filter e2e run test:unit — 172 files, 2,451 passed, 2 skipped; focused suite — 59 passed. Please treat this as the completed test for item 1.

[fecolinhares]

Update: the executor-acted regression test and the preceding corrections are now rebased onto current upstream/main (371706e) and included in head c7f1bb9. The dedicated action-failed hand-off test passes and checks that the app’s post-action settling interval remains in endWaitMs. I also corrected the PR body’s measured counts to 2,451 unit tests / 59 focused tests; read-back confirms one ## Verified section. No merge or approval was performed.

[fecolinhares]

CI update for head c7f1bb9: the spec job in run 37366205751 failed only at test (24) — tests/integration/web-platform.test.ts:485, expected NaN to be >= 190 in the pre-existing “download that never started” assertion. The failing test and packages/web/src/browser.ts are unchanged in this PR; the PR diff is limited to the changeset and packages/e2e/src/agent/step-cache.ts / its unit tests. I reran that exact integration case locally three times; all 3 passed. This looks unrelated to the end-wait change and environment/timing-sensitive, but the failure is real and I did not alter or mask the test. Could a maintainer rerun the failed shard?

[fecolinhares]

test (24) is red on this PR, and it is not from this branch — a3f0f9f, the commit this branch forked from, fails the same way.

Both runs fail the same test with the same error:

FAIL   web  explore > Explore the home page and find bugs
AUTOMATION_UNSUPPORTED: exploration concluded nothing: no step ran and no finding was recorded
   agent.act blocked: Required service is unavailable
ENVIRONMENT_UNAVAILABLE: exploration could not complete a charter: agent.act blocked: Required service is unavailable

run	sha	test (24)
this PR	c7f1bb9	failure
main, before this branch	a3f0f9f	test (24.8.0)=failure, same error
63482bd, b4da513, 371706e	main	test (24)=success

The explorer runs against fake/scripted-explore and agent.act comes back Required service is unavailable, so no step runs and no finding is recorded. That path never reaches a trace cache — it stops at agent.act, before any entry is staged — so endWaitMs is not involved. The other four test jobs on this PR are green, including the unit suite that covers the files here.

I have not re-run the job: rerunning it myself would only tell me whether the service was back, and either way this is a CI-infra failure to call, not mine to mask. Leaving it for you to decide — happy to re-run just test (24) if you would rather see whether it clears.

[fecolinhares]

Follow-up to my earlier CI note (#6002740835): that comment described head c7f1bb9 before the rebase. The PR was subsequently rebased onto fd3a0c7 and pushed as 14c10b1; on this current head, test (24) completed successfully at 22:32:07Z. The current checks are 17 success, 1 skipped, 0 failures, 0 pending, and GitHub reports mergeable_state=clean. The earlier comparison with a3f0f9f remains historical evidence about the old failing run, not the current CI state.

[okwasniewski]

Thanks, this now does what we asked: settle time is kept when the executor acts, and its turn is left out when it doesn't. A few cleanups before merge:

1. Revert the holdLastPath / remainingMs params on makeHost and recordingSession and give the two new tests their own host.
2. Trim the test comments to one line each. The main-vs-branch numbers belong in the PR body.
3. Move the nested ternary in stage() into a small private method with a JSDoc.
4. The changeset says the wait is measured from the hand-off, which is no longer true. Please reword it to "from the agent's verdict, or its last action if it acted".

[fecolinhares]

Addressed all four cleanup requests in the current head 2a177be (rebased onto main 13da94b):

1. Restored the original makeHost / recordingSession signatures. Each of the two hand-off regression tests now owns its host, including its longer budget/held route behavior.
2. Trimmed their inline comments to one line; the measured main-vs-branch values are in the PR body.
3. Extracted the nested baseline selection from stage() into private endWaitBaselineMs() with JSDoc.
4. Reworded the changeset to say the baseline is the agent's verdict when it did not act, or its last action when it did.

Verified after rebasing: focused step-cache.test.ts 59 passed; pnpm --filter e2e run test:unit 172 files / 2,461 passed / 2 skipped; pnpm check passed. The deterministic main-vs-branch probe produced [200, 28000, 42000, 56000] on the current main runtime and [200, 10000, 10000, 10000] on this branch. CI for the new head is running; I will not claim it green until completed.

[fecolinhares]

Addressed all four cleanup requests in head 2a177be (rebased onto main 13da94b):

1. Restored the original makeHost / recordingSession signatures. Each of the two hand-off regressions now has its own host, including the held route and larger budget it needs.
2. Trimmed test comments to one line; main-vs-branch measurements are in the PR body.
3. Extracted the nested baseline ternary from stage() into private endWaitBaselineMs() with JSDoc.
4. Reworded the changeset: measure from the agent's verdict when it settled without acting, or from its last action if it acted.

Locally verified on the new main base: pnpm check passed; pnpm --filter e2e run test:unit passed (172 files, 2,461 passed, 2 skipped); focused step-cache.test.ts passed (59). The same fake-clock test measured current main at [200, 28000, 42000, 56000] and this branch at [200, 10000, 10000, 10000]. CI for head 2a177be is running; I will update when it completes.

[santoislamsh-eng]

(as)

[fecolinhares]

Hi @santoislamsh-eng — I can't tell what issue you intended to flag from the comment (as). Could you clarify the behavior or expected change? The referenced line was in the shared test host; after the maintainer's request, both new hand-off tests now use dedicated hosts and the shared helper signature is restored. I have not treated this fragment as an actionable defect.

[okwasniewski]

Thanks!

btw feel free to join our discord as a frequent contributor, we have a channel for e2e-contributors! https://tester.army/discord