Workflow resume from persisted state intermittently returns ok:True with missing keys (repro: test_workflow_dsl.py, ~1 in 4)

Summary

tests/test_goal_dsl.py::GoalDslTests::test_resume_goal fails intermittently in
CI with KeyError: 'goal' — the resumed result is missing the key entirely,
which means builtin_resume_goal returned something other than a goal result.

Not a new failure introduced by any one change: the same commit passed in the
sibling CI run and on a rerun, and the test passes locally.

Evidence

Observed on the CI for #375 (commit 9d85a80):

ERROR: test_resume_goal (test_goal_dsl.GoalDslTests.test_resume_goal)
Traceback (most recent call last):
  File "/home/runner/work/Nodus/Nodus/tests/test_goal_dsl.py", line 187, in test_resume_goal
    self.assertEqual(resumed["goal"], "demo")
                     ~~~~~~~^^^^^^^^
KeyError: 'goal'

The pull_request and push workflows ran the same commit; one failed, one
passed.
gh run rerun --failed on the failing job passed.
Locally: python -m unittest tests.test_goal_dsl passed 3/3, and the full
pytest suite passes.

It fails in the Unit tests step (python -m unittest discover -s tests -v),
not the pytest step, so test ordering differs from the local pytest run —
worth suspecting before anything else.

Why it matters

This is a resume path — persisted graph state being reloaded after the in-memory
registry entry is dropped:

graph_id = result["graph_id"]
task_graph._GRAPH_REGISTRY.pop(graph_id, None)
task_graph._GRAPH_VMS.pop(graph_id, None)

resumed_vm = lang.VM([], {}, code_locs=[], source_path=None)
resumed = resumed_vm.builtin_resume_goal(graph_id, "after_a")

So an intermittent failure here is either a genuine race in graph-state
persistence or cross-test interference in .nodus/graphs/. Either would be worth
knowing about independently of the test: resume-from-disk is a user-facing
feature, and a nondeterministic one is worse than a broken one.

A KeyError rather than an assertion mismatch suggests builtin_resume_goal
returned an error record (or an empty map) instead of a goal result, so the first
thing to check is what it actually returns when the state file is missing or
partially written — it should not silently return a shape that only fails at the
call site.

Reproduction

Not reliably reproducible on demand yet. Suggested approach:

Run python -m unittest discover -s tests -v repeatedly (the CI command),
rather than pytest — the failure has only been seen under that ordering.
Check whether .nodus/graphs/ state written by one test is removed by
another test's cleanup while this one is between write and read.
Assert on the returned value rather than indexing it, so a failure reports
what came back instead of KeyError.

Fix direction

Two separate things:

Make the test report usefully: assert the returned shape before indexing.
Find the actual nondeterminism. If it is cross-test interference in
.nodus/graphs/, give the test its own state directory; if it is a
write/flush race in graph persistence, that is a runtime bug, not a test bug.

Affected versions

v4.1.1 and current main. First observed 2026-08-15.

fix(errors): one path convention, and name the file the error is actu…

More evidence, and a sharper hypothesis than the one I filed this with.

Five intermittent failures observed across full-suite runs on 2026-08-15, every one passing in isolation:

test	file
`test_resume_goal`	`test_goal_dsl.py` (this issue)
`test_linear_goal`	`test_goal_dsl.py`
`test_workflow_runs_endpoint_supports_wait_retry_and_cursor_filters`	`test_server.py`
`test_dead_letter_list_and_replay_are_exposed_over_http`	`test_server.py`
`test_workflow_cli_commands`, `test_workflow_resume_api_accepts_payload_and_event_metadata`	`test_workflow_dsl.py`

All are HTTP-server or workflow/goal-runner tests. None is a timing test in the usual sense.

Not the file accumulation from #380. I fixed that in #381 and these continued. To rule out my own changes I ran the suite with an unrelated in-flight fix stashed and got test_goal_dsl.py::test_linear_goal — the family flakes with or without it.

The common factor left is the global default workflow runner: _DEFAULT_RUNNER in nodus_lang_workflow/runner.py is process-global, rebuilt whenever os.getcwd() differs from the root it was built for, and _start_default_sweep_locked() attaches a daemon sweep thread to it. Tests that chdir — several build a project directory and chdir into it — silently swap the runner underneath any sweep thread still running, and the tests above all read or write run state through that shared object.

That is a different mechanism from list_runs() cost, and the store isolation shipped in #381 does not touch it.

Suggested next step, cheaper than chasing individual tests: give each test its own runner rather than sharing a global one — the same treatment test_worker_death_detected_by_sweeper already applies by hand — or make the rebuild-on-chdir path stop the previous sweep thread deterministically and assert it has stopped.

Worth keeping as one issue rather than five: they are the same shared object, and fixing them one at a time is how the --help guard (#353) recurred four times.

Not fixed. Narrowed considerably, and five hypotheses ruled out by test rather than by argument. Writing it up so the next attempt starts from evidence instead of repeating mine.

A reliable reproduction

The full suite is not needed. One file reproduces it in ~10 seconds:

PYTHONPATH=".../src" python -m pytest tests/test_workflow_dsl.py -q -p no:cacheprovider

Roughly 1 failure in 3–6 runs. Three files together (test_goal_dsl.py test_workflow_dsl.py test_server.py) reproduce more often — 6 of 10 in one sample.

It is always the same operation

Every failure I captured is a resume from persisted state, immediately after the run that created it, in the tests that do:

task_graph._GRAPH_REGISTRY.pop(graph_id, None)
task_graph._GRAPH_VMS.pop(graph_id, None)

— popping the in-memory registry precisely to force a load from disk. Both the HTTP path (POST /workflow/resume) and the CLI path (nodus workflow-resume) fail the same way.

The shape of the failure is consistent and specific: the resume reports ok: True and returns a result that is missing keys — KeyError: 'state', KeyError: 'steps', KeyError: 'goal'. It is not an error path. It is a successful resume against state that came back incomplete.

Ruled out — each tested, not reasoned about

The auto-sweep thread. Forced it to fire every 10 ms with a plugin: failures continued. Ran with NODUS_WORKFLOW_AUTOSWEEP=0: failures continued. Not the sweeper.
Port conflicts. Every server test binds port 0 (ephemeral). Not a clash.
Accumulated run files (the Test suite accumulates workflow-run files in the repo's .nodus/, and LocalWorkflowStore rescans all of them — the suite destabilizes its own later runs #380 mechanism). Reproduces with the store at zero files.
os.chdir repointing the CWD-keyed global runner. Removed the two os.chdir calls in SQLiteWorkflowServerTests and added reset_default_workflow_runner() after them: failure rate unchanged. (The hazard is real — chdir is process-wide and the default runner keys on os.getcwd(), so it can repoint a store under a live server thread — but it is not this.)
Unlocked reads of graph state. Writes take _STATE_LOCK and are atomic via os.replace; reads took no lock, and a resume reads two separately-written files (_graph_state_path and _checkpoint_path), so a reader can land between two write transactions. Made both readers take _STATE_LOCK: 2 failures in 12 runs, versus a comparable baseline. Not eliminated, so not the cause — though reads arguably should take the lock regardless.

All five changes are reverted; none is in the tree.

What is in the tree

The payload["ok"] assertions in test_server.py, test_workflow_dsl.py and test_goal_dsl.py now pass the payload as the failure message, and one dict index has an assertIn guard before it. That is the only change kept, and it is why the above was possible to learn: the original failure was a bare AssertionError: False is not true or an unexplained KeyError, which says nothing about why a resume came back empty. A flake that cannot be diagnosed from its own CI output is a flake nobody fixes.

Where I would look next

The evidence points at run state being incomplete at the moment of an immediate read-back, rather than at anything concurrent in the test harness:

Does the /workflow/run response return before the graph state and checkpoint are both durably written? A resume issued microseconds later is exactly the window that would expose it.
_merge_resume_state(state, checkpoint) combines the two files. What does it return when one is present and complete and the other is stale by one write? A partial dict with ok: True is consistent with what the tests see.
Worth adding a temporary assertion inside the resume path that the merged state has the keys the runner expects, and running the loop above — that would say which of the two inputs is short.

Severity note

This is not only a test-infrastructure problem. The failing operation is "run a workflow, then resume it from persistence", which is the feature's whole point, and it fails a few percent of the time on a fast machine with no contention. If it is a write-ordering race, an embedder doing run-then-resume hits it too — and ok: True with missing keys is the worst possible presentation, because a host cannot tell it went wrong.

test(workflow): report the payload when an ok assertion fails (#376) (#…

Second investigation round. Still not fixed, but the search space is much smaller. Two more hypotheses rejected, and one result that rules out the whole run/resume implementation.

The run → resume cycle is not the problem

A standalone harness doing exactly what the failing tests do — run a workflow via nodus workflow-run, drop the graph from _GRAPH_REGISTRY and _GRAPH_VMS to force a load from disk, resume via nodus workflow-resume --checkpoint — in one process, no pytest, no server:

0 failures in 40 rounds

So persistence, the two-file state/checkpoint merge, and the resume path are all fine on their own. The failure needs the test process's environment, which is what a RuntimeService brings with it. Every failing file starts one in setUpClass via run_in_thread.

What a live RuntimeService adds

RuntimeService.__init__ starts _worker_sweeper_loop as a daemon thread. Every WORKER_SWEEP_INTERVAL_MS (500 ms) it calls _run_workflow_sweep_once() → workflow_runner.sweep(vm_factory), and sweep() does this:

for record in self.list_rehydratable_runs():
    ...
    info = self.rehydrate_run(vm, record.run_id, rebuild_graph=rebuild_graph)

It rehydrates every non-terminal run in the store — not only runs that server owns. Any run a test created and is about to resume is fair game, twice a second, from another thread, against the same records.

That is a genuine concurrent mutator of exactly the state the failing assertions read. Neutralising it (_run_workflow_sweep_once → no-op) moved the observed rate from 1/8 to 1/16, so it is a contributor — but not sufficient on its own, and I would not claim a rate change on those sample sizes as more than a hint.

Also rejected this round: the 200 ms deadline

resume_workflow_in_vm() applies timeout_ms=EXECUTION_TIMEOUT_MS (200 ms) by default via configure_vm_limits. That looked like an excellent fit — load-dependent, only bites the most expensive operation, invisible standalone. Removing the deadline made it worse: 5 failures in 16 runs versus 1 in 8 with it.

Worth recording as a negative result: the race is timing-sensitive in both directions, which is what you would expect from concurrent access rather than a simple timeout.

Running tally of ruled-out causes

hypothesis	how tested	verdict
auto-sweep thread (default runner)	10 ms interval; then `AUTOSWEEP=0`	rejected
port conflicts	all server tests bind port 0	rejected
accumulated run files (#380)	reproduced at 0 files	rejected
`os.chdir` repointing the CWD-keyed runner	chdirs removed + runner reset	rejected
unlocked reads of graph state	both readers given `_STATE_LOCK`	rejected (2/12)
run/resume logic itself	40 standalone rounds	rejected — 0 failures
200 ms resume deadline	deadline stripped	rejected (worse: 5/16)
`RuntimeService` background sweep	sweep neutralised	contributor, not sufficient (1/16)

Two capture attempts that did not fire

Worth recording so the next attempt does not repeat them:

Patching task_graph.resume_graph after import does nothing — vm.py does from nodus.orchestration.task_graph import resume_graph, binding the name at import.
Patching WorkflowFrameworkRunner.resume_workflow and VM.builtin_resume_workflow at class level (which bound imports cannot dodge) produced no capture in 14 runs. Either the CLI --checkpoint path reaches neither — likely, it appears to go through resume_graph in task_graph — or the instrumentation perturbs the timing enough to hide the race.

The next capture should wrap nodus.cli.cli.resume_workflow and nodus.orchestration.task_graph.resume_graph in the consuming modules' namespaces (nodus.vm.vm.resume_graph, nodus.services.api.resume_graph), not at the definition site.

Where I would go next

The architecture question is more promising than another instrumentation round: should a RuntimeService sweeper rehydrate runs it does not own? It currently adopts every non-terminal run in whatever store the process-global runner points at. In a test process — or any host with two services, or a service alongside CLI activity — that means a background thread resuming other people's workflows. Scoping the sweep to runs the service created (or claimed) would make the interference structurally impossible rather than timing-dependent, and is likely correct on its own merits.

That is the same through-line as #380 and #387: process-global state with no ownership, and a guard that only one entry point applies.

Status

Still a release blocker for 4.2.0. No source changes were made in this round — every experiment was a throwaway pytest plugin, and the tree is clean.

fix(workflow): a sweeper must not adopt runs it does not own (#376) (#…

Partial fix landed in #388 (546a2ea). Issue stays open.

Found the mechanism

sweep() rehydrates every non-terminal run in the store, and rehydration is not read-only:

graph = register_graph(graph)
register_graph_vm(run_id, vm)     # the sweeper's own throwaway VM

Those replace the process-global registry entry for a run and bind it to the sweeper's VM. Landing that between a test's registry-drop and its resume hands the test a graph pointed at someone else's VM — and the resume returns ok: true with empty steps, which is exactly the shape every captured failure had. It explains the ok: true presentation, which nothing else I tried did.

Fixed, using machinery that already existed

rehydrate_run() now claims the run before adopting it. resume_workflow() has always claimed; this path never did, so the two could mutate the same record concurrently.
sweep(min_idle_ms=…) — do not adopt a run touched more recently than that. Rehydration is for runs whose owner is gone. RuntimeService passes the store's claim TTL; explicit callers are unchanged.

Why it is not closed

evidence	direction
standalone run→resume, no server: 0 failures / 40	the run/resume logic is not at fault
neutralising the service sweep pre-fix: 1/8 → 1/16	pointed at the sweeper
full suite post-fix on a loaded machine: 3 failures → 1 (and that one is the documented `test_scheduler_fairness`)	improvement
2 failures in a 16-run sample post-fix	something remains

For whoever picks this up

The residual is worth re-testing against the 200 ms deadline on the resume path. resume_workflow_in_vm() applies timeout_ms=EXECUTION_TIMEOUT_MS by default. I rejected it earlier because removing it made things worse (5/16) — but that experiment stripped the deadline globally via configure_vm_limits, which also lengthens every other operation and changes the interleaving. A narrower experiment, raising the deadline only on the resume path, has not been run.

That suspicion has independent support: the same 200 ms default was the real cause of a different intermittent failure in test_finally_rethrow.py, found and fixed in the same PR. It is the third time in this cycle (#350, #49, now this) that the CLI's 200 ms default has been the thing actually breaking under load, and each time it presented as something else.

Running tally of ruled-out causes is in the previous comment; RuntimeService sweep moves from "contributor, not sufficient" to fixed, and it was a real defect.

fix(workflow): lock store reads and give resume a workable deadline (#…

Two more causes fixed in #389 (53fc1e0). Four total. Still not closing — here is where it stands.

Fixed this round, both found by capturing the failure

3. Windows sharing violation in the store's atomic write. list_runs() scanned without the store lock, so a scan could hold a run file open exactly while another thread replaced it:

PermissionError: [WinError 5] Access is denied:
  '...\runs\g_57537a5a.json.<uuid>.tmp' -> '...\runs\g_57537a5a.json'

POSIX permits replacing an open file; Windows does not. That is why this was invisible on Linux CI and only ever reproduced locally. Reads take the lock now, and os.replace retries briefly for handles held by scanners or indexers.

4. A 200ms wall-clock budget on resume. resume_workflow_in_vm used EXECUTION_TIMEOUT_MS, sized for running a script. A resume first reads state and checkpoint from disk and rebuilds the graph — recompiling the stored workflow source — before any step runs, all charged to the same budget. New RESUME_TIMEOUT_MS (30s) covers the resume paths only.

I had rejected the deadline earlier because removing it globally made things worse (5/16). That rejection was correct about the experiment and wrong about the cause: raising it on the resume path alone took a two-file sample from 2/16 to 0/16. Worth remembering when a broad experiment refutes a narrow hypothesis.

Measured

	flaky trio (workflow_dsl + goal_dsl + server)
worst observed, before any fix	~6 failures / 10 runs
after all four fixes	2 / 20

Full suite reached 1997 passed, 0 failed — the first fully green run in this cycle, including test_scheduler_fairness, which CLAUDE.md lists as a known flake.

Why it stays open

2/20 is not zero, and the residual failures are a different test each time (test_linear_goal, test_workflow_checkpoint_rollback, test_workflow_run_uses_sqlite_store_when_configured). That pattern suggests several small independent races rather than one remaining cause, and I have no evidence they are test-only — they run real product paths.

The path to zero, if it is wanted

Every cause found so far traces to the same root: process-global workflow state with no ownership. RuntimeService binds the process-global runner rather than owning one, so any two participants in a process share a store, a registry and a sweeper. Making a service own its runner would make the whole class structurally impossible instead of individually fixable — but the VM resolves the runner globally in builtin_run_workflow, so it is the same VM-agnostic-resolution problem as #339, and a real piece of design work rather than another patch.

Closing — decision recorded, since the comment above says the opposite.

The previous comment ended "Still not closing," and the issue was then closed without a rationale. Filling that in.

Decision: ship with this downgraded from release blocker to a known issue, and carry the remaining work as its own item.

What that rests on:

Four real defects were found and fixed, all user-facing rather than test-only — sweeper hijack of unowned runs (fix(workflow): a sweeper must not adopt runs it does not own (#376) #388), Windows os.replace sharing violation from a lock-free list_runs() (fix(workflow): lock store reads and give resume a workable deadline (#376) #389), a 200ms budget on resume (fix(workflow): lock store reads and give resume a workable deadline (#376) #389), and unbounded store growth (Test suite accumulates workflow-run files in the repo's .nodus/, and LocalWorkflowStore rescans all of them — the suite destabilizes its own later runs #380/perf(workflow): stop LocalWorkflowStore paying per-record syscalls (#380 part 2) #385).
The reported symptom is gone from ordinary use. The originally reported "~1 in 4" resume returning ok: true with missing keys did not recur after the fixes.
2/20 residual on the flaky trio, naming a different test each run — test_linear_goal, test_workflow_checkpoint_rollback, test_workflow_run_uses_sqlite_store_when_configured. That is consistent with several small independent races, not one remaining cause, so there is nothing specific left for this issue to track.

The remaining work is #390 — workflow state is process-global with no owner, which is where all four causes trace back to. That is a design change (the VM resolves the runner from module state, not from its execution context — same shape as #339), not another patch, and it deserves its own cycle.

Recorded in CHANGELOG.md under [Unreleased] as a known issue, so this does not disappear at release.

docs(changelog): record the #376 fixes, and stop the gate punishing h…

docs(audit): verify external architecture audit 01; file 5 findings (#…

docs(audit): verify external architecture audit 03; file a critical w…

docs(design): decide the agent boundary -- in, narrowly, on a split rule

docs(design): propose a domain statement — #409 Part B (#423)

feat(goal): a goal can declare a stopping condition (#409 Part A) (#428)

fix: give process-global runtime state an owner (#460)

release: 5.0.3 (#461)

docs: bring CLAUDE.md current with 5.0.4 (#464)

Navigation Menu

Repository navigation

Workflow resume from persisted state intermittently returns ok:True with missing keys (repro: test_workflow_dsl.py, ~1 in 4) #376

Summary

Evidence

Why it matters

Reproduction

Fix direction

Affected versions

A reliable reproduction

It is always the same operation

Ruled out — each tested, not reasoned about

What is in the tree

Where I would look next

Severity note

The run → resume cycle is not the problem

What a live RuntimeService adds

Also rejected this round: the 200 ms deadline

Running tally of ruled-out causes

Two capture attempts that did not fire

Where I would go next

Status

Found the mechanism

Fixed, using machinery that already existed

Why it is not closed

For whoever picks this up

Fixed this round, both found by capturing the failure

Measured

Why it stays open

The path to zero, if it is wanted

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Workflow resume from persisted state intermittently returns ok:True with missing keys (repro: test_workflow_dsl.py, ~1 in 4) #376

Description

Summary

Evidence

Why it matters

Reproduction

Fix direction

Affected versions

Activity

Masterplanner25 commented on Aug 15, 2026

Masterplanner25 commented on Aug 15, 2026

A reliable reproduction

It is always the same operation

Ruled out — each tested, not reasoned about

What is in the tree

Where I would look next

Severity note

Masterplanner25 commented on Aug 15, 2026

The run → resume cycle is not the problem

What a live RuntimeService adds

Also rejected this round: the 200 ms deadline

Running tally of ruled-out causes

Two capture attempts that did not fire

Where I would go next

Status

Masterplanner25 commented on Aug 15, 2026

Found the mechanism

Fixed, using machinery that already existed

Why it is not closed

For whoever picks this up

Masterplanner25 commented on Aug 15, 2026

Fixed this round, both found by capturing the failure

Measured

Why it stays open

The path to zero, if it is wanted

Masterplanner25 commented on Aug 15, 2026

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions