diff --git a/.goreleaser.yml b/.goreleaser.yml index bb0f6cf..d46aca9 100644 --- a/.goreleaser.yml +++ b/.goreleaser.yml @@ -87,8 +87,10 @@ nfpms: type: dir - dst: /var/log/pdagent type: dir - - dst: /var/run/pdagent - type: dir + # /var/run/pdagent is deliberately NOT shipped. /run is tmpfs, so a + # packaged directory does not survive a reboot and a package operation + # recreates it owned by root, leaving the daemon unable to remove its own + # pidfile. systemd creates it via RuntimeDirectory= in pdagent.service. overrides: deb: scripts: diff --git a/init/pdagent.service b/init/pdagent.service index c3f0736..c93aea6 100644 --- a/init/pdagent.service +++ b/init/pdagent.service @@ -14,5 +14,17 @@ User=pdagent Group=pdagent PermissionsStartOnly=true +# /run is tmpfs, so a runtime directory shipped in the package does not +# survive a reboot, and a package operation recreates it owned by root. +# The daemon then cannot unlink its own pidfile -- removing a file needs +# write permission on the directory -- so every subsequent start fails with +# "pidfile already exists". +# +# Letting systemd own the directory fixes both halves: it is created with +# User/Group ownership before ExecStart, and removed on stop, which takes the +# pidfile with it. +RuntimeDirectory=pdagent +RuntimeDirectoryMode=0755 + [Install] WantedBy=multi-user.target diff --git a/pkg/common/logging.go b/pkg/common/logging.go index a8024c8..0a44196 100644 --- a/pkg/common/logging.go +++ b/pkg/common/logging.go @@ -7,17 +7,53 @@ import ( var BaseLogger *zap.Logger var Logger *zap.SugaredLogger +// productionLogPath is where the daemon writes its log in production. It is a +// variable rather than a constant so tests can point it somewhere unwritable. +var productionLogPath = "/var/log/pdagent/pdagent.log" + // TODO: Eventually move configuration to config files. func init() { + BaseLogger = newBaseLogger() + Logger = BaseLogger.Sugar() +} + +// newBaseLogger always returns a usable logger. +// +// The previous implementation discarded the error from Build() and then called +// Sugar() on the result, so any failure to construct the logger surfaced as a +// nil pointer dereference during package initialisation -- before main() runs, +// producing a stack trace rather than a diagnostic. +// +// That is reachable in normal use. The daemon runs as the pdagent user and owns +// /var/log/pdagent, but the CLI runs as whoever invoked it. A monitoring system +// calling `pdagent nagios enqueue` does so as its own user, which has no reason +// to be able to write the daemon's log, so opening it fails and the command +// crashes. Falling back to stderr keeps the command usable: being unable to +// write a log file should not stop an event being enqueued. +func newBaseLogger() *zap.Logger { + var logger *zap.Logger + var err error + if IsProduction() { config := zap.NewProductionConfig() - config.OutputPaths = []string{ - "/var/log/pdagent/pdagent.log", + config.OutputPaths = []string{productionLogPath} + logger, err = config.Build() + + if err != nil { + fallback := zap.NewProductionConfig() + fallback.OutputPaths = []string{"stderr"} + fallback.ErrorOutputPaths = []string{"stderr"} + logger, err = fallback.Build() } - BaseLogger, _ = config.Build() } else { - BaseLogger, _ = zap.NewDevelopment() + logger, err = zap.NewDevelopment() } - Logger = BaseLogger.Sugar() + // Last resort. Discarding logs is unfortunate, but it beats panicking in an + // init function, and it guarantees Sugar() has a receiver. + if err != nil || logger == nil { + logger = zap.NewNop() + } + + return logger } diff --git a/pkg/common/logging_test.go b/pkg/common/logging_test.go new file mode 100644 index 0000000..266ae09 --- /dev/null +++ b/pkg/common/logging_test.go @@ -0,0 +1,55 @@ +package common + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func withProductionLogPath(t *testing.T, path string) { + t.Helper() + original := productionLogPath + productionLogPath = path + t.Cleanup(func() { productionLogPath = original }) +} + +// The package-level logger is built in init(). If that ever yields nil again, +// every command in the binary panics before main() runs. +func TestPackageLoggersAreUsable(t *testing.T) { + assert.NotNil(t, BaseLogger) + assert.NotNil(t, Logger) + assert.NotPanics(t, func() { Logger.Debugw("usable") }) +} + +func TestNewBaseLogger_development(t *testing.T) { + t.Setenv("APP_ENV", "development") + + logger := newBaseLogger() + + assert.NotNil(t, logger) + assert.NotPanics(t, func() { logger.Sugar().Debugw("ok") }) +} + +func TestNewBaseLogger_production(t *testing.T) { + t.Setenv("APP_ENV", "production") + withProductionLogPath(t, t.TempDir()+"/pdagent.log") + + logger := newBaseLogger() + + assert.NotNil(t, logger) + assert.NotPanics(t, func() { logger.Sugar().Infow("ok") }) +} + +// The regression this file exists for. The CLI runs as whoever invoked it -- +// for a Nagios/Naemon integration, the monitoring user -- which cannot write +// the daemon's log. That used to return a nil logger from a discarded error and +// panic in init() on Sugar(). +func TestNewBaseLogger_fallsBackWhenLogPathUnwritable(t *testing.T) { + t.Setenv("APP_ENV", "production") + withProductionLogPath(t, "/proc/nonexistent-directory/pdagent.log") + + logger := newBaseLogger() + + assert.NotNil(t, logger, "must not return nil when the log file cannot be opened") + assert.NotPanics(t, func() { logger.Sugar().Infow("still usable") }) +} diff --git a/scripts/deb/postinstall.sh b/scripts/deb/postinstall.sh index 8f3de80..d54225b 100755 --- a/scripts/deb/postinstall.sh +++ b/scripts/deb/postinstall.sh @@ -21,9 +21,18 @@ if [ "$1" = "configure" ]; then /usr/sbin/adduser --system --shell /bin/false --no-create-home \ --group pdagent - APP_ENV=production /usr/local/bin/pdagent init + # `pdagent init` refuses to overwrite an existing config and exits + # non-zero. The package manager preserves /etc/pdagent/config.yaml across + # removal and upgrade, so on any reinstall or upgrade this aborted the + # script under `set -e` -- before the service was enabled and started, + # leaving the daemon down. + if [ ! -f /etc/pdagent/config.yaml ]; then + APP_ENV=production /usr/local/bin/pdagent init + fi - chown -R pdagent:pdagent /etc/pdagent /var/db/pdagent /var/lib/pdagent /var/log/pdagent /var/run/pdagent + # /var/run/pdagent is intentionally absent: systemd creates it per-boot via + # RuntimeDirectory= in pdagent.service, with the correct ownership. + chown -R pdagent:pdagent /etc/pdagent /var/db/pdagent /var/lib/pdagent /var/log/pdagent if which systemctl >/dev/null; then install_systemd diff --git a/scripts/rpm/postinstall.sh b/scripts/rpm/postinstall.sh index 6676102..e0044a1 100755 --- a/scripts/rpm/postinstall.sh +++ b/scripts/rpm/postinstall.sh @@ -19,9 +19,17 @@ install_systemd () { /usr/bin/getent passwd pdagent >/dev/null || \ /usr/sbin/adduser --system --shell /bin/false --no-create-home pdagent -APP_ENV=production /usr/local/bin/pdagent init +# `pdagent init` refuses to overwrite an existing config and exits non-zero. +# rpm preserves /etc/pdagent/config.yaml across erase and upgrade, so on any +# reinstall or upgrade this aborted the scriptlet under `set -e` -- before the +# service was enabled and started, leaving the daemon down. +if [ ! -f /etc/pdagent/config.yaml ]; then + APP_ENV=production /usr/local/bin/pdagent init +fi -chown -R pdagent:pdagent /etc/pdagent /var/db/pdagent /var/lib/pdagent /var/log/pdagent /var/run/pdagent +# /var/run/pdagent is intentionally absent: systemd creates it per-boot via +# RuntimeDirectory= in pdagent.service, with the correct ownership. +chown -R pdagent:pdagent /etc/pdagent /var/db/pdagent /var/lib/pdagent /var/log/pdagent if which systemctl >/dev/null; then install_systemd