From 012b4b3d40dae32502503c9d6bc6333acb135cb3 Mon Sep 17 00:00:00 2001 From: Francis Lavoie Date: Wed, 10 Sep 2025 12:03:52 -0400 Subject: [PATCH] logging: Buffer the logs before config is loaded (#7245) --- cmd/commandfuncs.go | 19 +++++++++++- internal/logbuffer.go | 72 +++++++++++++++++++++++++++++++++++++++++++ logging.go | 17 ++++++++++ 3 files changed, 107 insertions(+), 1 deletion(-) create mode 100644 internal/logbuffer.go diff --git a/cmd/commandfuncs.go b/cmd/commandfuncs.go index 028ce5bd9..9c67e8778 100644 --- a/cmd/commandfuncs.go +++ b/cmd/commandfuncs.go @@ -172,7 +172,14 @@ func cmdStart(fl Flags) (int, error) { func cmdRun(fl Flags) (int, error) { caddy.TrapSignals() - logger := caddy.Log() + // set up buffered logging for early startup + // so that we can hold onto logs until after + // the config is loaded (or fails to load) + // so that we can write the logs to the user's + // configured output. we must be sure to flush + // on any error before the config is loaded. + logger, defaultLogger, logBuffer := caddy.BufferedLog() + undoMaxProcs := setResourceLimits(logger) defer undoMaxProcs() @@ -187,6 +194,7 @@ func cmdRun(fl Flags) (int, error) { // load all additional envs as soon as possible err := handleEnvFileFlag(fl) if err != nil { + logBuffer.FlushTo(defaultLogger) return caddy.ExitCodeFailedStartup, err } @@ -204,6 +212,7 @@ func cmdRun(fl Flags) (int, error) { logger.Info("no autosave file exists", zap.String("autosave_file", caddy.ConfigAutosavePath)) resumeFlag = false } else if err != nil { + logBuffer.FlushTo(defaultLogger) return caddy.ExitCodeFailedStartup, err } else { if configFlag == "" { @@ -222,6 +231,7 @@ func cmdRun(fl Flags) (int, error) { if !resumeFlag { config, configFile, err = LoadConfig(configFlag, configAdapterFlag) if err != nil { + logBuffer.FlushTo(defaultLogger) return caddy.ExitCodeFailedStartup, err } } @@ -239,8 +249,15 @@ func cmdRun(fl Flags) (int, error) { // run the initial config err = caddy.Load(config, true) if err != nil { + logBuffer.FlushTo(defaultLogger) return caddy.ExitCodeFailedStartup, fmt.Errorf("loading initial config: %v", err) } + + // at this stage the config will have replaced + // the default logger to the configured one, so + // we can now flush the buffered logs, then log + // that the config is running. + logBuffer.FlushTo(caddy.Log()) logger.Info("serving initial configuration") // if we are to report to another process the successful start diff --git a/internal/logbuffer.go b/internal/logbuffer.go new file mode 100644 index 000000000..6a3aa7c36 --- /dev/null +++ b/internal/logbuffer.go @@ -0,0 +1,72 @@ +// Copyright 2015 Matthew Holt and The Caddy 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 internal + +import ( + "sync" + + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +// LogBufferCore is a zapcore.Core that buffers log entries in memory. +type LogBufferCore struct { + mu sync.Mutex + entries []zapcore.Entry + fields [][]zapcore.Field + level zapcore.LevelEnabler +} + +func NewLogBufferCore(level zapcore.LevelEnabler) *LogBufferCore { + return &LogBufferCore{ + level: level, + } +} + +func (c *LogBufferCore) Enabled(lvl zapcore.Level) bool { + return c.level.Enabled(lvl) +} + +func (c *LogBufferCore) With(fields []zapcore.Field) zapcore.Core { + return c +} + +func (c *LogBufferCore) Check(entry zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry { + if c.Enabled(entry.Level) { + return ce.AddCore(entry, c) + } + return ce +} + +func (c *LogBufferCore) Write(entry zapcore.Entry, fields []zapcore.Field) error { + c.mu.Lock() + defer c.mu.Unlock() + c.entries = append(c.entries, entry) + c.fields = append(c.fields, fields) + return nil +} + +func (c *LogBufferCore) Sync() error { return nil } + +// FlushTo flushes buffered logs to the given zap.Logger. +func (c *LogBufferCore) FlushTo(logger *zap.Logger) { + c.mu.Lock() + defer c.mu.Unlock() + for idx, entry := range c.entries { + logger.WithOptions().Check(entry.Level, entry.Message).Write(c.fields[idx]...) + } + c.entries = nil + c.fields = nil +} diff --git a/logging.go b/logging.go index 1a7b0ce29..fa48fb849 100644 --- a/logging.go +++ b/logging.go @@ -28,6 +28,8 @@ import ( "go.uber.org/zap" "go.uber.org/zap/zapcore" "golang.org/x/term" + + "github.com/caddyserver/caddy/v2/internal" ) func init() { @@ -773,6 +775,21 @@ func Log() *zap.Logger { return defaultLogger.logger } +// BufferedLog sets the default logger to one that buffers +// logs before a config is loaded. +// Returns the buffered logger, the original default logger +// (for flushing on errors), and the buffer core so that the +// caller can flush the logs after the config is loaded or +// fails to load. +func BufferedLog() (*zap.Logger, *zap.Logger, *internal.LogBufferCore) { + defaultLoggerMu.Lock() + defer defaultLoggerMu.Unlock() + origLogger := defaultLogger.logger + bufferCore := internal.NewLogBufferCore(zap.InfoLevel) + defaultLogger.logger = zap.New(bufferCore) + return defaultLogger.logger, origLogger, bufferCore +} + var ( coloringEnabled = os.Getenv("NO_COLOR") == "" && os.Getenv("TERM") != "xterm-mono" defaultLogger, _ = newDefaultProductionLog()