From 182be3feb9339afd76aecd109192de1c85c5b357 Mon Sep 17 00:00:00 2001 From: Colin Sullivan Date: Tue, 13 Mar 2018 15:31:45 -0600 Subject: [PATCH 1/5] Close files on reload. --- logger/log.go | 18 ++++++++++++++--- server/log.go | 21 ++++++++++++------- server/reload_test.go | 47 +++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 76 insertions(+), 10 deletions(-) diff --git a/logger/log.go b/logger/log.go index 485ae12e..260c1404 100644 --- a/logger/log.go +++ b/logger/log.go @@ -19,6 +19,7 @@ type Logger struct { fatalLabel string debugLabel string traceLabel string + logFile *os.File // file pointer for the file logger. } // NewStdLogger creates a logger with output directed to Stderr @@ -67,15 +68,26 @@ func NewFileLogger(filename string, time, debug, trace, pid bool) *Logger { } l := &Logger{ - logger: log.New(f, pre, flags), - debug: debug, - trace: trace, + logger: log.New(f, pre, flags), + debug: debug, + trace: trace, + logFile: f, } setPlainLabelFormats(l) return l } +// Close cleans up any resources with the server's logger implementation. +func (l *Logger) Close() { + if l.logFile != nil { + if err := l.logFile.Close(); err != nil { + l.Noticef("couldn't close log file on restart: %v", err) + } + l.logFile = nil + } +} + // Generate the pid prefix string func pidPrefix() string { return fmt.Sprintf("[%d] ", os.Getpid()) diff --git a/server/log.go b/server/log.go index 16ea0698..f6fb8564 100644 --- a/server/log.go +++ b/server/log.go @@ -6,7 +6,7 @@ import ( "os" "sync/atomic" - "github.com/nats-io/gnatsd/logger" + srvlog "github.com/nats-io/gnatsd/logger" ) // Logger interface of the NATS Server @@ -45,11 +45,11 @@ func (s *Server) ConfigureLogger() { } if opts.LogFile != "" { - log = logger.NewFileLogger(opts.LogFile, opts.Logtime, opts.Debug, opts.Trace, true) + log = srvlog.NewFileLogger(opts.LogFile, opts.Logtime, opts.Debug, opts.Trace, true) } else if opts.RemoteSyslog != "" { - log = logger.NewRemoteSysLogger(opts.RemoteSyslog, opts.Debug, opts.Trace) + log = srvlog.NewRemoteSysLogger(opts.RemoteSyslog, opts.Debug, opts.Trace) } else if syslog { - log = logger.NewSysLogger(opts.Debug, opts.Trace) + log = srvlog.NewSysLogger(opts.Debug, opts.Trace) } else { colors := true // Check to see if stderr is being redirected and if so turn off color @@ -58,7 +58,7 @@ func (s *Server) ConfigureLogger() { if err != nil || (stat.Mode()&os.ModeCharDevice) == 0 { colors = false } - log = logger.NewStdLogger(opts.Logtime, opts.Debug, opts.Trace, colors, true) + log = srvlog.NewStdLogger(opts.Logtime, opts.Debug, opts.Trace, colors, true) } s.SetLogger(log, opts.Debug, opts.Trace) @@ -76,8 +76,15 @@ func (s *Server) SetLogger(logger Logger, debugFlag, traceFlag bool) { } else { atomic.StoreInt32(&s.logging.trace, 0) } - s.logging.Lock() + if s.logging.logger != nil { + // if we are the server's logger, call its Close function, but check + // the type because this could be a logger from another process + // embedding the NATS server, a SysLogger, or a dummy test logger. + if l, ok := s.logging.logger.(*srvlog.Logger); ok { + l.Close() + } + } s.logging.logger = logger s.logging.Unlock() } @@ -102,7 +109,7 @@ func (s *Server) ReOpenLogFile() { if opts.LogFile == "" { s.Noticef("File log re-open ignored, not a file logger") } else { - fileLog := logger.NewFileLogger(opts.LogFile, + fileLog := srvlog.NewFileLogger(opts.LogFile, opts.Logtime, opts.Debug, opts.Trace, true) s.SetLogger(fileLog, opts.Debug, opts.Trace) s.Noticef("File log re-opened") diff --git a/server/reload_test.go b/server/reload_test.go index 92d397cc..09faa0dd 100644 --- a/server/reload_test.go +++ b/server/reload_test.go @@ -1706,6 +1706,53 @@ func TestConfigReloadMaxPayload(t *testing.T) { } } +// Ensure reload supports rotating out files. Test this by starting +// a server with log and pid files, reloading new ones, then check that +// we can rename and delete the old log/pid files. +func TestConfigReloadRotateFiles(t *testing.T) { + opts, config := newOptionsWithSymlinkConfig(t, "tmp.conf", "./configs/reload/file_rotate.conf") + server := RunServer(opts) + defer func() { + os.Remove(config) + os.Remove("log1.txt") + os.Remove("gnatsd1.pid") + }() + defer server.Shutdown() + + // Configure the logger to enable actual logging + server.ConfigureLogger() + + // Load a config that renames the files. + createSymlink(t, config, "./configs/reload/file_rotate1.conf") + if err := server.Reload(); err != nil { + t.Fatalf("Error reloading config: %v", err) + } + + // Make sure the new files exist. + if _, err := os.Stat("log1.txt"); os.IsNotExist(err) { + t.Fatalf("Error reloading config, no new file: %v", err) + } + if _, err := os.Stat("gnatsd1.pid"); os.IsNotExist(err) { + t.Fatalf("Error reloading config, no new file: %v", err) + } + + // Check that old file can be renamed. + if err := os.Rename("log.txt", "log_old.txt"); err != nil { + t.Fatalf("Error reloading config, cannot rename file: %v", err) + } + if err := os.Rename("gnatsd.pid", "gnatsd_old.pid"); err != nil { + t.Fatalf("Error reloading config, cannot rename file: %v", err) + } + + // Check that the old files can be removed after rename. + if err := os.Remove("log_old.txt"); err != nil { + t.Fatalf("Error reloading config, cannot delete file: %v", err) + } + if err := os.Remove("gnatsd_old.pid"); err != nil { + t.Fatalf("Error reloading config, cannot delete file: %v", err) + } +} + func runServerWithSymlinkConfig(t *testing.T, symlinkName, configName string) (*Server, *Options, string) { opts, config := newOptionsWithSymlinkConfig(t, symlinkName, configName) opts.NoLog = true From f7368bf90368f43421f09d2a8d231d2cb209b083 Mon Sep 17 00:00:00 2001 From: Colin Sullivan Date: Tue, 13 Mar 2018 15:38:52 -0600 Subject: [PATCH 2/5] Add config files --- server/configs/reload/file_rotate.conf | 4 ++++ server/configs/reload/file_rotate1.conf | 4 ++++ 2 files changed, 8 insertions(+) create mode 100644 server/configs/reload/file_rotate.conf create mode 100644 server/configs/reload/file_rotate1.conf diff --git a/server/configs/reload/file_rotate.conf b/server/configs/reload/file_rotate.conf new file mode 100644 index 00000000..15b88da9 --- /dev/null +++ b/server/configs/reload/file_rotate.conf @@ -0,0 +1,4 @@ +# Copyright 2018 Authors +listen: localhost:-1 +logfile: "log.txt" +pid_file: "gnatsd.pid" diff --git a/server/configs/reload/file_rotate1.conf b/server/configs/reload/file_rotate1.conf new file mode 100644 index 00000000..9dee0437 --- /dev/null +++ b/server/configs/reload/file_rotate1.conf @@ -0,0 +1,4 @@ +# Copyright 2018 Authors +listen: localhost:-1 +logfile: "log1.txt" +pid_file: "gnatsd1.pid" From 508ce2bcf32875c74f2d2304efcb34665a2632d0 Mon Sep 17 00:00:00 2001 From: Colin Sullivan Date: Tue, 13 Mar 2018 19:08:45 -0600 Subject: [PATCH 3/5] implement io.Closer interface in the logger --- logger/log.go | 13 +++++++------ server/log.go | 13 ++++++++----- 2 files changed, 15 insertions(+), 11 deletions(-) diff --git a/logger/log.go b/logger/log.go index 260c1404..2a8b737f 100644 --- a/logger/log.go +++ b/logger/log.go @@ -78,14 +78,15 @@ func NewFileLogger(filename string, time, debug, trace, pid bool) *Logger { return l } -// Close cleans up any resources with the server's logger implementation. -func (l *Logger) Close() { - if l.logFile != nil { - if err := l.logFile.Close(); err != nil { - l.Noticef("couldn't close log file on restart: %v", err) - } +// Close implements the io.Closer interface to clean up +// resources in the server's logger implementation. +// Caller must ensure threadsafety. +func (l *Logger) Close() error { + if f := l.logFile; f != nil { l.logFile = nil + return f.Close() } + return nil } // Generate the pid prefix string diff --git a/server/log.go b/server/log.go index f6fb8564..5b816b04 100644 --- a/server/log.go +++ b/server/log.go @@ -3,6 +3,7 @@ package server import ( + "io" "os" "sync/atomic" @@ -78,11 +79,13 @@ func (s *Server) SetLogger(logger Logger, debugFlag, traceFlag bool) { } s.logging.Lock() if s.logging.logger != nil { - // if we are the server's logger, call its Close function, but check - // the type because this could be a logger from another process - // embedding the NATS server, a SysLogger, or a dummy test logger. - if l, ok := s.logging.logger.(*srvlog.Logger); ok { - l.Close() + // Check to see if the logger implements io.Closer. This could be a + // logger from another process embedding the NATS server or a dummy + // test logger that may not implement that interface. + if l, ok := s.logging.logger.(io.Closer); ok { + if err := l.Close(); err != nil { + s.Noticef("error closing logger: %v", err) + } } } s.logging.logger = logger From bc59ad6ba7d8ac33d20d8d08d2b3f9dd169e2abe Mon Sep 17 00:00:00 2001 From: Colin Sullivan Date: Tue, 13 Mar 2018 19:12:41 -0600 Subject: [PATCH 4/5] Fix capitalization in log statement --- server/log.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/log.go b/server/log.go index 5b816b04..b4c63abd 100644 --- a/server/log.go +++ b/server/log.go @@ -84,7 +84,7 @@ func (s *Server) SetLogger(logger Logger, debugFlag, traceFlag bool) { // test logger that may not implement that interface. if l, ok := s.logging.logger.(io.Closer); ok { if err := l.Close(); err != nil { - s.Noticef("error closing logger: %v", err) + s.Noticef("Error closing logger: %v", err) } } } From 920cdddfc86771f365ba689dfaa8bd3942a9043f Mon Sep 17 00:00:00 2001 From: Colin Sullivan Date: Wed, 14 Mar 2018 10:25:17 -0600 Subject: [PATCH 5/5] Change log level to error --- server/log.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/log.go b/server/log.go index b4c63abd..6e8ed8ef 100644 --- a/server/log.go +++ b/server/log.go @@ -84,7 +84,7 @@ func (s *Server) SetLogger(logger Logger, debugFlag, traceFlag bool) { // test logger that may not implement that interface. if l, ok := s.logging.logger.(io.Closer); ok { if err := l.Close(); err != nil { - s.Noticef("Error closing logger: %v", err) + s.Errorf("Error closing logger: %v", err) } } }