Conversation
There was a problem hiding this comment.
Pull request overview
This PR migrates shim/vminitd/libkrun console output toward a unified slog-based structured logging flow, forwarding VM console lines into structured records and configuring slog as the default logger in both shim and vminitd.
Changes:
- Add
internal/loggingutilities to configure shim slog output and to forward VM console output as structuredslogrecords. - Update
vminitdto emit JSONsloglogs to/dev/console(to avoid polluting kmsg) and support debug level via aslog.LevelVar. - Adjust console log forwarding in libkrun and update file-dumping to log file contents as structured fields; bump
github.com/containerd/logdependency.
Reviewed changes
Copilot reviewed 8 out of 9 changed files in this pull request and generated 4 comments.
Show a summary per file
| File | Description |
|---|---|
| internal/vm/libkrun/instance.go | Switch console forwarding to the new logging.ForwardConsoleLogs helper. |
| internal/systools/dump.go | Change file dumping to structured debug logging with file content included. |
| internal/logging/shim.go | Add shim-specific slog setup using containerd’s log FIFO. |
| internal/logging/logging.go | Add console-line forwarding and JSON-log re-emission utilities. |
| internal/logging/logging_test.go | Add benchmarks and correctness tests for the new logging utilities. |
| go.mod | Bump github.com/containerd/log to a newer pseudo-version. |
| go.sum | Add checksums for the updated github.com/containerd/log version. |
| cmd/vminitd/main.go | Configure slog JSON logging to /dev/console and wire debug level. |
| cmd/containerd-shim-nerdbox-v1/main.go | Initialize shim slog logging and disable shim’s default logger setup. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| import ( | ||
| "context" | ||
| "io" | ||
| "log/slog" | ||
| "os" | ||
|
|
||
| "github.com/containerd/fifo" | ||
| "github.com/containerd/log" | ||
| "golang.org/x/sys/unix" | ||
| ) |
There was a problem hiding this comment.
This file imports golang.org/x/sys/unix and uses unix.O_WRONLY, but it has no build constraints. That will make the internal/logging package (and anything importing it) fail to compile on Windows. Add an appropriate //go:build constraint (e.g., !windows) and provide a Windows alternative (even if it’s a no-op or stderr-based SetupShimLog) so cross-platform builds remain intact.
| func ForwardConsoleLogs(r io.Reader, raw io.Writer) { | ||
| scanner := bufio.NewScanner(r) | ||
| for scanner.Scan() { | ||
| line := scanner.Text() | ||
|
|
||
| if raw != nil { | ||
| raw.Write([]byte(line)) | ||
| raw.Write([]byte("\n")) | ||
| } | ||
|
|
||
| if line == "" { | ||
| continue | ||
| } | ||
|
|
||
| if strings.HasPrefix(line, "{") { | ||
| if forwardJSONLog(line) { | ||
| continue | ||
| } | ||
| } | ||
|
|
||
| // Kernel message. | ||
| record := slog.NewRecord(time.Now(), slog.LevelInfo, line, 0) | ||
| record.AddAttrs(slog.String("component", "kmsg")) | ||
| handler := consoleHandler() | ||
| if handler.Enabled(context.Background(), slog.LevelInfo) { | ||
| handler.Handle(context.Background(), record) //nolint:errcheck | ||
| } | ||
| } | ||
| } |
There was a problem hiding this comment.
ForwardConsoleLogs uses bufio.Scanner but never checks scanner.Err() after the scan loop, so read errors (including token-too-long) will stop forwarding silently. Also, Scanner’s default max token size (64K) can truncate/abort on long kernel or JSON log lines. Consider increasing the scanner buffer (or using bufio.Reader) and handling scanner.Err() (at least logging it) to avoid dropping console logs unnoticed.
| } | ||
|
|
||
| // forwardJSONLog attempts to parse line as a JSON slog record and emit it | ||
| // through the default handler. Returns true if the line was handled. |
There was a problem hiding this comment.
The doc comment for forwardJSONLog says it emits “through the default handler”, but the implementation uses consoleHandler() (baseHandler if set, otherwise slog.Default().Handler()). Update the comment to match the actual behavior to avoid confusion when maintaining this code.
| // through the default handler. Returns true if the line was handled. | |
| // through the handler returned by consoleHandler() (the base handler if set, | |
| // otherwise the default slog handler). Returns true if the line was handled. |
| func DumpFile(ctx context.Context, name string) { | ||
| e := log.G(ctx) | ||
| if e.Logger.IsLevelEnabled(log.DebugLevel) { | ||
| f, err := os.Open(name) | ||
| if err == nil { | ||
| defer f.Close() | ||
| log.G(ctx).WithField("f", name).Debug("dumping file to stderr") | ||
| if strings.HasSuffix(name, ".json") { | ||
| var b bytes.Buffer | ||
| v := map[string]any{} | ||
| io.Copy(&b, f) | ||
| if err := json.Unmarshal(b.Bytes(), &v); err != nil { | ||
| os.Stderr.Write(b.Bytes()) | ||
| fmt.Fprintln(os.Stderr) | ||
| return | ||
| } | ||
| enc := json.NewEncoder(os.Stderr) | ||
| enc.SetIndent("", " ") | ||
| enc.Encode(v) | ||
| } else { | ||
| io.Copy(os.Stderr, f) | ||
| fmt.Fprintln(os.Stderr) | ||
| } | ||
| } else { | ||
| log.G(ctx).WithError(err).WithField("f", name).Warn("failed to open file to dump") | ||
| } | ||
| b, err := os.ReadFile(name) | ||
| if err != nil { | ||
| log.G(ctx).WithError(err).WithField("f", name).Warn("failed to read file to dump") | ||
| return | ||
| } | ||
| log.G(ctx).WithFields(log.Fields{ | ||
| "f": name, | ||
| "content": string(b), | ||
| }).Debug("dump file") |
There was a problem hiding this comment.
DumpFile now always reads the entire file into memory (os.ReadFile) before issuing a Debug log entry. This can be expensive and risky for large files (e.g., runtime logs on failure paths), and it will still incur the I/O/memory cost even when debug logging is disabled. Consider first checking whether debug is enabled (via slog handler Enabled / log level) and/or limiting the amount of data read/logged (truncate/stream) to avoid excessive memory usage.
Signed-off-by: Derek McGowan <derek@mcg.dev>
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 9 out of 10 changed files in this pull request and generated 2 comments.
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| // If raw is non-nil, every line is also written there verbatim (useful for | ||
| // tests that need the unprocessed console output). | ||
| func ForwardConsoleLogs(r io.Reader, raw io.Writer) { | ||
| scanner := bufio.NewScanner(r) |
There was a problem hiding this comment.
ForwardConsoleLogs uses bufio.Scanner with the default 64K token limit. A single long console line (e.g., large JSON payloads or kernel messages) will trigger ErrTooLong, stop scanning, and drop all subsequent console output (only emitting a single WARN). Consider switching to a bufio.Reader ReadString/ReadBytes loop, or call scanner.Buffer with a larger max token size appropriate for expected console output.
| scanner := bufio.NewScanner(r) | |
| scanner := bufio.NewScanner(r) | |
| scanner.Buffer(make([]byte, 0, 64*1024), 1024*1024) |
| go func() { | ||
| conn, err := l.Accept() | ||
| l.Close() | ||
|
|
||
| var w io.Writer = oldStderr | ||
| if err == nil { | ||
| w = io.MultiWriter(oldStderr, conn) | ||
| defer conn.Close() | ||
| } | ||
| io.Copy(w, pr) //nolint:errcheck | ||
| }() |
There was a problem hiding this comment.
On Windows, the goroutine blocks on l.Accept() before starting io.Copy from pr. If the shim writes enough to stderr before containerd connects to the named pipe, the os.Pipe buffer can fill and block the process, causing a startup hang. Consider starting io.Copy to oldStderr immediately and then teeing to the named-pipe connection once it’s accepted (or accept in a separate goroutine and stream concurrently).
Output all shim, kernel, and vminit logs as slot entries, using the default text output of slog by default.