Collect self-hosted worker logs for debug archives - #121
Collect self-hosted worker logs for debug archives#121warp-agent-staging[bot] wants to merge 6 commits into
Conversation
Co-Authored-By: Warp Agent <agent@warp.dev>
Co-Authored-By: Warp Agent <agent@warp.dev>
Co-Authored-By: Warp Agent <agent@warp.dev>
Warp can assemble a debug archive for a cloud-agent run, but for self-hosted executions the logs live inside customer infrastructure that warp-server cannot reach, and the worker removed its ownership record and destroyed the backend resource as soon as an execution ended. The ANY_FAILURE case — the one an operator most wants an archive for — was therefore unrecoverable. Implement the worker half of the REMOTE-2516 protocol: - New internal/debuglog package: protocol-v1 request validation, a schema-v1 NDJSON encoder with 32 KiB chunking and first/last truncation on record boundaries, a versioned no-op ContentTransformer applied while encoding, a secure 0700/0600 capture store with startup orphan removal and a shared disk budget, bounded TaskLogCapture, immutable request-scoped snapshots with CRC32C/SHA-256, a redirect-refusing PUT/POST uploader with bounded retry before expiry, and the coordinator that runs all of it off the WebSocket read loop. - TaskRegistry with exact (run_id, execution_id) ownership. Only the instance that executed an assignment answers; every other instance is silent. Ownership moves to cleanup grace before the terminal lifecycle message is enqueued, so a request triggered by that message cannot race registry deletion. - Retention reuses the execution's already-resolved idle-on-complete grace rather than adding a second cleanup clock. Docker retains its container and Kubernetes its Job until the deadline; direct execution retains only its bounded output capture. - Backend adapters: Docker demultiplexes its framed log stream into true stdout/stderr records, Kubernetes walks every pod and container in deterministic order including previous logs after a restart, direct execution tees phase-labeled output into a non-blocking capture, and the command backend reports its opaque runtime as unsupported. - Report main.Version as X-Warp-Worker-Version on every authenticated dial so the server can snapshot the build that claims an execution. Collection is best effort throughout: a capture that cannot be allocated, a provider that cannot be read, or an upload that fails never changes a task's claim, result, terminal message, cleanup deadline, or reconnect behavior. Co-Authored-By: Warp Agent <agent@warp.dev>
Review rework, cycle 1. `max_bytes` was a retention target, not a ceiling. A request could set `max_bytes=1` and still receive a complete NDJSON line, because the spool retained any record too large for a tail segment rather than dropping it, and the truncation record was appended on top of an already-full budget. The spool now reserves room for the truncation record up front, caps head + both tails against the remainder, and drops a record that cannot fit a segment instead of overrunning — accounting for it in the omitted byte count so the loss is still reported. Finalize skips the truncation record when even that would not fit, leaving an empty object the coordinator classifies as unavailable, and asserts the ceiling before returning. Retention is still whole records at both ends, so the object stays valid NDJSON at every bound. Shutdown drained cleanup-grace entries without running backend cleanup. Those executions have already reported terminal state and are retained only so their logs stay readable, but ownership and the expiry timer are process-local: a replacement worker cannot inherit them. On Kubernetes, whose shutdown deliberately preserves Jobs, a successful terminal Job therefore outlived its resolved cleanup grace and survived to the 24h TTL default. Shutdown now performs the same cleanup the expiry timer would have, under one bounded budget for the whole sweep. Active executions are untouched — they are not in cleanup grace, so each backend's own shutdown contract still decides whether their task units may outlive the process. Arming the grace timer also raced its own callback: a zero grace fires onExpiry before the assignment completes, while the callback reads the field under the registry mutex. The timer is now armed and stopped only under that mutex. Found by running the race detector over internal/worker, which the previous pass had only run over internal/debuglog. Co-Authored-By: Warp Agent <agent@warp.dev>
There was a problem hiding this comment.
Overview
This re-review confirms the hard snapshot bound, terminal cleanup-grace shutdown, and zero-grace timer race fixes at 0aea651. A shutdown failure path can still leave retained provider resources past the configured grace, so the worker PR is not ready to accept.
Concerns
The operator-facing ttlSecondsAfterFinished comment in the Helm values and the matching Kubernetes helper comment still say successful Jobs are deleted immediately, despite the new grace-period retention. This implementation-addressable documentation correction is included in the foreman relay.
Verdict
Checks: CI ✅ · build ✅ · tests ✅ · race ✅ · visual proof n/a (headless backend change); local golangci-lint/Helm unavailable because the installed linter targets Go 1.25 and Helm is absent, while their current CI jobs pass.
Found: 0 critical, 1 important, 0 suggestions, 1 question
Prior concerns: the prior snapshot-bound and restart-cleanup findings are addressed; the shutdown failure path above remains.
Request changes
Review run
https://oz.staging.warp.dev/runs/019fd6cb-ac2b-784b-ad28-72b55a74fd2f
Directed follow-up from the terminal review. Shutdown's cleanup sweep could lose the resources it failed to delete. Both backends removed the registry entry before the deletion was confirmed, and Docker additionally returned nil after a failed remove, so a transient API error left nothing for the backend's own shutdown to retry. The earlier fix made shutdown attempt cleanup; this makes the attempt durable. Docker and Kubernetes now look the resource up, delete it, and forget the identifier only once deletion is confirmed — treating an already-absent resource as deleted and surfacing every other failure. The entry that cannot be released stays registered, so Docker's shutdown still gets a final attempt at it and an operator sees a warning naming what was left behind. The sweep also shared one 10-second budget across every pending entry, so one slow call could consume it and starve the rest, which on a busy worker is exactly when there is the most to release. Each entry now runs concurrently under its own budget with a bounded retry, keeping the whole sweep within one timeout regardless of how many entries there are. The local capture is still released unconditionally: a replacement worker's startup sweep removes any file left behind, so it cannot accumulate the way a provider resource can. Also correct two docs that still claimed successful Jobs are deleted immediately. Both now describe cleanup-grace retention and say plainly that ttl_seconds_after_finished shorter than the effective grace makes a debug archive partial, matching the README. Co-Authored-By: Warp Agent <agent@warp.dev>
The problem
Warp assembles a HAR-style debug archive for a cloud-agent run, but for self-hosted executions the logs live inside customer infrastructure that
warp-servercannot reach. It cannot query a customer's Docker daemon, Kubernetes cluster, or direct child process.Worse, the worker removed its ownership record and destroyed the backend resource as soon as an execution ended. The
ANY_FAILUREcase — the one an operator most wants an archive for — was therefore unrecoverable by construction: by the time the server reacted totask_failed, the container was already gone.The change
This implements the worker half of the REMOTE-2516 protocol, per the approved spec committed on this branch at
.agents/specs/REMOTE-2516-debug-archive-worker-logs.md. The server half iswarp-server#13839.New
internal/debuglogpackageutf8/base64encoding selection,source_errorrecords carrying only a stable warning code, and first/last truncation that always cuts on a record boundary.ContentTransformerhook applied while encoding, so the first object uploaded to cloud storage already carries the transformed bytes. V1 ships only the byte-preservingnoop@1; an unsupported descriptor uploads nothing.0700root,0600files, non-user-derived names,O_EXCLcreation, startup orphan removal, and a shared process-local disk budget.TaskLogCapture: bounded, disk-backed, non-blocking. A full queue drops archive bytes and marks the capture partial rather than back-pressuring the subprocess pipe.DebugLogCoordinator: runs entirely off the WebSocket read loop behind an upload semaphore and a per-execution mutex, with a 1,024-entry request cache making duplicate delivery idempotent.Exact ownership and cleanup grace
TaskRegistryresolves ownership by the exact(run_id, execution_id)pair. Only the instance that executed the assignment answers; every other instance receiving the Pub/Sub fan-out is completely silent — no acknowledgement, no log, no ID-bearing metric, no cache entry. Ownership is checked before validation so a non-owner stays silent even for a request it would otherwise reject.task_failedalways finds the grace entry instead of racing registry deletion.idle-on-completegrace (taskidle_timeout_minutes→ workeridle_on_complete→ Oz default) rather than adding a second cleanup clock. A request never extends it.Backend adapters
io.ReadAlldiagnostic path is now capped.unavailable/backend_not_supported; its dispatch stdout is not the remote agent's log.Worker build provenance
main.Versionnow travels asX-Warp-Worker-Versionon every authenticated dial and reconnect, so the server can snapshot the exact build that claims an execution. An empty, overlong, or control-character-bearing value is omitted (never logged raw) and the connection still executes tasks.Non-negotiable: collection is best effort
A capture that cannot be allocated, a provider that cannot be read, a transform that fails, or an upload that is rejected never changes a task's claim, execution result, terminal message, cleanup deadline, or reconnect behavior. Invalid capture bounds or an unwritable capture root disable archive capture and log it; they do not fail assigned task execution.
Verification
gofmt -s,go vet ./...,golangci-lint run(0 issues),go test ./...,go build -v ./...,helm lint, andhelm templateall pass. Theinternal/debuglogsuite additionally passes under-race -count=2.Two real defects were caught by the new tests and fixed before this landed:
TaskLogCapture.Finalizereturned once the queue drained, but the background encoder could still be holding the last record — so a terminal snapshot could miss the execution's final output. It now tracks in-flight records.upload_rejected.Regression tests added:
datachanges while timestamps, sequence, and identity stay structural.0700/0600modes, orphan removal, symlink refusal, budget exhaustion and release, per-execution isolation, watermark snapshots that exclude later output, andWritealways reporting the child's byte count even when the queue is saturated.unavailable, command-backend unsupported, duplicate request replay with exactly one upload, reused request ID with different content rejected, expiry and grace lapse while queued, and semaphore-bounded concurrency.retentionkey is rejected so no second cleanup clock can be configured, and cleanup-grace precedence is proven to match the emitted--idle-on-completeflag.This is a headless backend change with no rendered UI, so computer-use visual verification does not apply.
Operator-facing notes
README.mddocuments the sensitive-data implication, the supported backends, sizing the cleanup grace forANY_FAILURE, Kubernetesttl_seconds_after_finishedalignment, the ephemeral worker-replacement limitation, capture bounds, and version compatibility. The chart gains a bounded 1 GiB ephemeral capture volume and renders the matching config; RBAC is unchanged — the existing namespace-scopedget pods/loggrant is sufficient.Behavior changes worth a close look
Shutdownsweeps any still-retained containers so nothing leaks across a worker restart.ANY_FAILUREarchives may need to lengthenidle_on_completeand raisettl_seconds_after_finished.Rework changes
Code review cycle 1 returned two findings, both fixed here (commit
0aea651). A third defect surfaced while validating them.1.
max_byteswas not a hard output limit —internal/debuglog/spool.goThe budget was a retention target, not a ceiling. A valid request could set
max_bytes=1and still receive a complete NDJSON line, because the spool retained any record too large for a tail segment rather than dropping it, and the truncation record was appended on top of an already-full budget.The spool now reserves room for the truncation record up front, caps head plus both tail segments against the remainder, and drops a record that cannot fit a segment instead of overrunning — counting it in the omitted byte total so the loss is still reported.
Finalizeskips the truncation record when even that would not fit, leaving an empty object the coordinator already classifies asunavailable, and asserts the ceiling before returning. Retention is still whole records at both ends, so the object stays valid NDJSON at every bound.Added
TestEncoderNeverExceedsItsBound, a sweep over bounds1, 2, 16, 64, maxTruncationLineBytes±1, 256, 512, 1024, 4096, 65536crossed with tiny, line-sized, and full-chunk payloads, asserting the finalized size never exceeds the bound and the output still parses; plus targeted tests for a tight-but-usable bound (whole records at both ends, exactly one truncation record), a bound too small to hold any record (empty object,truncated=false), and an oversized single record (dropped and accounted for).2. Shutdown left terminal cleanup-grace resources behind —
internal/worker/worker.goShutdown drained cleanup-grace entries without running backend cleanup. Those executions have already reported terminal state and are retained only so their logs stay readable, but ownership and the expiry timer are process-local — a replacement worker cannot inherit them. On Kubernetes, whose shutdown deliberately preserves Jobs, a successful terminal Job therefore outlived its resolved cleanup grace and survived to the 24h TTL default. This turned the deliberate retention change into a leak across worker restarts.
Shutdown now performs the same cleanup the expiry timer would have, under one bounded budget for the whole sweep so it cannot stall on an unresponsive backend. Active executions are untouched: they are not in cleanup grace, so each backend's own shutdown contract still decides whether their task units may outlive the process.
Added tests covering the restart path (terminal grace entry released), the preservation path (an active execution is never cleaned up at shutdown), and direct-capture disk budget release.
3. Data race on the cleanup-grace timer (found while validating the above)
Running the race detector over
internal/worker— the previous pass had only racedinternal/debuglog, which I should have said rather than implying full coverage — surfaced a real race.MoveToCleanupGraceassignedentry.cleanupTimeroutside the registry mutex, but a zero grace firesonExpirybefore that assignment completes, and the callback reads the field under the mutex. The timer is now armed and stopped only under that mutex.Verification
Both new test groups were confirmed to fail before their fix and pass after.
gofmt -s,go vet ./...,golangci-lint run(0 issues),go test ./...,go build ./...,helm lint, andhelm templateall pass;internal/debuglog,internal/worker,internal/common, andinternal/configare additionally green under-race -count=2.On the reviewer's
golangci-lintnote: I hit the same Go 1.25-vs-1.26.5 wall with the preinstalled binary and resolved it by installinggithub.com/golangci/golangci-lint/v2/cmd/golangci-lint@latest, which targets the repo's Go version. Lint was run locally, not skipped.Directed follow-up changes
The terminal re-review verified all three rework fixes and found one more real issue, plus stale docs. Both addressed in
8e32ae1.1. Shutdown cleanup could lose resources it failed to delete —
internal/worker/{docker,kubernetes,worker}.goThe previous fix made shutdown attempt cleanup; the attempt was not durable. Both backends removed the registry entry before deletion was confirmed, and Docker additionally returned nil after a failed remove, so a transient API error left nothing for the backend's own shutdown to retry — a stopped container or successful Job then outlived its grace across a worker restart.
CleanupTaskResourcesnow looks the resource up, deletes it, and drops the identifier only once deletion is confirmed; an already-absent container or Job counts as deleted.removeContainersurfaces every failure that is not a not-found, and Docker'sShutdownwarns by task name for anything it still could not remove. An unreleasable entry stays registered, which is what givesShutdownsomething to retry.The sweep also shared one 10-second budget across every pending entry, so one slow call could consume it and starve the rest — worst on a busy worker, which is exactly when there is the most to release. Each entry now runs concurrently under its own
BackendShutdownTimeoutwith a bounded 3-attempt retry, keeping the whole sweep within one timeout regardless of entry count. The local capture is still released unconditionally: a replacement worker's startup sweep removes any file left behind, so unlike a provider resource it cannot accumulate.New
internal/worker/cleanup_durability_test.gocovers a failed Kubernetes delete retaining the Job and a retry both deleting it and releasing the entry, an absent Job counting as deleted, a failed Job released without deletion, a failed Docker removal against an unreachable daemon surfacing the error and keeping the container registered, and the sweep retrying a transient failure, giving up after its budget, and attempting all 8 entries when each call stalls 300 ms. The two retention tests were confirmed to fail under the previous forget-before-confirm ordering.2. Stale docs —
charts/oz-agent-worker/values.yamland thetaskJobTTLSecondsAfterFinishedcommentBoth still said successful Jobs are deleted immediately. They now describe cleanup-grace retention and state plainly that a
ttl_seconds_after_finishedshorter than the effective grace makes a debug archive partial, matching the README.Verification.
gofmt -s,go vet ./...,golangci-lint run(0 issues),go test ./...,go build ./...,helm lint,helm templateall pass, plus-race -count=2across everyinternal/...package.Spec deviation
The backend contract is
SnapshotTaskLogs(ctx, *SnapshotParams)carrying adebuglog.Sinkrather than the spec's(ctx, taskID, executionID string, writer io.Writer). A bareio.Writercannot work: the content transformer must be applied to each record's decodeddatawhile leaving timestamps, sequence, and identity structural, so the transformer has to live inside the encoder rather than in each backend. TheSinkkeeps framing, chunk bounds, transformation, encoding selection, sequencing, and truncation in one place while backends supply only provider output and the identity the provider actually reports. Every behavioral requirement of the spec's contract — streaming, cancellation, bounded output, no lifecycle change, no resource removal, safe duringExecuteTask, deterministic source ordering, typed partial errors — is preserved.Originating thread: https://warpdev.slack.com/archives/C0BDQDW8V5E/p1785881958158819
Co-Authored-By: Warp Agent agent@warp.dev
Conversation: https://staging.warp.dev/conversation/12a2ee47-a3be-4337-a627-e55424ca1a82
Run: https://oz.staging.warp.dev/runs/019fd69b-ebf9-71c8-a33f-28546567f042
This PR was generated with Oz.