fix: update log level handling

src/cmd/root.go

@@ -72,6 +72,7 @@ func cliSetup() {
 		"info":  message.InfoLevel,
 		"debug": message.DebugLevel,
 		"trace": message.TraceLevel,
+		"error": message.ErrorLevel,
 	}
 
 	printViperConfigUsed()

src/config/lang/english.go

@@ -18,9 +18,9 @@ const (
 const (
 	RootCmdShort              = "CLI for the maru runner"
 	RootCmdFlagSkipLogFile    = "Disable log file creation"
-	RootCmdFlagLogLevel       = "Log level for the runner. Valid options are: warn, info, debug, trace"
+	RootCmdFlagLogLevel       = "Log level for the runner. Valid options are: error, warn, info, debug, trace"
 	RootCmdFlagNoProgress     = "Disable fancy UI progress bars, spinners, logos, etc"
-	RootCmdErrInvalidLogLevel = "Invalid log level. Valid options are: warn, info, debug, trace."
+	RootCmdErrInvalidLogLevel = "Invalid log level. Valid options are: error, warn, info, debug, trace."
 	RootCmdFlagArch           = "Architecture for the runner"
 	RootCmdFlagTempDir        = "Specify the temporary directory to use for intermediate files"
 )

src/message/logging.go

@@ -17,18 +17,31 @@ import (
 type LogLevel int
 
 const (
-	// WarnLevel level. Non-critical entries that deserve eyes.
-	WarnLevel LogLevel = iota
+	// Supported log levels. These are in order of increasing severity, and
+	// match the constants in the log/slog package.
+
+	// TraceLevel level. Effectively the same as Debug but with line numbers.
+	//
+	// NOTE: There currently is no Trace() function in the log/slog package. In
+	// order to use this level, you must use message.SLog.Log() and specify the
+	// level. Maru currently uses the Trace level specifically for adding line
+	// numbers to logs from calls to message.SLog.Debug(). Because of this,
+	// Trace is effectively the same as Debug but with line numbers.
+	TraceLevel LogLevel = -8
+	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
+	DebugLevel LogLevel = -4
 	// InfoLevel level. General operational entries about what's going on inside the
 	// application.
-	InfoLevel
-	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
-	DebugLevel
-	// TraceLevel level. Designates finer-grained informational events than the Debug.
-	TraceLevel
+	InfoLevel LogLevel = 0
+	// WarnLevel level. Non-critical entries that deserve eyes.
+	WarnLevel LogLevel = 4
+	// ErrorLevel level. Errors only.
+	ErrorLevel LogLevel = 8
 )
 
-// logLevel is the log level for the runner
+// logLevel is the log level for the runner. When set, log messages with a level
+// greater than or equal to this level will be logged. Log messages with a level
+// lower than this level will be ignored.
 var logLevel = InfoLevel
 
 // logFile acts as a buffer for logFile generation
@@ -59,7 +72,8 @@ func LogFileLocation() string {
 // SetLogLevel sets the log level.
 func SetLogLevel(lvl LogLevel) {
 	logLevel = lvl
-	if logLevel >= DebugLevel {
+	// Enable pterm debug messages if the log level is Trace or Debug
+	if logLevel <= DebugLevel {
 		pterm.EnableDebugMessages()
 	}
 }

src/message/logging_test.go

@@ -0,0 +1,158 @@
+// SPDX-License-Identifier: Apache-2.0
+// SPDX-FileCopyrightText: 2023-Present the Maru Authors
+
+// Package message provides a rich set of functions for displaying messages to the user.
+package message
+
+import (
+	"bytes"
+	"log/slog"
+	"slices"
+	"strings"
+
+	"testing"
+
+	"github.com/pterm/pterm"
+)
+
+func Test_LogLevel_Diff(t *testing.T) {
+	maruLogger := slog.New(MaruHandler{})
+
+	cases := map[string]struct {
+		// the level we're set to log at with SetLogLevel(). We expect logs with
+		// a lower level to be ignored.
+		setLevel LogLevel
+		// the level which we will log, e.g. SLog.Debug(), SLog.Info(), etc.
+		logLevel LogLevel
+		// the expected output of the log. We special case DebugLevel as it
+		// should contain a timestamp.
+		expected string
+	}{
+		"DebugLevel": {
+			setLevel: DebugLevel,
+			logLevel: DebugLevel,
+			expected: "DEBUG test",
+		},
+		"InfoInfoLevel": {
+			setLevel: InfoLevel,
+			logLevel: InfoLevel,
+			expected: "INFO test",
+		},
+		"InfoWarnLevel": {
+			setLevel: InfoLevel,
+			logLevel: WarnLevel,
+			expected: "WARNING test",
+		},
+		"WarnInfoLevel": {
+			setLevel: WarnLevel,
+			logLevel: InfoLevel,
+			expected: "",
+		},
+		"InfoErrorLevel": {
+			setLevel: InfoLevel,
+			logLevel: ErrorLevel,
+			expected: "ERROR test",
+		},
+		"TraceInfoLevel": {
+			setLevel: TraceLevel,
+			logLevel: InfoLevel,
+			expected: "INFO test",
+		},
+		"TraceDebugLevel": {
+			setLevel: TraceLevel,
+			logLevel: DebugLevel,
+			expected: "DEBUG test",
+		},
+		"TraceErrorLevel": {
+			setLevel: TraceLevel,
+			logLevel: ErrorLevel,
+			expected: "ERROR test",
+		},
+		"ErrorWarnLevel": {
+			setLevel: ErrorLevel,
+			logLevel: WarnLevel,
+			expected: "",
+		},
+		"ErrorErrorLevel": {
+			setLevel: ErrorLevel,
+			logLevel: ErrorLevel,
+			expected: "ERROR test",
+		},
+		"ErrorInfoLevel": {
+			setLevel: ErrorLevel,
+			logLevel: InfoLevel,
+			expected: "",
+		},
+	}
+
+	for name, tc := range cases {
+		t.Run(name, func(t *testing.T) {
+			SetLogLevel(tc.setLevel)
+
+			// set the underlying writer, like we do in utils/utils.go
+			var outBuf bytes.Buffer
+			pterm.SetDefaultOutput(&outBuf)
+
+			switch tc.logLevel {
+			case DebugLevel:
+				maruLogger.Debug("test")
+			case InfoLevel:
+				maruLogger.Info("test")
+			case WarnLevel:
+				maruLogger.Warn("test")
+			case ErrorLevel:
+				maruLogger.Error("test")
+			}
+			content := outBuf.String()
+			// remove color codes
+			content = pterm.RemoveColorFromString(content)
+			// remove extra whitespace from the output
+			content = strings.TrimSpace(content)
+			parts := strings.Split(tc.expected, " ")
+			for _, part := range parts {
+				if !strings.Contains(content, part) {
+					t.Errorf("Expected debug message to contain '%s', but it didn't: (%s)", part, content)
+				}
+			}
+			// if the set level is Trace and the log level is Debug, then we
+			// expect extra	debug lines to be printed. Conversely, if it's trace
+			// but not Debug, then we expect no extra debug lines to be printed.
+			partsOutput := strings.Split(content, " ")
+			// when debugging with TraceLevel, spliting on spaces will result in a slice
+			// like so:
+			// []string{
+			//   "DEBUG",
+			//   "",
+			//   "",
+			//   "2024-09-19T10:21:16-05:00",
+			//   "",
+			//   "-",
+			//   "",
+			//   "test\n└",
+			//   "(/Users/clint/go/github.com/defenseunicorns/maru-runner/src/message/slog.go:56)",
+			// }
+			//
+			// here we sort the slice to move the timestamp to the front,
+			// then compact to remove them. The result should be a slice of
+			// 6 eleements.
+			//
+			// While debugging without trace level, we expect the same slice
+			// except there is no file name and line number, so it would have 5
+			// elements.
+			slices.Sort(partsOutput)
+			partsOutput = slices.Compact(partsOutput)
+			expectedLen := 3
+			if tc.logLevel == DebugLevel {
+				expectedLen = 5
+			}
+			if tc.setLevel == TraceLevel && tc.logLevel == DebugLevel {
+				expectedLen = 6
+			}
+
+			if len(partsOutput) > expectedLen {
+				t.Errorf("Expected debug message to contain timestamp, but it didn't: (%s)", content)
+			}
+		})
+	}
+
+}

src/message/message.go

@@ -67,7 +67,7 @@ func paragraph(format string, a ...any) string {
 }
 
 func debugPrinter(offset int, a ...any) {
-	printer := pterm.Debug.WithShowLineNumber(logLevel > 2).WithLineNumberOffset(offset)
+	printer := pterm.Debug.WithShowLineNumber(logLevel <= TraceLevel).WithLineNumberOffset(offset)
 	now := time.Now().Format(time.RFC3339)
 	// prepend to a
 	a = append([]any{now, " - "}, a...)

src/message/slog.go

@@ -17,9 +17,22 @@ var (
 // MaruHandler is a simple handler that implements the slog.Handler interface
 type MaruHandler struct{}
 
-// Enabled is always set to true as Maru logging functions are already aware of if they are allowed to be called
-func (z MaruHandler) Enabled(_ context.Context, _ slog.Level) bool {
-	return true
+// Enabled determines if the handler is enabled for the given level. This
+// function is called for every log message and will compare the level of the
+// message to the log level set (default is info). Log levels are defined in
+// src/message/logging.go and match the levels used in the underlying log/slog
+// package. Logs with a level below the set log level will be ignored.
+//
+// Examples:
+//
+//	SetLogLevel(TraceLevel) // show everything, with file names and line numbers
+//	SetLogLevel(DebugLevel) // show everything
+//	SetLogLevel(InfoLevel)  // show info and above (does not show debug logs)
+//	SetLogLevel(WarnLevel)  // show warn and above (does not show debug/info logs)
+//	SetLogLevel(ErrorLevel)  // show only errors (does not show debug/info/warn logs)
+func (z MaruHandler) Enabled(_ context.Context, level slog.Level) bool {
+	// only log if the log level is greater than or equal to the set log level
+	return int(level) >= int(logLevel)
 }
 
 // WithAttrs is not suppported

src/test/e2e/runner_test.go

@@ -232,7 +232,7 @@ func TestTaskRunner(t *testing.T) {
 		t.Parallel()
 		_, stdErr, err := e2e.Maru("run", "wait-fail", "--file", "src/test/tasks/tasks.yaml")
 		require.Error(t, err)
-		require.Contains(t, stdErr, "Waiting for")
+		require.Contains(t, stdErr, "timed out after 1 seconds")
 	})
 
 	t.Run("test successful call to zarf tools wait-for (requires Zarf on path)", func(t *testing.T) {