Relationships
#4038 Shared dispatch bookkeeping queue delays completed worker results by up to 58 seconds
Opened by swamp_lord · 10/27/2026
Summary
Serve serializes dispatch bookkeeping through one shared TransitionTail. A worker's completed result cannot return from remote execution until its step_lease.complete transition reaches the front of that queue and finishes.
In the investigated run, one readiness dispatch spent 57.79 seconds settling after the worker returned. Of that, 56.007 seconds was explicitly measured queue wait, with 23 transitions ahead of it.
This is confirmed server-side head-of-line blocking. The shared queue and awaited completion remain on main at 0f682899. This is a Swamp core runtime issue, not a request to change UAT workflow structure.
Environment and evidence identifiers
| Field | Value |
|---|---|
| Workflow run | 5b5b8600-5e0d-4bb5-bb8b-1fc326eaf8ad |
| Axiom dataset | swamp-serve-traces |
| Axiom trace | b08a36c2d27545c25ccd48352f98980b |
| Deployed serve version | 20261025.114930.0-sha.b4dd513d |
| Serve host | swamp-serve-vm-1 |
| Bitbison stream | b5257a30-7297-4632-9030-6292d077b26c |
| Serve process surrogate | 554601050635676792091667423413 |
| Step | ready-serve-8 |
| Dispatch/lease ID | 78c59e6c-f622-47a4-9dbe-3e314d43572b |
| Settlement span | 5205f3863f28e6a3 |
| Queue-wait span | ac523c4abb1ba4b4 |
| Completion-transition span | ead99343075cf12f |
All timestamps below are October 26, 2026, UTC.
Mechanism
src/serve/dispatch_service.ts owns a single:
readonly #transitions = new TransitionTail("dispatch");#leaseTransition() routes lease methods through the general model-method execution path and places the entire operation on that tail. The shared ordering includes lease acquisition, write marking, completion and failure/expiry transitions. Pending-dispatch bookkeeping also uses the dispatch tail.
worker result received
→ await leaseTransition("complete")
→ wait behind earlier dispatch-tail operations
→ run complete through the model-method execution path
→ return outputs/result
→ finish remote execution cleanupLocations on inspected main:
dispatch_service.ts:210: shared tail.dispatch_service.ts:892: awaited completion.dispatch_service.ts:1177:#leaseTransition().- src/serve/transition_tail.ts: promise-chain serialization.
This is a different queue from worker selection. A short swamp.dispatch.queue span does not imply the result can settle promptly.
Axiom evidence: completed-worker timeline
For ready-serve-8:
| Event | UTC time / duration |
|---|---|
| Dispatch send begins | 21:30:19.026 |
| Dispatch send duration | 9.017 s |
| Worker execution duration | 6.237 s |
| Serve settlement begins | 21:30:28.043 |
| Completion transition finally starts | 21:31:24.050 |
| Queue wait | 56.007 s |
| Queue depth at enqueue | 23 transitions ahead |
| Completion transition execution | 1.780 s |
| Total settlement duration | 57.788 s |
The settlement delay is approximately 9.3 times the worker execution duration for this dispatch. The completion transition explicitly carries:
swamp.transition.tail = dispatch
swamp.transition.operation = step_lease.complete
swamp.transition.queue_depth = 23
swamp.transition.queue_wait_ms = 56007Other completions in the same burst waited 54.001 s, 52.264 s, 50.436 s, and 48.056 s. This is a queue draining over time, not an isolated slow response.
Across the selected run trace:
- 72 settlement spans.
- Settlement p95 approximately 50.57 s.
- Maximum settlement 57.79 s.
- 842.50 seconds cumulative settlement duration.
The cumulative figure includes concurrent waits and must not be interpreted as workflow wall-clock savings.
To reproduce, query the trace above in swamp-serve-traces, service swamp-serve-vm, time window 21:23–21:55 UTC. Select swamp.dispatch.settle, swamp.transition.wait, and swamp.serve.transition, preserving span IDs, parents, duration and attributes.custom. The detailed export of transitions, settlements and secret-get spans returned 523 of 523 matching records. Worker spans for this dispatch identify slot serve-8 and connect through the same trace to the settlement span.
Bitbison evidence: repository activity during queue draining
A separate completion transition in this burst, span 02d38c569777ffad, ran from 21:31:19.989, for 1.892 seconds. Its Axiom spans show:
swamp.model.methodbegins at 21:31:20.055.- Actual
swamp.method.executebegins at 21:31:21.782. - Method-body execution takes 77.6 ms.
During that approximately 1.727-second pre-body interval, Bitbison attributes to the confirmed serve process:
- 2,539 auto-definition read records.
- 2,476 distinct auto-definition paths.
SELECT op, count() AS records, uniqExact(node_path) AS distinct_paths
FROM edges
WHERE stream_id = 'b5257a30-7297-4632-9030-6292d077b26c'
AND ts_ms >= '2026-10-26 21:31:20.055'
AND ts_ms < '2026-10-26 21:31:21.782'
AND node_path LIKE '/var/lib/swamp/repo/.swamp/auto-definitions/%'
AND if(tgid_surrogate > 1, tgid_surrogate, thread_surrogate)
= toUInt128('554601050635676792091667423413')
GROUP BY op ORDER BY records DESCServe was performing broad definition-reading work while completions were draining slowly.
Attribution limit: Serve handles concurrent work in one process. These reads cannot be assigned exclusively to this completion transition from process identity and time overlap. They may belong to other concurrent preparation. Axiom independently proves queue wait; Bitbison supports investigation of competing repository work, not a claim that complete itself scanned those files. Read records are not exact syscall counts.
Impact
- Completed worker results remain unavailable to the caller for tens of seconds.
- Downstream progress waits on server bookkeeping after useful worker execution has finished.
- Independent dispatches inherit latency from earlier operations on the shared tail.
- The first durable worker write also uses this queue: observed write-marking spans reached 6.074 seconds.
- Additional concurrency can increase queue depth even when worker selection and transport are fast.
Requested change
Reduce head-of-line blocking while retaining durable ordering required for leases and recovery. Investigate:
- Which work inside
#leaseTransition()genuinely requires serialization. - Moving independent preparation outside the serialized section.
- Reducing the durable mutation's service time, including unnecessary general execution overhead.
- Batching compatible mutations or narrower ordering where the storage model permits it.
Do not simply remove serialization or acknowledge completion before its required durable transition. A per-lease queue alone is insufficient if all leases still mutate shared persisted state without safe coordination.
Acceptance criteria
- Reproduce a burst of at least 25 concurrent short dispatches, including simultaneous completions.
- Report worker execution, result receipt, transition queue wait, transition execution, and settlement separately.
- Add a controlled slow-operation case demonstrating which unrelated transitions can safely continue.
- Preserve crash recovery, lease ordering, write-before-disconnect classification, and cancellation behavior.
- Show materially reduced completion queue wait under the same workload.
- Re-test with production-sized definition inventory to distinguish queue-design improvement from reduced competing scan work.
Relationship to definition-scan work
Global definition scanning can increase load while this queue drains, but these are distinct findings: excessive work before dispatch versus a shared ordered queue propagating delay to already-completed work. Fixing scans may reduce observed queue latency; it does not by itself remove the completion queue's head-of-line blocking mechanism.
Related: Lab #4037 — global definition scans before dispatch.
Triaged
Click a lifecycle step above to view its details.
Sign in to post a ripple.