Unify logging with slog

cmd/containerd-shim-nerdbox-v1/main.go

@@ -21,6 +21,7 @@ import (
 
 	"github.com/containerd/containerd/v2/pkg/shim"
 
+	"github.com/containerd/nerdbox/internal/logging"
 	"github.com/containerd/nerdbox/internal/shim/manager"
 
 	_ "github.com/containerd/nerdbox/plugins/shim/sandbox"
@@ -30,6 +31,14 @@ import (
 	_ "github.com/containerd/nerdbox/plugins/vm/libkrun"
 )
 
+func init() {
+	logging.SetupShimLog()
+}
+
 func main() {
-	shim.RunShim(context.Background(), manager.NewShimManager("io.containerd.nerdbox.v1"))
+	shim.RunShim(context.Background(), manager.NewShimManager("io.containerd.nerdbox.v1"),
+		func(c *shim.Config) {
+			c.NoSetupLogger = true
+		},
+	)
 }

cmd/vminitd/main.go

@@ -23,6 +23,7 @@ import (
 	"errors"
 	"flag"
 	"fmt"
+	"log/slog"
 	"net"
 	"os"
 	"os/signal"
@@ -55,6 +56,21 @@ import (
 	_ "github.com/containerd/nerdbox/plugins/vminit/task"
 )
 
+// logLevel controls the slog handler level for vminitd.
+var logLevel = &slog.LevelVar{}
+
+func init() {
+	log.UseSlog()
+	// Write structured logs to /dev/console rather than stderr so that
+	// output does not end up in the kernel message buffer (kmsg).
+	console, err := os.OpenFile("/dev/console", os.O_WRONLY, 0644)
+	if err != nil {
+		console = os.Stderr
+	}
+	handler := slog.NewJSONHandler(console, &slog.HandlerOptions{Level: logLevel})
+	slog.SetDefault(slog.New(handler).With("component", "vminitd"))
+}
+
 func main() {
 	t1 := time.Now()
 	var (
@@ -74,18 +90,10 @@ func main() {
 	}
 	flag.CommandLine.Parse(args)
 
-	/*
-		c, err := os.OpenFile("/dev/console", os.O_WRONLY, 0644)
-		if err != nil {
-			fmt.Fprintf(os.Stderr, "failed to open /dev/console: %v\n", err)
-			os.Exit(1)
-		}
-		defer c.Close()
-		log.L.Logger.SetOutput(c)
-	*/
 	var err error
 
 	if *dev || config.Debug {
+		logLevel.Set(slog.LevelDebug)
 		log.SetLevel("debug")
 	}
 

go.mod

@@ -12,7 +12,7 @@ require (
 	github.com/containerd/errdefs/pkg v0.3.0
 	github.com/containerd/fifo v1.1.0
 	github.com/containerd/go-runc v1.1.0
-	github.com/containerd/log v0.1.0
+	github.com/containerd/log v0.1.1-0.20260403072107-cb1839ebf76b
 	github.com/containerd/otelttrpc v0.1.0
 	github.com/containerd/plugin v1.0.0
 	github.com/containerd/ttrpc v1.2.8

go.sum

@@ -25,8 +25,8 @@ github.com/containerd/fifo v1.1.0 h1:4I2mbh5stb1u6ycIABlBw9zgtlK8viPI9QkQNRQEEmY
 github.com/containerd/fifo v1.1.0/go.mod h1:bmC4NWMbXlt2EZ0Hc7Fx7QzTFxgPID13eH0Qu+MAb2o=
 github.com/containerd/go-runc v1.1.0 h1:OX4f+/i2y5sUT7LhmcJH7GYrjjhHa1QI4e8yO0gGleA=
 github.com/containerd/go-runc v1.1.0/go.mod h1:xJv2hFF7GvHtTJd9JqTS2UVxMkULUYw4JN5XAUZqH5U=
-github.com/containerd/log v0.1.0 h1:TCJt7ioM2cr/tfR8GPbGf9/VRAX8D2B4PjzCpfX540I=
-github.com/containerd/log v0.1.0/go.mod h1:VRRf09a7mHDIRezVKTRCrOq78v577GXq3bSa3EhrzVo=
+github.com/containerd/log v0.1.1-0.20260403072107-cb1839ebf76b h1:VT47r68OzwhsTu84qAaG6Dv7xQVRmMvt7yotn9auLtI=
+github.com/containerd/log v0.1.1-0.20260403072107-cb1839ebf76b/go.mod h1:VRRf09a7mHDIRezVKTRCrOq78v577GXq3bSa3EhrzVo=
 github.com/containerd/otelttrpc v0.1.0 h1:UOX68eVTE8H/T45JveIg+I22Ev2aFj4qPITCmXsskjw=
 github.com/containerd/otelttrpc v0.1.0/go.mod h1:XhoA2VvaGPW1clB2ULwrBZfXVuEWuyOd2NUD1IM0yTg=
 github.com/containerd/platforms v1.0.0-rc.4 h1:M42JrUT4zfZTqtkUwkr0GzmUWbfyO5VO0Q5b3op97T4=

internal/logging/logging.go

@@ -0,0 +1,237 @@
+/*
+   Copyright The containerd Authors.
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+// Package logging provides unified structured logging utilities for the
+// shim and vminitd components.
+package logging
+
+import (
+	"bufio"
+	"context"
+	"encoding/json"
+	"io"
+	"log/slog"
+	"os"
+	"strings"
+	"time"
+
+	"github.com/containerd/log"
+)
+
+// SetupShimLog configures slog-based logging for the shim process.
+// It opens the platform-specific log output (FIFO on Unix, named pipe
+// on Windows), then creates a slog TextHandler and sets it as the
+// default logger with a "component=shim" attribute.
+//
+// The base handler (without component) is stored for use by
+// [ForwardConsoleLogs] so that forwarded records carry their own
+// component rather than inheriting "shim".
+//
+// For the short-lived start and delete actions, only [log.UseSlog] is
+// called to route logrus through slog; the log output is not opened.
+func SetupShimLog() {
+	log.UseSlog()
+
+	var (
+		debug bool
+		ns    string
+		id    string
+		attrs []slog.Attr
+	)
+	args := os.Args[1:]
+	for i := 0; i < len(args); i++ {
+		switch args[i] {
+		case "start", "delete":
+			return
+		case "-debug":
+			debug = true
+		case "-namespace":
+			if i+1 < len(args) {
+				i++
+				ns = args[i]
+				attrs = append(attrs, slog.String("ns", ns))
+			}
+		case "-id":
+			if i+1 < len(args) {
+				i++
+				id = args[i]
+				attrs = append(attrs, slog.String("id", id))
+			}
+		}
+	}
+
+	w := openShimLog(ns, id)
+
+	var level slog.LevelVar
+	if debug {
+		level.Set(slog.LevelDebug)
+		log.SetLevel("debug") //nolint:errcheck
+	}
+
+	handler := slog.NewTextHandler(w, &slog.HandlerOptions{Level: &level}).WithAttrs(attrs)
+	SetBaseHandler(handler)
+	slog.SetDefault(slog.New(handler).With("component", "shim"))
+}
+
+// baseHandler is the slog handler used by ForwardConsoleLogs to emit
+// records without the caller's pre-applied attributes (e.g. component=shim).
+var baseHandler slog.Handler
+
+// SetBaseHandler stores the base handler for use by ForwardConsoleLogs.
+// This should be called before any console forwarding starts, typically
+// during init with the handler before any .With() attributes are applied.
+func SetBaseHandler(h slog.Handler) {
+	baseHandler = h
+}
+
+// consoleHandler returns the handler that ForwardConsoleLogs should use.
+// It prefers the base handler set via SetBaseHandler, falling back to
+// the default slog handler.
+func consoleHandler() slog.Handler {
+	if baseHandler != nil {
+		return baseHandler
+	}
+	return slog.Default().Handler()
+}
+
+// ForwardConsoleLogs reads lines from r and re-emits them as structured
+// log entries through the base [slog.Handler] set via [SetBaseHandler].
+//
+// Lines that are valid JSON objects (emitted by vminitd's JSON slog handler)
+// are parsed and re-emitted preserving the original level, message,
+// and attributes. All other lines are treated as kernel messages and emitted
+// at INFO level with component=kmsg.
+//
+// The base handler is used directly (rather than the default logger) so that
+// pre-applied attributes such as component=shim are not added to forwarded
+// records, which carry their own component.
+//
+// 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)
+	scanner.Buffer(make([]byte, 0, bufio.MaxScanTokenSize), 1<<20) // 1 MiB max line
+	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 — parse optional "[    1.234567] " timestamp prefix.
+		msg := line
+		attrs := []slog.Attr{slog.String("component", "kmsg")}
+		if after, ktime, ok := parseKernelTimestamp(line); ok {
+			msg = after
+			attrs = append(attrs, slog.String("ktime", ktime))
+		}
+		record := slog.NewRecord(time.Now(), slog.LevelInfo, msg, 0)
+		record.AddAttrs(attrs...)
+		handler := consoleHandler()
+		if handler.Enabled(context.Background(), slog.LevelInfo) {
+			handler.Handle(context.Background(), record) //nolint:errcheck
+		}
+	}
+	if err := scanner.Err(); err != nil {
+		record := slog.NewRecord(time.Now(), slog.LevelWarn, "console log reader stopped", 0)
+		record.AddAttrs(slog.String("component", "kmsg"), slog.Any("error", err))
+		handler := consoleHandler()
+		if handler.Enabled(context.Background(), slog.LevelWarn) {
+			handler.Handle(context.Background(), record) //nolint:errcheck
+		}
+	}
+}
+
+// forwardJSONLog attempts to parse line as a JSON slog record and emit it
+// through the console handler. Returns true if the line was handled.
+func forwardJSONLog(line string) bool {
+	var fields map[string]json.RawMessage
+	if err := json.Unmarshal([]byte(line), &fields); err != nil {
+		return false
+	}
+
+	// A valid vminitd log must at least have "msg".
+	rawMsg, ok := fields["msg"]
+	if !ok {
+		return false
+	}
+
+	var msg string
+	if err := json.Unmarshal(rawMsg, &msg); err != nil {
+		return false
+	}
+	delete(fields, "msg")
+
+	var level slog.Level
+	if raw, ok := fields["level"]; ok {
+		var s string
+		if err := json.Unmarshal(raw, &s); err == nil {
+			level.UnmarshalText([]byte(s)) //nolint:errcheck
+		}
+		delete(fields, "level")
+	}
+
+	// Discard the VM-side timestamp — the guest clock is not
+	// synchronised and typically reads as epoch.
+	delete(fields, "time")
+	t := time.Now()
+
+	handler := consoleHandler()
+	if !handler.Enabled(context.Background(), level) {
+		return true
+	}
+
+	record := slog.NewRecord(t, level, msg, 0)
+	for k, v := range fields {
+		var val any
+		if err := json.Unmarshal(v, &val); err == nil {
+			record.AddAttrs(slog.Any(k, val))
+		}
+	}
+
+	handler.Handle(context.Background(), record) //nolint:errcheck
+	return true
+}
+
+// parseKernelTimestamp extracts the "[  seconds.usecs] " prefix from a
+// kernel log line. Returns the message after the prefix, the timestamp
+// string, and whether a timestamp was found.
+func parseKernelTimestamp(line string) (msg, ktime string, ok bool) {
+	if len(line) < 3 || line[0] != '[' {
+		return "", "", false
+	}
+	end := strings.IndexByte(line, ']')
+	if end < 0 {
+		return "", "", false
+	}
+	ktime = strings.TrimSpace(line[1:end])
+	msg = line[end+1:]
+	if len(msg) > 0 && msg[0] == ' ' {
+		msg = msg[1:]
+	}
+	return msg, ktime, true
+}