logs.go: LogToSlogWriter wasn't setting the right logs as ERROR

Author: maelvls

pkg/logs/logs.go

@@ -116,38 +116,39 @@ func Initialize() {
 	slog := slog.Default()
 
 	Log = &log.Logger{}
-	Log.SetOutput(logToSlogWriter{slog: slog, source: "agent"})
+	Log.SetOutput(LogToSlogWriter{Slog: slog, Source: "agent"})
 
 	// Let's make sure the VCert library, which is the only library we import to
 	// be using the global log.Default, also uses the common slog logger.
 	vcertLog := log.Default()
-	vcertLog.SetOutput(logToSlogWriter{slog: slog, source: "vcert"})
+	vcertLog.SetOutput(LogToSlogWriter{Slog: slog, Source: "vcert"})
 	// This is a work around for a bug in vcert where it adds a `vCert: ` prefix
 	// to the global log logger. It can be removed when this is fixed upstream
 	// in vcert:  https://github.com/Venafi/vcert/pull/512
 	vcertLog.SetPrefix("")
 }
 
-type logToSlogWriter struct {
-	slog   *slog.Logger
-	source string
+type LogToSlogWriter struct {
+	Slog   *slog.Logger
+	Source string
 }
 
-func (w logToSlogWriter) Write(p []byte) (n int, err error) {
+func (w LogToSlogWriter) Write(p []byte) (n int, err error) {
 	// log.Printf writes a newline at the end of the message, so we need to trim
 	// it.
 	p = bytes.TrimSuffix(p, []byte("\n"))
 
 	message := string(p)
-	if isCritical(message) {
-		w.slog.With("source", w.source).Error(message)
+	if strings.Contains(message, "error") ||
+		strings.Contains(message, "failed") ||
+		strings.Contains(message, "fatal") ||
+		strings.Contains(message, "Failed") ||
+		strings.Contains(message, "While evaluating configuration") ||
+		strings.Contains(message, "data-path override present") ||
+		strings.Contains(message, "Cannot marshal readings") {
+		w.Slog.With("source", w.Source).Error(message)
 	} else {
-		w.slog.With("source", w.source).Info(message)
+		w.Slog.With("source", w.Source).Info(message)
 	}
 	return len(p), nil
 }
-
-func isCritical(msg string) bool {
-	// You can implement more robust logic to detect critical log messages
-	return strings.Contains(msg, "FATAL") || strings.Contains(msg, "ERROR")
-}

pkg/logs/logs_test.go

@@ -15,6 +15,7 @@ import (
 
 	_ "github.com/Venafi/vcert/v5"
 	"github.com/spf13/pflag"
+	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"k8s.io/klog/v2"
 
@@ -316,3 +317,76 @@ func replaceWithStaticTimestamps(input string) string {
 	input = fileAndLineRegexpKlog.ReplaceAllString(input, " $1.go:000")
 	return input
 }
+
+func TestLogToSlogWriter(t *testing.T) {
+	// This test makes sure that all the agent's Log.Fatalf calls are correctly
+	// translated to slog.Error calls.
+	//
+	// This list was generated using:
+	//  grep -r "Log\.Fatalf" ./cmd ./pkg
+	given := strings.TrimPrefix(`
+Failed to load config file for agent from
+Failed to read config file
+Failed to parse config file
+While evaluating configuration
+failed to run pprof profiler
+failed to run the health check server
+failed to start a controller-runtime component
+failed to wait for controller-runtime component to stop
+running data gatherer %s of type %s as Local, data-path override present
+failed to instantiate %q data gatherer
+failed to read local data file
+failed to unmarshal local data file
+failed to output to local file
+Exiting due to fatal error uploading
+halting datagathering in strict mode due to error
+Cannot marshal readings
+Failed to read config file
+Failed to parse config file
+Failed to validate data gatherers
+this is a happy log that should show as INFO`, "\n")
+	expect := strings.TrimPrefix(`
+level=ERROR msg="Failed to load config file for agent from" source=agent
+level=ERROR msg="Failed to read config file" source=agent
+level=ERROR msg="Failed to parse config file" source=agent
+level=ERROR msg="While evaluating configuration" source=agent
+level=ERROR msg="failed to run pprof profiler" source=agent
+level=ERROR msg="failed to run the health check server" source=agent
+level=ERROR msg="failed to start a controller-runtime component" source=agent
+level=ERROR msg="failed to wait for controller-runtime component to stop" source=agent
+level=ERROR msg="running data gatherer %!s(MISSING) of type %!s(MISSING) as Local, data-path override present" source=agent
+level=ERROR msg="failed to instantiate %!q(MISSING) data gatherer" source=agent
+level=ERROR msg="failed to read local data file" source=agent
+level=ERROR msg="failed to unmarshal local data file" source=agent
+level=ERROR msg="failed to output to local file" source=agent
+level=ERROR msg="Exiting due to fatal error uploading" source=agent
+level=ERROR msg="halting datagathering in strict mode due to error" source=agent
+level=ERROR msg="Cannot marshal readings" source=agent
+level=ERROR msg="Failed to read config file" source=agent
+level=ERROR msg="Failed to parse config file" source=agent
+level=ERROR msg="Failed to validate data gatherers" source=agent
+level=INFO msg="this is a happy log that should show as INFO" source=agent
+`, "\n")
+
+	gotBuf := &bytes.Buffer{}
+	slogHandler := slog.NewTextHandler(gotBuf, &slog.HandlerOptions{
+		// Remove the timestamp from the logs so that we can compare them.
+		ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+			if a.Key == "time" {
+				return slog.Attr{}
+			}
+			return a
+		},
+	})
+	slogLogger := slog.New(slogHandler)
+
+	logger := log.New(&bytes.Buffer{}, "", 0)
+	logger.SetOutput(logs.LogToSlogWriter{Slog: slogLogger, Source: "agent"})
+
+	for _, line := range strings.Split(given, "\n") {
+		// Simulate the current agent's logs.
+		logger.Printf(line)
+	}
+
+	assert.Equal(t, expect, gotBuf.String())
+}