backport of commit 753f752

command/agent/command.go

@@ -28,7 +28,6 @@ import (
 	discover "github.com/hashicorp/go-discover"
 	hclog "github.com/hashicorp/go-hclog"
 	gsyslog "github.com/hashicorp/go-syslog"
-	"github.com/hashicorp/logutils"
 	"github.com/hashicorp/nomad/helper"
 	flaghelper "github.com/hashicorp/nomad/helper/flags"
 	gatedwriter "github.com/hashicorp/nomad/helper/gated-writer"
@@ -55,8 +54,6 @@ type Command struct {
 	args           []string
 	agent          *Agent
 	httpServers    []*HTTPServer
-	logFilter      *logutils.LevelFilter
-	logOutput      io.Writer
 	retryJoinErrCh chan struct{}
 }
 
@@ -550,28 +547,31 @@ func (c *Command) IsValidConfig(config, cmdConfig *Config) bool {
 	return true
 }
 
-// SetupLoggers is used to set up the logGate, and our logOutput
-func SetupLoggers(ui cli.Ui, config *Config) (*logutils.LevelFilter, *gatedwriter.Writer, io.Writer) {
-	// Setup logging. First create the gated log writer, which will
-	// store logs until we're ready to show them. Then create the level
-	// filter, filtering logs of the specified level.
-	logGate := &gatedwriter.Writer{
-		Writer: &cli.UiWriter{Ui: ui},
-	}
+// setupLoggers is used to set up the logGate and our logOutput.
+func setupLoggers(ui cli.Ui, config *Config) (*gatedwriter.Writer, io.Writer) {
 
-	logFilter := LevelFilter()
-	logFilter.MinLevel = logutils.LogLevel(strings.ToUpper(config.LogLevel))
-	logFilter.Writer = logGate
-	if !ValidateLevelFilter(logFilter.MinLevel, logFilter) {
+	// Pull the log level from the configuration, ensure it is titled and then
+	// perform validation. Do this before the gated writer, as this can
+	// generate an error, whereas the writer does not.
+	logLevel := strings.ToUpper(config.LogLevel)
+
+	if !isLogLevelValid(logLevel) {
 		ui.Error(fmt.Sprintf(
 			"Invalid log level: %s. Valid log levels are: %v",
-			logFilter.MinLevel, logFilter.Levels))
-		return nil, nil, nil
+			logLevel, validLogLevels.Slice()))
+		return nil, nil
 	}
 
-	// Create a log writer, and wrap a logOutput around it
-	writers := []io.Writer{logFilter}
-	logLevel := strings.ToUpper(config.LogLevel)
+	// Create a gated log writer, which will store logs until we're ready to
+	// output them.
+	logGate := &gatedwriter.Writer{
+		Writer: &cli.UiWriter{Ui: ui},
+	}
+
+	// Initialize our array of log writers with the gated writer. Additional
+	// log writers will be appended if/when configured.
+	writers := []io.Writer{logGate}
+
 	if logLevel == "OFF" {
 		config.EnableSyslog = false
 	}
@@ -581,7 +581,7 @@ func SetupLoggers(ui cli.Ui, config *Config) (*logutils.LevelFilter, *gatedwrite
 		l, err := gsyslog.NewLogger(getSysLogPriority(logLevel), config.SyslogFacility, "nomad")
 		if err != nil {
 			ui.Error(fmt.Sprintf("Syslog setup failed: %v", err))
-			return nil, nil, nil
+			return nil, nil
 		}
 		writers = append(writers, newSyslogWriter(l, config.LogJson))
 	}
@@ -601,7 +601,7 @@ func SetupLoggers(ui cli.Ui, config *Config) (*logutils.LevelFilter, *gatedwrite
 			duration, err := time.ParseDuration(config.LogRotateDuration)
 			if err != nil {
 				ui.Error(fmt.Sprintf("Failed to parse log rotation duration: %v", err))
-				return nil, nil, nil
+				return nil, nil
 			}
 			logRotateDuration = duration
 		} else {
@@ -610,19 +610,18 @@ func SetupLoggers(ui cli.Ui, config *Config) (*logutils.LevelFilter, *gatedwrite
 		}
 
 		logFile := &logFile{
-			logFilter: logFilter,
-			fileName:  fileName,
-			logPath:   dir,
-			duration:  logRotateDuration,
-			MaxBytes:  config.LogRotateBytes,
-			MaxFiles:  config.LogRotateMaxFiles,
+			fileName: fileName,
+			logPath:  dir,
+			duration: logRotateDuration,
+			MaxBytes: config.LogRotateBytes,
+			MaxFiles: config.LogRotateMaxFiles,
 		}
 
 		writers = append(writers, logFile)
 	}
 
 	logOutput := io.MultiWriter(writers...)
-	return logFilter, logGate, logOutput
+	return logGate, logOutput
 }
 
 // setupAgent is used to start the agent and various interfaces
@@ -798,10 +797,8 @@ func (c *Command) Run(args []string) int {
 		}
 	}
 
-	// Setup the log outputs
-	logFilter, logGate, logOutput := SetupLoggers(c.Ui, config)
-	c.logFilter = logFilter
-	c.logOutput = logOutput
+	// Set up the log outputs.
+	logGate, logOutput := setupLoggers(c.Ui, config)
 	if logGate == nil {
 		return 1
 	}
@@ -1113,13 +1110,12 @@ func (c *Command) handleReload() {
 	}
 
 	// Change the log level
-	minLevel := logutils.LogLevel(strings.ToUpper(newConf.LogLevel))
-	if ValidateLevelFilter(minLevel, c.logFilter) {
-		c.logFilter.SetMinLevel(minLevel)
-	} else {
+	minLevel := strings.ToUpper(newConf.LogLevel)
+
+	if !isLogLevelValid(minLevel) {
 		c.Ui.Error(fmt.Sprintf(
 			"Invalid log level: %s. Valid log levels are: %v",
-			minLevel, c.logFilter.Levels))
+			minLevel, validLogLevels.Slice()))
 
 		// Keep the current log level
 		newConf.LogLevel = c.agent.GetConfig().LogLevel

command/agent/command_test.go

@@ -12,15 +12,15 @@ import (
 	"testing"
 
 	"github.com/hashicorp/cli"
+	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/nomad/ci"
 	"github.com/hashicorp/nomad/helper/pointer"
-	"github.com/shoenig/test/must"
-	"github.com/stretchr/testify/assert"
-	"github.com/stretchr/testify/require"
-
 	"github.com/hashicorp/nomad/nomad/structs"
 	"github.com/hashicorp/nomad/nomad/structs/config"
 	"github.com/hashicorp/nomad/version"
+	"github.com/shoenig/test/must"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 )
 
 func TestCommand_Implements(t *testing.T) {
@@ -625,3 +625,59 @@ vault {
 		})
 	}
 }
+
+func Test_setupLoggers_logFile(t *testing.T) {
+
+	// Generate a mock UI and temporary log file location to write to.
+	mockUI := cli.NewMockUi()
+	logFile := filepath.Join(t.TempDir(), "nomad.log")
+
+	// The initial configuration contains an invalid log level parameter.
+	cfg := &Config{
+		LogFile:  logFile,
+		LogLevel: "warning",
+	}
+
+	// Generate the loggers and ensure the correct error is generated.
+	gatedWriter, writer := setupLoggers(mockUI, cfg)
+	must.Nil(t, gatedWriter)
+	must.Nil(t, writer)
+	must.StrContains(t, mockUI.ErrorWriter.String(), "Invalid log level: WARNING")
+
+	mockUI.ErrorWriter.Reset()
+	mockUI.OutputWriter.Reset()
+
+	// Update the log level, so that it is a valid option and set up the
+	// loggers again.
+	cfg.LogLevel = "warn"
+	gatedWriter, writer = setupLoggers(mockUI, cfg)
+	must.NotNil(t, gatedWriter)
+	must.NotNil(t, writer)
+
+	// Build the logger as the command does.
+	testLogger := hclog.NewInterceptLogger(&hclog.LoggerOptions{
+		Name:   "agent",
+		Level:  hclog.LevelFromString(cfg.LogLevel),
+		Output: writer,
+	})
+
+	// Flush the log gate and write messages at all levels.
+	gatedWriter.Flush()
+	testLogger.Error("error log entry")
+	testLogger.Warn("warn log entry")
+	testLogger.Info("info log entry")
+	testLogger.Debug("debug log entry")
+	testLogger.Trace("trace log entry")
+
+	// Read the file out and ensure it only contains log entries which match
+	// our desired level.
+	fileContents, err := os.ReadFile(logFile)
+	must.NoError(t, err)
+
+	fileContentsStr := string(fileContents)
+	must.StrContains(t, fileContentsStr, "error log entry")
+	must.StrContains(t, fileContentsStr, "warn log entry")
+	must.StrNotContains(t, fileContentsStr, "info log entry")
+	must.StrNotContains(t, fileContentsStr, "debug log entry")
+	must.StrNotContains(t, fileContentsStr, "trace log entry")
+}

command/agent/log_file.go

@@ -12,8 +12,6 @@ import (
 	"strings"
 	"sync"
 	"time"
-
-	"github.com/hashicorp/logutils"
 )
 
 var (
@@ -22,8 +20,6 @@ var (
 
 // logFile is used to setup a file based logger that also performs log rotation
 type logFile struct {
-	// Log level Filter to filter out logs that do not matcch LogLevel criteria
-	logFilter *logutils.LevelFilter
 
 	//Name of the log file
 	fileName string
@@ -121,7 +117,7 @@ func (l *logFile) pruneFiles() error {
 		return err
 	}
 
-	// Stort the strings as filepath.Glob does not publicly guarantee that files
+	// Sort the strings as filepath.Glob does not publicly guarantee that files
 	// are sorted, so here we add an extra defensive sort.
 	sort.Strings(matches)
 
@@ -135,15 +131,14 @@ func (l *logFile) pruneFiles() error {
 	return nil
 }
 
-// Write is used to implement io.Writer
+// Write is used to implement io.Writer.
+//
+// Nomad's log file capability is fed by go-hclog which is responsible for
+// performing the log level filtering. It is not needed here.
 func (l *logFile) Write(b []byte) (int, error) {
-	// Filter out log entries that do not match log level criteria
-	if !l.logFilter.Check(b) {
-		return 0, nil
-	}
-
 	l.acquire.Lock()
 	defer l.acquire.Unlock()
+
 	//Create a new file if we have no file to write to
 	if l.FileInfo == nil {
 		if err := l.openNew(); err != nil {