diff --git a/cmd/thv-operator/controllers/mcpserver_controller.go b/cmd/thv-operator/controllers/mcpserver_controller.go index 31ac8c416..025749e98 100644 --- a/cmd/thv-operator/controllers/mcpserver_controller.go +++ b/cmd/thv-operator/controllers/mcpserver_controller.go @@ -284,7 +284,7 @@ func (r *MCPServerReconciler) createRBACResource( ) error { desired := createResource() if err := controllerutil.SetControllerReference(mcpServer, desired, r.Scheme); err != nil { - logger.Error(fmt.Sprintf("Failed to set controller reference for %s", resourceType), err) + logger.Errorf("Failed to set controller reference for %s: %v", resourceType, err) return nil } @@ -310,7 +310,7 @@ func (r *MCPServerReconciler) updateRBACResourceIfNeeded( ) error { desired := createResource() if err := controllerutil.SetControllerReference(mcpServer, desired, r.Scheme); err != nil { - logger.Error(fmt.Sprintf("Failed to set controller reference for %s", resourceType), err) + logger.Errorf("Failed to set controller reference for %s: %v", resourceType, err) return nil } @@ -665,7 +665,7 @@ func (r *MCPServerReconciler) deploymentForMCPServer(m *mcpv1alpha1.MCPServer) * // Set MCPServer instance as the owner and controller if err := controllerutil.SetControllerReference(m, dep, r.Scheme); err != nil { - logger.Error("Failed to set controller reference for Deployment", err) + logger.Errorf("Failed to set controller reference for Deployment %v", err) return nil } return dep @@ -752,7 +752,7 @@ func (r *MCPServerReconciler) serviceForMCPServer(m *mcpv1alpha1.MCPServer) *cor // Set MCPServer instance as the owner and controller if err := controllerutil.SetControllerReference(m, svc, r.Scheme); err != nil { - logger.Error("Failed to set controller reference for Service", err) + logger.Errorf("Failed to set controller reference for Service %v", err) return nil } return svc diff --git a/go.mod b/go.mod index b0f752d5a..95b6664af 100644 --- a/go.mod +++ b/go.mod @@ -12,12 +12,12 @@ require ( github.com/docker/docker v28.3.3+incompatible github.com/docker/go-connections v0.6.0 github.com/go-chi/chi/v5 v5.2.2 + github.com/go-logr/zapr v1.3.0 github.com/gofrs/flock v0.12.1 github.com/google/go-containerregistry v0.20.6 github.com/google/uuid v1.6.0 github.com/lestrrat-go/httprc/v3 v3.0.1 github.com/lestrrat-go/jwx/v3 v3.0.10 - github.com/lmittmann/tint v1.1.2 github.com/mark3labs/mcp-go v0.37.0 github.com/olekukonko/tablewriter v1.0.9 github.com/onsi/ginkgo/v2 v2.24.0 @@ -26,7 +26,6 @@ require ( github.com/pkg/browser v0.0.0-20240102092130-5ac0b6a4141c github.com/prometheus/client_golang v1.23.0 github.com/santhosh-tekuri/jsonschema/v5 v5.3.1 - github.com/santhosh-tekuri/jsonschema/v6 v6.0.2 github.com/sigstore/protobuf-specs v0.5.0 github.com/sigstore/sigstore-go v1.1.1 github.com/spf13/viper v1.20.1 @@ -41,6 +40,7 @@ require ( go.opentelemetry.io/otel/sdk v1.37.0 go.opentelemetry.io/otel/sdk/metric v1.37.0 go.uber.org/mock v0.6.0 + go.uber.org/zap v1.27.0 golang.ngrok.com/ngrok/v2 v2.1.0 golang.org/x/exp/jsonrpc2 v0.0.0-20250813145105-42675adae3e6 golang.org/x/mod v0.27.0 @@ -239,7 +239,6 @@ require ( go.opentelemetry.io/proto/otlp v1.7.0 // indirect go.uber.org/automaxprocs v1.6.0 // indirect go.uber.org/multierr v1.11.0 // indirect - go.uber.org/zap v1.27.0 // indirect go.yaml.in/yaml/v2 v2.4.2 // indirect golang.ngrok.com/muxado/v2 v2.0.1 // indirect golang.org/x/exp/event v0.0.0-20250718183923-645b1fa84792 // indirect diff --git a/go.sum b/go.sum index fa36dd1c8..6b2017003 100644 --- a/go.sum +++ b/go.sum @@ -1282,8 +1282,6 @@ github.com/lib/pq v1.1.0/go.mod h1:5WUZQaWbwv1U+lTReE5YruASi9Al49XbQIvNi/34Woo= github.com/lib/pq v1.2.0/go.mod h1:5WUZQaWbwv1U+lTReE5YruASi9Al49XbQIvNi/34Woo= github.com/lib/pq v1.10.2/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o= github.com/lib/pq v1.10.7/go.mod h1:AlVN5x4E4T544tWzH6hKfbfQvm3HdbOxrmggDNAPY9o= -github.com/lmittmann/tint v1.1.2 h1:2CQzrL6rslrsyjqLDwD11bZ5OpLBPU+g3G/r5LSfS8w= -github.com/lmittmann/tint v1.1.2/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE= github.com/lucasb-eyer/go-colorful v1.2.0 h1:1nnpGOrhyZZuNyfu1QjKiUICQ74+3FNCN69Aj6K7nkY= github.com/lucasb-eyer/go-colorful v1.2.0/go.mod h1:R4dSotOR9KMtayYi1e77YzuveK+i7ruzyGqttikkLy0= github.com/luna-duclos/instrumentedsql v1.1.3/go.mod h1:9J1njvFds+zN7y85EDhN9XNQLANWwZt2ULeIC8yMNYs= @@ -1459,7 +1457,6 @@ github.com/sagikazarmark/locafero v0.7.0 h1:5MqpDsTGNDhY8sGp0Aowyf0qKsPrhewaLSsF github.com/sagikazarmark/locafero v0.7.0/go.mod h1:2za3Cg5rMaTMoG/2Ulr9AwtFaIppKXTRYnozin4aB5k= github.com/santhosh-tekuri/jsonschema/v5 v5.3.1 h1:lZUw3E0/J3roVtGQ+SCrUrg3ON6NgVqpn3+iol9aGu4= github.com/santhosh-tekuri/jsonschema/v5 v5.3.1/go.mod h1:uToXkOrWAZ6/Oc07xWQrPOhJotwFIyu2bBVN41fcDUY= -github.com/santhosh-tekuri/jsonschema/v6 v6.0.2/go.mod h1:JXeL+ps8p7/KNMjDQk3TCwPpBy0wYklyWTfbkIzdIFU= github.com/sassoftware/relic v7.2.1+incompatible h1:Pwyh1F3I0r4clFJXkSI8bOyJINGqpgjJU3DYAZeI05A= github.com/sassoftware/relic v7.2.1+incompatible/go.mod h1:CWfAxv73/iLZ17rbyhIEq3K9hs5w6FpNMdUT//qR+zk= github.com/sassoftware/relic/v7 v7.6.2 h1:rS44Lbv9G9eXsukknS4mSjIAuuX+lMq/FnStgmZlUv4= diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index 7be4ac945..74bd47f2f 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -2,142 +2,125 @@ package logger import ( - "context" - "fmt" - "log/slog" "os" - "runtime" "strconv" "time" - "github.com/lmittmann/tint" + "github.com/go-logr/logr" + "github.com/go-logr/zapr" "github.com/spf13/viper" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" ) -// Log is a global logger instance -var log Logger - // Debug logs a message at debug level using the singleton logger. -func Debug(msg string, args ...any) { - log.Debug(msg, args...) +func Debug(msg string) { + zap.S().Debug(msg) } // Debugf logs a message at debug level using the singleton logger. func Debugf(msg string, args ...any) { - log.Debugf(msg, args...) + zap.S().Debugf(msg, args...) +} + +// Debugw logs a message at debug level using the singleton logger with additional key-value pairs. +func Debugw(msg string, keysAndValues ...any) { + zap.S().Debugw(msg, keysAndValues...) } // Info logs a message at info level using the singleton logger. -func Info(msg string, args ...any) { - log.Info(msg, args...) +func Info(msg string) { + zap.S().Info(msg) } // Infof logs a message at info level using the singleton logger. func Infof(msg string, args ...any) { - log.Infof(msg, args...) + zap.S().Infof(msg, args...) +} + +// Infow logs a message at info level using the singleton logger with additional key-value pairs. +func Infow(msg string, keysAndValues ...any) { + zap.S().Infow(msg, keysAndValues...) } // Warn logs a message at warning level using the singleton logger. -func Warn(msg string, args ...any) { - log.Warn(msg, args...) +func Warn(msg string) { + zap.S().Warn(msg) } // Warnf logs a message at warning level using the singleton logger. func Warnf(msg string, args ...any) { - log.Warnf(msg, args...) + zap.S().Warnf(msg, args...) +} + +// Warnw logs a message at warning level using the singleton logger with additional key-value pairs. +func Warnw(msg string, keysAndValues ...any) { + zap.S().Warnw(msg, keysAndValues...) } // Error logs a message at error level using the singleton logger. -func Error(msg string, args ...any) { - log.Error(msg, args...) +func Error(msg string) { + zap.S().Error(msg) } // Errorf logs a message at error level using the singleton logger. func Errorf(msg string, args ...any) { - log.Errorf(msg, args...) + zap.S().Errorf(msg, args...) +} + +// Errorw logs a message at error level using the singleton logger with additional key-value pairs. +func Errorw(msg string, keysAndValues ...any) { + zap.S().Errorw(msg, keysAndValues...) } // Panic logs a message at error level using the singleton logger and panics the program. func Panic(msg string) { - log.Panic(msg) + zap.S().Panic(msg) } // Panicf logs a message at error level using the singleton logger and panics the program. func Panicf(msg string, args ...any) { - log.Panicf(msg, args...) + zap.S().Panicf(msg, args...) } -// Logger provides a unified interface for logging -type Logger interface { - Debug(msg string, args ...any) - Debugf(msg string, args ...any) - Info(msg string, args ...any) - Infof(msg string, args ...any) - Warn(msg string, args ...any) - Warnf(msg string, args ...any) - Error(msg string, args ...any) - Errorf(msg string, args ...any) - Panic(msg string) - Panicf(msg string, args ...any) +// Panicw logs a message at error level using the singleton logger with additional key-value pairs and panics the program. +func Panicw(msg string, keysAndValues ...any) { + zap.S().Panicw(msg, keysAndValues...) } -// Implementation using slog -type slogLogger struct { - logger *slog.Logger +// DPanic logs a message at error level using the singleton logger and panics the program. +func DPanic(msg string) { + zap.S().DPanic(msg) } -func (l *slogLogger) Debugf(msg string, args ...any) { - l.logger.Debug(fmt.Sprintf(msg, args...)) +// DPanicf logs a message at error level using the singleton logger and panics the program. +func DPanicf(msg string, args ...any) { + zap.S().DPanicf(msg, args...) } -func (l *slogLogger) Infof(msg string, args ...any) { - l.logger.Info(fmt.Sprintf(msg, args...)) +// DPanicw logs a message at error level using the singleton logger with additional key-value pairs and panics the program. +func DPanicw(msg string, keysAndValues ...any) { + zap.S().DPanicw(msg, keysAndValues...) } -func (l *slogLogger) Warnf(msg string, args ...any) { - l.logger.Warn(fmt.Sprintf(msg, args...)) +// Fatal logs a message at error level using the singleton logger and exits the program. +func Fatal(msg string) { + zap.S().Fatal(msg) } -func (l *slogLogger) Errorf(msg string, args ...any) { - l.logger.Error(fmt.Sprintf(msg, args...)) +// Fatalf logs a message at error level using the singleton logger and exits the program. +func Fatalf(msg string, args ...any) { + zap.S().Fatalf(msg, args...) } -func (l *slogLogger) Panicf(msg string, args ...any) { - l.Panic(fmt.Sprintf(msg, args...)) +// Fatalw logs a message at error level using the singleton logger with additional key-value pairs and exits the program. +func Fatalw(msg string, keysAndValues ...any) { + zap.S().Fatalw(msg, keysAndValues...) } -func (l *slogLogger) Debug(msg string, args ...any) { - l.logger.Debug(msg, args...) -} - -func (l *slogLogger) Info(msg string, args ...any) { - l.logger.Info(msg, args...) -} - -func (l *slogLogger) Warn(msg string, args ...any) { - l.logger.Warn(msg, args...) -} - -func (l *slogLogger) Error(msg string, args ...any) { - l.logger.Error(msg, args...) -} - -func (l *slogLogger) Panic(msg string) { - var pcs [1]uintptr - runtime.Callers(2, pcs[:]) // skip [Callers, Panic] - record := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0]) - _ = l.logger.Handler().Handle(context.Background(), record) - panic(msg) -} - -func unstructuredLogs() bool { - unstructuredLogs, err := strconv.ParseBool(os.Getenv("UNSTRUCTURED_LOGS")) - if err != nil { - // at this point if the error is not nil, the env var wasn't set, or is "" - // which means we just default to outputting unstructured logs. - return true - } - return unstructuredLogs +// NewLogr returns a logr.Logger which uses zap logger +func NewLogr() logr.Logger { + return zapr.NewLogger(zap.L()) } // Initialize creates and configures the appropriate logger. @@ -145,50 +128,33 @@ func unstructuredLogs() bool { // with only time and LogLevelType (INFO, DEBUG, ERROR, WARN)). // Otherwise it will create a standard structured slog logger func Initialize() { + var config zap.Config if unstructuredLogs() { - w := os.Stderr - - handler := tint.NewHandler(w, &tint.Options{ - Level: getLogLevel(), - TimeFormat: time.Kitchen, - }) - - slogger := slog.New(handler) - - slog.SetDefault(slogger) - log = &slogLogger{logger: slogger} + config = zap.NewDevelopmentConfig() + config.EncoderConfig.EncodeLevel = zapcore.CapitalColorLevelEncoder + config.EncoderConfig.EncodeTime = zapcore.TimeEncoderOfLayout(time.Kitchen) + config.OutputPaths = []string{"stderr"} } else { - w := os.Stdout - - handler := slog.NewJSONHandler(w, &slog.HandlerOptions{ - Level: getLogLevel(), - }) - - slogger := slog.New(handler) - - slog.SetDefault(slogger) - log = &slogLogger{logger: slogger} + config = zap.NewProductionConfig() + config.OutputPaths = []string{"stdout"} } -} -// GetLogger returns a context-specific logger -func GetLogger(component string) Logger { - if slogger, ok := log.(*slogLogger); ok { - return &slogLogger{ - logger: slogger.logger.With("component", component), - } + // Set log level based on current debug flag + if viper.GetBool("debug") { + config.Level = zap.NewAtomicLevelAt(zap.DebugLevel) + } else { + config.Level = zap.NewAtomicLevelAt(zap.InfoLevel) } - return log + zap.ReplaceGlobals(zap.Must(config.Build())) } -// getLogLevel returns the appropriate slog.Level based on the debug flag -func getLogLevel() slog.Level { - var level slog.Level - if viper.GetBool("debug") { - level = slog.LevelDebug - } else { - level = slog.LevelInfo +func unstructuredLogs() bool { + unstructuredLogs, err := strconv.ParseBool(os.Getenv("UNSTRUCTURED_LOGS")) + if err != nil { + // at this point if the error is not nil, the env var wasn't set, or is "" + // which means we just default to outputting unstructured logs. + return true } - return level + return unstructuredLogs } diff --git a/pkg/logger/logger_test.go b/pkg/logger/logger_test.go index 622b186c0..16f8a94aa 100644 --- a/pkg/logger/logger_test.go +++ b/pkg/logger/logger_test.go @@ -12,6 +12,7 @@ import ( "github.com/stretchr/testify/assert" ) +// TestUnstructuredLogsCheck tests the unstructuredLogs function func TestUnstructuredLogsCheck(t *testing.T) { //nolint:paralleltest // Uses environment variables tests := []struct { name string @@ -41,25 +42,33 @@ func TestUnstructuredLogsCheck(t *testing.T) { //nolint:paralleltest // Uses env } } +// TestStructuredLogger tests the structured logger functionality +// TODO: Keeping this for migration but can be removed as we don't need really need to test zap func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environment variables - unformattedLogTestCases := []struct { - level string // The log level to test - message string // The message to log - key string // Key for structured logging - value string // Value for structured logging - contains bool // Whether to check if output contains the message + const ( + levelDebug = "debug" + levelInfo = "info" + levelWarn = "warn" + levelError = "error" + levelDPanic = "dpanic" + levelPanic = "panic" + ) + // Test cases for basic logging methods (Debug, Info, Warn, etc.) + basicLogTestCases := []struct { + level string // The log level to test + message string // The message to log }{ - {"DEBUG", "debug message", "key", "value", true}, - {"INFO", "info message", "key", "value", true}, - {"WARN", "warn message", "key", "value", true}, - {"ERROR", "error message", "key", "value", true}, + {levelDebug, "debug message"}, + {levelInfo, "info message"}, + {levelWarn, "warn message"}, + {levelError, "error message"}, + {levelDPanic, "dpanic message"}, + {levelPanic, "panic message"}, } - for _, tc := range unformattedLogTestCases { - t.Run("NonFormattedLogs", func(t *testing.T) { - + for _, tc := range basicLogTestCases { //nolint:paralleltest // Uses environment variables + t.Run("BasicLogs_"+tc.level, func(t *testing.T) { // we create a pipe to capture the output of the log - // so we can test that the logger logs the right message originalStdout := os.Stdout r, w, _ := os.Pipe() os.Stdout = w @@ -70,21 +79,114 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm viper.SetDefault("debug", true) Initialize() + + // Handle panic and fatal recovery + defer func() { + if r := recover(); r != nil { + if tc.level != levelPanic && tc.level != levelDPanic { + t.Errorf("Unexpected panic for level %s: %v", tc.level, r) + } + } + }() + + // Log using basic methods + switch tc.level { + case levelDebug: + Debug(tc.message) + case levelInfo: + Info(tc.message) + case levelWarn: + Warn(tc.message) + case levelError: + Error(tc.message) + case levelDPanic: + DPanic(tc.message) + case levelPanic: + Panic(tc.message) + } + + w.Close() os.Stdout = originalStdout - // Log the message based on the level + // Read the captured output + var capturedOutput bytes.Buffer + io.Copy(&capturedOutput, r) + output := capturedOutput.String() + + // Parse JSON output + var logEntry map[string]any + if err := json.Unmarshal([]byte(output), &logEntry); err != nil { + t.Fatalf("Failed to parse JSON log output: %v", err) + } + + // Check level + if level, ok := logEntry["level"].(string); !ok || level != tc.level { + t.Errorf("Expected level %s, got %v", tc.level, logEntry["level"]) + } + + // Check message + if msg, ok := logEntry["msg"].(string); !ok || msg != tc.message { + t.Errorf("Expected message %s, got %v", tc.message, logEntry["msg"]) + } + }) + } + + // Test cases for structured logging methods (Debugw, Infow, etc.) + structuredLogTestCases := []struct { + level string // The log level to test + message string // The message to log + key string // Key for structured logging + value string // Value for structured logging + }{ + {levelDebug, "debug message", "key", "value"}, + {levelInfo, "info message", "key", "value"}, + {levelWarn, "warn message", "key", "value"}, + {levelError, "error message", "key", "value"}, + {levelDPanic, "dpanic message", "key", "value"}, + {levelPanic, "panic message", "key", "value"}, + } + + for _, tc := range structuredLogTestCases { //nolint:paralleltest // Uses environment variables + t.Run("StructuredLogs_"+tc.level, func(t *testing.T) { + // we create a pipe to capture the output of the log + originalStdout := os.Stdout + r, w, _ := os.Pipe() + os.Stdout = w + + os.Setenv("UNSTRUCTURED_LOGS", "false") + defer os.Unsetenv("UNSTRUCTURED_LOGS") + + viper.SetDefault("debug", true) + + Initialize() + + // Handle panic and fatal recovery + defer func() { + if r := recover(); r != nil { + if tc.level != "panic" && tc.level != levelDPanic { + t.Errorf("Unexpected panic for level %s: %v", tc.level, r) + } + } + }() + + // Log using structured methods switch tc.level { - case "DEBUG": - log.Debug(tc.message, tc.key, tc.value) - case "INFO": - log.Info(tc.message, tc.key, tc.value) - case "WARN": - log.Warn(tc.message, tc.key, tc.value) - case "ERROR": - log.Error(tc.message, tc.key, tc.value) + case levelDebug: + Debugw(tc.message, tc.key, tc.value) + case levelInfo: + Infow(tc.message, tc.key, tc.value) + case levelWarn: + Warnw(tc.message, tc.key, tc.value) + case levelError: + Errorw(tc.message, tc.key, tc.value) + case levelDPanic: + DPanicw(tc.message, tc.key, tc.value) + case levelPanic: + Panicw(tc.message, tc.key, tc.value) } w.Close() + os.Stdout = originalStdout // Read the captured output var capturedOutput bytes.Buffer @@ -92,7 +194,7 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm output := capturedOutput.String() // Parse JSON output - var logEntry map[string]interface{} + var logEntry map[string]any if err := json.Unmarshal([]byte(output), &logEntry); err != nil { t.Fatalf("Failed to parse JSON log output: %v", err) } @@ -114,6 +216,7 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm }) } + // Test cases for formatted logging methods (Debugf, Infof, etc.) formattedLogTestCases := []struct { level string message string @@ -122,16 +225,17 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm expected string contains bool }{ - {"DEBUG", "debug message %s and %s", "key", "value", "debug message key and value", true}, - {"INFO", "info message %s and %s", "key", "value", "info message key and value", true}, - {"WARN", "warn message %s and %s", "key", "value", "warn message key and value", true}, - {"ERROR", "error message %s and %s", "key", "value", "error message key and value", true}, + {levelDebug, "debug message %s and %s", "key", "value", "debug message key and value", true}, + {levelInfo, "info message %s and %s", "key", "value", "info message key and value", true}, + {levelWarn, "warn message %s and %s", "key", "value", "warn message key and value", true}, + {levelError, "error message %s and %s", "key", "value", "error message key and value", true}, + {levelDPanic, "dpanic message %s and %s", "key", "value", "dpanic message key and value", true}, + {levelPanic, "panic message %s and %s", "key", "value", "panic message key and value", true}, } for _, tc := range formattedLogTestCases { //nolint:paralleltest // Uses environment variables - t.Run("FormattedLogs", func(t *testing.T) { + t.Run("FormattedLogs_"+tc.level, func(t *testing.T) { // we create a pipe to capture the output of the log - // so we can test that the logger logs the right message originalStdout := os.Stdout r, w, _ := os.Pipe() os.Stdout = w @@ -142,31 +246,41 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm viper.SetDefault("debug", true) Initialize() - os.Stdout = originalStdout - // Log the message based on the level + // Handle panic and fatal recovery + defer func() { + if r := recover(); r != nil { + if tc.level != levelPanic && tc.level != levelDPanic { + t.Errorf("Unexpected panic for level %s: %v", tc.level, r) + } + } + }() + + // Log using formatted methods switch tc.level { - case "DEBUG": - log.Debugf(tc.message, tc.key, tc.value) - case "INFO": - log.Infof(tc.message, tc.key, tc.value) - case "WARN": - log.Warnf(tc.message, tc.key, tc.value) - case "ERROR": - log.Errorf(tc.message, tc.key, tc.value) + case levelDebug: + Debugf(tc.message, tc.key, tc.value) + case levelInfo: + Infof(tc.message, tc.key, tc.value) + case levelWarn: + Warnf(tc.message, tc.key, tc.value) + case levelError: + Errorf(tc.message, tc.key, tc.value) + case levelDPanic: + DPanicf(tc.message, tc.key, tc.value) + case levelPanic: + Panicf(tc.message, tc.key, tc.value) } - w.Close() + os.Stdout = originalStdout // Read the captured output var capturedOutput bytes.Buffer io.Copy(&capturedOutput, r) output := capturedOutput.String() - capturedOutput.Reset() - // Parse JSON output - var logEntry map[string]interface{} + var logEntry map[string]any if err := json.Unmarshal([]byte(output), &logEntry); err != nil { t.Fatalf("Failed to parse JSON log output: %v", err) } @@ -178,15 +292,25 @@ func TestStructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environm // Check message if msg, ok := logEntry["msg"].(string); !ok || msg != tc.expected { - t.Errorf(tc.expected, tc.message, logEntry["msg"]) + t.Errorf("Expected message %s, got %v", tc.expected, logEntry["msg"]) } }) } } +// TestUnstructuredLogger tests the unstructured logger functionality func TestUnstructuredLogger(t *testing.T) { //nolint:paralleltest // Uses environment variables // we only test for the formatted logs here because the unstructured logs // do not contain the key/value pair format that the structured logs do + const ( + levelDebug = "DEBUG" + levelInfo = "INFO" + levelWarn = "WARN" + levelError = "ERROR" + levelDPanic = "DPANIC" + levelPanic = "PANIC" + ) + formattedLogTestCases := []struct { level string message string @@ -194,14 +318,16 @@ func TestUnstructuredLogger(t *testing.T) { //nolint:paralleltest // Uses enviro value string expected string }{ - {"DBG", "debug message %s and %s", "key", "value", "debug message key and value"}, - {"INF", "info message %s and %s", "key", "value", "info message key and value"}, - {"WRN", "warn message %s and %s", "key", "value", "warn message key and value"}, - {"ERR", "error message %s and %s", "key", "value", "error message key and value"}, + {levelDebug, "debug message %s and %s", "key", "value", "debug message key and value"}, + {levelInfo, "info message %s and %s", "key", "value", "info message key and value"}, + {levelWarn, "warn message %s and %s", "key", "value", "warn message key and value"}, + {levelError, "error message %s and %s", "key", "value", "error message key and value"}, + {levelDPanic, "error message %s and %s", "key", "value", "dpanic message key and value"}, + {levelPanic, "error message %s and %s", "key", "value", "panic message key and value"}, } for _, tc := range formattedLogTestCases { //nolint:paralleltest // Uses environment variables - t.Run("FormattedLogs", func(t *testing.T) { + t.Run("FormattedLogs_"+tc.level, func(t *testing.T) { // we create a pipe to capture the output of the log // so we can test that the logger logs the right message @@ -212,21 +338,35 @@ func TestUnstructuredLogger(t *testing.T) { //nolint:paralleltest // Uses enviro viper.SetDefault("debug", true) Initialize() - os.Stderr = originalStderr + + // Handle panic recovery for DPANIC and PANIC levels + defer func() { + if r := recover(); r != nil { + // Expected for panic levels + if tc.level != "PANIC" && tc.level != "DPANIC" { + t.Errorf("Unexpected panic for level %s: %v", tc.level, r) + } + } + }() // Log the message based on the level switch tc.level { - case "DBG": - log.Debugf(tc.message, tc.key, tc.value) - case "INF": - log.Infof(tc.message, tc.key, tc.value) - case "WRN": - log.Warnf(tc.message, tc.key, tc.value) - case "ERR": - log.Errorf(tc.message, tc.key, tc.value) + case levelDebug: + Debugf(tc.message, tc.key, tc.value) + case levelInfo: + Infof(tc.message, tc.key, tc.value) + case levelWarn: + Warnf(tc.message, tc.key, tc.value) + case levelError: + Errorf(tc.message, tc.key, tc.value) + case levelDPanic: + DPanicf(tc.message, tc.key, tc.value) + case levelPanic: + Panicf(tc.message, tc.key, tc.value) } w.Close() + os.Stderr = originalStderr // Read the captured output var capturedOutput bytes.Buffer @@ -256,7 +396,7 @@ func TestInitialize(t *testing.T) { //nolint:paralleltest // Uses environment va Initialize() // Log a test message - log.Info("test message", "key", "value") + Info("test message") // Restore stdout w.Close() @@ -268,7 +408,7 @@ func TestInitialize(t *testing.T) { //nolint:paralleltest // Uses environment va output := buf.String() // Verify JSON format - var logEntry map[string]interface{} + var logEntry map[string]any if err := json.Unmarshal([]byte(output), &logEntry); err != nil { t.Fatalf("Failed to parse JSON log output: %v", err) } @@ -293,7 +433,7 @@ func TestInitialize(t *testing.T) { //nolint:paralleltest // Uses environment va Initialize() // Log a test message - log.Info("test message", "key", "value") + Info("test message") // Restore stderr w.Close() @@ -314,42 +454,3 @@ func TestInitialize(t *testing.T) { //nolint:paralleltest // Uses environment va } }) } - -// TestGetLogger tests the GetLogger function -func TestGetLogger(t *testing.T) { //nolint:paralleltest // Uses environment variables - // Set up structured logger for testing - os.Setenv("UNSTRUCTURED_LOGS", "false") - defer os.Unsetenv("UNSTRUCTURED_LOGS") - - // Redirect stdout to capture output - oldStdout := os.Stdout - r, w, _ := os.Pipe() - os.Stdout = w - - // Initialize and get a component logger - Initialize() - componentLogger := GetLogger("test-component") - - // Log a test message - componentLogger.Info("component message") - - // Restore stdout - w.Close() - os.Stdout = oldStdout - - // Read captured output - var buf bytes.Buffer - buf.ReadFrom(r) - output := buf.String() - - // Parse JSON output - var logEntry map[string]interface{} - if err := json.Unmarshal([]byte(output), &logEntry); err != nil { - t.Fatalf("Failed to parse JSON log output: %v", err) - } - - // Verify the component was added - if component, ok := logEntry["component"].(string); !ok || component != "test-component" { - t.Errorf("Expected component='test-component', got %v", logEntry["component"]) - } -} diff --git a/pkg/logger/logr.go b/pkg/logger/logr.go deleted file mode 100644 index 4d4f8c9ea..000000000 --- a/pkg/logger/logr.go +++ /dev/null @@ -1,74 +0,0 @@ -// Package logger provides a logging capability for toolhive for running locally as a CLI and in Kubernetes -package logger - -import ( - "github.com/go-logr/logr" -) - -// NewLogr returns a logr.Logger which uses the singleton logger. -func NewLogr() logr.Logger { - return logr.New(&toolhiveLogSink{logger: log}) -} - -// toolhiveLogSink adapts our logger to the logr.LogSink interface -type toolhiveLogSink struct { - logger Logger - name string -} - -// Init implements logr.LogSink -func (*toolhiveLogSink) Init(logr.RuntimeInfo) { - // Nothing to do -} - -// Enabled implements logr.LogSink -func (*toolhiveLogSink) Enabled(int) bool { - // Always enable logging - return true -} - -// Info implements logr.LogSink -func (l *toolhiveLogSink) Info(_ int, msg string, keysAndValues ...interface{}) { - l.logger.Info(msg, keysAndValues...) -} - -// Error implements logr.LogSink -func (l *toolhiveLogSink) Error(err error, msg string, keysAndValues ...interface{}) { - args := append([]interface{}{"error", err}, keysAndValues...) - l.logger.Error(msg, args...) -} - -// WithValues implements logr.LogSink -func (l *toolhiveLogSink) WithValues(keysAndValues ...interface{}) logr.LogSink { - // Create a new logger with the additional key-value pairs - if slogger, ok := l.logger.(*slogLogger); ok { - newLogger := &slogLogger{ - logger: slogger.logger.With(keysAndValues...), - } - return &toolhiveLogSink{ - logger: newLogger, - name: l.name, - } - } - - // If we can't add the values, just return a sink with the same logger - return &toolhiveLogSink{ - logger: l.logger, - name: l.name, - } -} - -// WithName implements logr.LogSink -func (l *toolhiveLogSink) WithName(name string) logr.LogSink { - // If we already have a name, append the new name - newName := name - if l.name != "" { - newName = l.name + "/" + name - } - - // Create a new sink with the component logger - return &toolhiveLogSink{ - logger: GetLogger(newName), - name: newName, - } -}