DEV Community

Marin T. Kael
Marin T. Kael

Posted on

Four green Mondays that wrote nothing: a uuid above the first step

The symptom

For four Mondays in a row my data pipeline finished with complete, stages_ok: 16, stages_failed: 0. And the run row in the database stayed empty: duration_ms was NULL, no summary written.

Every downstream reader filters on duration_ms IS NOT NULL, sensibly, to skip fragmented runs. So those runs did not show up as broken. They did not show up at all. The public time series just had holes in it, and nothing anywhere used the word error.

The only clue was in a later stage: a foreign key violation. It was writing against a run that did not exist.

The cause

The pipeline is a Cloudflare Workflow. Reduced to the shape that matters:

export class ResearchPipeline extends WorkflowEntrypoint {
  async run(event, step) {
    const runId = crypto.randomUUID()               // <-- here

    await step.do('create-run', () => insertRun(runId))
    await step.do('collect',    () => collect(runId))

    if (event.payload.weekly) {
      await step.sleep('cool-off', '5 minutes')     // <-- and here
    }

    await step.do('finalize-run', () => finalizeRun(runId))
  }
}
Enter fullscreen mode Exit fullscreen mode

step.sleep does not block. It ends the invocation. When the timer fires, the engine calls run() again from the top and replays it. Anything inside a step.do hands back its cached result without executing. Anything outside a step runs again, for real.

So crypto.randomUUID() ran a second time, and after the sleep runId held a value nothing had ever been written under. create-run did not re-execute, so no row existed for the new id. finalize-run then updated a row that was not there.

Why it hid so well

UPDATE ... WHERE id = ? matching zero rows is not an error. It is an ordinary result. D1 reports success, meta.changes is 0, and if you never read meta.changes you cannot tell a write from a no-op.

Put that next to a reader that filters incomplete rows out and you get a very quiet failure. The writer believes it wrote. The reader believes there is nothing to read. The monitoring shows green.

It only happened on Mondays because only the weekly branch carried the sleep. That turned out to be the most useful part of the fingerprint: a bug that appears on exactly one weekday is pointing at the branch that only that day takes.

The two rules I took out of it

First, in any environment that can replay your function, everything identity-bearing or time-bearing belongs inside a persisted step. Uuids, Date.now(), anything random. Computed above the first step, you get a fresh one on every replay.

const runId = await step.do('run-id', async () => crypto.randomUUID())
Enter fullscreen mode Exit fullscreen mode

Second, a write that reports success is not the same as a write that happened. Check the row count and throw on zero.

const res = await db.prepare('UPDATE runs SET ... WHERE id = ?').bind(runId).run()
if (res.meta.changes === 0) throw new Error(`finalize hit 0 rows for run ${runId}`)
Enter fullscreen mode Exit fullscreen mode

The second rule is the more general one. The first only bites inside workflow engines. The second bites everywhere, and it is what turned four silent Mondays into a loud error on the fifth.

Still open

The older runs are still holes. Their stage data sits in the database, the run row does not, and for the oldest two the workflow instance history is past retention, so the duration cannot be reconstructed. I am recording those as documented gaps instead of estimating them. A gap you can see is worth more than a number you made up.

Top comments (0)