diff --git a/logger/level_test.go b/logger/level_test.go new file mode 100644 index 0000000..fabd746 --- /dev/null +++ b/logger/level_test.go @@ -0,0 +1,235 @@ +package logger + +import ( + "context" + "log/slog" + "os" + "testing" + "time" +) + +func TestParseLevel(t *testing.T) { + tests := []struct { + name string + input string + expected slog.Level + expectError bool + }{ + {"empty string", "", slog.LevelInfo, false}, + {"DEBUG upper", "DEBUG", slog.LevelDebug, false}, + {"debug lower", "debug", slog.LevelDebug, false}, + {"INFO upper", "INFO", slog.LevelInfo, false}, + {"info lower", "info", slog.LevelInfo, false}, + {"WARN upper", "WARN", slog.LevelWarn, false}, + {"warn lower", "warn", slog.LevelWarn, false}, + {"ERROR upper", "ERROR", slog.LevelError, false}, + {"error lower", "error", slog.LevelError, false}, + {"invalid level", "invalid", slog.LevelInfo, true}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + level, err := ParseLevel(tt.input) + if tt.expectError { + if err == nil { + t.Errorf("expected error for input %q, got nil", tt.input) + } + } else { + if err != nil { + t.Errorf("unexpected error for input %q: %v", tt.input, err) + } + if level != tt.expected { + t.Errorf("expected level %v for input %q, got %v", tt.expected, tt.input, level) + } + } + }) + } +} + +func TestSetLevel(t *testing.T) { + // Store original level to restore later + originalLevel := Level.Level() + defer Level.Set(originalLevel) + + SetLevel(slog.LevelDebug) + if Level.Level() != slog.LevelDebug { + t.Errorf("expected Level to be Debug, got %v", Level.Level()) + } + + SetLevel(slog.LevelError) + if Level.Level() != slog.LevelError { + t.Errorf("expected Level to be Error, got %v", Level.Level()) + } +} + +func TestSetOTLPLevel(t *testing.T) { + // Store original level to restore later + originalLevel := OTLPLevel.Level() + defer OTLPLevel.Set(originalLevel) + + SetOTLPLevel(slog.LevelWarn) + if OTLPLevel.Level() != slog.LevelWarn { + t.Errorf("expected OTLPLevel to be Warn, got %v", OTLPLevel.Level()) + } + + SetOTLPLevel(slog.LevelDebug) + if OTLPLevel.Level() != slog.LevelDebug { + t.Errorf("expected OTLPLevel to be Debug, got %v", OTLPLevel.Level()) + } +} + +func TestOTLPLevelHandler(t *testing.T) { + // Create a mock handler that counts calls + callCount := 0 + mockHandler := &mockHandler{ + handleFunc: func(ctx context.Context, r slog.Record) error { + callCount++ + return nil + }, + } + + // Set OTLP level to Warn + originalLevel := OTLPLevel.Level() + defer OTLPLevel.Set(originalLevel) + OTLPLevel.Set(slog.LevelWarn) + + // Create OTLP level handler + handler := newOTLPLevelHandler(mockHandler) + + ctx := context.Background() + + // Test that Debug and Info are filtered out + if handler.Enabled(ctx, slog.LevelDebug) { + t.Error("Debug level should be disabled when OTLP level is Warn") + } + if handler.Enabled(ctx, slog.LevelInfo) { + t.Error("Info level should be disabled when OTLP level is Warn") + } + + // Test that Warn and Error are enabled + if !handler.Enabled(ctx, slog.LevelWarn) { + t.Error("Warn level should be enabled when OTLP level is Warn") + } + if !handler.Enabled(ctx, slog.LevelError) { + t.Error("Error level should be enabled when OTLP level is Warn") + } + + // Test that Handle respects level filtering + now := time.Now() + debugRecord := slog.NewRecord(now, slog.LevelDebug, "debug message", 0) + warnRecord := slog.NewRecord(now, slog.LevelWarn, "warn message", 0) + + handler.Handle(ctx, debugRecord) + if callCount != 0 { + t.Error("Debug record should not be passed to underlying handler") + } + + handler.Handle(ctx, warnRecord) + if callCount != 1 { + t.Error("Warn record should be passed to underlying handler") + } +} + +func TestEnvironmentVariables(t *testing.T) { + tests := []struct { + name string + envVar string + envValue string + configPrefix string + testFunc func(t *testing.T) + }{ + { + name: "LOG_LEVEL sets stderr level", + envVar: "LOG_LEVEL", + envValue: "ERROR", + testFunc: func(t *testing.T) { + // Reset the setup state + resetLoggerSetup() + + // Call setupStdErrHandler which should read the env var + handler := setupStdErrHandler() + if handler == nil { + t.Fatal("setupStdErrHandler returned nil") + } + + if Level.Level() != slog.LevelError { + t.Errorf("expected Level to be Error after setting LOG_LEVEL=ERROR, got %v", Level.Level()) + } + }, + }, + { + name: "Prefixed LOG_LEVEL", + envVar: "TEST_LOG_LEVEL", + envValue: "DEBUG", + configPrefix: "TEST", + testFunc: func(t *testing.T) { + ConfigPrefix = "TEST" + defer func() { ConfigPrefix = "" }() + + resetLoggerSetup() + handler := setupStdErrHandler() + if handler == nil { + t.Fatal("setupStdErrHandler returned nil") + } + + if Level.Level() != slog.LevelDebug { + t.Errorf("expected Level to be Debug after setting TEST_LOG_LEVEL=DEBUG, got %v", Level.Level()) + } + }, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + // Store original env value and level + originalEnv := os.Getenv(tt.envVar) + originalLevel := Level.Level() + defer func() { + os.Setenv(tt.envVar, originalEnv) + Level.Set(originalLevel) + }() + + // Set test environment variable + os.Setenv(tt.envVar, tt.envValue) + + // Run the test + tt.testFunc(t) + }) + } +} + +// mockHandler is a simple mock implementation of slog.Handler for testing +type mockHandler struct { + handleFunc func(ctx context.Context, r slog.Record) error +} + +func (m *mockHandler) Enabled(ctx context.Context, level slog.Level) bool { + return true +} + +func (m *mockHandler) Handle(ctx context.Context, r slog.Record) error { + if m.handleFunc != nil { + return m.handleFunc(ctx, r) + } + return nil +} + +func (m *mockHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return m +} + +func (m *mockHandler) WithGroup(name string) slog.Handler { + return m +} + +// resetLoggerSetup resets the sync.Once instances for testing +func resetLoggerSetup() { + // Reset package-level variables + textLogger = nil + otlpLogger = nil + multiLogger = nil + + // Note: We can't easily reset sync.Once instances in tests, + // but for the specific test we're doing (environment variable parsing) + // we can test the setupStdErrHandler function directly +} diff --git a/logger/logger.go b/logger/logger.go index 99961dd..9955b18 100644 --- a/logger/logger.go +++ b/logger/logger.go @@ -18,12 +18,15 @@ // - Context propagation for request-scoped logging // // Environment variables: -// - DEBUG: Enable debug level logging (configurable prefix via ConfigPrefix) +// - LOG_LEVEL: Set stderr log level (DEBUG, INFO, WARN, ERROR) (configurable prefix via ConfigPrefix) +// - OTLP_LOG_LEVEL: Set OTLP log level independently (configurable prefix via ConfigPrefix) +// - DEBUG: Enable debug level logging for backward compatibility (configurable prefix via ConfigPrefix) // - INVOCATION_ID: Systemd detection for timestamp handling package logger import ( "context" + "fmt" "log" "log/slog" "os" @@ -43,6 +46,16 @@ import ( // This enables multiple services to have independent logging configuration. var ConfigPrefix = "" +var ( + // Level controls the log level for the default stderr logger. + // Can be changed at runtime to adjust logging verbosity. + Level = new(slog.LevelVar) // Info by default + + // OTLPLevel controls the log level for OTLP output. + // Can be changed independently from the stderr logger level. + OTLPLevel = new(slog.LevelVar) // Info by default +) + var ( textLogger *slog.Logger otlpLogger *slog.Logger @@ -56,21 +69,64 @@ var ( mu sync.Mutex ) -func setupStdErrHandler() slog.Handler { - programLevel := new(slog.LevelVar) // Info by default +// SetLevel sets the log level for the default stderr logger. +// This affects the primary application logger returned by Setup(). +func SetLevel(level slog.Level) { + Level.Set(level) +} - envVar := "DEBUG" +// SetOTLPLevel sets the log level for OTLP output. +// This affects the logger returned by SetupOLTP() and the OTLP portion of SetupMultiLogger(). +func SetOTLPLevel(level slog.Level) { + OTLPLevel.Set(level) +} + +// ParseLevel converts a string log level to slog.Level. +// Supported levels: "DEBUG", "INFO", "WARN", "ERROR" (case insensitive). +// Returns an error for unrecognized level strings. +func ParseLevel(level string) (slog.Level, error) { + switch { + case level == "": + return slog.LevelInfo, nil + case level == "DEBUG" || level == "debug": + return slog.LevelDebug, nil + case level == "INFO" || level == "info": + return slog.LevelInfo, nil + case level == "WARN" || level == "warn": + return slog.LevelWarn, nil + case level == "ERROR" || level == "error": + return slog.LevelError, nil + default: + return slog.LevelInfo, fmt.Errorf("unknown log level: %s", level) + } +} + +func setupStdErrHandler() slog.Handler { + // Parse LOG_LEVEL environment variable + logLevelVar := "LOG_LEVEL" if len(ConfigPrefix) > 0 { - envVar = ConfigPrefix + "_" + envVar + logLevelVar = ConfigPrefix + "_" + logLevelVar } - if opt := os.Getenv(envVar); len(opt) > 0 { - if debug, _ := strconv.ParseBool(opt); debug { - programLevel.Set(slog.LevelDebug) + if levelStr := os.Getenv(logLevelVar); levelStr != "" { + if level, err := ParseLevel(levelStr); err == nil { + Level.Set(level) } } - logOptions := &slog.HandlerOptions{Level: programLevel} + // Maintain backward compatibility with DEBUG environment variable + debugVar := "DEBUG" + if len(ConfigPrefix) > 0 { + debugVar = ConfigPrefix + "_" + debugVar + } + + if opt := os.Getenv(debugVar); len(opt) > 0 { + if debug, _ := strconv.ParseBool(opt); debug { + Level.Set(slog.LevelDebug) + } + } + + logOptions := &slog.HandlerOptions{Level: Level} if len(os.Getenv("INVOCATION_ID")) > 0 { // don't add timestamps when running under systemd @@ -88,6 +144,18 @@ func setupStdErrHandler() slog.Handler { func setupOtlpLogger() *slog.Logger { setupOtlp.Do(func() { + // Parse OTLP_LOG_LEVEL environment variable + otlpLevelVar := "OTLP_LOG_LEVEL" + if len(ConfigPrefix) > 0 { + otlpLevelVar = ConfigPrefix + "_" + otlpLevelVar + } + + if levelStr := os.Getenv(otlpLevelVar); levelStr != "" { + if level, err := ParseLevel(levelStr); err == nil { + OTLPLevel.Set(level) + } + } + // Create our buffering exporter // It will buffer until tracing is configured bufferingExp := newBufferingExporter() @@ -107,8 +175,9 @@ func setupOtlpLogger() *slog.Logger { // Set global provider global.SetLoggerProvider(provider) - // Create slog handler - handler := newLogFmtHandler(otelslog.NewHandler("common")) + // Create slog handler with level control + baseHandler := newLogFmtHandler(otelslog.NewHandler("common")) + handler := newOTLPLevelHandler(baseHandler) otlpLogger = slog.New(handler) }) return otlpLogger diff --git a/logger/otlp_handler.go b/logger/otlp_handler.go new file mode 100644 index 0000000..d31e0db --- /dev/null +++ b/logger/otlp_handler.go @@ -0,0 +1,48 @@ +package logger + +import ( + "context" + "log/slog" +) + +// otlpLevelHandler is a wrapper that enforces level checking for OTLP handlers. +// This allows independent level control for OTLP output separate from stderr logging. +type otlpLevelHandler struct { + next slog.Handler +} + +// newOTLPLevelHandler creates a new OTLP level wrapper handler. +func newOTLPLevelHandler(next slog.Handler) slog.Handler { + return &otlpLevelHandler{ + next: next, + } +} + +// Enabled checks if the log level should be processed by the OTLP handler. +// It uses the OTLPLevel variable to determine if the record should be processed. +func (h *otlpLevelHandler) Enabled(ctx context.Context, level slog.Level) bool { + return level >= OTLPLevel.Level() +} + +// Handle processes the log record if the level is enabled. +// If disabled by level checking, the record is silently dropped. +func (h *otlpLevelHandler) Handle(ctx context.Context, r slog.Record) error { + if !h.Enabled(ctx, r.Level) { + return nil + } + return h.next.Handle(ctx, r) +} + +// WithAttrs returns a new handler with the specified attributes added. +func (h *otlpLevelHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return &otlpLevelHandler{ + next: h.next.WithAttrs(attrs), + } +} + +// WithGroup returns a new handler with the specified group name. +func (h *otlpLevelHandler) WithGroup(name string) slog.Handler { + return &otlpLevelHandler{ + next: h.next.WithGroup(name), + } +}