Repository navigation
ateom-gvisor: attribute runsc output for the pause container - #2330
Jeff Luo (JeffLuoo) merged 6 commits into
Conversation
Max Smythe (maxsmythe)
added
kind/bug
| // startPauseLogPipe starts the log pipe for the pause container's sandbox | ||
| // runtime (sentry and gofer) output, so its lines reach the pod log tagged | ||
| // with the actor and the pause container's runsc container name. The caller | ||
| // owns the pipe and must Close it when the workload RPC returns; the | ||
| // subprocess keeps its inherited write end for its lifetime. |
There was a problem hiding this comment.
This pipe does not receive sentry or gofer output. In runsc (runsc/sandbox/sandbox.go and runsc/container/container.go), when -debug is off, both the sentry and gofer processes have their Stdin/Stdout/Stderr set to nil (/dev/null). The pipe passed to cmdCreate, cmdStart, and cmdRestore only receives:
- The
runscCLI process's own--alsologtostderroutput duringcreate/start/restore, and - The
/pausecontainer process's stdio (donated via--stdio-fds), which produces no output.
Please update this comment, docs/observability.md:15, and the PR description so they describe the runsc CLI / pause container output rather than sentry and gofer output.
There was a problem hiding this comment.
Updated in 98d9a78. The source comments, observability documentation, and PR title/description now describe the runsc CLI's create/start/restore output and the pause container's stdio. They also clarify that sentry and gofer stdio remains directed to /dev/null when debug logging is disabled. This PR does not enable those logs.
| pw, err := s.startPauseLogPipe(attribution) | ||
| if err != nil { | ||
| return nil, fmt.Errorf("while starting pause log pipe: %w", err) | ||
| } | ||
| defer pw.Close() |
There was a problem hiding this comment.
startPauseLogPipe opens the pipe and spawns the reader goroutine before switch req.GetScope() validates the scope. Moving it after the scope check (or into the valid cases) avoids creating the pipe and goroutine on an unsupported scope.
Also, since the application container loop below calls s.actorLogger.StartJSONLogPipe(attribution, ac.GetName()) directly, consider calling s.actorLogger.StartJSONLogPipe(attribution, ocispec.PauseContainer) inline in RunWorkload and RestoreWorkload instead of adding the one-line startPauseLogPipe wrapper.
There was a problem hiding this comment.
Updated in 98d9a78. RestoreWorkload now validates the snapshot scope after path validation and before acquiring actor locks, configuring networking, or opening log pipes. TestRestoreWorkloadRejectsUnsupportedScope covers scopes 0 and 99 with an otherwise uninitialized service, so reaching those dependencies would fail the test. I also removed startPauseLogPipe; RunWorkload and RestoreWorkload call StartJSONLogPipe directly, consistent with the application container loop.
| if err != nil { | ||
| t.Fatalf("startPauseLogPipe: %v", err) | ||
| } | ||
| const jsonLine = `{"severity":"warning","message":"gofer: I/O error","ate.actor.name":"forged"}` |
There was a problem hiding this comment.
nit: runsc's JSON log emitter (pkg/log/json.go) and util.Errorf (runsc/cmd/util/util.go) use the keys msg, level, and time rather than message and severity (and --alsologtostderr uses -debug-log-format, which defaults to glog text unless -debug-log-format=json is set). Using runsc's actual JSON keys (msg/level) here would make the test input match real runsc output.
There was a problem hiding this comment.
Updated in 98d9a78. TestPauseContainerLogAttribution now uses msg, level, and time, including the lowercase warning level, and verifies that all three fields survive forwarding while forged ate.* attribution cannot override the actor labels. The plain-text fixture uses a glog-style runsc banner, and the documentation notes that --alsologtostderr defaults to glog text. This regression test passed 20 repetitions with the race detector.
| // owns the pipe and must Close it when the workload RPC returns; the | ||
| // subprocess keeps its inherited write end for its lifetime. | ||
| func (s *AteomService) startPauseLogPipe(attribution resources.ActorAttribution) (io.WriteCloser, error) { | ||
| return s.actorLogger.StartJSONLogPipe(attribution, ocispec.PauseContainer) |
There was a problem hiding this comment.
Because logLineFilter.matches in cmd/kubectl-ate/internal/cmd/actor.go:550 matches all containers when -c is not set, tagging _pause with ate.actor.container.name="_pause" means kubectl ate logs actors <name> now prints the runsc create and runsc start/restore --alsologtostderr banners (including host paths in Args: and conf.Log()) alongside the workload's logs.
Should kubectl ate logs exclude ocispec.PauseContainer by default unless -c _pause is explicitly requested (tracked also in #2212 item 3)?
There was a problem hiding this comment.
Implemented in 98d9a78. The default log filter now excludes ocispec.PauseContainer. Passing -c _pause shows its diagnostics; application logs and actor lifecycle records remain visible by default. The CLI help and observability documentation explain this behavior. The attributed _pause records remain available in worker pod logs and centralized logging.
Tests cover default filtering, explicit _pause selection, application-container selection, and lifecycle records. The CLI regression tests passed 20 repetitions with the race detector. After rebasing onto main, both binaries compiled and full make verify passed all 145 Go test packages and 14 verification scripts. These checks ran as an unprivileged user; root-gated tests and real gVisor E2E were not run. This change handles the pause-container portion of the concern; it does not separate application-container runsc output.
Luomu (cloudonly)
changed the title
f741aa9 to
98d9a78
Compare
The pause container's sentry and gofer output went to the worker pod log raw, via os.Stdout, so on multi-actor workers its lines carried no actor identity and were invisible to `kubectl ate logs`, which only keeps lines whose labels name an actor. RunWorkload and RestoreWorkload now give the pause container its own actor-log pipe, like the application containers already had: every line is wrapped in the labeled envelope under the pause container's real runsc container name, "_pause", runsc JSON diagnostics pass their fields through, and subprocess-originated records still cannot forge the reserved ate.* attribution.
Attribute pause-container runsc CLI output accurately, validate restore scopes before acquiring resources, and call the log pipe API directly. Preserve runsc JSON fields and test default and explicit pause-container filtering without hiding actor lifecycle events.
98d9a78 to
7955607
Compare
# Conflicts: # cmd/kubectl-ate/internal/cmd/actor.go # cmd/kubectl-ate/internal/cmd/actor_test.go # docs/observability.md
…est-race-fix # Conflicts: # cmd/ateom-gvisor/main.go
# Conflicts: # cmd/kubectl-ate/internal/cmd/actor.go
The
runsc create,start, andrestorecommands for the pause container previously wrote their stdout/stderr to the shared worker pod log without actor attribution.RunWorkloadandRestoreWorkloadnow forward that CLI output and the pause container's stdio through the existing actor log envelope, labeled with the actor andate.actor.container.name="_pause". This covers cold startup and VOLUMES/MEMORY restore. JSON fields are preserved, and reservedate.*fields cannot override platform attribution.kubectl ate logs actorsexcludes_pauseby default, keeping the pause container's runsc startup banners and host paths out of the default application log view. Application container logs and actor lifecycle records remain visible. Pass-c _pauseto inspect the pause container's runsc diagnostics. The attributed records remain in the worker pod log and centralized logging backends.Restore requests reject unsupported snapshot fidelity values before acquiring actor locks or setting up networking and log pipes. Both workload paths call
StartJSONLogPipedirectly, consistent with application containers. The RPC closes its pipe writer when it returns; the forwarding goroutine does not retain the RPC context.This change attributes runsc CLI/pause stdio output. With runsc debug logging disabled, sentry and gofer stdio is directed to
/dev/null; this change does not enable that logging.--alsologtostderruses glog text by default. Tests cover that text format and runsc JSON diagnostics usingmsg,level, andtime.Addresses the pause-container invocation portion of #2271 and the default log display concern raised in review. One-shot runsc helpers, sentry panic capture, and the micro-VM implementation remain separate work. No new registry attributes are introduced.
Validation after merging main
f03327bd:go test -race -count=1 ./...passed for 152 packages, with PostgreSQL/envtest integration enabled byCI=true.Both VOLUMES and MEMORY restore paths retain main's fs restore arguments while forwarding pause output through the actor log pipe. The checkout remained clean.
Verification ran as an unprivileged user. Root-gated mount tests and real gVisor E2E were not run for this head.
AI assistance was used to resolve the merge conflicts and run verification.