diff --git a/logger/logger.go b/logger/logger.go index a3abbc61..8decb94d 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -1,4 +1,4 @@ -// Copyright 2017-2019 The NATS Authors +// Copyright 2017-2020 The NATS Authors // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at @@ -32,11 +32,14 @@ type Logger natsd.Logger // the Logger interface. type StanLogger struct { mu sync.RWMutex + ns *natsd.Server debug bool trace bool ltime bool lfile string fszl int64 + ndbg bool + ntrc bool log natsd.Logger } @@ -46,6 +49,7 @@ func NewStanLogger() *StanLogger { } // SetLogger sets the logger, debug and trace +// DEPRECATED: Use SetLoggerWithOpts instead. func (s *StanLogger) SetLogger(log Logger, logtime, debug, trace bool, logfile string) { s.mu.Lock() s.log = log @@ -57,12 +61,37 @@ func (s *StanLogger) SetLogger(log Logger, logtime, debug, trace bool, logfile s } // SetFileSizeLimit sets the size limit for a logfile +// DEPRECATED: Use SetLoggerWithOpts instead. func (s *StanLogger) SetFileSizeLimit(limit int64) { s.mu.Lock() s.fszl = limit s.mu.Unlock() } +// SetLoggerWithOpts sets the logger and various options. +// Note that `debug` and `trace` here are for STAN. +func (s *StanLogger) SetLoggerWithOpts(log Logger, nOpts *natsd.Options, debug, trace bool) { + s.mu.Lock() + s.log = log + s.ltime = nOpts.Logtime + s.debug = debug + s.trace = trace + s.lfile = nOpts.LogFile + s.fszl = nOpts.LogSizeLimit + s.ndbg = nOpts.Debug + s.ntrc = nOpts.Trace + s.mu.Unlock() +} + +// SetNATSServer allows the logger to have a handle to the embedded NATS Server. +// This sets the logger for the NATS Server and used during logfile re-opening. +func (s *StanLogger) SetNATSServer(ns *natsd.Server) { + s.mu.Lock() + s.ns = ns + ns.SetLogger(s.log, s.ndbg, s.ntrc) + s.mu.Unlock() +} + // GetLogger returns the logger func (s *StanLogger) GetLogger() Logger { s.mu.RLock() @@ -87,10 +116,14 @@ func (s *StanLogger) ReopenLogFile() { return } } - fileLog := natsdLogger.NewFileLogger(s.lfile, s.ltime, s.debug, s.trace, true) + // Pass true for debug and trace here. The higher level will suppress the debug/traces if needed. + fileLog := natsdLogger.NewFileLogger(s.lfile, s.ltime, true, true, true) if s.fszl > 0 { fileLog.SetSizeLimit(s.fszl) } + if s.ns != nil { + s.ns.SetLogger(fileLog, s.ndbg, s.ntrc) + } s.log = fileLog s.mu.Unlock() s.Noticef("File log re-opened") diff --git a/server/server.go b/server/server.go index adabfb58..60159619 100644 --- a/server/server.go +++ b/server/server.go @@ -1858,7 +1858,7 @@ func (s *StanServer) configureLogger() { newLogger = natsdLogger.NewStdLogger(nOpts.Logtime, enableDebug, enableTrace, colors, true) } - s.log.SetLogger(newLogger, nOpts.Logtime, sOpts.Debug, sOpts.Trace, nOpts.LogFile) + s.log.SetLoggerWithOpts(newLogger, nOpts, sOpts.Debug, sOpts.Trace) } // This is either running inside RunServerWithOpts() and before any reference @@ -2366,9 +2366,7 @@ func (s *StanServer) startNATSServer() error { if s.natsServer == nil { return fmt.Errorf("no NATS Server object returned") } - if stanLogger := s.log.GetLogger(); stanLogger != nil { - s.natsServer.SetLogger(stanLogger, opts.Debug, opts.Trace) - } + s.log.SetNATSServer(s.natsServer) // Run server in Go routine. go s.natsServer.Start() // Wait for accept loop(s) to be started diff --git a/server/server_run_test.go b/server/server_run_test.go index b96985e6..a115ac38 100644 --- a/server/server_run_test.go +++ b/server/server_run_test.go @@ -1,4 +1,4 @@ -// Copyright 2016-2019 The NATS Authors +// Copyright 2016-2020 The NATS Authors // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at @@ -17,6 +17,7 @@ import ( "crypto/tls" "flag" "fmt" + "io/ioutil" "os" "reflect" "runtime" @@ -1277,3 +1278,82 @@ func TestStreamingServerReadyLog(t *testing.T) { getLeader(t, 5*time.Second, s, s2) checkLog(t, l, true) } + +func TestReopenLogFileStopsNATSDebugTrace(t *testing.T) { + tmpDir, err := ioutil.TempDir("", "nats-streaming-server") + if err != nil { + t.Fatal("Could not create tmp dir") + } + defer os.RemoveAll(tmpDir) + file, err := ioutil.TempFile(tmpDir, "log_") + if err != nil { + t.Fatalf("Could not create the temp file: %v", err) + } + file.Close() + + nOpts := natsdTest.DefaultTestOptions + nOpts.LogFile = file.Name() + nOpts.Debug = true + nOpts.Trace = true + nOpts.Logtime = true + nOpts.LogSizeLimit = 10 * 1024 + + sOpts := GetDefaultOptions() + // Ensure STAN debug and trace are set to false. This was the issue + sOpts.Debug = false + sOpts.Trace = false + sOpts.EnableLogging = true + s := runServerWithOpts(t, sOpts, &nOpts) + defer s.Shutdown() + + check := func(str string, expected bool) { + t.Helper() + buf, err := ioutil.ReadFile(nOpts.LogFile) + if err != nil { + t.Fatalf("Error reading file: %v", err) + } + sbuf := string(buf) + present := strings.Contains(sbuf, str) + if expected && !present { + t.Fatalf("Expected to find %q, did not: %s", str, sbuf) + } else if !expected && present { + t.Fatalf("Expected to not find %q, but it was: %s", str, sbuf) + } + } + sc, err := stan.Connect(clusterName, "before_reopen") + if err != nil { + t.Fatalf("Error on connect: %v", err) + } + defer sc.Close() + check("before_reopen", true) + check("[DBG] STREAM: [Client:before_reopen]", false) + + s.log.ReopenLogFile() + check("File log re-opened", true) + + sc.Close() + sc, err = stan.Connect(clusterName, "after_reopen") + if err != nil { + t.Fatalf("Error on connect: %v", err) + } + defer sc.Close() + check("after_reopen", true) + check("[DBG] STREAM: [Client:after_reopen]", false) + + payload := make([]byte, 1000) + for i := 0; i < len(payload); i++ { + payload[i] = 'A' + } + pstr := string(payload) + for i := 0; i < 10; i++ { + s.log.Noticef(pstr) + } + // Check that size limit has been applied. + files, err := ioutil.ReadDir(tmpDir) + if err != nil { + t.Fatalf("Error reading directory: %v", err) + } + if len(files) == 1 { + t.Fatal("Expected log to have been rotated, was not") + } +}