When replay goes wrong

Every transcript on this page is output from running the script shown with it locally (spool run, or spool dev for the debugging commands), with the server’s startup lines left out.

A workflow that sleeps, waits for a signal, or survives a deploy is a program the engine runs more than once. Most of the time you never notice. This page is about the times you do: what the engine refuses, what the error is telling you, and how to find the line that caused it.

It assumes the short rules in Authoring model.

What a replay actually looks like

Start with the case where nothing is wrong, because the shape surprises people.

#!/usr/bin/env bash
set -euo pipefail
echo pass >> /tmp/pass-count
spool step a -- echo one
spool sleep 3s
spool step b -- echo two

That file wrote two lines to /tmp/pass-count. The sleep evicted the script, and the resume ran it again from the top. The second time, spool step a returned its recorded result, but the echo outside any step ran again because nothing recorded it.

Code between durable calls runs on every pass. Durable calls run once and replay from the log after that.

The determinism error

Here is a script with a bug that looks reasonable:

#!/usr/bin/env bash
set -euo pipefail

if [ -f /tmp/spool-marker-demo ]; then
  spool step reuse-cache -- echo "cache hit"
else
  touch /tmp/spool-marker-demo
  spool step build -- echo "built it"
fi

spool sleep 2s
echo "past the sleep"

It branches on a file, and the branch it takes creates that file. First pass: the marker is absent, so it builds. After the sleep the script replays, the marker now exists, and it takes the other branch:

$ spool run diverge.sh
  run: dev:default:run-slsQVAbzHBHC6J4o
built it

  - replaying from checkpoint (completed steps are cached, not re-run)
error: determinism violation: this script took a different path on replay. Its
durable call number 1 was step "build" the first time and is step "reuse-cache"
now. A durable script has to make the same durable calls in the same order on
every pass, and a branch on something that changes between passes (the clock, a
random value, a read outside a step) breaks that. Put the value that changes
inside a step, or set SPOOL_REPLAY_MODE=lenient if the new path is intended.
  dev:default:run-slsQVAbzHBHC6J4o failed: script exited 2

(The error is one line in the terminal; it is wrapped here.)

Reading it

durable call number 1 is a position in a sequence, not a line number. These calls take the next number, counting from one, in one shared sequence:

step · sleep · wait signal · wait event · lock · activity run · activity submit · spawn · call · event emit · state cas · state incr

So call number 1 is the first of those the script makes, whichever it is. spool artifact put / get, spool activity wait and spool state add are recorded too and replay like the rest, but they take no number in this sequence and don’t advance the count.

was step "build" is what stood at that position on the first pass: the step named build. is step "reuse-cache" is what the replay found there instead. A call with no name of its own is named by its count, as in sleep number 2.

To locate the bug, count calls from that list down your script until you reach the reported position, then look at what decides which call happens there. It is almost always the nearest enclosing if, loop bound, or early return. Here call number 1 is inside the if, whose condition reads a file the first pass created. The condition is the bug; neither branch is.

The check has limits:

• It compares positions. Two different branches that both reach spool step deploy at call number 5 look identical to it, so a divergence that rejoins is not reported.
• It fires on the first mismatch only. Everything after that is unexamined.
• If reading the recorded sequence fails, the check is skipped rather than failing your run.

Fixing it

Move the nondeterministic read into a durable call, so both passes branch on the same recorded answer:

#!/usr/bin/env bash
set -euo pipefail

cached=$(spool step check-cache -- bash -c \
  'test -f /tmp/spool-marker-demo && echo hit || echo miss')

if [ "$cached" = hit ]; then
  spool step reuse-cache -- echo "cache hit"
else
  touch /tmp/spool-marker-demo
  spool step build -- echo "built it"
fi

spool sleep 2s
echo "past the sleep"

$ spool run fixed.sh
  run: dev:default:run-s6fuH4h1gURg1U5V
built it

  - replaying from checkpoint (completed steps are cached, not re-run)
built it
past the sleep
  dev:default:run-s6fuH4h1gURg1U5V completed

check-cache recorded miss on the first pass and replayed miss on the second, so both passes took the build branch. The built it line appears twice because replaying a step prints its recorded output; the command behind it ran once.

This holds with any number of agents. A second pass claimed by a machine where /tmp/spool-marker-demo does not exist still takes the build branch, because the answer comes out of the log. The broken version gets worse as you add agents.

The marker is still a local file, so this is no way to cache across runs. touch runs on whichever agent that pass landed on, and a later run scheduled elsewhere sees nothing. Anything that has to be shared belongs in an entity-scoped state cell or an artifact (spool artifact put/get), both of which live in the project rather than on a machine.

The general form: anything the run itself changes, or that changes on its own, has to be read inside a durable call. Wall-clock, $RANDOM, a directory listing, an HTTP GET, the contents of a file another step writes.

spool step is the usual one, but any durable call will do: a read that has to happen on another machine can be a spool activity run. spool artifact get is recorded for this reason. It pins which artifact you resolved, so a later pass branching on what it restored takes the same path.

SPOOL_REPLAY_MODE=lenient

The error message offers lenient mode. It does not make the divergence safe; it removes the check.

Same broken script, same divergence, lenient:

$ SPOOL_REPLAY_MODE=lenient spool run diverge.sh
  run: dev:default:run-kMTjGkoNhRxMx2K2
built it

  - replaying from checkpoint (completed steps are cached, not re-run)
cache hit
past the sleep
  dev:default:run-kMTjGkoNhRxMx2K2 completed

The run completes, and cache hit executed. This run had never seen reuse-cache, so there was nothing to replay: it ran for real on the resume, doing work the first pass never did. The build step’s recorded result is still in the log, orphaned.

Strict mode fails a run that has gone off its recorded path. Lenient mode lets it keep going down a different one. off is a synonym for lenient; strict is the default and anything else you set means strict.

Reach for it when the divergence is deliberate and you understand what will re-execute - a debugging session, or a workflow you are mid-way through rewriting. It is read from the agent’s environment, so it applies to everything that agent runs, and only where you control that environment: an agent you run, or a local spool run / spool dev, whose built-in agent reads your shell’s environment. Managed environments always run strict.

A lenient run also records no positions, so spool run rerun --from has nothing to cut at and the run page can’t show which step is in flight.

Debugging a run that suspended many times

A run that sleeps between every item can suspend hundreds of times. Some of what you might expect to find is not there, so start with what is. The transcripts below are from this script, submitted to a local spool dev:

#!/usr/bin/env bash
set -euo pipefail
spool step fetch -- ./fetch.sh
for host in web-1 web-2 web-3; do
  spool step drain --label "$host" -- ./drain.sh "$host"
  spool sleep 1s
done
spool step summarise -- ./summarise.sh

spool run steps <run> lists the durable calls the run completed, in the order it reached them:

$ spool run steps dev:default:run-DtoUoWCRZ7KGH9wv
SITE       #  LABEL           OUTCOME
fetch      0  ./fetch.sh      ✓ (exit 0)
drain      0  web-1           ✓ (exit 0)
sleep      0  -               · (slept)
drain      1  web-2           ✓ (exit 0)
sleep      1  -               · (slept)
drain      2  web-3           ✓ (exit 0)
sleep      2  -               · (slept)
summarise  0  ./summarise.sh  ✓ (exit 0)

This is the first thing to look at: a run stuck mid-loop shows which iteration it reached. drain is one step reached three times, so it lists once per reach with its number, counting from 0. A signal wait shows under its name, as · (signal).

The third column says what each reach was working on: the --label when you passed one, otherwise the command. A label doesn’t affect which result a call replays, so two passes may label one step differently without the replay losing it.

It lists only what finished, so the call a run is blocked on is the one absent from the list. Locks and activities appear under their names; sleeps, emits, calls and artifact calls appear under the verb, as sleep does above.

What you will not find: a suspension count. Suspending is not a workflow event. The run above suspended three times, and its durable log records one activity from start to finish. spool run events -o json prints that log; here it is reduced to one line per event:

$ spool run events dev:default:run-DtoUoWCRZ7KGH9wv -o json | jq -r '.events[] | "\(.seq) \(.kind)"'
0 WorkflowStarted
1 ActivityScheduled
2 ActivityCompleted
3 WorkflowCompleted

spool run get <run> -o json agrees with "activities_completed": 1. A suspension keeps the same activity open rather than completing it, so the run stays on one activity across every eviction, and you cannot ask the system how many times a run has replayed. If you need that number, record it yourself, the way the first example on this page did.

Every pass’s output is stored, though. Plain spool logs shows only the final pass, so a run that replayed forty times reads like a script that ran once:

$ spool logs dev:default:run-DtoUoWCRZ7KGH9wv
fetched 3 hosts
drained web-1
drained web-2
drained web-3
done

--follow keeps every pass and marks where each begins. On a run that has already finished it replays the whole history rather than tailing:

$ spool logs dev:default:run-DtoUoWCRZ7KGH9wv --follow
fetched 3 hosts
drained web-1

  - replaying from checkpoint (completed steps are cached, not re-run)
fetched 3 hosts
drained web-1
drained web-2

  - replaying from checkpoint (completed steps are cached, not re-run)
fetched 3 hosts
drained web-1
drained web-2
drained web-3

  - replaying from checkpoint (completed steps are cached, not re-run)
fetched 3 hosts
drained web-1
drained web-2
drained web-3
done

Four passes for a script with three sleeps. Read it as blocks: each replaying from checkpoint marker starts a pass. fetched 3 hosts appearing four times is the recorded step replaying its output; ./fetch.sh ran once.

So the debugging loop for a long-lived run is: spool run steps for how far it got, spool logs --follow for what each pass did, spool run events for the run-level story, and your own instrumentation for anything you need counted.

What the engine does not catch

• Side effects between durable calls. The engine cannot see your echo, your curl, or your rm. Code outside a durable call runs on every pass and nothing warns you.
• Nondeterminism inside a call. A step whose command is itself nondeterministic records whatever it produced the first time. That is usually the point, and occasionally a surprise.
• Divergence in the calls it does not sequence. spool artifact, spool activity wait and spool state add replay their recorded results but take no position, so a branch that changes how many of those happen is invisible to the check.
• Divergence that rejoins (above).