Merge pull request #644 from nats-io/fix-reload-open-files

[FIXED] Close old log files when reloading (log rotation)

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,27 @@ 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 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
 func pidPrefix() string {
 	return fmt.Sprintf("[%d] ", os.Getpid())

server/configs/reload/file_rotate.conf

@@ -0,0 +1,4 @@
+# Copyright 2018 Authors
+listen:   localhost:-1
+logfile: "log.txt"
+pid_file: "gnatsd.pid"

server/configs/reload/file_rotate1.conf

@@ -0,0 +1,4 @@
+# Copyright 2018 Authors
+listen:   localhost:-1
+logfile: "log1.txt"
+pid_file: "gnatsd1.pid"

server/log.go

@@ -3,10 +3,11 @@
 package server
 
 import (
+	"io"
 	"os"
 	"sync/atomic"
 
-	"github.com/nats-io/gnatsd/logger"
+	srvlog "github.com/nats-io/gnatsd/logger"
 )
 
 // Logger interface of the NATS Server
@@ -45,11 +46,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 +59,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 +77,17 @@ func (s *Server) SetLogger(logger Logger, debugFlag, traceFlag bool) {
 	} else {
 		atomic.StoreInt32(&s.logging.trace, 0)
 	}
-
 	s.logging.Lock()
+	if s.logging.logger != nil {
+		// 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.Errorf("Error closing logger: %v", err)
+			}
+		}
+	}
 	s.logging.logger = logger
 	s.logging.Unlock()
 }
@@ -102,7 +112,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")

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