#3755 serve: multi-minute write_resource latency during concurrent worker readiness

Summary

Production swamp serve exhibits multi-minute worker write_resource RPC latency during concurrent UAT readiness dispatch. A small readiness resource takes up to 6m34s in the server data-plane span. The latest provisioning job took 20m56s, although its VM provisioning step took only 3m37s.

Filed against Swamp core: the observed symptom concerns worker RPC, dispatch completion and resource persistence. The extension provides the small workload; no particular locking or storage root cause has been established.

Environment and evidence

• Serve: ops.swamp-club.com, GCE Linux; runtime last verified as 20261021.050521.0-sha.bfde0792.
• Workflow: @swamp/ci-uat/run, 36 ephemeral GCE workers, isolated runner definitions per run/shard.
• Run: c2e766d5-e851-47a7-9cdf-8b803036f042, testing binary version 20261021.200228.0-sha.15d680c4 (distinct from the serve runtime).
• Run URL: https://ops.swamp-club.com/dashboard/workflows/@swamp%2Fci-uat%2Frun/runs/c2e766d5-e851-47a7-9cdf-8b803036f042
• Axiom datasets: swamp-serve-traces, swamp-serve-logs.
• Trace ID: 52ca74223f126944d5ba6bed33ec2e92.
• All timestamps below are UTC on 2026-10-21. Evidence was read through the ops ops-axiom behavior and remote workflow history.

Readiness workload

The runner's ready method verifies its hostname, calls context.queryData to confirm the VM belongs to the running UAT run, and calls context.writeResource("ready", runId + "-" + vm, {runId, vm, ready: true}).

It does not install packages, compile binaries, or execute tests. The method source is ci-uat/extensions/models/runner.ts in platform-swamp, function ready.

Observed timings

Readiness is elapsed wall time, not a sum of concurrent spans. These five runs demonstrate increased readiness latency, not proof of a specific version regression.

Latest run timeline

• 20:10:35.688: provisioning job starts.
• 20:10:49.611–20:14:26.315: VM provisioning step, 216.704s.
• 20:14:26.347: first 25 readiness steps start.
• 20:20:25.626–20:24:17.156: remaining 11 readiness steps start as earlier steps complete; this stagger amplifies the critical path.
• 20:31:31.935: last readiness step (ready-vault-integration) completes.
• 20:31:32.017: provisioning job completes; tests begin immediately afterward.

Specific slow server spans

All below are swamp.serve.data_plane spans with swamp.data_plane.operation = write_resource in the trace above:

These are whole RPC-handler durations, not measured disk-write times. They may include queueing, lease updates, persistence or other processing; nested/overlapping spans must not be added together.

Worker-side logs also report successful readiness dispatches taking 48s–395s. Remote dispatch spans reach 11m32s. Both show delay beyond simply allocating/booting VMs.

Related symptom, causality unconfirmed

Between approximately 20:15 and 20:18, multiple workers log:

connection failed 3 consecutive times before enrollment — giving up (last error: RPC call 'worker.enroll' timed out after 30000ms)

Successful enrollment messages continue through 20🔞35. This may share a control-plane bottleneck, but the relationship to slow writes is not established.

Reproduction approach

Production occurrence is established; a minimal reproduction has not yet been run.

1. Run serve with the same remote-worker/data-plane configuration.
2. Enroll approximately 36 workers concurrently.
3. Dispatch a readiness method to each using independent behavior definitions: hostname check, one ownership query, one small resource write.
4. Record per-stage latency through dispatch, query, write, lease bookkeeping and completion.
5. Compare single-worker and concurrent runs and repeat to identify contention or accumulation effects.

Expected

Small independent readiness resource writes should complete promptly, rather than blocking for minutes. Concurrency should not turn a roughly four-minute VM provisioning stage into a twenty-minute readiness barrier through control-plane overhead.

Investigation requested

• Split write_resource latency into request queue wait, lease bookkeeping, actual persistence and response completion.
• Inspect shared serialization/locking and storage latency under concurrent independent resource writes; do not assume a specific lock is responsible.
• Check enrollment responsiveness during the same workload.
• Explain why completion remains delayed after worker-side method success.
• Add concurrent-worker performance/regression coverage once the cause is identified.

Useful APL (time window 20:14–20:32 UTC):

['swamp-serve-traces']
| where trace_id == '52ca74223f126944d5ba6bed33ec2e92'
| where name == 'swamp.serve.data_plane'
| where ['attributes.custom']['swamp.data_plane.operation'] == 'write_resource'
| project _time, name, duration, span_id, parent_span_id, ['attributes.custom']
| sort by duration desc