From bdfa269715068e033fa4f9aa28115d8ddf6e18de Mon Sep 17 00:00:00 2001 From: Marco Dinis Date: Fri, 21 Jun 2024 17:12:18 +0100 Subject: [PATCH 01/15] Re-open the log file on OS Signal trigger This PR implements an handler for the CONT signal. The handler will close and re-open the log file. If the log destination is not a file, this is a no-op. Useful for logrotate postrotate hook. --- docs/pages/reference/signals.mdx | 1 + lib/config/configuration.go | 25 +++++++++++--------- lib/service/servicecfg/config.go | 5 ++++ lib/service/signals.go | 6 +++++ lib/utils/log/writer.go | 40 ++++++++++++++++++++++++++++++++ 5 files changed, 66 insertions(+), 11 deletions(-) diff --git a/docs/pages/reference/signals.mdx b/docs/pages/reference/signals.mdx index 95139796f935..31d30ce0795f 100644 --- a/docs/pages/reference/signals.mdx +++ b/docs/pages/reference/signals.mdx @@ -20,3 +20,4 @@ $ kill -SIG | `TERM`, `INT` | Immediate non-graceful shutdown. All existing connections will be closed after a very short delay. | | `USR2` | Forks a new Teleport daemon to serve new connections. | | `HUP` | Forks a new Teleport daemon to serve new connections **and** initiates the graceful shutdown of the existing process, same as `SIGQUIT`. | +| `CONT` | Re-open the log file (useful for `logrotate`). | diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 589113a4476c..7eb46a90fd83 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -26,6 +26,7 @@ import ( "crypto/x509" "errors" "io" + "io/fs" "log/slog" "maps" "net" @@ -756,12 +757,12 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { var w io.Writer switch loggerConfig.Output { case "": - w = os.Stderr + w = logutils.NewSharedWriter(os.Stderr) case "stderr", "error", "2": - w = os.Stderr + w = logutils.NewSharedWriter(os.Stderr) cfg.Console = io.Discard // disable console printing case "stdout", "out", "1": - w = os.Stdout + w = logutils.NewSharedWriter(os.Stdout) cfg.Console = io.Discard // disable console printing case teleport.Syslog: w = os.Stderr @@ -779,14 +780,22 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { logger.ReplaceHooks(make(log.LevelHooks)) logger.AddHook(hook) + // If syslog output has been configured and is supported by the operating system, + // then the shared writer is not needed because the syslog writer is already + // protected with a mutex. w = sw default: // assume it's a file path: - logFile, err := os.Create(loggerConfig.Output) + var flag int = os.O_WRONLY | os.O_CREATE | os.O_APPEND + var mode = fs.FileMode(0666) + logFile, err := os.OpenFile(loggerConfig.Output, flag, mode) if err != nil { return trace.Wrap(err, "failed to create the log file") } - w = logFile + fileWriter := logutils.NewFileSharedWriter(logFile, flag, mode) + cfg.LogFileReopen = fileWriter.Reopen + + w = fileWriter } level := new(slog.LevelVar) @@ -815,12 +824,6 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { return trace.Wrap(err) } - // If syslog output has been configured and is supported by the operating system, - // then the shared writer is not needed because the syslog writer is already - // protected with a mutex. - if len(logger.Hooks) == 0 { - w = logutils.NewSharedWriter(w) - } var slogLogger *slog.Logger switch strings.ToLower(loggerConfig.Format.Output) { case "": diff --git a/lib/service/servicecfg/config.go b/lib/service/servicecfg/config.go index 456321cdf35e..7d547d60df51 100644 --- a/lib/service/servicecfg/config.go +++ b/lib/service/servicecfg/config.go @@ -227,6 +227,9 @@ type Config struct { Logger *slog.Logger // LoggerLevel defines the Logger log level. LoggerLevel *slog.LevelVar + // LogFileReopen is used to close and re-open the log file. + // If the logger is not writting to a log file, this is a no-op. + LogFileReopen func() error // PluginRegistry allows adding enterprise logic to Teleport services PluginRegistry plugin.Registry @@ -592,6 +595,8 @@ func ApplyDefaults(cfg *Config) { cfg.MaxRetryPeriod = defaults.MaxWatcherBackoff cfg.Testing.ConnectFailureC = make(chan time.Duration, 1) cfg.CircuitBreakerConfig = breaker.DefaultBreakerConfig(cfg.Clock) + + cfg.LogFileReopen = func() error { return nil } } // FileDescriptor is a file descriptor associated diff --git a/lib/service/signals.go b/lib/service/signals.go index ebcdadfac501..3eb8af9a580e 100644 --- a/lib/service/signals.go +++ b/lib/service/signals.go @@ -76,6 +76,7 @@ var teleportSignals = []os.Signal{ syscall.SIGUSR1, // log process diagnostic info syscall.SIGUSR2, // initiate process restart procedure syscall.SIGHUP, // graceful restart procedure + syscall.SIGCONT, // Re-open the log file } // WaitForSignals waits for system signals and processes them. @@ -151,6 +152,11 @@ func (process *TeleportProcess) WaitForSignals(ctx context.Context, sigC <-chan process.Shutdown(timeoutCtx) process.logger.InfoContext(process.ExitContext(), "All services stopped, exiting.") return nil + case syscall.SIGCONT: + process.logger.InfoContext(process.ExitContext(), "Rotating log file.") + if err := process.Config.LogFileReopen(); err != nil { + return trace.Wrap(err) + } default: process.logger.InfoContext(process.ExitContext(), "Ignoring unknown signal.", "signal", signal) } diff --git a/lib/utils/log/writer.go b/lib/utils/log/writer.go index 77cf3037a8b6..510b954be946 100644 --- a/lib/utils/log/writer.go +++ b/lib/utils/log/writer.go @@ -20,7 +20,11 @@ package log import ( "io" + "io/fs" + "os" "sync" + + "github.com/gravitational/trace" ) // SharedWriter is an [io.Writer] implementation that protects @@ -43,3 +47,39 @@ func (s *SharedWriter) Write(p []byte) (int, error) { func NewSharedWriter(w io.Writer) *SharedWriter { return &SharedWriter{Writer: w} } + +// FileSharedWriter is similar to SharedWriter except that it requires a os.File instead of a io.Writer. +// This is to allow the File reopen required by logrotate and similar tools. +// SharedWriter must be used for log destinations that don't have the reopen requirement, like stdout and stderr. +// This is thread safe. +type FileSharedWriter struct { + *os.File + fileFlag int + fileMode fs.FileMode + mu sync.Mutex +} + +func (s *FileSharedWriter) Write(p []byte) (int, error) { + s.mu.Lock() + defer s.mu.Unlock() + + return s.File.Write(p) +} + +// Reopen closes the file and opens it again using APPEND mode. +func (s *FileSharedWriter) Reopen() (err error) { + s.mu.Lock() + defer s.mu.Unlock() + + if err := s.Close(); err != nil { + return trace.Wrap(err) + } + + s.File, err = os.OpenFile(s.Name(), s.fileFlag, s.fileMode) + return trace.Wrap(err) +} + +// NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe. +func NewFileSharedWriter(f *os.File, flag int, mode fs.FileMode) *FileSharedWriter { + return &FileSharedWriter{File: f, fileFlag: flag, fileMode: mode} +} From 29c994cd88b99a5fd2ea8ae7c1579bc12369d266 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Fri, 28 Jun 2024 20:08:21 -0400 Subject: [PATCH 02/15] signal replaced with the fsnotify --- docs/pages/reference/signals.mdx | 1 - lib/config/configuration.go | 19 +++++++----- lib/service/servicecfg/config.go | 12 +++++--- lib/service/signals.go | 5 --- lib/utils/log/writer.go | 53 ++++++++++++++++++++++++++++++-- 5 files changed, 70 insertions(+), 20 deletions(-) diff --git a/docs/pages/reference/signals.mdx b/docs/pages/reference/signals.mdx index 31d30ce0795f..95139796f935 100644 --- a/docs/pages/reference/signals.mdx +++ b/docs/pages/reference/signals.mdx @@ -20,4 +20,3 @@ $ kill -SIG | `TERM`, `INT` | Immediate non-graceful shutdown. All existing connections will be closed after a very short delay. | | `USR2` | Forks a new Teleport daemon to serve new connections. | | `HUP` | Forks a new Teleport daemon to serve new connections **and** initiates the graceful shutdown of the existing process, same as `SIGQUIT`. | -| `CONT` | Re-open the log file (useful for `logrotate`). | diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 4281486f1963..107c93aace38 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -72,6 +72,13 @@ import ( logutils "github.com/gravitational/teleport/lib/utils/log" ) +const ( + // logFileDefaultMode is the preferred permissions mode for log file. + logFileDefaultMode fs.FileMode = 0666 + // logFileDefaultFlag is the preferred flags set to log file. + logFileDefaultFlag = os.O_WRONLY | os.O_CREATE | os.O_APPEND +) + // CommandLineFlags stores command line flag values, it's a much simplified subset // of Teleport configuration (which is fully expressed via YAML config file) type CommandLineFlags struct { @@ -786,16 +793,14 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { w = sw default: // assume it's a file path: - var flag int = os.O_WRONLY | os.O_CREATE | os.O_APPEND - var mode = fs.FileMode(0666) - logFile, err := os.OpenFile(loggerConfig.Output, flag, mode) + logFile, err := os.OpenFile(loggerConfig.Output, logFileDefaultFlag, logFileDefaultMode) if err != nil { return trace.Wrap(err, "failed to create the log file") } - fileWriter := logutils.NewFileSharedWriter(logFile, flag, mode) - cfg.LogFileReopen = fileWriter.Reopen - - w = fileWriter + w, err = logutils.NewFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode, cfg.LogFileReopen) + if err != nil { + return trace.Wrap(err, "failed to init the log file") + } } level := new(slog.LevelVar) diff --git a/lib/service/servicecfg/config.go b/lib/service/servicecfg/config.go index 7d547d60df51..e0c9e7521cc5 100644 --- a/lib/service/servicecfg/config.go +++ b/lib/service/servicecfg/config.go @@ -222,14 +222,18 @@ type Config struct { // Log optionally specifies the logger. // Deprecated: use Logger instead. Log utils.Logger + // Logger outputs messages using slog. The underlying handler respects // the user supplied logging config. Logger *slog.Logger + // LoggerLevel defines the Logger log level. LoggerLevel *slog.LevelVar - // LogFileReopen is used to close and re-open the log file. - // If the logger is not writting to a log file, this is a no-op. - LogFileReopen func() error + + // LogFileReopen is used to close and re-open the log file by + // filesystem notify to react on rename or remove event, might be used + // in log rotation. + LogFileReopen bool // PluginRegistry allows adding enterprise logic to Teleport services PluginRegistry plugin.Registry @@ -595,8 +599,6 @@ func ApplyDefaults(cfg *Config) { cfg.MaxRetryPeriod = defaults.MaxWatcherBackoff cfg.Testing.ConnectFailureC = make(chan time.Duration, 1) cfg.CircuitBreakerConfig = breaker.DefaultBreakerConfig(cfg.Clock) - - cfg.LogFileReopen = func() error { return nil } } // FileDescriptor is a file descriptor associated diff --git a/lib/service/signals.go b/lib/service/signals.go index 3eb8af9a580e..e82e6e9909ba 100644 --- a/lib/service/signals.go +++ b/lib/service/signals.go @@ -152,11 +152,6 @@ func (process *TeleportProcess) WaitForSignals(ctx context.Context, sigC <-chan process.Shutdown(timeoutCtx) process.logger.InfoContext(process.ExitContext(), "All services stopped, exiting.") return nil - case syscall.SIGCONT: - process.logger.InfoContext(process.ExitContext(), "Rotating log file.") - if err := process.Config.LogFileReopen(); err != nil { - return trace.Wrap(err) - } default: process.logger.InfoContext(process.ExitContext(), "Ignoring unknown signal.", "signal", signal) } diff --git a/lib/utils/log/writer.go b/lib/utils/log/writer.go index 510b954be946..7609e4236287 100644 --- a/lib/utils/log/writer.go +++ b/lib/utils/log/writer.go @@ -19,11 +19,14 @@ package log import ( + "context" "io" "io/fs" + "log/slog" "os" "sync" + "github.com/fsnotify/fsnotify" "github.com/gravitational/trace" ) @@ -79,7 +82,53 @@ func (s *FileSharedWriter) Reopen() (err error) { return trace.Wrap(err) } +// runWatcher spawns goroutine with the watcher loop to consume events of moving +// or removing the log file to re-open it for log rotation purposes. +func (s *FileSharedWriter) runWatcher() error { + watcher, err := fsnotify.NewWatcher() + if err != nil { + return trace.Wrap(err) + } + + err = watcher.Add(s.Name()) + if err != nil { + return trace.Wrap(err) + } + + go func() { + for { + select { + case event, ok := <-watcher.Events: + if !ok { + return + } + if event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove) { + slog.DebugContext(context.Background(), "Log file was moved/removed, reopen new one", "file", event.Name) + if err := s.Reopen(); err != nil { + slog.ErrorContext(context.Background(), "Failed to reopen new file", err, "file", event.Name) + continue + } + if err = watcher.Add(s.Name()); err != nil { + slog.ErrorContext(context.Background(), "Failed to reinit watcher", err, "file", event.Name) + continue + } + } + case err := <-watcher.Errors: + slog.ErrorContext(context.Background(), "Error received on logger watcher", "error", err) + } + } + }() + + return nil +} + // NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe. -func NewFileSharedWriter(f *os.File, flag int, mode fs.FileMode) *FileSharedWriter { - return &FileSharedWriter{File: f, fileFlag: flag, fileMode: mode} +func NewFileSharedWriter(f *os.File, flag int, mode fs.FileMode, watcherEnabled bool) (*FileSharedWriter, error) { + sharedWriter := &FileSharedWriter{File: f, fileFlag: flag, fileMode: mode} + if watcherEnabled { + if err := sharedWriter.runWatcher(); err != nil { + return nil, trace.Wrap(err) + } + } + return sharedWriter, nil } From f34ae035504243ccba60d4b8f600f53cd934f4a7 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Wed, 3 Jul 2024 15:22:00 -0400 Subject: [PATCH 03/15] code review changes: - refactored to launch watcher with process context - make file shared writer as singleton - add test for logrotate case --- go.mod | 2 +- lib/config/configuration.go | 9 +- lib/service/service.go | 8 ++ lib/service/servicecfg/config.go | 4 +- lib/service/signals.go | 1 - lib/utils/log/file_writer.go | 137 ++++++++++++++++++++++++++++++ lib/utils/log/file_writer_test.go | 98 +++++++++++++++++++++ lib/utils/log/writer.go | 89 ------------------- 8 files changed, 251 insertions(+), 97 deletions(-) create mode 100644 lib/utils/log/file_writer.go create mode 100644 lib/utils/log/file_writer_test.go diff --git a/go.mod b/go.mod index f886035e9505..74131fabad31 100644 --- a/go.mod +++ b/go.mod @@ -322,7 +322,7 @@ require ( github.com/fatih/color v1.16.0 // indirect github.com/felixge/httpsnoop v1.0.4 // indirect github.com/form3tech-oss/jwt-go v3.2.5+incompatible // indirect - github.com/fsnotify/fsnotify v1.7.0 // indirect + github.com/fsnotify/fsnotify v1.7.0 github.com/fvbommel/sortorder v1.1.0 // indirect github.com/gabriel-vasile/mimetype v1.4.3 // indirect github.com/go-asn1-ber/asn1-ber v1.5.5 // indirect diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 107c93aace38..ca8b58485605 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -74,7 +74,7 @@ import ( const ( // logFileDefaultMode is the preferred permissions mode for log file. - logFileDefaultMode fs.FileMode = 0666 + logFileDefaultMode fs.FileMode = 0o666 // logFileDefaultFlag is the preferred flags set to log file. logFileDefaultFlag = os.O_WRONLY | os.O_CREATE | os.O_APPEND ) @@ -792,14 +792,15 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { // protected with a mutex. w = sw default: - // assume it's a file path: + // Assume this is a file path. logFile, err := os.OpenFile(loggerConfig.Output, logFileDefaultFlag, logFileDefaultMode) if err != nil { return trace.Wrap(err, "failed to create the log file") } - w, err = logutils.NewFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode, cfg.LogFileReopen) + w, err = logutils.InitFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode) if err != nil { - return trace.Wrap(err, "failed to init the log file") + logFile.Close() + return trace.Wrap(err, "failed to init the log file shared writer") } } diff --git a/lib/service/service.go b/lib/service/service.go index 40c6e9407bd2..d30775860ded 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -1354,6 +1354,14 @@ func NewTeleport(cfg *servicecfg.Config) (*TeleportProcess, error) { } } + // Enable shared log file watcher if configuration is set, to react on rename event. + sharedWriter := logutils.GetFileSharedWriter() + if cfg.WatchLogFile && sharedWriter != nil { + if err := sharedWriter.RunReopenWatcher(process.GracefulExitContext()); err != nil { + return nil, trace.Wrap(err) + } + } + // notify parent process that this process has started go process.notifyParent() diff --git a/lib/service/servicecfg/config.go b/lib/service/servicecfg/config.go index e0c9e7521cc5..1cc34bbae124 100644 --- a/lib/service/servicecfg/config.go +++ b/lib/service/servicecfg/config.go @@ -230,10 +230,10 @@ type Config struct { // LoggerLevel defines the Logger log level. LoggerLevel *slog.LevelVar - // LogFileReopen is used to close and re-open the log file by + // WatchLogFile is used to close and re-open the log file by // filesystem notify to react on rename or remove event, might be used // in log rotation. - LogFileReopen bool + WatchLogFile bool // PluginRegistry allows adding enterprise logic to Teleport services PluginRegistry plugin.Registry diff --git a/lib/service/signals.go b/lib/service/signals.go index e82e6e9909ba..ebcdadfac501 100644 --- a/lib/service/signals.go +++ b/lib/service/signals.go @@ -76,7 +76,6 @@ var teleportSignals = []os.Signal{ syscall.SIGUSR1, // log process diagnostic info syscall.SIGUSR2, // initiate process restart procedure syscall.SIGHUP, // graceful restart procedure - syscall.SIGCONT, // Re-open the log file } // WaitForSignals waits for system signals and processes them. diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go new file mode 100644 index 000000000000..33684a19b7a1 --- /dev/null +++ b/lib/utils/log/file_writer.go @@ -0,0 +1,137 @@ +/* + * Teleport + * Copyright (C) 2024 Gravitational, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +package log + +import ( + "context" + "io" + "io/fs" + "log/slog" + "os" + "path/filepath" + "sync" + "sync/atomic" + + "github.com/fsnotify/fsnotify" + "github.com/gravitational/trace" +) + +var ( + // fileSharedWriter global file shared writer with the ability to reopen the log file + // in the same mode and with the same flags, either by function call or by filesystem + // notification subscription on the changes. + fileSharedWriter *FileSharedWriter + + // mu protects global init of the file shared writer. + mu sync.Mutex +) + +// FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. +// This is to allow the File reopen required by logrotate and similar tools. +type FileSharedWriter struct { + logFile atomic.Pointer[os.File] + fileFlag int + fileMode fs.FileMode +} + +// InitFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, +// with ability to enable filesystem notification watch and reopen file on specific events. +func InitFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (io.Writer, error) { + mu.Lock() + defer mu.Unlock() + + if fileSharedWriter != nil { + return nil, trace.BadParameter("file shared writer already initialized") + } + fileSharedWriter = &FileSharedWriter{fileFlag: flag, fileMode: mode} + fileSharedWriter.logFile.Store(logFile) + + return fileSharedWriter, nil +} + +// GetFileSharedWriter returns instance of the file shared writer. +func GetFileSharedWriter() *FileSharedWriter { + mu.Lock() + defer mu.Unlock() + + return fileSharedWriter +} + +// Write writes len(b) bytes from b to the File. +func (s *FileSharedWriter) Write(b []byte) (int, error) { + return s.logFile.Load().Write(b) +} + +// Reopen closes the file and opens it again using APPEND mode. +func (s *FileSharedWriter) Reopen() error { + logFile, err := os.OpenFile(s.logFile.Load().Name(), s.fileFlag, s.fileMode) + if err != nil { + return trace.Wrap(err) + } + prevLogFile := s.logFile.Swap(logFile) + if err := prevLogFile.Close(); err != nil { + return trace.Wrap(err) + } + + return nil +} + +// RunReopenWatcher spawns goroutine with the watcher loop to consume events of moving +// or removing the log file to re-open it for log rotation purposes. +func (s *FileSharedWriter) RunReopenWatcher(ctx context.Context) error { + watcher, err := fsnotify.NewWatcher() + if err != nil { + return trace.Wrap(err) + } + + go func() { + for { + select { + case event, ok := <-watcher.Events: + if !ok { + return + } + if s.logFile.Load().Name() == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { + slog.DebugContext(ctx, "Log file was moved/removed, reopen new one", "file", event.Name) + if err := s.Reopen(); err != nil { + slog.ErrorContext(ctx, "Failed to reopen new file", "error", err, "file", event.Name) + continue + } + } + case err, ok := <-watcher.Errors: + if !ok { + return + } + slog.ErrorContext(ctx, "Error received on logger watcher", "error", err) + case <-ctx.Done(): + if err := watcher.Close(); err != nil { + slog.ErrorContext(context.Background(), "Failed to close file watcher", "error", err) + } + } + } + }() + + logDirParent := filepath.Dir(s.logFile.Load().Name()) + err = watcher.Add(logDirParent) + if err != nil { + return trace.Wrap(err) + } + + return nil +} diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go new file mode 100644 index 000000000000..5b0cd693562b --- /dev/null +++ b/lib/utils/log/file_writer_test.go @@ -0,0 +1,98 @@ +/* + * Teleport + * Copyright (C) 2024 Gravitational, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +package log + +import ( + "context" + "fmt" + "os" + "path/filepath" + "testing" + "time" + + "github.com/fsnotify/fsnotify" + "github.com/stretchr/testify/require" +) + +// TestFileSharedWriterNotify checks that if we create the file with shared writer and enable +// watcher functionality, we should expect the file to be reopened after renaming the original one. +func TestFileSharedWriterNotify(t *testing.T) { + t.Parallel() + + ctx, cancel := context.WithCancel(context.Background()) + + logDir := t.TempDir() + testFileMode := os.FileMode(0o600) + testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND + logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) + require.NoError(t, err, "failed to open log file") + + // We need to use the watcher in tests as well to react only when the log file is recreated. + watcher, err := fsnotify.NewWatcher() + require.NoError(t, err) + err = watcher.Add(logDir) + require.NoError(t, err, "failed to apply watcher to temporary log directory") + + t.Cleanup(func() { + cancel() + watcher.Close() + logFile.Close() + fileSharedWriter = nil + }) + + logWriter, err := InitFileSharedWriter(logFile, testFileFlag, testFileMode) + require.NoError(t, err, "failed to init the file shared writer") + + err = GetFileSharedWriter().RunReopenWatcher(ctx) + require.NoError(t, err, "failed to run reopen watcher") + + // Write a custom phrase to ensure that the original file was written to before the rotation. + firstPhrase := "first-write" + n, err := logWriter.Write([]byte(firstPhrase)) + require.NoError(t, err) + require.Equal(t, len(firstPhrase), n, "failed to write first phrase") + + data, err := os.ReadFile(logFile.Name()) + require.NoError(t, err, "cannot read log file") + require.Equal(t, firstPhrase, string(data), "first written phrase does not match") + + // Move the original file to a new location to simulate the logrotate operation. + err = os.Rename(logFile.Name(), fmt.Sprintf("%s.1", logFile.Name())) + require.NoError(t, err, "can't rename log file") + + timeout := time.After(5 * time.Second) + var event fsnotify.Event + for !event.Has(fsnotify.Create) || event.Name != logFile.Name() { + select { + case <-timeout: + require.Fail(t, "timed out waiting for file to change") + case event = <-watcher.Events: + } + } + + // Write a second custom phrase to ensure the previous one is not in the file. + secondPhrase := "second-write" + n, err = logWriter.Write([]byte(secondPhrase)) + require.NoError(t, err) + require.Equal(t, len(secondPhrase), n, "failed to write second phrase") + + data, err = os.ReadFile(logFile.Name()) + require.NoError(t, err, "cannot read log file") + require.Equal(t, secondPhrase, string(data), "second written phrase does not match") +} diff --git a/lib/utils/log/writer.go b/lib/utils/log/writer.go index 7609e4236287..77cf3037a8b6 100644 --- a/lib/utils/log/writer.go +++ b/lib/utils/log/writer.go @@ -19,15 +19,8 @@ package log import ( - "context" "io" - "io/fs" - "log/slog" - "os" "sync" - - "github.com/fsnotify/fsnotify" - "github.com/gravitational/trace" ) // SharedWriter is an [io.Writer] implementation that protects @@ -50,85 +43,3 @@ func (s *SharedWriter) Write(p []byte) (int, error) { func NewSharedWriter(w io.Writer) *SharedWriter { return &SharedWriter{Writer: w} } - -// FileSharedWriter is similar to SharedWriter except that it requires a os.File instead of a io.Writer. -// This is to allow the File reopen required by logrotate and similar tools. -// SharedWriter must be used for log destinations that don't have the reopen requirement, like stdout and stderr. -// This is thread safe. -type FileSharedWriter struct { - *os.File - fileFlag int - fileMode fs.FileMode - mu sync.Mutex -} - -func (s *FileSharedWriter) Write(p []byte) (int, error) { - s.mu.Lock() - defer s.mu.Unlock() - - return s.File.Write(p) -} - -// Reopen closes the file and opens it again using APPEND mode. -func (s *FileSharedWriter) Reopen() (err error) { - s.mu.Lock() - defer s.mu.Unlock() - - if err := s.Close(); err != nil { - return trace.Wrap(err) - } - - s.File, err = os.OpenFile(s.Name(), s.fileFlag, s.fileMode) - return trace.Wrap(err) -} - -// runWatcher spawns goroutine with the watcher loop to consume events of moving -// or removing the log file to re-open it for log rotation purposes. -func (s *FileSharedWriter) runWatcher() error { - watcher, err := fsnotify.NewWatcher() - if err != nil { - return trace.Wrap(err) - } - - err = watcher.Add(s.Name()) - if err != nil { - return trace.Wrap(err) - } - - go func() { - for { - select { - case event, ok := <-watcher.Events: - if !ok { - return - } - if event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove) { - slog.DebugContext(context.Background(), "Log file was moved/removed, reopen new one", "file", event.Name) - if err := s.Reopen(); err != nil { - slog.ErrorContext(context.Background(), "Failed to reopen new file", err, "file", event.Name) - continue - } - if err = watcher.Add(s.Name()); err != nil { - slog.ErrorContext(context.Background(), "Failed to reinit watcher", err, "file", event.Name) - continue - } - } - case err := <-watcher.Errors: - slog.ErrorContext(context.Background(), "Error received on logger watcher", "error", err) - } - } - }() - - return nil -} - -// NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe. -func NewFileSharedWriter(f *os.File, flag int, mode fs.FileMode, watcherEnabled bool) (*FileSharedWriter, error) { - sharedWriter := &FileSharedWriter{File: f, fileFlag: flag, fileMode: mode} - if watcherEnabled { - if err := sharedWriter.runWatcher(); err != nil { - return nil, trace.Wrap(err) - } - } - return sharedWriter, nil -} From 926f68af92d7d4eee318266d6f678dcf85268e70 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Wed, 3 Jul 2024 20:46:58 -0400 Subject: [PATCH 04/15] add locking for write, reopen --- go.mod | 2 +- lib/utils/log/file_writer.go | 20 ++++++++++++++------ lib/utils/log/file_writer_test.go | 2 -- 3 files changed, 15 insertions(+), 9 deletions(-) diff --git a/go.mod b/go.mod index 74131fabad31..c5efaf79a024 100644 --- a/go.mod +++ b/go.mod @@ -84,6 +84,7 @@ require ( github.com/elastic/go-elasticsearch/v8 v8.13.1 github.com/elimity-com/scim v0.0.0-20240320110924-172bf2aee9c8 github.com/evanphx/json-patch v5.9.0+incompatible + github.com/fsnotify/fsnotify v1.7.0 github.com/fsouza/fake-gcs-server v1.48.0 github.com/fxamacker/cbor/v2 v2.6.0 github.com/ghodss/yaml v1.0.0 @@ -322,7 +323,6 @@ require ( github.com/fatih/color v1.16.0 // indirect github.com/felixge/httpsnoop v1.0.4 // indirect github.com/form3tech-oss/jwt-go v3.2.5+incompatible // indirect - github.com/fsnotify/fsnotify v1.7.0 github.com/fvbommel/sortorder v1.1.0 // indirect github.com/gabriel-vasile/mimetype v1.4.3 // indirect github.com/go-asn1-ber/asn1-ber v1.5.5 // indirect diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 33684a19b7a1..effa60d207f5 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -38,8 +38,8 @@ var ( // notification subscription on the changes. fileSharedWriter *FileSharedWriter - // mu protects global init of the file shared writer. - mu sync.Mutex + // initLock protects global init of the file shared writer. + initLock sync.Mutex ) // FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. @@ -48,13 +48,15 @@ type FileSharedWriter struct { logFile atomic.Pointer[os.File] fileFlag int fileMode fs.FileMode + + lock sync.Mutex } // InitFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, // with ability to enable filesystem notification watch and reopen file on specific events. func InitFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (io.Writer, error) { - mu.Lock() - defer mu.Unlock() + initLock.Lock() + defer initLock.Unlock() if fileSharedWriter != nil { return nil, trace.BadParameter("file shared writer already initialized") @@ -67,19 +69,25 @@ func InitFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (io.Writ // GetFileSharedWriter returns instance of the file shared writer. func GetFileSharedWriter() *FileSharedWriter { - mu.Lock() - defer mu.Unlock() + initLock.Lock() + defer initLock.Unlock() return fileSharedWriter } // Write writes len(b) bytes from b to the File. func (s *FileSharedWriter) Write(b []byte) (int, error) { + s.lock.Lock() + defer s.lock.Unlock() + return s.logFile.Load().Write(b) } // Reopen closes the file and opens it again using APPEND mode. func (s *FileSharedWriter) Reopen() error { + s.lock.Lock() + defer s.lock.Unlock() + logFile, err := os.OpenFile(s.logFile.Load().Name(), s.fileFlag, s.fileMode) if err != nil { return trace.Wrap(err) diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 5b0cd693562b..2d9900841b97 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -33,8 +33,6 @@ import ( // TestFileSharedWriterNotify checks that if we create the file with shared writer and enable // watcher functionality, we should expect the file to be reopened after renaming the original one. func TestFileSharedWriterNotify(t *testing.T) { - t.Parallel() - ctx, cancel := context.WithCancel(context.Background()) logDir := t.TempDir() From f14d2b6ba003ce757e3b35a291118e5c1e22d0b8 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Wed, 3 Jul 2024 22:10:07 -0400 Subject: [PATCH 05/15] - configuration for log section update - test simplification --- .../helm-reference/teleport-cluster.mdx | 19 ++++++++++++- .../__snapshot__/auth_config_test.yaml.snap | 1 + .../__snapshot__/proxy_config_test.yaml.snap | 1 + lib/config/configuration.go | 1 + lib/config/fileconf.go | 3 +++ lib/service/service.go | 2 +- lib/utils/log/file_writer.go | 8 +++--- lib/utils/log/file_writer_test.go | 27 +++++++------------ 8 files changed, 39 insertions(+), 23 deletions(-) diff --git a/docs/pages/reference/helm-reference/teleport-cluster.mdx b/docs/pages/reference/helm-reference/teleport-cluster.mdx index ee071e5a8aaf..6c8f6fbbeb95 100644 --- a/docs/pages/reference/helm-reference/teleport-cluster.mdx +++ b/docs/pages/reference/helm-reference/teleport-cluster.mdx @@ -705,7 +705,7 @@ It is recommended to set resource requests/limits for each container based on th |----------|--------------------------------------------------| | `string` | `cluster.local` | -`global.clusterDomain` sets the the domain suffix used by the Kubernetes DNS service. +`global.clusterDomain` sets the the domain suffix used by the Kubernetes DNS service. This is used to resolve service names in the cluster. `values.yaml` example: @@ -1527,6 +1527,23 @@ See the [Teleport config file reference](../../reference/config.mdx) for more de extraFields: ["timestamp", "level"] ``` +### `log.watch_log_file` + +| Type | Default value | `teleport.yaml` equivalent | +|--------|---------------|-------------------------------| +| `bool` | `false` | `teleport.log.watch_log_file` | + +`log.watch_log_file` Enables/disables the file shared logger's watching functionality +to reopen the log file if it was renamed or removed. Must be used in conjunction with output set as a file path. + +`values.yaml` example: + + ```yaml + log: + output: /var/log/teleport.log + watch_log_file: true + ``` + ## `nodeSelector` | Type | Default value | diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap index bff9e2a397a7..4d14c6b52a61 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap @@ -1282,6 +1282,7 @@ matches snapshot for log-extra.yaml: - caller output: json output: /var/lib/teleport/test.log + watch_log_file: true severity: DEBUG version: v3 matches snapshot for log-legacy.yaml: diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap index 32830dc1a9d4..3c0f5f381780 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap @@ -361,6 +361,7 @@ matches snapshot for log-extra.yaml: - caller output: json output: /var/lib/teleport/test.log + watch_log_file: true severity: DEBUG version: v3 matches snapshot for proxy-listener-mode-multiplex.yaml: diff --git a/lib/config/configuration.go b/lib/config/configuration.go index ca8b58485605..7543dc1d7e85 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -802,6 +802,7 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { logFile.Close() return trace.Wrap(err, "failed to init the log file shared writer") } + cfg.WatchLogFile = loggerConfig.WatchLogFile } level := new(slog.LevelVar) diff --git a/lib/config/fileconf.go b/lib/config/fileconf.go index 72f1b0869877..7cc8e0176271 100644 --- a/lib/config/fileconf.go +++ b/lib/config/fileconf.go @@ -539,6 +539,9 @@ type Log struct { Severity string `yaml:"severity,omitempty"` // Format defines the logs output format and extra fields Format LogFormat `yaml:"format,omitempty"` + // WatchLogFile is used to close and re-open the log file by filesystem notification + // to react on rename or remove event, might be used in log rotation. + WatchLogFile bool `yaml:"watch_log_file,omitempty"` } // LogFormat specifies the logs output format and extra fields diff --git a/lib/service/service.go b/lib/service/service.go index d30775860ded..89969665df6b 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -1357,7 +1357,7 @@ func NewTeleport(cfg *servicecfg.Config) (*TeleportProcess, error) { // Enable shared log file watcher if configuration is set, to react on rename event. sharedWriter := logutils.GetFileSharedWriter() if cfg.WatchLogFile && sharedWriter != nil { - if err := sharedWriter.RunReopenWatcher(process.GracefulExitContext()); err != nil { + if err := sharedWriter.RunWatcherFunc(process.GracefulExitContext(), sharedWriter.Reopen); err != nil { return nil, trace.Wrap(err) } } diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index effa60d207f5..968af646cda1 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -100,9 +100,9 @@ func (s *FileSharedWriter) Reopen() error { return nil } -// RunReopenWatcher spawns goroutine with the watcher loop to consume events of moving -// or removing the log file to re-open it for log rotation purposes. -func (s *FileSharedWriter) RunReopenWatcher(ctx context.Context) error { +// RunWatcherFunc spawns goroutine with the watcher loop to consume events of renaming +// or removing the log file to trigger the action function when event appeared. +func (s *FileSharedWriter) RunWatcherFunc(ctx context.Context, action func() error) error { watcher, err := fsnotify.NewWatcher() if err != nil { return trace.Wrap(err) @@ -117,7 +117,7 @@ func (s *FileSharedWriter) RunReopenWatcher(ctx context.Context) error { } if s.logFile.Load().Name() == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { slog.DebugContext(ctx, "Log file was moved/removed, reopen new one", "file", event.Name) - if err := s.Reopen(); err != nil { + if err := action(); err != nil { slog.ErrorContext(ctx, "Failed to reopen new file", "error", err, "file", event.Name) continue } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 2d9900841b97..5715dc6e52dc 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -26,7 +26,6 @@ import ( "testing" "time" - "github.com/fsnotify/fsnotify" "github.com/stretchr/testify/require" ) @@ -41,15 +40,8 @@ func TestFileSharedWriterNotify(t *testing.T) { logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) require.NoError(t, err, "failed to open log file") - // We need to use the watcher in tests as well to react only when the log file is recreated. - watcher, err := fsnotify.NewWatcher() - require.NoError(t, err) - err = watcher.Add(logDir) - require.NoError(t, err, "failed to apply watcher to temporary log directory") - t.Cleanup(func() { cancel() - watcher.Close() logFile.Close() fileSharedWriter = nil }) @@ -57,7 +49,12 @@ func TestFileSharedWriterNotify(t *testing.T) { logWriter, err := InitFileSharedWriter(logFile, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") - err = GetFileSharedWriter().RunReopenWatcher(ctx) + signal := make(chan struct{}) + err = GetFileSharedWriter().RunWatcherFunc(ctx, func() error { + err := GetFileSharedWriter().Reopen() + signal <- struct{}{} + return err + }) require.NoError(t, err, "failed to run reopen watcher") // Write a custom phrase to ensure that the original file was written to before the rotation. @@ -74,14 +71,10 @@ func TestFileSharedWriterNotify(t *testing.T) { err = os.Rename(logFile.Name(), fmt.Sprintf("%s.1", logFile.Name())) require.NoError(t, err, "can't rename log file") - timeout := time.After(5 * time.Second) - var event fsnotify.Event - for !event.Has(fsnotify.Create) || event.Name != logFile.Name() { - select { - case <-timeout: - require.Fail(t, "timed out waiting for file to change") - case event = <-watcher.Events: - } + select { + case <-time.After(5 * time.Second): + require.Fail(t, "timed out waiting for file reopen") + case <-signal: } // Write a second custom phrase to ensure the previous one is not in the file. From 49ab434bbb52aaef3bdd0dff155c14b5485b08d2 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Sat, 6 Jul 2024 00:28:48 -0400 Subject: [PATCH 06/15] code review changes: - add closing for file shared writer - make runWatcherFunc not exported --- lib/config/configuration.go | 1 + lib/service/service.go | 2 +- lib/utils/log/file_writer.go | 53 ++++++++++++++++++++++++++----- lib/utils/log/file_writer_test.go | 5 ++- 4 files changed, 49 insertions(+), 12 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 7543dc1d7e85..5ec5cf40babd 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -760,6 +760,7 @@ func applyAuthOrProxyAddress(fc *FileConfig, cfg *servicecfg.Config) error { func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { logger := log.StandardLogger() + logutils.CloseFileSharedWriter() var w io.Writer switch loggerConfig.Output { diff --git a/lib/service/service.go b/lib/service/service.go index 062581b083c8..17f6f4d840f2 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -1426,7 +1426,7 @@ func NewTeleport(cfg *servicecfg.Config) (*TeleportProcess, error) { // Enable shared log file watcher if configuration is set, to react on rename event. sharedWriter := logutils.GetFileSharedWriter() if cfg.WatchLogFile && sharedWriter != nil { - if err := sharedWriter.RunWatcherFunc(process.GracefulExitContext(), sharedWriter.Reopen); err != nil { + if err := sharedWriter.RunWatcherReopen(process.ExitContext()); err != nil { return nil, trace.Wrap(err) } } diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 968af646cda1..2f091ae1c11d 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -46,6 +46,7 @@ var ( // This is to allow the File reopen required by logrotate and similar tools. type FileSharedWriter struct { logFile atomic.Pointer[os.File] + watcher atomic.Pointer[fsnotify.Watcher] fileFlag int fileMode fs.FileMode @@ -67,6 +68,19 @@ func InitFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (io.Writ return fileSharedWriter, nil } +// CloseFileSharedWriter closes the file shared writer and frees up resources. +func CloseFileSharedWriter() { + initLock.Lock() + defer initLock.Unlock() + + if fileSharedWriter != nil { + if err := fileSharedWriter.Close(); err != nil { + slog.ErrorContext(context.Background(), "Failed to close file shared writer", "error", err) + } + fileSharedWriter = nil + } +} + // GetFileSharedWriter returns instance of the file shared writer. func GetFileSharedWriter() *FileSharedWriter { initLock.Lock() @@ -100,13 +114,36 @@ func (s *FileSharedWriter) Reopen() error { return nil } -// RunWatcherFunc spawns goroutine with the watcher loop to consume events of renaming +// Close stops watcher loop and frees resources. +func (s *FileSharedWriter) Close() error { + s.lock.Lock() + defer s.lock.Unlock() + + if watcher := s.watcher.Swap(nil); watcher != nil { + return trace.Wrap(watcher.Close()) + } + s.logFile.Swap(nil) + + return nil +} + +// RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. +func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { + return s.runWatcherFunc(ctx, s.Reopen) +} + +// runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming // or removing the log file to trigger the action function when event appeared. -func (s *FileSharedWriter) RunWatcherFunc(ctx context.Context, action func() error) error { +func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() error) error { watcher, err := fsnotify.NewWatcher() if err != nil { return trace.Wrap(err) } + context.AfterFunc(ctx, func() { + if err := watcher.Close(); err != nil { + slog.ErrorContext(context.Background(), "Failed to close file watcher", "error", err) + } + }) go func() { for { @@ -127,19 +164,19 @@ func (s *FileSharedWriter) RunWatcherFunc(ctx context.Context, action func() err return } slog.ErrorContext(ctx, "Error received on logger watcher", "error", err) - case <-ctx.Done(): - if err := watcher.Close(); err != nil { - slog.ErrorContext(context.Background(), "Failed to close file watcher", "error", err) - } } } }() logDirParent := filepath.Dir(s.logFile.Load().Name()) - err = watcher.Add(logDirParent) - if err != nil { + if err = watcher.Add(logDirParent); err != nil { return trace.Wrap(err) } + oldWatcher := s.watcher.Swap(watcher) + if oldWatcher != nil { + return trace.Wrap(oldWatcher.Close()) + } + return nil } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 5715dc6e52dc..a1b3fa65f825 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -42,15 +42,14 @@ func TestFileSharedWriterNotify(t *testing.T) { t.Cleanup(func() { cancel() - logFile.Close() - fileSharedWriter = nil + CloseFileSharedWriter() }) logWriter, err := InitFileSharedWriter(logFile, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") signal := make(chan struct{}) - err = GetFileSharedWriter().RunWatcherFunc(ctx, func() error { + err = GetFileSharedWriter().runWatcherFunc(ctx, func() error { err := GetFileSharedWriter().Reopen() signal <- struct{}{} return err From 686a8ddc2d2cb885004117e9a06df71b6fce9faf Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Mon, 8 Jul 2024 13:24:58 -0400 Subject: [PATCH 07/15] linter fixes --- docs/pages/reference/helm-reference/teleport-cluster.mdx | 4 ++-- examples/chart/teleport-cluster/.lint/log-extra.yaml | 1 + .../chart/teleport-cluster/templates/auth/_config.common.tpl | 3 +++ .../chart/teleport-cluster/templates/proxy/_config.common.tpl | 3 +++ .../tests/__snapshot__/auth_config_test.yaml.snap | 2 +- .../tests/__snapshot__/proxy_config_test.yaml.snap | 2 +- examples/chart/teleport-kube-agent/.lint/log-extra.yaml | 1 + examples/chart/teleport-kube-agent/templates/_config.tpl | 3 +++ .../tests/__snapshot__/config_test.yaml.snap | 2 ++ integrations/event-handler/go.mod | 1 + integrations/event-handler/go.sum | 2 ++ integrations/terraform/go.mod | 1 + integrations/terraform/go.sum | 2 ++ 13 files changed, 23 insertions(+), 4 deletions(-) diff --git a/docs/pages/reference/helm-reference/teleport-cluster.mdx b/docs/pages/reference/helm-reference/teleport-cluster.mdx index 6c8f6fbbeb95..783dc51e4046 100644 --- a/docs/pages/reference/helm-reference/teleport-cluster.mdx +++ b/docs/pages/reference/helm-reference/teleport-cluster.mdx @@ -1533,8 +1533,8 @@ See the [Teleport config file reference](../../reference/config.mdx) for more de |--------|---------------|-------------------------------| | `bool` | `false` | `teleport.log.watch_log_file` | -`log.watch_log_file` Enables/disables the file shared logger's watching functionality -to reopen the log file if it was renamed or removed. Must be used in conjunction with output set as a file path. +`log.watch_log_file` enables/disables the file shared logger's watching functionality to reopen the log file +if it is renamed or removed. Must be used in conjunction with the output set as a file path. `values.yaml` example: diff --git a/examples/chart/teleport-cluster/.lint/log-extra.yaml b/examples/chart/teleport-cluster/.lint/log-extra.yaml index 7f3e21bb340a..d2d43acae7ac 100644 --- a/examples/chart/teleport-cluster/.lint/log-extra.yaml +++ b/examples/chart/teleport-cluster/.lint/log-extra.yaml @@ -3,4 +3,5 @@ log: format: json level: DEBUG output: /var/lib/teleport/test.log + watch_log_file: true extraFields: ["level", "timestamp", "component", "caller"] diff --git a/examples/chart/teleport-cluster/templates/auth/_config.common.tpl b/examples/chart/teleport-cluster/templates/auth/_config.common.tpl index cc506255f2ff..4019aa21cf2f 100644 --- a/examples/chart/teleport-cluster/templates/auth/_config.common.tpl +++ b/examples/chart/teleport-cluster/templates/auth/_config.common.tpl @@ -62,6 +62,9 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} + {{- if .Values.log.watch_log_file }} + watch_log_file: {{ .Values.log.watch_log_file }} + {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl b/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl index 32dd85c5476b..b5bca9059f67 100644 --- a/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl +++ b/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl @@ -9,6 +9,9 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} + {{- if .Values.log.watch_log_file }} + watch_log_file: {{ .Values.log.watch_log_file }} + {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap index 4d14c6b52a61..0d83e9e3db73 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap @@ -1282,8 +1282,8 @@ matches snapshot for log-extra.yaml: - caller output: json output: /var/lib/teleport/test.log - watch_log_file: true severity: DEBUG + watch_log_file: true version: v3 matches snapshot for log-legacy.yaml: 1: | diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap index 3c0f5f381780..bccd4c8f7656 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap @@ -361,8 +361,8 @@ matches snapshot for log-extra.yaml: - caller output: json output: /var/lib/teleport/test.log - watch_log_file: true severity: DEBUG + watch_log_file: true version: v3 matches snapshot for proxy-listener-mode-multiplex.yaml: 1: | diff --git a/examples/chart/teleport-kube-agent/.lint/log-extra.yaml b/examples/chart/teleport-kube-agent/.lint/log-extra.yaml index 656190d461bf..61a7d494ad2a 100644 --- a/examples/chart/teleport-kube-agent/.lint/log-extra.yaml +++ b/examples/chart/teleport-kube-agent/.lint/log-extra.yaml @@ -5,4 +5,5 @@ log: format: json level: DEBUG output: /var/lib/teleport/test.log + watch_log_file: true extraFields: ["level", "timestamp", "component", "caller"] diff --git a/examples/chart/teleport-kube-agent/templates/_config.tpl b/examples/chart/teleport-kube-agent/templates/_config.tpl index adb708ddfa4b..f44171685f55 100644 --- a/examples/chart/teleport-kube-agent/templates/_config.tpl +++ b/examples/chart/teleport-kube-agent/templates/_config.tpl @@ -21,6 +21,9 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} + {{- if .Values.log.watch_log_file }} + watch_log_file: {{ .Values.log.watch_log_file }} + {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap b/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap index ad817a9498ce..885501e7c457 100644 --- a/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap +++ b/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap @@ -1062,6 +1062,7 @@ matches snapshot for log-extra.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG + watch_log_file: true proxy_server: proxy.example.com:3080 version: v3 kind: ConfigMap @@ -1188,6 +1189,7 @@ matches snapshot for pdb.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG + watch_log_file: true proxy_server: proxy.example.com:3080 version: v3 kind: ConfigMap diff --git a/integrations/event-handler/go.mod b/integrations/event-handler/go.mod index 1f0ff993d977..31b90bb75604 100644 --- a/integrations/event-handler/go.mod +++ b/integrations/event-handler/go.mod @@ -129,6 +129,7 @@ require ( github.com/exponent-io/jsonpath v0.0.0-20151013193312-d6023ce2651d // indirect github.com/fatih/color v1.16.0 // indirect github.com/felixge/httpsnoop v1.0.4 // indirect + github.com/fsnotify/fsnotify v1.7.0 // indirect github.com/fxamacker/cbor/v2 v2.7.0 // indirect github.com/ghodss/yaml v1.0.0 // indirect github.com/go-errors/errors v1.4.2 // indirect diff --git a/integrations/event-handler/go.sum b/integrations/event-handler/go.sum index 38c3474170ca..d88e8403a354 100644 --- a/integrations/event-handler/go.sum +++ b/integrations/event-handler/go.sum @@ -938,6 +938,8 @@ github.com/foxcpp/go-mockdns v1.0.0 h1:7jBqxd3WDWwi/6WhDvacvH1XsN3rOLXyHM1uhvIx6 github.com/foxcpp/go-mockdns v1.0.0/go.mod h1:lgRN6+KxQBawyIghpnl5CezHFGS9VLzvtVlwxvzXTQ4= github.com/frankban/quicktest v1.14.6 h1:7Xjx+VpznH+oBnejlPUj8oUpdxnVs4f8XU8WnHkI4W8= github.com/frankban/quicktest v1.14.6/go.mod h1:4ptaffx2x8+WTWXmUCuVU6aPUX1/Mz7zb5vbUoiM6w0= +github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA= +github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM= github.com/fxamacker/cbor/v2 v2.7.0 h1:iM5WgngdRBanHcxugY4JySA0nk1wZorNOpTgCMedv5E= github.com/fxamacker/cbor/v2 v2.7.0/go.mod h1:pxXPTn3joSm21Gbwsv0w9OSA2y1HFR9qXEeXQVeNoDQ= github.com/ghodss/yaml v1.0.0 h1:wQHKEahhL6wmXdzwWG11gIVCkOv05bNOh+Rxn0yngAk= diff --git a/integrations/terraform/go.mod b/integrations/terraform/go.mod index e28a38300f50..a31430da2aeb 100644 --- a/integrations/terraform/go.mod +++ b/integrations/terraform/go.mod @@ -174,6 +174,7 @@ require ( github.com/exponent-io/jsonpath v0.0.0-20151013193312-d6023ce2651d // indirect github.com/fatih/color v1.16.0 // indirect github.com/felixge/httpsnoop v1.0.4 // indirect + github.com/fsnotify/fsnotify v1.7.0 // indirect github.com/fxamacker/cbor/v2 v2.7.0 // indirect github.com/ghodss/yaml v1.0.0 // indirect github.com/go-asn1-ber/asn1-ber v1.5.5 // indirect diff --git a/integrations/terraform/go.sum b/integrations/terraform/go.sum index cec38608a775..411433137ed0 100644 --- a/integrations/terraform/go.sum +++ b/integrations/terraform/go.sum @@ -1090,6 +1090,8 @@ github.com/foxcpp/go-mockdns v1.0.0 h1:7jBqxd3WDWwi/6WhDvacvH1XsN3rOLXyHM1uhvIx6 github.com/foxcpp/go-mockdns v1.0.0/go.mod h1:lgRN6+KxQBawyIghpnl5CezHFGS9VLzvtVlwxvzXTQ4= github.com/frankban/quicktest v1.14.6 h1:7Xjx+VpznH+oBnejlPUj8oUpdxnVs4f8XU8WnHkI4W8= github.com/frankban/quicktest v1.14.6/go.mod h1:4ptaffx2x8+WTWXmUCuVU6aPUX1/Mz7zb5vbUoiM6w0= +github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA= +github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM= github.com/fsouza/fake-gcs-server v1.49.2 h1:fukDqzEQM50QkA0jAbl6cLqeDu3maQjwZBuys759TR4= github.com/fsouza/fake-gcs-server v1.49.2/go.mod h1:17SYzJEXRcaAA5ATwwvgBkSIqIy7r1icnGM0y/y4foY= github.com/fxamacker/cbor/v2 v2.7.0 h1:iM5WgngdRBanHcxugY4JySA0nk1wZorNOpTgCMedv5E= From 550d75a374e4675a9eb83863f017ecd9a4cf79bb Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Tue, 9 Jul 2024 17:06:59 -0400 Subject: [PATCH 08/15] change default file mode for log file simplify setting global watcher --- lib/config/configuration.go | 11 +++-- lib/service/service.go | 2 +- lib/utils/log/file_writer.go | 76 +++++++++++-------------------- lib/utils/log/file_writer_test.go | 7 ++- 4 files changed, 36 insertions(+), 60 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 5ec5cf40babd..ea2580541e2a 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -74,7 +74,7 @@ import ( const ( // logFileDefaultMode is the preferred permissions mode for log file. - logFileDefaultMode fs.FileMode = 0o666 + logFileDefaultMode fs.FileMode = 0o644 // logFileDefaultFlag is the preferred flags set to log file. logFileDefaultFlag = os.O_WRONLY | os.O_CREATE | os.O_APPEND ) @@ -760,7 +760,6 @@ func applyAuthOrProxyAddress(fc *FileConfig, cfg *servicecfg.Config) error { func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { logger := log.StandardLogger() - logutils.CloseFileSharedWriter() var w io.Writer switch loggerConfig.Output { @@ -798,12 +797,14 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { if err != nil { return trace.Wrap(err, "failed to create the log file") } - w, err = logutils.InitFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode) + + cfg.WatchLogFile = loggerConfig.WatchLogFile + sharedWriter, err := logutils.NewFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode) if err != nil { - logFile.Close() return trace.Wrap(err, "failed to init the log file shared writer") } - cfg.WatchLogFile = loggerConfig.WatchLogFile + logutils.SetFileSharedWriter(sharedWriter) + w = sharedWriter } level := new(slog.LevelVar) diff --git a/lib/service/service.go b/lib/service/service.go index 17f6f4d840f2..6ea50d468234 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -1423,7 +1423,7 @@ func NewTeleport(cfg *servicecfg.Config) (*TeleportProcess, error) { } } - // Enable shared log file watcher if configuration is set, to react on rename event. + // Enable shared log file watcher if configuration is set, to react on filesystem event. sharedWriter := logutils.GetFileSharedWriter() if cfg.WatchLogFile && sharedWriter != nil { if err := sharedWriter.RunWatcherReopen(process.ExitContext()); err != nil { diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 2f091ae1c11d..cd1c37836bf8 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -20,7 +20,6 @@ package log import ( "context" - "io" "io/fs" "log/slog" "os" @@ -38,55 +37,47 @@ var ( // notification subscription on the changes. fileSharedWriter *FileSharedWriter - // initLock protects global init of the file shared writer. - initLock sync.Mutex + // mu protects global setter/getter of the file shared writer. + mu sync.Mutex ) // FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. // This is to allow the File reopen required by logrotate and similar tools. type FileSharedWriter struct { logFile atomic.Pointer[os.File] - watcher atomic.Pointer[fsnotify.Watcher] fileFlag int fileMode fs.FileMode lock sync.Mutex } -// InitFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, -// with ability to enable filesystem notification watch and reopen file on specific events. -func InitFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (io.Writer, error) { - initLock.Lock() - defer initLock.Unlock() - - if fileSharedWriter != nil { - return nil, trace.BadParameter("file shared writer already initialized") - } - fileSharedWriter = &FileSharedWriter{fileFlag: flag, fileMode: mode} - fileSharedWriter.logFile.Store(logFile) +// SetFileSharedWriter sets global file shared writer. +func SetFileSharedWriter(sharedWriter *FileSharedWriter) { + mu.Lock() + defer mu.Unlock() - return fileSharedWriter, nil + fileSharedWriter = sharedWriter } -// CloseFileSharedWriter closes the file shared writer and frees up resources. -func CloseFileSharedWriter() { - initLock.Lock() - defer initLock.Unlock() +// GetFileSharedWriter returns instance of the global file shared writer. +func GetFileSharedWriter() *FileSharedWriter { + mu.Lock() + defer mu.Unlock() - if fileSharedWriter != nil { - if err := fileSharedWriter.Close(); err != nil { - slog.ErrorContext(context.Background(), "Failed to close file shared writer", "error", err) - } - fileSharedWriter = nil - } + return fileSharedWriter } -// GetFileSharedWriter returns instance of the file shared writer. -func GetFileSharedWriter() *FileSharedWriter { - initLock.Lock() - defer initLock.Unlock() +// NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, +// with ability to enable filesystem notification watch and reopen file on specific events. +func NewFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (*FileSharedWriter, error) { + if logFile == nil { + return nil, trace.BadParameter("log file is not set") + } - return fileSharedWriter + sharedWriter := &FileSharedWriter{fileFlag: flag, fileMode: mode} + sharedWriter.logFile.Store(logFile) + + return sharedWriter, nil } // Write writes len(b) bytes from b to the File. @@ -114,21 +105,11 @@ func (s *FileSharedWriter) Reopen() error { return nil } -// Close stops watcher loop and frees resources. -func (s *FileSharedWriter) Close() error { +// RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. +func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { s.lock.Lock() defer s.lock.Unlock() - if watcher := s.watcher.Swap(nil); watcher != nil { - return trace.Wrap(watcher.Close()) - } - s.logFile.Swap(nil) - - return nil -} - -// RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. -func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { return s.runWatcherFunc(ctx, s.Reopen) } @@ -153,9 +134,9 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err return } if s.logFile.Load().Name() == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { - slog.DebugContext(ctx, "Log file was moved/removed, reopen new one", "file", event.Name) + slog.DebugContext(ctx, "Log file was moved/removed", "file", event.Name) if err := action(); err != nil { - slog.ErrorContext(ctx, "Failed to reopen new file", "error", err, "file", event.Name) + slog.ErrorContext(ctx, "Failed to take action", "error", err, "file", event.Name) continue } } @@ -173,10 +154,5 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err return trace.Wrap(err) } - oldWatcher := s.watcher.Swap(watcher) - if oldWatcher != nil { - return trace.Wrap(oldWatcher.Close()) - } - return nil } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index a1b3fa65f825..858694d0a684 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -42,15 +42,14 @@ func TestFileSharedWriterNotify(t *testing.T) { t.Cleanup(func() { cancel() - CloseFileSharedWriter() }) - logWriter, err := InitFileSharedWriter(logFile, testFileFlag, testFileMode) + logWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") signal := make(chan struct{}) - err = GetFileSharedWriter().runWatcherFunc(ctx, func() error { - err := GetFileSharedWriter().Reopen() + err = logWriter.runWatcherFunc(ctx, func() error { + err := logWriter.Reopen() signal <- struct{}{} return err }) From 991c70a76fcbdc0344d3745d5a4613b273c9a8a4 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Wed, 10 Jul 2024 23:23:40 -0400 Subject: [PATCH 09/15] terminate watcher after override global one added test for validating global override --- lib/config/configuration.go | 7 +-- lib/utils/log/file_writer.go | 38 ++++++++++------ lib/utils/log/file_writer_test.go | 73 +++++++++++++++++++++++++++++-- 3 files changed, 99 insertions(+), 19 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index ea2580541e2a..2544a959b5ef 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -797,14 +797,15 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { if err != nil { return trace.Wrap(err, "failed to create the log file") } - - cfg.WatchLogFile = loggerConfig.WatchLogFile sharedWriter, err := logutils.NewFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode) if err != nil { return trace.Wrap(err, "failed to init the log file shared writer") } - logutils.SetFileSharedWriter(sharedWriter) + if err := logutils.SetFileSharedWriter(sharedWriter); err != nil { + return trace.Wrap(err, "failed to set the log file shared writer") + } w = sharedWriter + cfg.WatchLogFile = loggerConfig.WatchLogFile } level := new(slog.LevelVar) diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index cd1c37836bf8..03b305e1697c 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -47,16 +47,22 @@ type FileSharedWriter struct { logFile atomic.Pointer[os.File] fileFlag int fileMode fs.FileMode + watcher *fsnotify.Watcher lock sync.Mutex } // SetFileSharedWriter sets global file shared writer. -func SetFileSharedWriter(sharedWriter *FileSharedWriter) { +func SetFileSharedWriter(sharedWriter *FileSharedWriter) (err error) { mu.Lock() defer mu.Unlock() + if fileSharedWriter != nil { + err = fileSharedWriter.Close() + } fileSharedWriter = sharedWriter + + return trace.Wrap(err) } // GetFileSharedWriter returns instance of the global file shared writer. @@ -73,8 +79,12 @@ func NewFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (*FileSha if logFile == nil { return nil, trace.BadParameter("log file is not set") } + watcher, err := fsnotify.NewWatcher() + if err != nil { + return nil, trace.Wrap(err) + } - sharedWriter := &FileSharedWriter{fileFlag: flag, fileMode: mode} + sharedWriter := &FileSharedWriter{fileFlag: flag, fileMode: mode, watcher: watcher} sharedWriter.logFile.Store(logFile) return sharedWriter, nil @@ -116,20 +126,14 @@ func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { // runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming // or removing the log file to trigger the action function when event appeared. func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() error) error { - watcher, err := fsnotify.NewWatcher() - if err != nil { - return trace.Wrap(err) + if s.watcher.WatchList() == nil { + return trace.BadParameter("watcher is already closed") } - context.AfterFunc(ctx, func() { - if err := watcher.Close(); err != nil { - slog.ErrorContext(context.Background(), "Failed to close file watcher", "error", err) - } - }) go func() { for { select { - case event, ok := <-watcher.Events: + case event, ok := <-s.watcher.Events: if !ok { return } @@ -140,7 +144,7 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err continue } } - case err, ok := <-watcher.Errors: + case err, ok := <-s.watcher.Errors: if !ok { return } @@ -150,9 +154,17 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err }() logDirParent := filepath.Dir(s.logFile.Load().Name()) - if err = watcher.Add(logDirParent); err != nil { + if err := s.watcher.Add(logDirParent); err != nil { return trace.Wrap(err) } return nil } + +// Close stops the internal watcher. +func (s *FileSharedWriter) Close() error { + s.lock.Lock() + defer s.lock.Unlock() + + return s.watcher.Close() +} diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 858694d0a684..c70e99f97dc0 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -40,13 +40,14 @@ func TestFileSharedWriterNotify(t *testing.T) { logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) require.NoError(t, err, "failed to open log file") + logWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + require.NoError(t, err, "failed to init the file shared writer") + t.Cleanup(func() { cancel() + require.NoError(t, logWriter.Close()) }) - logWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) - require.NoError(t, err, "failed to init the file shared writer") - signal := make(chan struct{}) err = logWriter.runWatcherFunc(ctx, func() error { err := logWriter.Reopen() @@ -85,3 +86,69 @@ func TestFileSharedWriterNotify(t *testing.T) { require.NoError(t, err, "cannot read log file") require.Equal(t, secondPhrase, string(data), "second written phrase does not match") } + +// TestFileSharedWriterGlobalSet verifies that logic with closing file shared writer +// after overriding it in the global variable. +func TestFileSharedWriterGlobalSet(t *testing.T) { + ctx, cancel := context.WithCancel(context.Background()) + + logDir := t.TempDir() + testFileMode := os.FileMode(0o600) + testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND + logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) + require.NoError(t, err, "failed to open log file") + + // Initiate the first file shared writer and set it as global. + var firstWatcherTriggered bool + firstLogWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + require.NoError(t, err, "failed to init the file shared writer") + + err = firstLogWriter.runWatcherFunc(ctx, func() error { + firstWatcherTriggered = true + return nil + }) + require.NoError(t, err, "failed to run reopen watcher") + + err = SetFileSharedWriter(firstLogWriter) + require.NoError(t, err, "can't set the global writer") + + // Initiate the second file shared writer and set it as global, + // previous must be closed automatically and stop reacting on events. + secondLogWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + require.NoError(t, err, "failed to init the file shared writer") + + signal := make(chan struct{}) + err = secondLogWriter.runWatcherFunc(ctx, func() error { + err := secondLogWriter.Reopen() + signal <- struct{}{} + return err + }) + require.NoError(t, err, "failed to run reopen watcher") + + err = SetFileSharedWriter(secondLogWriter) + require.NoError(t, err, "can't set the global writer") + + // Move the original file to a new location to simulate the logrotate operation. + err = os.Rename(logFile.Name(), fmt.Sprintf("%s.1", logFile.Name())) + require.NoError(t, err, "can't rename log file") + + select { + case <-time.After(5 * time.Second): + require.Fail(t, "timed out waiting for file reopen") + case <-signal: + } + + // Check that if we set new global file shared writer we close first one. + require.False(t, firstWatcherTriggered) + + // Check that we receive the error if we are going to try to run watcher + // again for closed one. + err = firstLogWriter.RunWatcherReopen(ctx) + require.Error(t, err) + + t.Cleanup(func() { + cancel() + require.NoError(t, firstLogWriter.Close()) + require.NoError(t, secondLogWriter.Close()) + }) +} From 4c762fb7d3ebef3af61cd0323ab71e243c849411 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Thu, 11 Jul 2024 10:56:17 -0400 Subject: [PATCH 10/15] make log file name static for shared writer --- lib/config/configuration.go | 6 +--- lib/utils/log/file_writer.go | 49 ++++++++++++++++++------------- lib/utils/log/file_writer_test.go | 20 ++++++------- 3 files changed, 38 insertions(+), 37 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 2544a959b5ef..5b79e8d462c8 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -793,11 +793,7 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { w = sw default: // Assume this is a file path. - logFile, err := os.OpenFile(loggerConfig.Output, logFileDefaultFlag, logFileDefaultMode) - if err != nil { - return trace.Wrap(err, "failed to create the log file") - } - sharedWriter, err := logutils.NewFileSharedWriter(logFile, logFileDefaultFlag, logFileDefaultMode) + sharedWriter, err := logutils.NewFileSharedWriter(loggerConfig.Output, logFileDefaultFlag, logFileDefaultMode) if err != nil { return trace.Wrap(err, "failed to init the log file shared writer") } diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 03b305e1697c..2afcae276ca5 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -25,7 +25,6 @@ import ( "os" "path/filepath" "sync" - "sync/atomic" "github.com/fsnotify/fsnotify" "github.com/gravitational/trace" @@ -44,15 +43,17 @@ var ( // FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. // This is to allow the File reopen required by logrotate and similar tools. type FileSharedWriter struct { - logFile atomic.Pointer[os.File] - fileFlag int - fileMode fs.FileMode - watcher *fsnotify.Watcher + logFileName string + fileFlag int + fileMode fs.FileMode + file *os.File + watcher *fsnotify.Watcher lock sync.Mutex } -// SetFileSharedWriter sets global file shared writer. +// SetFileSharedWriter sets the global file shared writer, closing the current +// one (if any). The returned error is the error from the closing operation. func SetFileSharedWriter(sharedWriter *FileSharedWriter) (err error) { mu.Lock() defer mu.Unlock() @@ -75,19 +76,26 @@ func GetFileSharedWriter() *FileSharedWriter { // NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, // with ability to enable filesystem notification watch and reopen file on specific events. -func NewFileSharedWriter(logFile *os.File, flag int, mode fs.FileMode) (*FileSharedWriter, error) { - if logFile == nil { - return nil, trace.BadParameter("log file is not set") +func NewFileSharedWriter(logFileName string, flag int, mode fs.FileMode) (*FileSharedWriter, error) { + if logFileName == "" { + return nil, trace.BadParameter("log file name is not set") + } + logFile, err := os.OpenFile(logFileName, flag, mode) + if err != nil { + return nil, trace.Wrap(err, "failed to create the log file") } watcher, err := fsnotify.NewWatcher() if err != nil { return nil, trace.Wrap(err) } - sharedWriter := &FileSharedWriter{fileFlag: flag, fileMode: mode, watcher: watcher} - sharedWriter.logFile.Store(logFile) - - return sharedWriter, nil + return &FileSharedWriter{ + logFileName: logFileName, + fileFlag: flag, + fileMode: mode, + file: logFile, + watcher: watcher, + }, nil } // Write writes len(b) bytes from b to the File. @@ -95,20 +103,19 @@ func (s *FileSharedWriter) Write(b []byte) (int, error) { s.lock.Lock() defer s.lock.Unlock() - return s.logFile.Load().Write(b) + return s.file.Write(b) } // Reopen closes the file and opens it again using APPEND mode. -func (s *FileSharedWriter) Reopen() error { +func (s *FileSharedWriter) Reopen() (err error) { s.lock.Lock() defer s.lock.Unlock() - logFile, err := os.OpenFile(s.logFile.Load().Name(), s.fileFlag, s.fileMode) - if err != nil { + if err := s.file.Close(); err != nil { return trace.Wrap(err) } - prevLogFile := s.logFile.Swap(logFile) - if err := prevLogFile.Close(); err != nil { + s.file, err = os.OpenFile(s.logFileName, s.fileFlag, s.fileMode) + if err != nil { return trace.Wrap(err) } @@ -137,7 +144,7 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err if !ok { return } - if s.logFile.Load().Name() == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { + if s.logFileName == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { slog.DebugContext(ctx, "Log file was moved/removed", "file", event.Name) if err := action(); err != nil { slog.ErrorContext(ctx, "Failed to take action", "error", err, "file", event.Name) @@ -153,7 +160,7 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err } }() - logDirParent := filepath.Dir(s.logFile.Load().Name()) + logDirParent := filepath.Dir(s.logFileName) if err := s.watcher.Add(logDirParent); err != nil { return trace.Wrap(err) } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index c70e99f97dc0..97d2f5bbcd02 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -37,10 +37,9 @@ func TestFileSharedWriterNotify(t *testing.T) { logDir := t.TempDir() testFileMode := os.FileMode(0o600) testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND - logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) - require.NoError(t, err, "failed to open log file") + logFileName := filepath.Join(logDir, "test.log") - logWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + logWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") t.Cleanup(func() { @@ -62,12 +61,12 @@ func TestFileSharedWriterNotify(t *testing.T) { require.NoError(t, err) require.Equal(t, len(firstPhrase), n, "failed to write first phrase") - data, err := os.ReadFile(logFile.Name()) + data, err := os.ReadFile(logFileName) require.NoError(t, err, "cannot read log file") require.Equal(t, firstPhrase, string(data), "first written phrase does not match") // Move the original file to a new location to simulate the logrotate operation. - err = os.Rename(logFile.Name(), fmt.Sprintf("%s.1", logFile.Name())) + err = os.Rename(logFileName, fmt.Sprintf("%s.1", logFileName)) require.NoError(t, err, "can't rename log file") select { @@ -82,7 +81,7 @@ func TestFileSharedWriterNotify(t *testing.T) { require.NoError(t, err) require.Equal(t, len(secondPhrase), n, "failed to write second phrase") - data, err = os.ReadFile(logFile.Name()) + data, err = os.ReadFile(logFileName) require.NoError(t, err, "cannot read log file") require.Equal(t, secondPhrase, string(data), "second written phrase does not match") } @@ -95,12 +94,11 @@ func TestFileSharedWriterGlobalSet(t *testing.T) { logDir := t.TempDir() testFileMode := os.FileMode(0o600) testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND - logFile, err := os.OpenFile(filepath.Join(logDir, "test.log"), testFileFlag, testFileMode) - require.NoError(t, err, "failed to open log file") + logFileName := filepath.Join(logDir, "test.log") // Initiate the first file shared writer and set it as global. var firstWatcherTriggered bool - firstLogWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + firstLogWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") err = firstLogWriter.runWatcherFunc(ctx, func() error { @@ -114,7 +112,7 @@ func TestFileSharedWriterGlobalSet(t *testing.T) { // Initiate the second file shared writer and set it as global, // previous must be closed automatically and stop reacting on events. - secondLogWriter, err := NewFileSharedWriter(logFile, testFileFlag, testFileMode) + secondLogWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") signal := make(chan struct{}) @@ -129,7 +127,7 @@ func TestFileSharedWriterGlobalSet(t *testing.T) { require.NoError(t, err, "can't set the global writer") // Move the original file to a new location to simulate the logrotate operation. - err = os.Rename(logFile.Name(), fmt.Sprintf("%s.1", logFile.Name())) + err = os.Rename(logFileName, fmt.Sprintf("%s.1", logFileName)) require.NoError(t, err, "can't rename log file") select { From d1ed93c66898060baff69dde35ec45e512d9fee5 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Tue, 16 Jul 2024 02:25:03 -0400 Subject: [PATCH 11/15] replace logic to use finalizer instead --- lib/config/configuration.go | 9 +++--- lib/service/service.go | 8 ----- lib/service/servicecfg/config.go | 5 --- lib/utils/log/file_writer.go | 54 ++++++++----------------------- lib/utils/log/file_writer_test.go | 52 ++++++++++++++++------------- lib/utils/log/writer_finalizer.go | 49 ++++++++++++++++++++++++++++ 6 files changed, 98 insertions(+), 79 deletions(-) create mode 100644 lib/utils/log/writer_finalizer.go diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 5b79e8d462c8..b21b20b2173c 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -797,11 +797,12 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { if err != nil { return trace.Wrap(err, "failed to init the log file shared writer") } - if err := logutils.SetFileSharedWriter(sharedWriter); err != nil { - return trace.Wrap(err, "failed to set the log file shared writer") + w = logutils.NewWriterFinalizer(sharedWriter) + if loggerConfig.WatchLogFile { + if err := sharedWriter.RunWatcherReopen(); err != nil { + return trace.Wrap(err) + } } - w = sharedWriter - cfg.WatchLogFile = loggerConfig.WatchLogFile } level := new(slog.LevelVar) diff --git a/lib/service/service.go b/lib/service/service.go index 6ea50d468234..23a21bf06bb4 100644 --- a/lib/service/service.go +++ b/lib/service/service.go @@ -1423,14 +1423,6 @@ func NewTeleport(cfg *servicecfg.Config) (*TeleportProcess, error) { } } - // Enable shared log file watcher if configuration is set, to react on filesystem event. - sharedWriter := logutils.GetFileSharedWriter() - if cfg.WatchLogFile && sharedWriter != nil { - if err := sharedWriter.RunWatcherReopen(process.ExitContext()); err != nil { - return nil, trace.Wrap(err) - } - } - // notify parent process that this process has started go process.notifyParent() diff --git a/lib/service/servicecfg/config.go b/lib/service/servicecfg/config.go index 1cc34bbae124..6d14bce4e5b2 100644 --- a/lib/service/servicecfg/config.go +++ b/lib/service/servicecfg/config.go @@ -230,11 +230,6 @@ type Config struct { // LoggerLevel defines the Logger log level. LoggerLevel *slog.LevelVar - // WatchLogFile is used to close and re-open the log file by - // filesystem notify to react on rename or remove event, might be used - // in log rotation. - WatchLogFile bool - // PluginRegistry allows adding enterprise logic to Teleport services PluginRegistry plugin.Registry diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 2afcae276ca5..8fe64f10054f 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -30,16 +30,6 @@ import ( "github.com/gravitational/trace" ) -var ( - // fileSharedWriter global file shared writer with the ability to reopen the log file - // in the same mode and with the same flags, either by function call or by filesystem - // notification subscription on the changes. - fileSharedWriter *FileSharedWriter - - // mu protects global setter/getter of the file shared writer. - mu sync.Mutex -) - // FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. // This is to allow the File reopen required by logrotate and similar tools. type FileSharedWriter struct { @@ -52,28 +42,6 @@ type FileSharedWriter struct { lock sync.Mutex } -// SetFileSharedWriter sets the global file shared writer, closing the current -// one (if any). The returned error is the error from the closing operation. -func SetFileSharedWriter(sharedWriter *FileSharedWriter) (err error) { - mu.Lock() - defer mu.Unlock() - - if fileSharedWriter != nil { - err = fileSharedWriter.Close() - } - fileSharedWriter = sharedWriter - - return trace.Wrap(err) -} - -// GetFileSharedWriter returns instance of the global file shared writer. -func GetFileSharedWriter() *FileSharedWriter { - mu.Lock() - defer mu.Unlock() - - return fileSharedWriter -} - // NewFileSharedWriter wraps the provided [os.File] in a writer that is thread safe, // with ability to enable filesystem notification watch and reopen file on specific events. func NewFileSharedWriter(logFileName string, flag int, mode fs.FileMode) (*FileSharedWriter, error) { @@ -123,16 +91,16 @@ func (s *FileSharedWriter) Reopen() (err error) { } // RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. -func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { +func (s *FileSharedWriter) RunWatcherReopen() error { s.lock.Lock() defer s.lock.Unlock() - return s.runWatcherFunc(ctx, s.Reopen) + return s.runWatcherFunc(s.Reopen) } // runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming // or removing the log file to trigger the action function when event appeared. -func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() error) error { +func (s *FileSharedWriter) runWatcherFunc(action func() error) error { if s.watcher.WatchList() == nil { return trace.BadParameter("watcher is already closed") } @@ -145,9 +113,9 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err return } if s.logFileName == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { - slog.DebugContext(ctx, "Log file was moved/removed", "file", event.Name) + slog.DebugContext(context.Background(), "Log file was moved/removed", "file", event.Name) if err := action(); err != nil { - slog.ErrorContext(ctx, "Failed to take action", "error", err, "file", event.Name) + slog.ErrorContext(context.Background(), "Failed to take action", "error", err, "file", event.Name) continue } } @@ -155,7 +123,7 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err if !ok { return } - slog.ErrorContext(ctx, "Error received on logger watcher", "error", err) + slog.ErrorContext(context.Background(), "Error received on logger watcher", "error", err) } } }() @@ -168,10 +136,16 @@ func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() err return nil } -// Close stops the internal watcher. +// Close stops the internal watcher and close the log file. func (s *FileSharedWriter) Close() error { s.lock.Lock() defer s.lock.Unlock() - return s.watcher.Close() + if err := s.watcher.Close(); err != nil { + return trace.Wrap(err) + } + if err := s.file.Close(); err != nil { + return trace.Wrap(err) + } + return nil } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 97d2f5bbcd02..69d4a2f11d46 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -19,10 +19,11 @@ package log import ( - "context" "fmt" + "io" "os" "path/filepath" + "runtime" "testing" "time" @@ -32,8 +33,6 @@ import ( // TestFileSharedWriterNotify checks that if we create the file with shared writer and enable // watcher functionality, we should expect the file to be reopened after renaming the original one. func TestFileSharedWriterNotify(t *testing.T) { - ctx, cancel := context.WithCancel(context.Background()) - logDir := t.TempDir() testFileMode := os.FileMode(0o600) testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND @@ -43,12 +42,11 @@ func TestFileSharedWriterNotify(t *testing.T) { require.NoError(t, err, "failed to init the file shared writer") t.Cleanup(func() { - cancel() require.NoError(t, logWriter.Close()) }) signal := make(chan struct{}) - err = logWriter.runWatcherFunc(ctx, func() error { + err = logWriter.runWatcherFunc(func() error { err := logWriter.Reopen() signal <- struct{}{} return err @@ -86,45 +84,48 @@ func TestFileSharedWriterNotify(t *testing.T) { require.Equal(t, secondPhrase, string(data), "second written phrase does not match") } -// TestFileSharedWriterGlobalSet verifies that logic with closing file shared writer -// after overriding it in the global variable. -func TestFileSharedWriterGlobalSet(t *testing.T) { - ctx, cancel := context.WithCancel(context.Background()) +// TestFileSharedWriterFinalizer verifies the logic with closing file shared writer +// after overriding it in `logger.SetOutput`. +func TestFileSharedWriterFinalizer(t *testing.T) { + // output simulates setting the file shared writer to logger. + var output io.WriteCloser logDir := t.TempDir() testFileMode := os.FileMode(0o600) testFileFlag := os.O_WRONLY | os.O_CREATE | os.O_APPEND logFileName := filepath.Join(logDir, "test.log") - // Initiate the first file shared writer and set it as global. + // Initiate the first file shared writer and set it to output. var firstWatcherTriggered bool firstLogWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") - err = firstLogWriter.runWatcherFunc(ctx, func() error { + err = firstLogWriter.runWatcherFunc(func() error { firstWatcherTriggered = true return nil }) require.NoError(t, err, "failed to run reopen watcher") - err = SetFileSharedWriter(firstLogWriter) - require.NoError(t, err, "can't set the global writer") + // Set wrapped file shared writer to fake logger output variable. + output = NewWriterFinalizer(firstLogWriter) - // Initiate the second file shared writer and set it as global, - // previous must be closed automatically and stop reacting on events. + // Initiate the second file shared writer and override it in common output, + // previous must be closed automatically by finalizer and stop reacting on events. secondLogWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") signal := make(chan struct{}) - err = secondLogWriter.runWatcherFunc(ctx, func() error { + err = secondLogWriter.runWatcherFunc(func() error { err := secondLogWriter.Reopen() signal <- struct{}{} return err }) require.NoError(t, err, "failed to run reopen watcher") - err = SetFileSharedWriter(secondLogWriter) - require.NoError(t, err, "can't set the global writer") + // Overriding second file shared writer to free resources of the first one + // and trigger finalizing logic. + output = secondLogWriter + runtime.GC() // Move the original file to a new location to simulate the logrotate operation. err = os.Rename(logFileName, fmt.Sprintf("%s.1", logFileName)) @@ -141,12 +142,19 @@ func TestFileSharedWriterGlobalSet(t *testing.T) { // Check that we receive the error if we are going to try to run watcher // again for closed one. - err = firstLogWriter.RunWatcherReopen(ctx) + err = firstLogWriter.RunWatcherReopen() + require.Error(t, err) + + // First file shared writer must be already closed and produce error after + // trying to close it second time. + err = firstLogWriter.Close() require.Error(t, err) + // Write must not fail after override. + _, err = output.Write([]byte("test")) + require.NoError(t, err) + t.Cleanup(func() { - cancel() - require.NoError(t, firstLogWriter.Close()) - require.NoError(t, secondLogWriter.Close()) + require.NoError(t, output.Close()) }) } diff --git a/lib/utils/log/writer_finalizer.go b/lib/utils/log/writer_finalizer.go new file mode 100644 index 000000000000..31ac39ed8737 --- /dev/null +++ b/lib/utils/log/writer_finalizer.go @@ -0,0 +1,49 @@ +/* + * Teleport + * Copyright (C) 2024 Gravitational, Inc. + * + * This program is free software: you can redistribute it and/or modify + * it under the terms of the GNU Affero General Public License as published by + * the Free Software Foundation, either version 3 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU Affero General Public License for more details. + * + * You should have received a copy of the GNU Affero General Public License + * along with this program. If not, see . + */ + +package log + +import ( + "io" + "runtime" +) + +// WriterFinalizer is a wrapper for the [io.WriteCloser] to automate resource cleanup. +type WriterFinalizer struct { + writer io.WriteCloser +} + +// NewWriterFinalizer wraps the provided writer [io.WriteCloser] to trigger Close function +// after writer is unassigned from any variable. +func NewWriterFinalizer(writer io.WriteCloser) *WriterFinalizer { + wr := &WriterFinalizer{ + writer: writer, + } + runtime.SetFinalizer(wr, (*WriterFinalizer).Close) + return wr +} + +// Write writes len(b) bytes from b to the writer. +func (w *WriterFinalizer) Write(b []byte) (int, error) { + return w.writer.Write(b) +} + +// Close wraps closing function of internal writer. +func (w *WriterFinalizer) Close() error { + return w.writer.Close() +} From babf127a6a8c0c36130da5d05ce07c18de4aa064 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Tue, 16 Jul 2024 12:45:51 -0400 Subject: [PATCH 12/15] fix possible locking write while reopen is triggered --- lib/config/configuration.go | 2 +- lib/utils/log/file_writer.go | 49 +++++++++++++++++++------------ lib/utils/log/file_writer_test.go | 6 ++-- lib/utils/log/writer_finalizer.go | 14 ++++----- 4 files changed, 42 insertions(+), 29 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index b21b20b2173c..08ede9a12946 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -797,7 +797,7 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { if err != nil { return trace.Wrap(err, "failed to init the log file shared writer") } - w = logutils.NewWriterFinalizer(sharedWriter) + w = logutils.NewWriterFinalizer[*logutils.FileSharedWriter](sharedWriter) if loggerConfig.WatchLogFile { if err := sharedWriter.RunWatcherReopen(); err != nil { return trace.Wrap(err) diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 8fe64f10054f..52ce61570942 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -20,6 +20,7 @@ package log import ( "context" + "errors" "io/fs" "log/slog" "os" @@ -30,6 +31,11 @@ import ( "github.com/gravitational/trace" ) +var ( + // ErrFileSharedWriterClosed is returned when file shared writer is already closed. + ErrFileSharedWriterClosed = errors.New("file shared writer is closed") +) + // FileSharedWriter is similar to SharedWriter except that it requires a `os.File` instead of a `io.Writer`. // This is to allow the File reopen required by logrotate and similar tools. type FileSharedWriter struct { @@ -38,6 +44,7 @@ type FileSharedWriter struct { fileMode fs.FileMode file *os.File watcher *fsnotify.Watcher + closed bool lock sync.Mutex } @@ -70,30 +77,39 @@ func NewFileSharedWriter(logFileName string, flag int, mode fs.FileMode) (*FileS func (s *FileSharedWriter) Write(b []byte) (int, error) { s.lock.Lock() defer s.lock.Unlock() + if s.closed { + return 0, ErrFileSharedWriterClosed + } return s.file.Write(b) } // Reopen closes the file and opens it again using APPEND mode. -func (s *FileSharedWriter) Reopen() (err error) { - s.lock.Lock() - defer s.lock.Unlock() - - if err := s.file.Close(); err != nil { - return trace.Wrap(err) - } - s.file, err = os.OpenFile(s.logFileName, s.fileFlag, s.fileMode) +func (s *FileSharedWriter) Reopen() error { + // If opening the file is locked we should not acquire a lock and blocking write. + file, err := os.OpenFile(s.logFileName, s.fileFlag, s.fileMode) if err != nil { return trace.Wrap(err) } - return nil + s.lock.Lock() + if s.closed { + return trace.NewAggregate(ErrFileSharedWriterClosed, file.Close()) + } + oldLogFile := s.file + s.file = file + s.lock.Unlock() + + return trace.Wrap(oldLogFile.Close()) } // RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. func (s *FileSharedWriter) RunWatcherReopen() error { s.lock.Lock() defer s.lock.Unlock() + if s.closed { + return ErrFileSharedWriterClosed + } return s.runWatcherFunc(s.Reopen) } @@ -101,10 +117,6 @@ func (s *FileSharedWriter) RunWatcherReopen() error { // runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming // or removing the log file to trigger the action function when event appeared. func (s *FileSharedWriter) runWatcherFunc(action func() error) error { - if s.watcher.WatchList() == nil { - return trace.BadParameter("watcher is already closed") - } - go func() { for { select { @@ -141,11 +153,10 @@ func (s *FileSharedWriter) Close() error { s.lock.Lock() defer s.lock.Unlock() - if err := s.watcher.Close(); err != nil { - return trace.Wrap(err) - } - if err := s.file.Close(); err != nil { - return trace.Wrap(err) + if s.closed { + return ErrFileSharedWriterClosed } - return nil + s.closed = true + + return trace.NewAggregate(s.watcher.Close(), s.file.Close()) } diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index 69d4a2f11d46..dbc452766502 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -108,6 +108,8 @@ func TestFileSharedWriterFinalizer(t *testing.T) { // Set wrapped file shared writer to fake logger output variable. output = NewWriterFinalizer(firstLogWriter) + _, err = output.Write([]byte("test")) + require.NoError(t, err) // Initiate the second file shared writer and override it in common output, // previous must be closed automatically by finalizer and stop reacting on events. @@ -143,12 +145,12 @@ func TestFileSharedWriterFinalizer(t *testing.T) { // Check that we receive the error if we are going to try to run watcher // again for closed one. err = firstLogWriter.RunWatcherReopen() - require.Error(t, err) + require.ErrorIs(t, err, ErrFileSharedWriterClosed) // First file shared writer must be already closed and produce error after // trying to close it second time. err = firstLogWriter.Close() - require.Error(t, err) + require.ErrorIs(t, err, ErrFileSharedWriterClosed) // Write must not fail after override. _, err = output.Write([]byte("test")) diff --git a/lib/utils/log/writer_finalizer.go b/lib/utils/log/writer_finalizer.go index 31ac39ed8737..b90de0e8e3fd 100644 --- a/lib/utils/log/writer_finalizer.go +++ b/lib/utils/log/writer_finalizer.go @@ -24,26 +24,26 @@ import ( ) // WriterFinalizer is a wrapper for the [io.WriteCloser] to automate resource cleanup. -type WriterFinalizer struct { - writer io.WriteCloser +type WriterFinalizer[T io.WriteCloser] struct { + writer T } // NewWriterFinalizer wraps the provided writer [io.WriteCloser] to trigger Close function // after writer is unassigned from any variable. -func NewWriterFinalizer(writer io.WriteCloser) *WriterFinalizer { - wr := &WriterFinalizer{ +func NewWriterFinalizer[T io.WriteCloser](writer T) *WriterFinalizer[T] { + wr := &WriterFinalizer[T]{ writer: writer, } - runtime.SetFinalizer(wr, (*WriterFinalizer).Close) + runtime.SetFinalizer(wr, (*WriterFinalizer[T]).Close) return wr } // Write writes len(b) bytes from b to the writer. -func (w *WriterFinalizer) Write(b []byte) (int, error) { +func (w *WriterFinalizer[T]) Write(b []byte) (int, error) { return w.writer.Write(b) } // Close wraps closing function of internal writer. -func (w *WriterFinalizer) Close() error { +func (w *WriterFinalizer[T]) Close() error { return w.writer.Close() } From 580c8019f50af575e6e6ee2b4131bb5a9283c409 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Thu, 18 Jul 2024 14:59:25 -0400 Subject: [PATCH 13/15] wrap internal error, fix incorrect unlock --- lib/utils/log/file_writer.go | 14 ++++++++------ 1 file changed, 8 insertions(+), 6 deletions(-) diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index 52ce61570942..eec817723b0e 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -57,7 +57,7 @@ func NewFileSharedWriter(logFileName string, flag int, mode fs.FileMode) (*FileS } logFile, err := os.OpenFile(logFileName, flag, mode) if err != nil { - return nil, trace.Wrap(err, "failed to create the log file") + return nil, trace.ConvertSystemError(err) } watcher, err := fsnotify.NewWatcher() if err != nil { @@ -86,7 +86,7 @@ func (s *FileSharedWriter) Write(b []byte) (int, error) { // Reopen closes the file and opens it again using APPEND mode. func (s *FileSharedWriter) Reopen() error { - // If opening the file is locked we should not acquire a lock and blocking write. + // If opening the file is locked we should not acquire a lock and block write. file, err := os.OpenFile(s.logFileName, s.fileFlag, s.fileMode) if err != nil { return trace.Wrap(err) @@ -94,7 +94,9 @@ func (s *FileSharedWriter) Reopen() error { s.lock.Lock() if s.closed { - return trace.NewAggregate(ErrFileSharedWriterClosed, file.Close()) + s.lock.Unlock() + _ = file.Close() + return trace.Wrap(ErrFileSharedWriterClosed) } oldLogFile := s.file s.file = file @@ -108,7 +110,7 @@ func (s *FileSharedWriter) RunWatcherReopen() error { s.lock.Lock() defer s.lock.Unlock() if s.closed { - return ErrFileSharedWriterClosed + return trace.Wrap(ErrFileSharedWriterClosed) } return s.runWatcherFunc(s.Reopen) @@ -127,7 +129,7 @@ func (s *FileSharedWriter) runWatcherFunc(action func() error) error { if s.logFileName == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { slog.DebugContext(context.Background(), "Log file was moved/removed", "file", event.Name) if err := action(); err != nil { - slog.ErrorContext(context.Background(), "Failed to take action", "error", err, "file", event.Name) + slog.ErrorContext(context.Background(), "Failed to reopen file", "error", err, "file", event.Name) continue } } @@ -154,7 +156,7 @@ func (s *FileSharedWriter) Close() error { defer s.lock.Unlock() if s.closed { - return ErrFileSharedWriterClosed + return trace.Wrap(ErrFileSharedWriterClosed) } s.closed = true From a303a8b0da2d1943179d0b66bf73d1de8f379784 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Thu, 18 Jul 2024 17:05:05 -0400 Subject: [PATCH 14/15] drop configuration flag, make watcher always enabled --- .../helm-reference/teleport-cluster.mdx | 19 +------------------ .../teleport-cluster/.lint/log-extra.yaml | 1 - .../templates/auth/_config.common.tpl | 3 --- .../templates/proxy/_config.common.tpl | 3 --- .../__snapshot__/auth_config_test.yaml.snap | 1 - .../__snapshot__/proxy_config_test.yaml.snap | 1 - .../teleport-kube-agent/.lint/log-extra.yaml | 1 - .../teleport-kube-agent/templates/_config.tpl | 3 --- .../tests/__snapshot__/config_test.yaml.snap | 2 -- lib/config/configuration.go | 6 ++---- lib/config/fileconf.go | 3 --- 11 files changed, 3 insertions(+), 40 deletions(-) diff --git a/docs/pages/reference/helm-reference/teleport-cluster.mdx b/docs/pages/reference/helm-reference/teleport-cluster.mdx index 783dc51e4046..ee071e5a8aaf 100644 --- a/docs/pages/reference/helm-reference/teleport-cluster.mdx +++ b/docs/pages/reference/helm-reference/teleport-cluster.mdx @@ -705,7 +705,7 @@ It is recommended to set resource requests/limits for each container based on th |----------|--------------------------------------------------| | `string` | `cluster.local` | -`global.clusterDomain` sets the the domain suffix used by the Kubernetes DNS service. +`global.clusterDomain` sets the the domain suffix used by the Kubernetes DNS service. This is used to resolve service names in the cluster. `values.yaml` example: @@ -1527,23 +1527,6 @@ See the [Teleport config file reference](../../reference/config.mdx) for more de extraFields: ["timestamp", "level"] ``` -### `log.watch_log_file` - -| Type | Default value | `teleport.yaml` equivalent | -|--------|---------------|-------------------------------| -| `bool` | `false` | `teleport.log.watch_log_file` | - -`log.watch_log_file` enables/disables the file shared logger's watching functionality to reopen the log file -if it is renamed or removed. Must be used in conjunction with the output set as a file path. - -`values.yaml` example: - - ```yaml - log: - output: /var/log/teleport.log - watch_log_file: true - ``` - ## `nodeSelector` | Type | Default value | diff --git a/examples/chart/teleport-cluster/.lint/log-extra.yaml b/examples/chart/teleport-cluster/.lint/log-extra.yaml index d2d43acae7ac..7f3e21bb340a 100644 --- a/examples/chart/teleport-cluster/.lint/log-extra.yaml +++ b/examples/chart/teleport-cluster/.lint/log-extra.yaml @@ -3,5 +3,4 @@ log: format: json level: DEBUG output: /var/lib/teleport/test.log - watch_log_file: true extraFields: ["level", "timestamp", "component", "caller"] diff --git a/examples/chart/teleport-cluster/templates/auth/_config.common.tpl b/examples/chart/teleport-cluster/templates/auth/_config.common.tpl index 4019aa21cf2f..cc506255f2ff 100644 --- a/examples/chart/teleport-cluster/templates/auth/_config.common.tpl +++ b/examples/chart/teleport-cluster/templates/auth/_config.common.tpl @@ -62,9 +62,6 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} - {{- if .Values.log.watch_log_file }} - watch_log_file: {{ .Values.log.watch_log_file }} - {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl b/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl index b5bca9059f67..32dd85c5476b 100644 --- a/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl +++ b/examples/chart/teleport-cluster/templates/proxy/_config.common.tpl @@ -9,9 +9,6 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} - {{- if .Values.log.watch_log_file }} - watch_log_file: {{ .Values.log.watch_log_file }} - {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap index 0d83e9e3db73..bff9e2a397a7 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/auth_config_test.yaml.snap @@ -1283,7 +1283,6 @@ matches snapshot for log-extra.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG - watch_log_file: true version: v3 matches snapshot for log-legacy.yaml: 1: | diff --git a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap index bccd4c8f7656..32830dc1a9d4 100644 --- a/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap +++ b/examples/chart/teleport-cluster/tests/__snapshot__/proxy_config_test.yaml.snap @@ -362,7 +362,6 @@ matches snapshot for log-extra.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG - watch_log_file: true version: v3 matches snapshot for proxy-listener-mode-multiplex.yaml: 1: | diff --git a/examples/chart/teleport-kube-agent/.lint/log-extra.yaml b/examples/chart/teleport-kube-agent/.lint/log-extra.yaml index 61a7d494ad2a..656190d461bf 100644 --- a/examples/chart/teleport-kube-agent/.lint/log-extra.yaml +++ b/examples/chart/teleport-kube-agent/.lint/log-extra.yaml @@ -5,5 +5,4 @@ log: format: json level: DEBUG output: /var/lib/teleport/test.log - watch_log_file: true extraFields: ["level", "timestamp", "component", "caller"] diff --git a/examples/chart/teleport-kube-agent/templates/_config.tpl b/examples/chart/teleport-kube-agent/templates/_config.tpl index f44171685f55..adb708ddfa4b 100644 --- a/examples/chart/teleport-kube-agent/templates/_config.tpl +++ b/examples/chart/teleport-kube-agent/templates/_config.tpl @@ -21,9 +21,6 @@ teleport: log: severity: {{ $logLevel }} output: {{ .Values.log.output }} - {{- if .Values.log.watch_log_file }} - watch_log_file: {{ .Values.log.watch_log_file }} - {{- end }} format: output: {{ .Values.log.format }} extra_fields: {{ .Values.log.extraFields | toJson }} diff --git a/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap b/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap index 885501e7c457..ad817a9498ce 100644 --- a/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap +++ b/examples/chart/teleport-kube-agent/tests/__snapshot__/config_test.yaml.snap @@ -1062,7 +1062,6 @@ matches snapshot for log-extra.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG - watch_log_file: true proxy_server: proxy.example.com:3080 version: v3 kind: ConfigMap @@ -1189,7 +1188,6 @@ matches snapshot for pdb.yaml: output: json output: /var/lib/teleport/test.log severity: DEBUG - watch_log_file: true proxy_server: proxy.example.com:3080 version: v3 kind: ConfigMap diff --git a/lib/config/configuration.go b/lib/config/configuration.go index 08ede9a12946..d4d1f78a4992 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -798,10 +798,8 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { return trace.Wrap(err, "failed to init the log file shared writer") } w = logutils.NewWriterFinalizer[*logutils.FileSharedWriter](sharedWriter) - if loggerConfig.WatchLogFile { - if err := sharedWriter.RunWatcherReopen(); err != nil { - return trace.Wrap(err) - } + if err := sharedWriter.RunWatcherReopen(); err != nil { + return trace.Wrap(err) } } diff --git a/lib/config/fileconf.go b/lib/config/fileconf.go index 7cc8e0176271..72f1b0869877 100644 --- a/lib/config/fileconf.go +++ b/lib/config/fileconf.go @@ -539,9 +539,6 @@ type Log struct { Severity string `yaml:"severity,omitempty"` // Format defines the logs output format and extra fields Format LogFormat `yaml:"format,omitempty"` - // WatchLogFile is used to close and re-open the log file by filesystem notification - // to react on rename or remove event, might be used in log rotation. - WatchLogFile bool `yaml:"watch_log_file,omitempty"` } // LogFormat specifies the logs output format and extra fields From 10042fafa5bea8626126e39db85ca649c62bd4a5 Mon Sep 17 00:00:00 2001 From: Vadym Popov Date: Thu, 18 Jul 2024 17:16:14 -0400 Subject: [PATCH 15/15] tune context passing --- lib/config/configuration.go | 3 ++- lib/utils/log/file_writer.go | 12 ++++++------ lib/utils/log/file_writer_test.go | 9 +++++---- 3 files changed, 13 insertions(+), 11 deletions(-) diff --git a/lib/config/configuration.go b/lib/config/configuration.go index d4d1f78a4992..03ecfe708734 100644 --- a/lib/config/configuration.go +++ b/lib/config/configuration.go @@ -23,6 +23,7 @@ package config import ( + "context" "crypto/x509" "errors" "io" @@ -798,7 +799,7 @@ func applyLogConfig(loggerConfig Log, cfg *servicecfg.Config) error { return trace.Wrap(err, "failed to init the log file shared writer") } w = logutils.NewWriterFinalizer[*logutils.FileSharedWriter](sharedWriter) - if err := sharedWriter.RunWatcherReopen(); err != nil { + if err := sharedWriter.RunWatcherReopen(context.Background()); err != nil { return trace.Wrap(err) } } diff --git a/lib/utils/log/file_writer.go b/lib/utils/log/file_writer.go index eec817723b0e..207ada327052 100644 --- a/lib/utils/log/file_writer.go +++ b/lib/utils/log/file_writer.go @@ -106,19 +106,19 @@ func (s *FileSharedWriter) Reopen() error { } // RunWatcherReopen runs a filesystem watcher for rename/remove events to reopen the log. -func (s *FileSharedWriter) RunWatcherReopen() error { +func (s *FileSharedWriter) RunWatcherReopen(ctx context.Context) error { s.lock.Lock() defer s.lock.Unlock() if s.closed { return trace.Wrap(ErrFileSharedWriterClosed) } - return s.runWatcherFunc(s.Reopen) + return s.runWatcherFunc(ctx, s.Reopen) } // runWatcherFunc spawns goroutine with the watcher loop to consume events of renaming // or removing the log file to trigger the action function when event appeared. -func (s *FileSharedWriter) runWatcherFunc(action func() error) error { +func (s *FileSharedWriter) runWatcherFunc(ctx context.Context, action func() error) error { go func() { for { select { @@ -127,9 +127,9 @@ func (s *FileSharedWriter) runWatcherFunc(action func() error) error { return } if s.logFileName == event.Name && (event.Has(fsnotify.Rename) || event.Has(fsnotify.Remove)) { - slog.DebugContext(context.Background(), "Log file was moved/removed", "file", event.Name) + slog.DebugContext(ctx, "Log file was moved/removed", "file", event.Name) if err := action(); err != nil { - slog.ErrorContext(context.Background(), "Failed to reopen file", "error", err, "file", event.Name) + slog.ErrorContext(ctx, "Failed to reopen file", "error", err, "file", event.Name) continue } } @@ -137,7 +137,7 @@ func (s *FileSharedWriter) runWatcherFunc(action func() error) error { if !ok { return } - slog.ErrorContext(context.Background(), "Error received on logger watcher", "error", err) + slog.ErrorContext(ctx, "Error received on logger watcher", "error", err) } } }() diff --git a/lib/utils/log/file_writer_test.go b/lib/utils/log/file_writer_test.go index dbc452766502..053b52a6d09c 100644 --- a/lib/utils/log/file_writer_test.go +++ b/lib/utils/log/file_writer_test.go @@ -19,6 +19,7 @@ package log import ( + "context" "fmt" "io" "os" @@ -46,7 +47,7 @@ func TestFileSharedWriterNotify(t *testing.T) { }) signal := make(chan struct{}) - err = logWriter.runWatcherFunc(func() error { + err = logWriter.runWatcherFunc(context.Background(), func() error { err := logWriter.Reopen() signal <- struct{}{} return err @@ -100,7 +101,7 @@ func TestFileSharedWriterFinalizer(t *testing.T) { firstLogWriter, err := NewFileSharedWriter(logFileName, testFileFlag, testFileMode) require.NoError(t, err, "failed to init the file shared writer") - err = firstLogWriter.runWatcherFunc(func() error { + err = firstLogWriter.runWatcherFunc(context.Background(), func() error { firstWatcherTriggered = true return nil }) @@ -117,7 +118,7 @@ func TestFileSharedWriterFinalizer(t *testing.T) { require.NoError(t, err, "failed to init the file shared writer") signal := make(chan struct{}) - err = secondLogWriter.runWatcherFunc(func() error { + err = secondLogWriter.runWatcherFunc(context.Background(), func() error { err := secondLogWriter.Reopen() signal <- struct{}{} return err @@ -144,7 +145,7 @@ func TestFileSharedWriterFinalizer(t *testing.T) { // Check that we receive the error if we are going to try to run watcher // again for closed one. - err = firstLogWriter.RunWatcherReopen() + err = firstLogWriter.RunWatcherReopen(context.Background()) require.ErrorIs(t, err, ErrFileSharedWriterClosed) // First file shared writer must be already closed and produce error after