Skip to content

world-postgres queue delivery inherits undici's 300s fetch timeouts: healthy long-running deliveries are declared crashed and re-executed while still alive #3811

Description

@lunareed720

Affected versions

  • @workflow/world-postgres@5.0.0-beta.35 (observed in production) — and the
    same code is present in 5.0.0-beta.36 (executeMessageOverHttp still uses
    the bare global fetch with no dispatcher/timeout override).
  • Runtime: Node 24 (undici defaults headersTimeout = bodyTimeout = 300 000 ms).

Summary

createQueue() delivers each graphile-worker job by POSTing the message to the
local workflow executor and executing the workflow body inline within that
HTTP request (executeMessageOverHttp). The call uses the global fetch
without a dispatcher, so Node's undici defaults apply: if the inline execution
takes longer than ~300 s before the response headers/body complete, the CLIENT
side of the loopback call times out with TypeError: fetch failed, the
graphile task is marked failed, and the message is redelivered a few seconds
later — while the server-side handler keeps executing.

The redelivery path then logs:

Re-executing inline steps owned by this queue message — a previous delivery
crashed mid-body and this redelivery is recovering them

but no crash happened; the "previous delivery" is still running in the same
process. The result is two concurrent executions of the same steps: duplicate
provider calls (fenced only if the application has its own idempotency layer)
and a stale writer that keeps appending to the run's streams after the
recovery attempt completed (see the companion Eve report on missing
delivery-generation fencing).

Production observations (single 13 h log window, Node 24.18, beta.35)

02:22:05 [Graphile Worker] Failed task 28212 (…, 304518.57ms, attempt 1 of 49) with error 'fetch failed'
02:22:08 [workflow-sdk] Re-executing inline steps owned by this queue message — …
04:32:53 [Graphile Worker] Failed task 28469 (…, 301084.86ms, attempt 1 of 49) with error 'fetch failed'
04:32:56 [workflow-sdk] Re-executing inline steps owned by this queue message — …
07:51:02 [Graphile Worker] Failed task 29233 (…, 309026.93ms, attempt 1 of 49) with error 'fetch failed'
07:51:05 [workflow-sdk] Re-executing inline steps owned by this queue message — …

All three deliveries died at the 300 s scale with fetch failed; the World
database showed the same step with two step_started events (one per
delivery) and a final completed row at attempt 2, while the first delivery
demonstrably kept running for another ten minutes (its provider stream error
arrived at 08:01:29 and it then appended a failure cascade to the session's
user stream). Only the top-level TypeError: fetch failed is currently
logged, so we could not distinguish UND_ERR_HEADERS_TIMEOUT from
UND_ERR_BODY_TIMEOUT; given the handler responds only after the inline body
finishes, headersTimeout is the likely subtype.

Why this matters

Any inline step slower than ~5 minutes (long LLM streams, long tool
executions) is systematically killed-and-redelivered:

  • every such delivery re-executes its recovered steps (duplicate side effects
    unless the application fences them);
  • the surviving original execution becomes a stale writer with no fencing;
  • with maxAttempts 49 the same long body can loop repeatedly.

Suggested fix

Give the loopback delivery call an explicit transport with no (or a very
generous, configurable) headers/body timeout — e.g. a dedicated undici Agent
with headersTimeout: 0, bodyTimeout: 0 (or a node:http request with an
explicit agent; note Node ≥19's http.globalAgent carries a 5 s socket
timeout of its own), while keeping the graphile abortSignal wiring for
shutdown. Crash recovery remains covered by worker restart plus the existing
startup reconciliation. Additionally, logging error.cause?.code,
the queue message id, and the delivery attempt would make this failure mode
diagnosable from logs alone.

Minimal reproduction sketch

  1. Postgres world with the graphile queue; one workflow whose single inline
    step await new Promise((r) => setTimeout(r, 6 * 60 * 1000)) (or any
    provider stream slower than 5 minutes).
  2. Start the run; watch the graphile task fail at ~300 s with fetch failed
    and the redelivery log line; observe two step_started events for the same
    step and both executions running concurrently.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions