From 5228850225db54a171025c58a710c9911f15a49f Mon Sep 17 00:00:00 2001 From: Sebastiaan van Stijn Date: Tue, 17 Sep 2024 15:27:31 +0200 Subject: [PATCH] cmd/dockerd: windows: don't use Fatal log to prevent early exit cmd/dockerd: notifyShutdown: don't use Fatal log to prevent early exit ------------------------------------------------------------------------ Commit 40868e263d7a239aa10acd922bd69ba5a943781e added this log for situations where the daemon failed to start, and where no event-log was created to discover the failure. However, it used a `Fatal` log which, when using logrus, not only logs a message, but also calls the [logger's Exit function][1], which defaults [to `os.Exit`][2]. The error passed to the `notifyShutdown` function can be the result of different steps in the service's lifecycle; `cli.start()` starts a long- lived process, and the error returned can be either because it failed to start the service, or an error produced while shutting down the service. We should reduce ambiguity here (which could be for `cli.Start()` to return whether the service was started in the first place). Regardless, we want code following the log-entry to be executed, to make sure that codepaths following the `notifyShutdown` (which could be (defer) statements or cleanup steps) are executed. This patch changes the log to an `Error`, which is non-fatal, and should make sure that at least the `service.stopped` is executed to signal the service no longer running. The logging is also moved out of the `notifyShutdown`. Disclaimer: this is with the assumption that calling `service.stopped` is always acceptable, even if the service is not running, or in other states. cmd/dockerd: preNotifyReady: return error instead of logging and exit ------------------------------------------------------------------------ Commit 57aef3b49025aac6bb084491478eb461b14b9109 added support for running the daemon as a Windows service. As part of this, it introduced a log for situations where the service failed to start. However, it used a `Fatal` log for this purpose which, when using logrus, not only logs a message, but also calls the [logger's Exit function][1], which defaults [to `os.Exit`][2]. A result of this is that the daemon does an unclean shutdown, causing other code (which could be (defer) statements or cleanup steps) not to be executed. This patch updates the `preNotifyReady` to return the error instead of logging and exiting. `preNotifyReady` is executed as part of `cli.start()`, which has an error-return, and the error that is returned, is already logged by `runDaemon` (so logging it as part of `preNotifyReady` would result in the error being logged twice). [1]: https://github.com/moby/moby/blob/5098132d84d3c20afd05453e430b5029e770fcc1/vendor/github.com/sirupsen/logrus/entry.go#L336-L339 [2]: https://github.com/moby/moby/blob/5098132d84d3c20afd05453e430b5029e770fcc1/vendor/github.com/sirupsen/logrus/logger.go#L342-L348 - relates to https://github.com/moby/moby/pull/22340 cmd/dockerd: preNotifyReady: return error instead of logging and exit Commit 57aef3b49025aac6bb084491478eb461b14b9109 added support for running the daemon as a Windows service. As part of this, it introduced a log for situations where the service failed to start. However, it used a `Fatal` log for this purpose which, when using logrus, not only logs a message, but also calls the [logger's Exit function][1], which defaults [to `os.Exit`][2]. A result of this is that the daemon does an unclean shutdown, causing other code (which could be (defer) statements or cleanup steps) not to be executed. This patch changes the `preNotifyReady` to [1]: https://github.com/moby/moby/blob/5098132d84d3c20afd05453e430b5029e770fcc1/vendor/github.com/sirupsen/logrus/entry.go#L336-L339 [2]: https://github.com/moby/moby/blob/5098132d84d3c20afd05453e430b5029e770fcc1/vendor/github.com/sirupsen/logrus/logger.go#L342-L348 Signed-off-by: Sebastiaan van Stijn --- cmd/dockerd/daemon.go | 4 +++- cmd/dockerd/daemon_freebsd.go | 3 ++- cmd/dockerd/daemon_linux.go | 3 ++- cmd/dockerd/daemon_windows.go | 8 +++----- cmd/dockerd/docker_windows.go | 5 +++++ 5 files changed, 15 insertions(+), 8 deletions(-) diff --git a/cmd/dockerd/daemon.go b/cmd/dockerd/daemon.go index 5637d275fe..3d4184b171 100644 --- a/cmd/dockerd/daemon.go +++ b/cmd/dockerd/daemon.go @@ -227,7 +227,9 @@ func (cli *daemonCLI) start(ctx context.Context) (err error) { }() // Notify that the API is active, but before daemon is set up. - preNotifyReady() + if err := preNotifyReady(); err != nil { + return err + } const otelServiceNameEnv = "OTEL_SERVICE_NAME" if _, ok := os.LookupEnv(otelServiceNameEnv); !ok { diff --git a/cmd/dockerd/daemon_freebsd.go b/cmd/dockerd/daemon_freebsd.go index ca230a22fe..d1293485a6 100644 --- a/cmd/dockerd/daemon_freebsd.go +++ b/cmd/dockerd/daemon_freebsd.go @@ -3,7 +3,8 @@ package main import "github.com/docker/docker/daemon/config" // preNotifyReady sends a message to the host when the API is active, but before the daemon is -func preNotifyReady() { +func preNotifyReady() error { + return nil } // notifyReady sends a message to the host when the server is ready to be used diff --git a/cmd/dockerd/daemon_linux.go b/cmd/dockerd/daemon_linux.go index 43f869bca6..b375459c67 100644 --- a/cmd/dockerd/daemon_linux.go +++ b/cmd/dockerd/daemon_linux.go @@ -26,7 +26,8 @@ func setPlatformOptions(conf *config.Config) error { } // preNotifyReady sends a message to the host when the API is active, but before the daemon is -func preNotifyReady() { +func preNotifyReady() error { + return nil } // notifyReady sends a message to the host when the server is ready to be used diff --git a/cmd/dockerd/daemon_windows.go b/cmd/dockerd/daemon_windows.go index bd17c1dc60..8bbbae8457 100644 --- a/cmd/dockerd/daemon_windows.go +++ b/cmd/dockerd/daemon_windows.go @@ -41,15 +41,16 @@ func setDefaultUmask() error { } // preNotifyReady sends a message to the host when the API is active, but before the daemon is -func preNotifyReady() { +func preNotifyReady() error { // start the service now to prevent timeouts waiting for daemon to start // but still (eventually) complete all requests that are sent after this if service != nil { err := service.started() if err != nil { - log.G(context.TODO()).Fatal(err) + return err } } + return nil } // notifyReady sends a message to the host when the server is ready to be used @@ -63,9 +64,6 @@ func notifyStopping() { // notifyShutdown is called after the daemon shuts down but before the process exits. func notifyShutdown(err error) { if service != nil { - if err != nil { - log.G(context.TODO()).Fatal(err) - } service.stopped(err) } } diff --git a/cmd/dockerd/docker_windows.go b/cmd/dockerd/docker_windows.go index 00ae098f3d..c745efc9c0 100644 --- a/cmd/dockerd/docker_windows.go +++ b/cmd/dockerd/docker_windows.go @@ -38,6 +38,11 @@ func runDaemon(ctx context.Context, opts *daemonOptions) error { } err = cli.start(ctx) + if service != nil { + // When running as a service, log the error, so that it's sent to + // the event-log. + log.G(ctx).Error(err) + } notifyShutdown(err) return err }