From 1af88ef741fd74204fef1de58d5ca2d91b68fcd4 Mon Sep 17 00:00:00 2001 From: Eugene Kalinin Date: Wed, 19 Aug 2026 23:00:24 +0300 Subject: [PATCH] feat(logging): add --log-file to persist nerdctl's own log nerdctl only reports its diagnostics on the standard error, so nothing survives the process. When a container fails to be created there is no record left to look at, and containerd does not log the client side of the failure either. Add a global --log-file (also log_file in nerdctl.toml and $NERDCTL_LOG_FILE) that appends nerdctl's own log to a file, in addition to the standard error. Every terminal error funnels through log.L.Fatal in main(), so the failure that ends the command is recorded together with everything logged on the way there. Combine with --debug for a full trace. The output is attached as a logrus hook rather than by replacing Logger.Out with an io.MultiWriter: the formatter picks its output style by type-asserting Logger.Out to *os.File, so a MultiWriter would silently change the console format whenever the flag is used. The file is opened in append mode so concurrent invocations can share it. SetLogFile hands the handle back so a library consumer can release it; the CLI does not, since log.L.Fatal exits the process. Fixes #4872 Signed-off-by: Eugene Kalinin --- cmd/nerdctl/helpers/flagutil.go | 5 + cmd/nerdctl/image/image_convert_test.go | 1 + cmd/nerdctl/main.go | 8 ++ cmd/nerdctl/main_test.go | 52 ++++++++++ docs/command-reference.md | 3 + docs/config.md | 2 + pkg/config/config.go | 2 + pkg/logging/file_hook.go | 90 +++++++++++++++++ pkg/logging/file_hook_test.go | 126 ++++++++++++++++++++++++ 9 files changed, 289 insertions(+) create mode 100644 pkg/logging/file_hook.go create mode 100644 pkg/logging/file_hook_test.go diff --git a/cmd/nerdctl/helpers/flagutil.go b/cmd/nerdctl/helpers/flagutil.go index 1ebed1f35d1..514651d3235 100644 --- a/cmd/nerdctl/helpers/flagutil.go +++ b/cmd/nerdctl/helpers/flagutil.go @@ -85,6 +85,10 @@ func ProcessRootCmdFlags(cmd *cobra.Command) (types.GlobalCommandOptions, error) if err != nil { return types.GlobalCommandOptions{}, err } + logFile, err := cmd.Flags().GetString("log-file") + if err != nil { + return types.GlobalCommandOptions{}, err + } address, err := cmd.Flags().GetString("address") if err != nil { return types.GlobalCommandOptions{}, err @@ -167,6 +171,7 @@ func ProcessRootCmdFlags(cmd *cobra.Command) (types.GlobalCommandOptions, error) return types.GlobalCommandOptions{ Debug: debug, DebugFull: debugFull, + LogFile: logFile, Address: address, Namespace: namespace, Snapshotter: snapshotter, diff --git a/cmd/nerdctl/image/image_convert_test.go b/cmd/nerdctl/image/image_convert_test.go index c9ab36ff2e5..266056506a4 100644 --- a/cmd/nerdctl/image/image_convert_test.go +++ b/cmd/nerdctl/image/image_convert_test.go @@ -65,6 +65,7 @@ func addRootFlagsForConvertOptionsTest(t *testing.T, cmd *cobra.Command) { flags := cmd.Flags() flags.Bool("debug", false, "") flags.Bool("debug-full", false, "") + flags.String("log-file", "", "") flags.String("address", "", "") flags.String("namespace", "default", "") flags.String("snapshotter", "", "") diff --git a/cmd/nerdctl/main.go b/cmd/nerdctl/main.go index 17d679f84c8..4d6ad706dca 100644 --- a/cmd/nerdctl/main.go +++ b/cmd/nerdctl/main.go @@ -170,6 +170,7 @@ func initRootCmdFlags(rootCmd *cobra.Command, tomlPath string) (*pflag.FlagSet, rootCmd.PersistentFlags().Bool("debug", cfg.Debug, "debug mode") rootCmd.PersistentFlags().Bool("debug-full", cfg.DebugFull, "debug mode (with full output)") + helpers.AddPersistentStringFlag(rootCmd, "log-file", nil, nil, nil, aliasToBeInherited, cfg.LogFile, "NERDCTL_LOG_FILE", "Append nerdctl's own log to this file, in addition to the standard error") // -a is aliases (conflicts with nerdctl images -a) helpers.AddPersistentStringFlag(rootCmd, "address", []string{"a", "H"}, nil, []string{"host"}, aliasToBeInherited, cfg.Address, "CONTAINERD_ADDRESS", `containerd address, optionally with "unix://" prefix`) // -n is aliases (conflicts with nerdctl logs -n) @@ -243,6 +244,13 @@ Config file ($NERDCTL_TOML): %s if debug { log.SetLevel(log.DebugLevel.String()) } + if globalOptions.LogFile != "" { + // The handle is deliberately not kept: log.L.Fatal terminates the process, + // so a deferred Close would not run anyway. + if _, err = logging.SetLogFile(globalOptions.LogFile); err != nil { + return err + } + } address := globalOptions.Address if strings.Contains(address, "://") && !strings.HasPrefix(address, "unix://") { return fmt.Errorf("invalid address %q", address) diff --git a/cmd/nerdctl/main_test.go b/cmd/nerdctl/main_test.go index 71bc19d1db5..4400599c1d0 100644 --- a/cmd/nerdctl/main_test.go +++ b/cmd/nerdctl/main_test.go @@ -22,10 +22,13 @@ import ( "strings" "testing" + "gotest.tools/v3/assert" + "github.com/containerd/containerd/v2/defaults" "github.com/containerd/nerdctl/mod/tigron/expect" "github.com/containerd/nerdctl/mod/tigron/require" "github.com/containerd/nerdctl/mod/tigron/test" + "github.com/containerd/nerdctl/mod/tigron/tig" "github.com/containerd/nerdctl/v2/pkg/testutil" "github.com/containerd/nerdctl/v2/pkg/testutil/nerdtest" @@ -133,6 +136,55 @@ version = 2`), testCase.Run(t) } +// TestLogFile tests https://github.com/containerd/nerdctl/issues/4872 +func TestLogFile(t *testing.T) { + testCase := nerdtest.Setup() + + // Docker has no equivalent of --log-file + testCase.Require = require.Not(nerdtest.Docker) + + const logFile = "nerdctl.log" + + testCase.SubTests = []*test.Case{ + { + Description: "records the failure that is only reported on the standard error", + Command: func(data test.Data, helpers test.Helpers) test.TestableCommand { + return helpers.Command("--log-file", data.Temp().Path(logFile), "non-existent-command") + }, + Expected: func(data test.Data, helpers test.Helpers) *test.Expected { + return &test.Expected{ + ExitCode: 1, + Errors: []error{errors.New("unknown subcommand")}, + Output: func(stdout string, t tig.T) { + assert.Assert(t, strings.Contains(data.Temp().Load(logFile), "unknown subcommand"), + "log file must contain the error") + }, + } + }, + }, + { + Description: "appends, so that a previous invocation is not lost", + Setup: func(data test.Data, helpers test.Helpers) { + helpers.Fail("--log-file", data.Temp().Path(logFile), "non-existent-command") + }, + Command: func(data test.Data, helpers test.Helpers) test.TestableCommand { + return helpers.Command("--log-file", data.Temp().Path(logFile), "non-existent-command") + }, + Expected: func(data test.Data, helpers test.Helpers) *test.Expected { + return &test.Expected{ + ExitCode: 1, + Output: func(stdout string, t tig.T) { + assert.Equal(t, strings.Count(data.Temp().Load(logFile), "unknown subcommand"), 2, + "log file must hold both invocations") + }, + } + }, + }, + } + + testCase.Run(t) +} + func TestRootHelpHidesAliasImplementationFlags(t *testing.T) { app, err := newApp() if err != nil { diff --git a/docs/command-reference.md b/docs/command-reference.md index b97eb45b50f..5f5d3887252 100644 --- a/docs/command-reference.md +++ b/docs/command-reference.md @@ -2012,6 +2012,9 @@ Flags: - Default: the IP address of the host - :nerd_face: `--userns-remap=:`: Support idmapping of containers. This options is only supported on rootful linux for container create and run if a user name and optionally group name is passed, it does idmapping based on the uidmap and gidmap ranges specified in /etc/subuid and /etc/subgid respectively. Note: `--userns-remap` is not supported for building containers. Nerdctl Build doesn't support userns-remap feature. (format: [:]) - :nerd_face: `--selinux-enabled`: Enable selinux support +- :nerd_face: `--log-file`: Append nerdctl's own log to this file, in addition to the standard error [`$NERDCTL_LOG_FILE`] + - Combine with `--debug` to record a full trace, e.g. to diagnose a failing `nerdctl run` + - The file is appended to, never truncated, so concurrent nerdctl invocations can share it. Rotation is left to `logrotate` or an equivalent The global flags can be also specified in `/etc/nerdctl/nerdctl.toml` (rootful) and `~/.config/nerdctl/nerdctl.toml` (rootless). See [`./config.md`](./config.md). diff --git a/docs/config.md b/docs/config.md index 605a776a68e..d371db50623 100644 --- a/docs/config.md +++ b/docs/config.md @@ -20,6 +20,7 @@ The path can be overridden with `$NERDCTL_TOML`. debug = false debug_full = false +log_file = "/var/log/nerdctl.log" address = "unix:///run/k3s/containerd/containerd.sock" namespace = "k8s.io" snapshotter = "stargz" @@ -39,6 +40,7 @@ selinux_enabled= true |---------------------|------------------------------------|---------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------|------------------| | `debug` | `--debug` | | Debug mode | Since 0.16.0 | | `debug_full` | `--debug-full` | | Debug mode (with full output) | Since 0.16.0 | +| `log_file` | `--log-file` | `$NERDCTL_LOG_FILE` | Append nerdctl's own log to this file, in addition to the standard error. Combine with `debug` to record a full trace | Since 2.4.0 | | `address` | `--address`,`--host`,`-a`,`-H` | `$CONTAINERD_ADDRESS` | containerd address | Since 0.16.0 | | `namespace` | `--namespace`,`-n` | `$CONTAINERD_NAMESPACE` | containerd namespace | Since 0.16.0 | | `snapshotter` | `--snapshotter`,`--storage-driver` | `$CONTAINERD_SNAPSHOTTER` | containerd snapshotter | Since 0.16.0 | diff --git a/pkg/config/config.go b/pkg/config/config.go index e967c91393a..337d5c68b98 100644 --- a/pkg/config/config.go +++ b/pkg/config/config.go @@ -28,6 +28,7 @@ import ( type Config struct { Debug bool `toml:"debug"` DebugFull bool `toml:"debug_full"` + LogFile string `toml:"log_file,omitempty"` Address string `toml:"address"` Namespace string `toml:"namespace"` Snapshotter string `toml:"snapshotter"` @@ -56,6 +57,7 @@ func New() *Config { return &Config{ Debug: false, DebugFull: false, + LogFile: "", Address: defaults.DefaultAddress, Namespace: namespaces.Default, Snapshotter: defaults.DefaultSnapshotter, diff --git a/pkg/logging/file_hook.go b/pkg/logging/file_hook.go new file mode 100644 index 00000000000..c5677464e40 --- /dev/null +++ b/pkg/logging/file_hook.go @@ -0,0 +1,90 @@ +/* + 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 + +import ( + "fmt" + "io" + "maps" + "os" + "slices" + "strings" + "sync" + + "github.com/containerd/log" +) + +// fileHook mirrors nerdctl's own diagnostic log (not the container logs) to an +// additional writer. +// +// A hook is used rather than log.L.Logger.SetOutput(io.MultiWriter(...)) so that +// the console output keeps its current formatting: the formatter picks its output +// style by type-asserting Logger.Out to *os.File, which an io.MultiWriter is not. +type fileHook struct { + mu sync.Mutex + w io.Writer +} + +// Levels implements the logrus Hook interface. Entries are already filtered against +// the logger level before the hooks are fired, so all levels are accepted here. +func (h *fileHook) Levels() []log.Level { + return []log.Level{ + log.PanicLevel, + log.FatalLevel, + log.ErrorLevel, + log.WarnLevel, + log.InfoLevel, + log.DebugLevel, + log.TraceLevel, + } +} + +// Fire implements the logrus Hook interface. The record format is deliberately +// independent of the console formatter, which varies with TTY detection. +func (h *fileHook) Fire(entry *log.Entry) error { + var sb strings.Builder + sb.WriteString(entry.Time.Format(log.RFC3339NanoFixed)) + sb.WriteString(" ") + sb.WriteString(strings.ToUpper(entry.Level.String())) + sb.WriteString(" ") + sb.WriteString(entry.Message) + for _, k := range slices.Sorted(maps.Keys(entry.Data)) { + fmt.Fprintf(&sb, " %s=%q", k, fmt.Sprint(entry.Data[k])) + } + sb.WriteString("\n") + + h.mu.Lock() + defer h.mu.Unlock() + _, err := io.WriteString(h.w, sb.String()) + return err +} + +// SetLogFile makes nerdctl append its own diagnostic log to path, in addition to +// the current output. The file is opened in append mode, so concurrent nerdctl +// invocations can share it. +// +// The returned io.Closer releases the file. The nerdctl CLI does not use it, as +// log.L.Fatal terminates the process and the hook writes are not buffered, but a +// library consumer has to be able to give the handle back. +func SetLogFile(path string) (io.Closer, error) { + f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0o600) + if err != nil { + return nil, fmt.Errorf("failed to open log file %q: %w", path, err) + } + log.L.Logger.AddHook(&fileHook{w: f}) + return f, nil +} diff --git a/pkg/logging/file_hook_test.go b/pkg/logging/file_hook_test.go new file mode 100644 index 00000000000..ef46f2c8bd2 --- /dev/null +++ b/pkg/logging/file_hook_test.go @@ -0,0 +1,126 @@ +/* + 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 + +import ( + "errors" + "io" + "maps" + "os" + "path/filepath" + "runtime" + "strings" + "testing" + "time" + + "gotest.tools/v3/assert" + + "github.com/containerd/log" +) + +func TestFileHookFire(t *testing.T) { + stamp := time.Date(2026, 4, 28, 3, 22, 52, 0, time.UTC) + + testCases := []struct { + name string + entry *log.Entry + expected string + }{ + { + name: "message only", + entry: &log.Entry{ + Time: stamp, + Level: log.InfoLevel, + Message: "creating container", + }, + expected: `2026-04-28T03:22:52.000000000Z INFO creating container` + "\n", + }, + { + name: "fields are sorted", + entry: &log.Entry{ + Time: stamp, + Level: log.ErrorLevel, + Message: "failed to create container", + Data: log.Fields{ + "id": "foo", + "error": errors.New("no such image"), + "containerName": "bar", + }, + }, + expected: `2026-04-28T03:22:52.000000000Z ERROR failed to create container ` + + `containerName="bar" error="no such image" id="foo"` + "\n", + }, + } + + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + var sb strings.Builder + hook := &fileHook{w: &sb} + assert.NilError(t, hook.Fire(tc.entry)) + assert.Equal(t, sb.String(), tc.expected) + }) + } +} + +func TestFileHookLevels(t *testing.T) { + // All levels must be accepted: entries are filtered against the logger level + // before the hooks are fired. + assert.Equal(t, len((&fileHook{}).Levels()), 7) +} + +func TestSetLogFile(t *testing.T) { + logFile := filepath.Join(t.TempDir(), "nerdctl.log") + assert.NilError(t, os.WriteFile(logFile, []byte("previous invocation\n"), 0o600)) + + savedHooks := log.L.Logger.ReplaceHooks(maps.Clone(log.L.Logger.Hooks)) + savedOut := log.L.Logger.Out + t.Cleanup(func() { + log.L.Logger.ReplaceHooks(savedHooks) + log.L.Logger.SetOutput(savedOut) + }) + + closer, err := SetLogFile(logFile) + assert.NilError(t, err) + // Windows can not remove a file that is still open, and t.TempDir() cleans up + // after this, so the handle has to go back first. + t.Cleanup(func() { _ = closer.Close() }) + // The console output must be left alone, otherwise the formatter stops + // detecting the terminal and downgrades its output style. + assert.Equal(t, log.L.Logger.Out, savedOut) + + log.L.Logger.SetOutput(io.Discard) + log.L.WithField("id", "foo").Error("failed to create container") + + b, err := os.ReadFile(logFile) + assert.NilError(t, err) + got := string(b) + // Opened in append mode, so a concurrent or previous invocation is not lost. + assert.Assert(t, strings.HasPrefix(got, "previous invocation\n"), got) + assert.Assert(t, strings.Contains(got, `ERROR failed to create container id="foo"`), got) + + if runtime.GOOS != "windows" { + st, err := os.Stat(logFile) + assert.NilError(t, err) + assert.Equal(t, st.Mode().Perm(), os.FileMode(0o600)) + } +} + +func TestSetLogFileError(t *testing.T) { + // A directory can not be opened for writing. + _, err := SetLogFile(t.TempDir()) + assert.ErrorContains(t, err, "failed to open log file") +}