Skip to content

fix(storage): workflow reaper consults execution activity clock - #1046

Merged
AbirAbbas merged 3 commits into
Agent-Field:mainfrom
ddbaron:fm/af-workflow-clock-fix-r1
Sep 9, 2026
Merged

fix(storage): workflow reaper consults execution activity clock#1046
AbirAbbas merged 3 commits into
Agent-Field:mainfrom
ddbaron:fm/af-workflow-clock-fix-r1

Conversation

@ddbaron

@ddbaron ddbaron commented Sep 8, 2026

Copy link
Copy Markdown
Contributor

Proposal

Keep the workflow cleanup path from reaping a workflow while its paired execution still has recent activity. The query should check the workflow timestamp and the timestamp on the paired active execution before declaring the workflow stale.

Observed failure

Each execution has two activity timestamps. Heartbeats and status writes update executions.updated_at. MarkStaleWorkflowExecutions reads workflow_executions.updated_at, which remains unchanged during a leaf wait.

Four coder runs were reaped 10 to 13 minutes after starting on a 10-minute fuse. Heartbeats were arriving every 90 seconds. One run was reaped 57 seconds after its latest heartbeat. File commits continued after the reap, and the late completion updates returned HTTP 409 because the records were already terminal.

Implementation

This PR makes the workflow reaper join each workflow row to its paired active execution. It requires the workflow timestamp and the execution timestamp to be older than the cutoff before selecting the workflow for reaping.

The query still allows cleanup when the paired execution is absent or already terminal. The existing workflow-to-execution terminal synchronization remains in place.

The regression tests cover two cases:

  1. Recent activity on executions.updated_at keeps an old workflow row running.
  2. Rows that are old on both timestamps are reaped, and both records receive the existing terminal timeout state.

The change is on the read path, so existing heartbeat and note writes do not create another database write. Updating both timestamps on every activity event is another reasonable implementation. I am open to changing to that approach if it fits the control plane better.

Validation and evidence

The storage and handler tests for this path pass, along with go vet and formatting checks. At the time of this update, upstream checks report 27 passed, 0 failed, and 22 skipped.

The local reproduction is documented in the comment below. It includes the sampled execution IDs, timestamps, the 57-second interval between a heartbeat and a reap, the HTTP 409 completion errors, and the post-fix smoke results.

This PR is a working implementation for maintainer review. The goal is to keep the existing stale cleanup behavior for genuinely inactive workflows while allowing recent activity in the paired execution to count.

@ddbaron

ddbaron commented Sep 8, 2026

Copy link
Copy Markdown
Contributor Author

Evidence from the local reproduction

I read these values directly from the local SQLite database and the execution records. The rows used UTC timestamps.

Three sampled coder executions showed the problem:

  • exec_20260908_063449_vawzsj9v: the workflow row started at 11:34:49Z and was reaped at 11:47:46Z, 12m57s later. The paired execution row continued receiving heartbeat notes through 11:50:13Z, including a coder complete note three minutes after the workflow had been reaped.
  • exec_20260908_064218_mrs177j6: the workflow row was reaped 10m28s after its start. The execution row continued receiving heartbeat updates for about 27 minutes after that.
  • exec_20260908_065048_xrszw2m7: the workflow row was reaped about 12 minutes after its start. The execution row continued receiving activity after the reap.

The heartbeat was fresh when the cleanup ran. For example, one harness/heartbeat note arrived at 11:46:49Z and the workflow was reaped at 11:47:46Z, 57 seconds later. The late completion updates returned HTTP 409 with execution is already in a terminal state.

During the investigation I checked the other likely explanations. All 66 same-day rows used +00:00 offsets, the julianday comparison behaved as expected, the 10-minute fuse matched the configuration, environment, and database, and every timed-out execution had a model recorded.

After the node heartbeat and workflow-clock changes, a full build survived a 17-minute silent coder interval with no no-activity reap. A separate 27-execution short-fuse round also completed with no timeout signatures.

@github-actions

github-actions Bot commented Sep 8, 2026

Copy link
Copy Markdown
Contributor

📊 Coverage gate

Thresholds from .coverage-gate.toml: per-surface ≥ 84%, aggregate ≥ 85%, max per-surface regression ≤ 1.0 pp, max aggregate regression ≤ 0.50 pp.

Surface Current Baseline Δ
control-plane 87.80% 87.40% ↑ +0.40 pp 🟡
sdk-go 93.10% 92.00% ↑ +1.10 pp 🟢
sdk-python 94.72% 93.73% ↑ +0.99 pp 🟢
sdk-typescript 91.72% 90.42% ↑ +1.30 pp 🟢
web-ui 84.76% 84.79% ↓ -0.03 pp 🟡
aggregate 85.88% 85.75% ↑ +0.13 pp 🟡

✅ Gate passed

No surface regressed past the allowed threshold and the aggregate stayed above the floor.

@github-actions

github-actions Bot commented Sep 8, 2026

Copy link
Copy Markdown
Contributor

📐 Patch coverage gate

Threshold: 80% on lines this PR touches vs origin/main (from .coverage-gate.toml:thresholds.min_patch).

Surface Touched lines Patch coverage Status
control-plane 63 100.00%
sdk-go 0 ➖ no changes
sdk-python 0 ➖ no changes
sdk-typescript 0 ➖ no changes
web-ui 0 ➖ no changes

✅ Patch gate passed

Every surface whose lines were touched by this PR has patch coverage at or above the threshold.

@santoshkumarradha santoshkumarradha left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

The focused storage tests and CI pass, and the join handles heartbeats that arrive before candidate selection. There is still a narrow concurrent-heartbeat race in the final update that can produce the same false timeout, so I think we should close that before merging.

Comment thread control-plane/internal/storage/execution_records.go
ddbaron and others added 2 commits September 9, 2026 09:16
MarkStaleWorkflowExecutions now repeats its candidate predicates in the
conditional UPDATE, but MarkStaleExecutions still only re-checked status.
A heartbeat that lands between its candidate selection and that UPDATE
therefore still flips a live execution row to timeout — the same false
timeout the workflow reaper just stopped producing, through a narrower
window (its candidate query reads the clock the heartbeat writes, so the
race is the millisecond gap between the two statements rather than the
whole run).

Give it the same treatment: the conditional UPDATE re-evaluates the
activity clock against the sweep cutoff and the non-terminal-child guard,
and the body moves behind the same post-selection seam the workflow reaper
uses so the interleaving is testable without sleeps.

Tests: a real execution-note write landing in that window leaves the row
running with its note intact; a seam that writes nothing still reaps the
silent row with the existing "no activity" message.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@AbirAbbas

Copy link
Copy Markdown
Contributor

@ddbaron pushed one commit on top of your branch so this can land. MarkStaleExecutions had the same select-then-update race you just closed in the workflow reaper — its conditional UPDATE also only re-checked status — so it now re-evaluates the activity clock and the child guard the same way, behind the same post-selection seam. Your two commits are untouched, and the two tests you wrote still pass unchanged.

I reproduced your report end to end on a real control plane with a 20s stale fuse and a 5s sweep, driving a real agent node and using POST /executions/note as the heartbeat: on main the heart-beating run's workflow row is reaped 31s in and the completion callback gets 409; on this branch the same run is still running at 91s with workflow_executions.updated_at frozen at dispatch and executions.updated_at advancing, and the completion returns 200 — while a silent run is still reaped at 30s and one whose heartbeats stop at 25s is reaped at 51s.

Separately, and not caused by this PR: on the PostgreSQL backend neither reaper runs at all. sqlTx has no PrepareContext override, so the ? placeholders in these prepared UPDATEs are never rebound to $n. Against a real PostgreSQL 14 with the storage layer in postgres mode, on main (v0.1.138-rc.13):

MarkStaleExecutions         -> n=0 err=prepare stale execution update: ERROR: syntax error at or near "," (SQLSTATE 42601)
MarkStaleWorkflowExecutions -> n=0 err=prepare stale workflow execution update: ERROR: syntax error at or near "," (SQLSTATE 42601)

and the row that is stale on both clocks stays running. So stale cleanup is a no-op in cloud mode today, and this fix only changes behaviour on the local/SQLite backend until that is addressed. It wants its own PR — and whoever picks it up should look at RetryStaleWorkflowExecutions in the same pass, because it still selects on the workflow clock alone and runs before the reaper, so switching the path on would start re-dispatching live runs wherever max_retries > 0.

@AbirAbbas AbirAbbas 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.

Verified at 8c2395e.

Gates run locally on the control-plane surface exactly as CI runs them (gofmt on the touched files, web UI npm ci && npm run build, go build ./..., go vet ./..., the full go test -tags sqlite_fts5 ./... coverage sweep, and the patch gate): all green, patch coverage 100% on the 63 touched lines, storage package coverage 86.6%.

Anti-tautology: with only the two conditional-UPDATE guards stripped and the seams and tests kept, both interleaving tests fail with expected 0 / actual 1 while SeamWithoutActivityStillReaps and SilentRowsReapAndSyncExecution still pass. Against origin/main's storage source, the PR's own ExecutionActivityProtectsWorkflow fails with the original symptom.

Manual: real control plane with a 20s stale fuse and a 5s sweep, a real agent node, three dispatched executions, notes as heartbeats. On main the heart-beating run is reaped at t=31s and its late completion gets 409; on this branch it is still running at t=91s with the workflow clock frozen and the execution clock advancing, completion returns 200, the silent run is still reaped at t=30s and the one whose heartbeats stop at t=25s is reaped at t=51s.

Caveat recorded in the PR comment, not a blocker for this change: the reapers never execute on the Postgres backend today (sqlTx has no PrepareContext, so ? is never rebound), so this only changes behaviour on the local backend until that is fixed separately.

@AbirAbbas
AbirAbbas dismissed santoshkumarradha’s stale review September 9, 2026 16:26

Addressed: the conditional UPDATE now repeats the stale predicates on both reapers (bcdfb06 workflow, 8c2395e execution), only RowsAffected>0 is counted, and the interleaving tests plus a live control-plane repro are on the thread. Dismissing so the merge queue can take it.

@AbirAbbas
AbirAbbas added this pull request to the merge queue Sep 9, 2026
Merged via the queue into Agent-Field:main with commit 78215f1 Sep 9, 2026
21 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.

3 participants