feat(logs): add pod logs and serverless logs with streaming - #325
Conversation
Adds `runpodctl pod logs <id>` and `runpodctl serverless logs <id>`, closing the biggest gap in debugging a failed deploy from the terminal: until now the only way to read container output was the web console. Both read the rest v2 log routes, which answer with server-sent events and never close on their own. That makes this the cli's first streaming transport and its first use of rest v2 (api.runpod.io/v2, RUNPOD_REST_V2_URL) — the crud commands stay on rest v1, and the two hosts are overridden separately. Output is json lines so it pipes into jq or an agent unchanged, with a workerId on serverless records. Flags: --tail, --since (a duration like 30m or an rfc3339 timestamp), --source, --follow, --max-wait. Notable behavior, all verified against prod: - a non-follow read is bounded by the client, since the stream has no eof: it returns once replayed lines stop arriving, or at --max-wait. - --follow reconnects on its own, resuming from Last-Event-ID (exclusive server-side) so no line is duplicated or skipped. - serverless logs without --worker reads every worker concurrently, resolved from the v2 worker listing. The v1 includeWorkers expansion is not usable for this: it reports EXITED for healthy workers. - stdout carries only log records; notes and errors go to stderr with the existing error codes.
Review of the previous commit found four ways a log read could mislead, all fixed here with regression tests. A snapshot discarded every non-fatal error once its --max-wait had passed, so a degraded log store printed nothing, said nothing and exited 0 — the same observation as a pod with no logs, and a different exit code for the same fault depending only on latency. A non-2xx is now always reported, and the client tracks whether response headers ever arrived so an unanswered request is a `timeout` rather than a silent empty success. That last case turns out to be common, not theoretical: the api withholds response headers until it has a line to send, so a filter matching nothing (--since past the last log, a --source with no output) never answers at all. Verified against prod: `?since=<recent>&source=system` sat at 0 bytes for 12s while `since` alone answered in 1.5s. The timeout message names both causes, since the wire cannot distinguish them. Also: - a sink error (a closed stdout) is terminal for a follow instead of taking the retry branch, where it hot-looped against the api and never backed off, because every delivered frame reset the backoff. - the resume cursor advances only after a line is delivered. Advancing first let a reconnect resume past a line that was never printed. - one newline-less line no longer grows the process without bound: reads are capped per line and per reassembled frame, and the entry is marked truncated rather than silently shortened. - `source`, `line` and `ts` are no longer omitempty. A container printing a blank line — ordinary between stanzas — emitted a record with no `line` key, so `jq -r .line` returned null on a shape the docs promise is fixed. - an endpoint with no workers reports `conflict`, not `usage_error`: the id was right, so telling an agent its input was wrong makes it re-guess the id instead of following the message. - concurrent streams are capped at 32 with a note on stderr, since an endpoint with a large workersMax would otherwise open that many tls connections and under --follow none of them ever finish.
Follow-up review nits, all four real. The one with teeth: a per-worker failure was only reported by combineStreamErrors, which runs after every stream has ended -- under --follow that is at ctrl-c. So a worker that 404'd five seconds into a ten-minute follow stayed invisible for the whole session, which is precisely the case someone watching a deploy needs to hear about. The note now goes out from the stream goroutine at the time of failure; combineStreamErrors only picks the return value. stderr notes are serialized, since they are now written from several goroutines and two Fprintf calls can interleave mid-line. Also: - --max-wait now says it is ignored under --follow, matching how the --tail/--since overlap already reports itself. - the test helper restores viper's previous `timeout` instead of leaving 0 behind -- the old comment claimed to prevent a leak while causing one. - README notes that --tail multiplies per worker as well as per source, so the default across many workers replays a few thousand lines before live output.
An endpoint's worker set is not fixed. Resolving it once meant `--follow` kept watching the original workers and silently ignored every one that arrived after -- so an endpoint scaling up mid-deploy showed nothing about the workers actually coming up. That is the mirror image of the failure the previous commit fixed, where workers that left went unreported. A serverless follow now re-resolves the worker set every 15s, attaches streams for ids it has not seen, and names each one on stderr. An explicit --worker still pins exactly one stream. Pods pass no discovery at all: there is one log stream and it keeps its id. The discovery goroutine deliberately holds a WaitGroup slot for its whole life. That is what makes calling wg.Add from it safe -- the counter cannot reach zero while it can still add, so the drain goroutine never closes the entries channel out from under a stream that was just spawned. Verified against a live endpoint scaled from 1 to 4 workers mid-follow: all four new workers were picked up and announced, and three of them streamed. The original worker was THROTTLED and silent the whole time, so before this change that follow would have printed nothing at all while three healthy workers logged. That run also surfaced a hang, fixed here with its own test: when the endpoint was deleted mid-follow, every worker stream 404'd and ended while the discovery loop kept re-polling a dead endpoint -- and since it holds a WaitGroup slot, the command stayed alive forever emitting nothing. A refresh error that will repeat identically now ends the loop instead of just the poll. isFatalLogStreamError is exported as IsPermanentStreamError so both paths share one definition rather than growing a second copy that can drift.
lukepiette
left a comment
There was a problem hiding this comment.
Read the transport, the fan-in, both commands, and all three test files end to end. This is unusually well-reasoned for a streaming client, and the hard-won details hold up:
- The cursor advancing only after sink delivery (with the regression test pinning it) is the correct resume semantics, and the
connectedflag genuinely distinguishes "never answered" from "healthy and quiet" — the send-before-streamErr/ read-after-receive synchronization is sound, no lock needed. readLimitedLine+ the frame cap close both shapes of the unbounded-memory problem, and marking entriestruncatedinstead of silently shortening is the right call.- The
sinkErrorwrapper fixing the hot-loop-on-closed-stdout bug, and the discovery goroutine holding a WaitGroup slot sowg.Addfrom it can't raceclose(entries), are both correct and both documented where the next reader needs them. - Error taxonomy is thoughtful throughout:
conflictfor a worker-less endpoint (so agents don't re-guess the id), permanent-vs-transient classification shared with the discovery loop, partial fan-in failure not failing the command. - The AGENTS.md additions encode exactly the on-the-wire behaviors (headers withheld until first line, per-source tail, exclusive Last-Event-ID) that would otherwise be re-discovered the hard way.
Two non-blocking inline notes: the streaming map never shrinks (long-follow cap accounting on churny endpoints), and 2xx responses are assumed to be SSE without a Content-Type check. Neither blocks merge.
Approving.
| for _, target := range fresh { | ||
| mu.Lock() | ||
| _, known := streaming[target.Path] | ||
| atCap := len(streaming) >= MaxStreams |
There was a problem hiding this comment.
streaming only ever grows — entries are never removed when a stream's goroutine ends. Two consequences on a long --follow of a churning endpoint (workers being replaced get fresh ids, so the map accumulates every id ever seen):
atCapcounts dead streams againstMaxStreams, so after 32 distinct worker ids have existed over the life of the follow, discovery stops attaching new workers even if only a handful of streams are actually live.- The "%d streams are already open" note can claim 32 open streams when most have long since 404'd and returned.
The motivating crash-loop case is unaffected (that worker keeps its id), so this is non-blocking — but pruning the map entry when the spawned goroutine returns (or tracking live-count separately from the seen-set used for dedup) would make the cap mean what the stderr note says it means.
| onConnect() | ||
| } | ||
|
|
||
| return decodeLogSSE(resp.Body, sink, onCursor) |
There was a problem hiding this comment.
Any 2xx is handed to the SSE decoder without checking Content-Type. An intermediary that answers 200 with an HTML body (corporate proxy, captive portal, an LB error page) gets decoded as SSE: every line of the page lands on stdout as a raw entry, and since HTML carries no id: fields the cursor never advances, so under --follow the same page replays on every reconnect at the backoff ceiling.
The Raw fallback is the right instinct for a wire-shape change on the real API, but a cheap guard here — if the 2xx Content-Type isn't text/event-stream, return an error naming what came back instead — would separate "the API changed its frame shape" (keep Raw) from "this isn't the API at all" (fail loudly). Non-blocking.
Two things review found, both of which mislead rather than crash. The stream map was both the dedup set and the cap's accounting, and it never shrank. Workers that are replaced rather than restarted come back with a fresh id, so on a long follow of a churning endpoint the cap was reached after 32 ids had *existed* -- discovery then refused to attach any new worker while the stderr note claimed 32 streams were open, though most had long since 404'd and returned. The seen set still never shrinks (that is what stops a dead worker being re-attached every tick); the cap now counts open streams, and the note reports that number. A 2xx was handed to the SSE decoder without checking Content-Type. An intermediary answering 200 with html -- captive portal, proxy, an LB error page -- had every line of that page printed as a raw entry, and since html carries no id: fields the cursor never advanced, so a follow replayed the same page on every reconnect. Non-sse 2xx is now an error naming what came back, which keeps the Raw fallback for a real frame shape change. It is deliberately not permanent: an intermediary answering for the api is the same class of fault as the 5xx a follow already reconnects through, while a snapshot fails immediately. A missing Content-Type is still accepted, since a proxy may strip it from an otherwise valid stream.
Closes #323. CON-693.
The problem
There was no way to read logs from the CLI. If a pod failed to start or a worker crash-looped, you had to open the web console, download the logs, and paste them back — which is exactly what agents driving
runpodctlwere stuck doing. The issue reporter hit this, and so did two UXR sessions.What this adds
Output is JSON Lines — one
{source,line,ts}object per line — so it pipes intojqor an agent with no parsing.sourceiscontainer(your workload's output) orsystem(the platform narrating image pull, container create/start/stop). A deploy that never comes up usually explains itself in the system lines.How it works
The v2 REST API serves these as Server-Sent Events. Two things made this more than a wrapper:
These streams never end. They replay
taillines, then stay open forever. There is no EOF, so none of the existing clients ininternal/apicould be pointed at them — they all doio.ReadAll, which would block until the pod died. This adds the CLI's first streaming transport, and its first REST v2 client (api.runpod.io/v2,RUNPOD_REST_V2_URL). The CRUD commands stay on REST v1; the two hosts are overridden separately so moving one doesn't move the other.Logs belong to a worker, not an endpoint.
serverless logswithout--workerresolves the endpoint's workers from the v2 listing and reads them all concurrently, tagging each line. The v1includeWorkersexpansion is not usable for this — it reportsEXITEDfor healthy workers.Nuances worth knowing
All of these were verified against prod, not inferred from the spec.
--sincepast the last log, a--sourcewith no output) never answers at all. Measured:?since=<recent>&source=systemsat at 0 bytes for 12s, whilesincealone answered in 1.5s. That case is reported as atimeoutnaming both possible causes, deliberately, because exiting 0 with no output would be indistinguishable from a workload that genuinely logged nothing.stop containerlines. Post-mortem debugging works, so nothing here is gated on the pod being up.--tailis applied per source.--tail 5on a pod writing both kinds returns up to 5 container lines and up to 5 system lines, so it is not a total.--followreconnects itself and resumes fromLast-Event-ID, which is exclusive server-side — so a dropped connection neither duplicates nor skips lines, and it does not replay--tailagain. Reconnect notes go to stderr; stdout stays pure JSON Lines.--max-wait(default 5s).Testing
Full suite green, including
-race. 142 assertions across the new packages.Live verification against prod
Ran against a real pod and a real endpoint, both deleted afterwards:
--tail,--tail 0,--source container,--source system,--since 30m,--since <rfc3339>,-o yaml--followstreaming live output, and terminating cleanly on a closed pipeserverless logsresolving workers automatically, and--workerexplicitly--tail, unknown--source, malformed--sinceBugs found in review and fixed in the second commit
A review pass over the first commit found several ways a log read could mislead:
--max-wait, so a degraded log store printed nothing and exited 0 — the same observation as a pod with no logs, and a different exit code for the same fault depending only on latencytruncatedsource/line/tswereomitempty, so a container printing a blank line emitted a record with nolinekey andjq -r .linereturned nullusage_error, which tells an agent its input was wrong; it now reportsconflictEach has a regression test.