diff --git a/README.md b/README.md index 20ae889..e03558b 100644 --- a/README.md +++ b/README.md @@ -16,6 +16,70 @@


+## Features + +- **Text Logging**: Traditional text-based logging with customizable prefixes and levels +- **JSON Logging**: Structured JSON logging using Go's `slog` library (Go 1.21+) +- **Level-based Filtering**: Support for TRACE, DEBUG, INFO, WARN, ERROR, and DISABLED levels +- **Scope-based Configuration**: Different log levels for different scopes/components +- **Environment Variable Configuration**: Configure log levels via environment variables +- **Thread-safe**: All logging operations are thread-safe + +## Usage + +### Text Logging (Default) + +```go +import "github.com/pion/logging" + +// Create a logger factory +factory := logging.NewDefaultLoggerFactory() + +// Create loggers for different scopes +apiLogger := factory.NewLogger("api") +dbLogger := factory.NewLogger("database") + +// Log messages +apiLogger.Info("API server started") +apiLogger.Debug("Processing request") +dbLogger.Error("Database connection failed") +``` + +### JSON Logging + +```go +import "github.com/pion/logging" + +// Create a JSON logger factory +factory := logging.NewJSONLoggerFactory() + +// Create loggers for different scopes +apiLogger := factory.NewLogger("api") +dbLogger := factory.NewLogger("database") + +// Log messages with structured data +apiLogger.Info("API server started") +apiLogger.Debug("Processing request", "method", "GET", "path", "/users") +dbLogger.Error("Database connection failed", "error", "connection timeout") +``` + +### Environment Variable Configuration + +Set environment variables to configure log levels: + +```bash +# Enable all log levels +export PION_LOG_TRACE=all +export PION_LOG_DEBUG=all +export PION_LOG_INFO=all +export PION_LOG_WARN=all +export PION_LOG_ERROR=all + +# Enable specific scopes +export PION_LOG_DEBUG=api,database +export PION_LOG_INFO=feature1,feature2 +``` + ### Roadmap The library is used as a part of our WebRTC implementation. Please refer to that [roadmap](https://github.com/pion/webrtc/issues/9) to track our major milestones. diff --git a/examples/example_json_logger.go b/examples/example_json_logger.go new file mode 100644 index 0000000..b75d3a8 --- /dev/null +++ b/examples/example_json_logger.go @@ -0,0 +1,41 @@ +// SPDX-FileCopyrightText: 2023 The Pion community +// SPDX-License-Identifier: MIT + +package main + +import ( + "os" + + "github.com/pion/logging" +) + +func main() { + // Create a JSON logger factory + factory := logging.NewJSONLoggerFactory(logging.WithJSONWriter(os.Stdout)) + + // Create loggers for different scopes + apiLogger := factory.NewLogger("api") + dbLogger := factory.NewLogger("database") + authLogger := factory.NewLogger("auth") + + // Log some messages + apiLogger.Info("API server started") + apiLogger.Debugf("Processing request method=%s path=%s", "GET", "/users") + apiLogger.Warnf("Rate limit approaching requests=%d limit=%d", 95, 100) + + dbLogger.Info("Database connection established") + dbLogger.Debugf("Executing query query=%q duration_ms=%d", "SELECT * FROM users", 15) + + authLogger.Errorf("Authentication failed user_id=%s reason=%s", "12345", "invalid_token") + authLogger.Infof("User logged in user_id=%s ip=%s", "67890", "192.168.1.100") + + // nolint:lll + // Example output will be JSON formatted like: + // {"time":"2023-12-07T10:30:00Z","level":"INFO","msg":"API server started","scope":"api"} + // {"time":"2023-12-07T10:30:00Z","level":"DEBUG","msg":"Processing request","scope":"api","method":"GET","path":"/users"} + // {"time":"2023-12-07T10:30:00Z","level":"WARN","msg":"Rate limit approaching","scope":"api","requests":95,"limit":100} + // {"time":"2023-12-07T10:30:00Z","level":"INFO","msg":"Database connection established","scope":"database"} + // {"time":"2023-12-07T10:30:00Z","level":"DEBUG","msg":"Executing query","scope":"database","query":"SELECT * FROM users","duration_ms":15} + // {"time":"2023-12-07T10:30:00Z","level":"ERROR","msg":"Authentication failed","scope":"auth","user_id":"12345","reason":"invalid_token"} + // {"time":"2023-12-07T10:30:00Z","level":"INFO","msg":"User logged in","scope":"auth","user_id":"67890","ip":"192.168.1.100"} +} diff --git a/json_logger.go b/json_logger.go new file mode 100644 index 0000000..62ca5e8 --- /dev/null +++ b/json_logger.go @@ -0,0 +1,336 @@ +// SPDX-FileCopyrightText: 2023 The Pion community +// SPDX-License-Identifier: MIT + +package logging + +import ( + "context" + "fmt" + "io" + "log/slog" + "os" + "strings" + "time" +) + +// jsonLeveledLogger provides JSON structured logging using Go's slog library. +type jsonLeveledLogger struct { + level LogLevel + writer *loggerWriter + logger *slog.Logger + scope string +} + +var _ LeveledLogger = (*jsonLeveledLogger)(nil) + +func (jl *jsonLeveledLogger) Slog() *slog.Logger { + return jl.logger +} + +// newJSONLeveledLoggerForScope returns a configured JSON LeveledLogger. +func newJSONLeveledLoggerForScope(scope string, level LogLevel, writer io.Writer) *jsonLeveledLogger { + if writer == nil { + writer = os.Stderr + } + + // Create a JSON handler with custom options + lw := &loggerWriter{output: writer} + logger := slog.New(newJSONHandlerHelper(lw)) + + return &jsonLeveledLogger{ + level: level, + writer: lw, + logger: logger, + scope: scope, + } +} + +// WithOutput is a chainable configuration function which sets the logger's +// logging output to the supplied io.Writer. +func (jl *jsonLeveledLogger) WithOutput(output io.Writer) LeveledLogger { + if output == nil { + output = os.Stderr + } + jl.writer.SetOutput(output) + + return jl +} + +// newJSONHandlerHelper creates a new JSON slog.Handler with custom formatting. +func newJSONHandlerHelper(w io.Writer) slog.Handler { + return slog.NewJSONHandler(w, &slog.HandlerOptions{ + Level: slog.Level(-8), // Allow all levels, filter ourselves + ReplaceAttr: func(_ []string, attr slog.Attr) slog.Attr { + // Customize timestamp format + switch attr.Key { + case slog.TimeKey: + attr.Value = slog.StringValue(attr.Value.Time().Format(time.RFC3339)) + + return attr + + case slog.LevelKey: + if lvl, ok := attr.Value.Any().(slog.Level); ok { + attr.Value = slogLevelToSlogStringValue(lvl) + + return attr + } + + // if slog changes representation then leave it alone. + return attr + + default: + return attr + } + }, + }) +} + +// SetLevel sets the logger's logging level. +func (jl *jsonLeveledLogger) SetLevel(newLevel LogLevel) { + jl.level.Set(newLevel) +} + +// logf is the internal logging function that handles level checking and formatting. +func (jl *jsonLeveledLogger) logf(level slog.Level, msg string, args ...any) { + if jl.level.Get() < logLevelToPionLevel(level) { + return + } + + // Create structured log entry + attrs := []any{ + "scope", jl.scope, + } + + // Add any additional arguments as key-value pairs + if len(args) > 0 { + attrs = append(attrs, args...) + } + + jl.logger.Log(context.Background(), level, msg, attrs...) +} + +// logfWithFormatf formats the message and calls logf. +func (jl *jsonLeveledLogger) logfWithFormatf(level slog.Level, format string, args ...any) { + if jl.level.Get() < logLevelToPionLevel(level) { + return + } + + // Format the message + msg := format + if len(args) > 0 { + msg = fmt.Sprintf(format, args...) + } + + // Create structured log entry + attrs := []any{ + "scope", jl.scope, + } + + jl.logger.Log(context.Background(), level, msg, attrs...) +} + +// Convert slog record levels to the exact strings you want in JSON. +func slogLevelToSlogStringValue(level slog.Level) slog.Value { + switch level { + case slog.Level(-8): // trace + return slog.StringValue("TRACE") + case slog.LevelDebug: + return slog.StringValue("DEBUG") + case slog.LevelInfo: + return slog.StringValue("INFO") + case slog.LevelWarn: + return slog.StringValue("WARN") + case slog.LevelError: + return slog.StringValue("ERROR") + default: + return slog.StringValue("UNKNOWN") + } +} + +// Helper to convert slog levels to Pion log levels. +func logLevelToPionLevel(level slog.Level) LogLevel { + switch level { + case slog.Level(-8): // trace + return LogLevelTrace + case slog.LevelDebug: + return LogLevelDebug + case slog.LevelInfo: + return LogLevelInfo + case slog.LevelWarn: + return LogLevelWarn + case slog.LevelError: + return LogLevelError + default: + return LogLevelDisabled + } +} + +// Trace emits the preformatted message if the logger is at or below LogLevelTrace. +func (jl *jsonLeveledLogger) Trace(msg string) { + jl.logf(slog.Level(-8), msg) // slog.LevelTrace is -8 +} + +// Tracef formats and emits a message if the logger is at or below LogLevelTrace. +func (jl *jsonLeveledLogger) Tracef(format string, args ...any) { + jl.logfWithFormatf(slog.Level(-8), format, args...) // slog.LevelTrace is -8 +} + +// Debug emits the preformatted message if the logger is at or below LogLevelDebug. +func (jl *jsonLeveledLogger) Debug(msg string) { + jl.logf(slog.LevelDebug, msg) +} + +// Debugf formats and emits a message if the logger is at or below LogLevelDebug. +func (jl *jsonLeveledLogger) Debugf(format string, args ...any) { + jl.logfWithFormatf(slog.LevelDebug, format, args...) +} + +// Info emits the preformatted message if the logger is at or below LogLevelInfo. +func (jl *jsonLeveledLogger) Info(msg string) { + jl.logf(slog.LevelInfo, msg) +} + +// Infof formats and emits a message if the logger is at or below LogLevelInfo. +func (jl *jsonLeveledLogger) Infof(format string, args ...any) { + jl.logfWithFormatf(slog.LevelInfo, format, args...) +} + +// Warn emits the preformatted message if the logger is at or below LogLevelWarn. +func (jl *jsonLeveledLogger) Warn(msg string) { + jl.logf(slog.LevelWarn, msg) +} + +// Warnf formats and emits a message if the logger is at or below LogLevelWarn. +func (jl *jsonLeveledLogger) Warnf(format string, args ...any) { + jl.logfWithFormatf(slog.LevelWarn, format, args...) +} + +// Error emits the preformatted message if the logger is at or below LogLevelError. +func (jl *jsonLeveledLogger) Error(msg string) { + jl.logf(slog.LevelError, msg) +} + +// Errorf formats and emits a message if the logger is at or below LogLevelError. +func (jl *jsonLeveledLogger) Errorf(format string, args ...any) { + jl.logfWithFormatf(slog.LevelError, format, args...) +} + +// jsonLoggerFactory defines levels by scopes and creates new jsonLeveledLogger. +type jsonLoggerFactory struct { + writer io.Writer + defaultLogLevel LogLevel + scopeLevels map[string]LogLevel +} + +var _ LoggerFactory = (*jsonLoggerFactory)(nil) + +// JSONLoggerFactoryOption configures the JSON LoggerFactory. +type JSONLoggerFactoryOption func(*jsonLoggerFactory) + +// WithJSONWriter overrides the writer used by JSON loggers. +func WithJSONWriter(writer io.Writer) JSONLoggerFactoryOption { + return func(factory *jsonLoggerFactory) { + if writer == nil { + factory.writer = os.Stderr + + return + } + + factory.writer = writer + } +} + +// WithJSONDefaultLevel overrides the default log level used by JSON loggers. +func WithJSONDefaultLevel(level LogLevel) JSONLoggerFactoryOption { + return func(factory *jsonLoggerFactory) { + factory.defaultLogLevel = level + } +} + +// WithJSONScopeLevels sets specific log levels for scopes, overriding env values. +func WithJSONScopeLevels(levels map[string]LogLevel) JSONLoggerFactoryOption { + return func(factory *jsonLoggerFactory) { + if levels == nil { + return + } + + if factory.scopeLevels == nil { + factory.scopeLevels = make(map[string]LogLevel, len(levels)) + } + + for scope, level := range levels { + factory.scopeLevels[strings.ToLower(scope)] = level + } + } +} + +// NewJSONLoggerFactory creates a new LoggerFactory that emits JSON logs. +func NewJSONLoggerFactory(options ...JSONLoggerFactoryOption) LoggerFactory { + factory := newJSONLoggerFactory() + + for _, option := range options { + if option == nil { + continue + } + + option(factory) + } + + return factory +} + +// newJSONLoggerFactory creates a new JSON LoggerFactory. +func newJSONLoggerFactory() *jsonLoggerFactory { + factory := jsonLoggerFactory{} + factory.defaultLogLevel = LogLevelError + factory.scopeLevels = make(map[string]LogLevel) + factory.writer = os.Stderr + + logLevels := map[string]LogLevel{ + "DISABLE": LogLevelDisabled, + "ERROR": LogLevelError, + "WARN": LogLevelWarn, + "INFO": LogLevelInfo, + "DEBUG": LogLevelDebug, + "TRACE": LogLevelTrace, + } + + for name, level := range logLevels { + env := os.Getenv(fmt.Sprintf("PION_LOG_%s", name)) + + if env == "" { + env = os.Getenv(fmt.Sprintf("PIONS_LOG_%s", name)) + } + + if env == "" { + continue + } + + if strings.ToLower(env) == "all" { + if factory.defaultLogLevel < level { + factory.defaultLogLevel = level + } + + continue + } + + scopes := strings.Split(strings.ToLower(env), ",") + for _, scope := range scopes { + factory.scopeLevels[scope] = level + } + } + + return &factory +} + +// NewLogger returns a configured JSON LeveledLogger for the given scope. +func (f *jsonLoggerFactory) NewLogger(scope string) LeveledLogger { + logLevel := f.defaultLogLevel + if f.scopeLevels != nil { + if scopeLevel, found := f.scopeLevels[scope]; found { + logLevel = scopeLevel + } + } + + return newJSONLeveledLoggerForScope(scope, logLevel, f.writer) +} diff --git a/json_logger_test.go b/json_logger_test.go new file mode 100644 index 0000000..ad102ed --- /dev/null +++ b/json_logger_test.go @@ -0,0 +1,383 @@ +// SPDX-FileCopyrightText: 2023 The Pion community +// SPDX-License-Identifier: MIT + +package logging + +import ( + "bytes" + "encoding/json" + "fmt" + "io" + "log/slog" + "os" + "strings" + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestJSONLoggerLevels(t *testing.T) { + logger := newJSONLeveledLoggerForScope("test", LogLevelTrace, os.Stderr) + + var outBuf bytes.Buffer + logger.WithOutput(&outBuf) + + // Test Info level + infoMsg := "this is an info message" + logger.Info(infoMsg) + output := outBuf.String() + assert.True(t, strings.Contains(output, infoMsg), "Expected to find %q in %q", infoMsg, output) + assert.True(t, strings.Contains(output, `"level":"INFO"`), "Expected JSON to contain INFO level") + assert.True(t, strings.Contains(output, `"scope":"test"`), "Expected JSON to contain scope") + + // Test Debug level + outBuf.Reset() + debugMsg := "this is a debug message" + logger.Debug(debugMsg) + output = outBuf.String() + assert.True(t, strings.Contains(output, debugMsg), "Expected to find %q in %q", debugMsg, output) + assert.True(t, strings.Contains(output, `"level":"DEBUG"`), "Expected JSON to contain DEBUG level") + + // Test Warn level + outBuf.Reset() + warnMsg := "this is a warning message" + logger.Warn(warnMsg) + output = outBuf.String() + assert.True(t, strings.Contains(output, warnMsg), "Expected to find %q in %q", warnMsg, output) + assert.True(t, strings.Contains(output, `"level":"WARN"`), "Expected JSON to contain WARN level") + + // Test Error level + outBuf.Reset() + errMsg := "this is an error message" + logger.Error(errMsg) + output = outBuf.String() + assert.True(t, strings.Contains(output, errMsg), "Expected to find %q in %q", errMsg, output) + assert.True(t, strings.Contains(output, `"level":"ERROR"`), "Expected JSON to contain ERROR level") + + // Test Trace level + outBuf.Reset() + traceMsg := "this is a trace message" + logger.Trace(traceMsg) + output = outBuf.String() + assert.True(t, strings.Contains(output, traceMsg), "Expected to find %q in %q", traceMsg, output) +} + +func TestJSONLoggerFormatting(t *testing.T) { + logger := newJSONLeveledLoggerForScope("test", LogLevelTrace, os.Stderr) + + var outBuf bytes.Buffer + logger.WithOutput(&outBuf) + + // Test formatted messages + formatMsg := "formatted message with %s" + arg := "argument" + logger.Infof(formatMsg, arg) + output := outBuf.String() + expectedMsg := "formatted message with argument" + assert.True(t, strings.Contains(output, expectedMsg), "Expected to find %q in %q", expectedMsg, output) +} + +func TestJSONLoggerLevelFiltering(t *testing.T) { + logger := newJSONLeveledLoggerForScope("test", LogLevelTrace, os.Stderr) + + var outBuf bytes.Buffer + logger.WithOutput(&outBuf) + + // Set level to WARN, so DEBUG and INFO should be filtered + logger.SetLevel(LogLevelWarn) + + // These should not be logged + logger.Debug("debug message") + logger.Info("info message") + assert.Equal(t, 0, outBuf.Len(), "Debug and Info messages should not be logged at WARN level") + + // These should be logged + logger.Warn("warn message") + logger.Error("error message") + output := outBuf.String() + assert.True(t, strings.Contains(output, "warn message"), "Warn message should be logged") + assert.True(t, strings.Contains(output, "error message"), "Error message should be logged") +} + +func TestJSONLoggerFactory(t *testing.T) { + factory := jsonLoggerFactory{ + writer: os.Stderr, + defaultLogLevel: LogLevelWarn, + scopeLevels: map[string]LogLevel{ + "foo": LogLevelDebug, + }, + } + + logger := factory.NewLogger("baz") + bazLogger, ok := logger.(*jsonLeveledLogger) + assert.True(t, ok, "Invalid logger type") + + // Test that baz logger respects WARN level + var outBuf bytes.Buffer + bazLogger.WithOutput(&outBuf) + bazLogger.Debug("debug message") + assert.Equal(t, 0, outBuf.Len(), "Debug message should not be logged at WARN level") + + logger = factory.NewLogger("foo") + fooLogger, ok := logger.(*jsonLeveledLogger) + assert.True(t, ok, "Invalid logger type") + + // Test that foo logger respects DEBUG level + outBuf.Reset() + fooLogger.WithOutput(&outBuf) + fooLogger.Debug("debug message") + output := outBuf.String() + assert.True(t, strings.Contains(output, "debug message"), "Debug message should be logged at DEBUG level") +} + +func TestNewJSONLoggerFactoryReturnsPrivateType(t *testing.T) { + factory := NewJSONLoggerFactory() + + assert.Equal(t, "*logging.jsonLoggerFactory", fmt.Sprintf("%T", factory)) +} + +func TestNewJSONLoggerFactory(t *testing.T) { + factory := NewJSONLoggerFactory() + + disabled := factory.NewLogger("DISABLE") + errorLevel := factory.NewLogger("ERROR") + warnLevel := factory.NewLogger("WARN") + infoLevel := factory.NewLogger("INFO") + debugLevel := factory.NewLogger("DEBUG") + traceLevel := factory.NewLogger("TRACE") + + disabledLogger, ok := disabled.(*jsonLeveledLogger) + assert.True(t, ok, "Missing disabled logger") + + errorLogger, ok := errorLevel.(*jsonLeveledLogger) + assert.True(t, ok, "Missing error logger") + + _, ok = warnLevel.(*jsonLeveledLogger) + assert.True(t, ok, "Missing warn logger") + + _, ok = infoLevel.(*jsonLeveledLogger) + assert.True(t, ok, "Missing info logger") + + _, ok = debugLevel.(*jsonLeveledLogger) + assert.True(t, ok, "Missing debug logger") + + _, ok = traceLevel.(*jsonLeveledLogger) + assert.True(t, ok, "Missing trace logger") + + // Test that all loggers are properly configured + var outBuf bytes.Buffer + disabledLogger.WithOutput(&outBuf) + disabledLogger.Info("test message") + assert.Equal(t, 0, outBuf.Len(), "Disabled logger should not log anything") + + outBuf.Reset() + errorLogger.WithOutput(&outBuf) + errorLogger.Error("error message") + output := outBuf.String() + assert.True(t, strings.Contains(output, "error message"), "Error logger should log error messages") +} + +func TestNewJSONLoggerFactoryOptions(t *testing.T) { + var outBuf bytes.Buffer + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory( + WithJSONWriter(&outBuf), + WithJSONDefaultLevel(LogLevelDebug), + WithJSONScopeLevels(map[string]LogLevel{"CustomScope": LogLevelTrace}), + )) + + assert.Equal(t, LogLevelDebug, factory.defaultLogLevel) + assert.Equal(t, LogLevelTrace, factory.scopeLevels["customscope"]) + + logger := factory.NewLogger("customscope") + logger.Debug("configured logger output") + + assert.Contains(t, outBuf.String(), "configured logger output") +} + +func TestJSONLoggerFactorySupportsWithOutputInterface(t *testing.T) { + factory := NewJSONLoggerFactory() + logger := factory.NewLogger("interface-scope") + + withOutput, ok := logger.(interface { + WithOutput(io.Writer) LeveledLogger + }) + assert.True(t, ok, "Logger should allow WithOutput without concrete type") + + var outBuf bytes.Buffer + withOutput.WithOutput(&outBuf) + + logger.Error("interface error") + assert.Contains(t, outBuf.String(), "interface error") +} + +func TestJSONLoggerTraceOutput(t *testing.T) { + logger := newJSONLeveledLoggerForScope("trace-scope", LogLevelTrace, os.Stderr) + var outBuf bytes.Buffer + logger.WithOutput(&outBuf) + + logger.Trace("test message") + output := outBuf.String() + + // Verify it's valid JSON + var jsonData map[string]any + err := json.Unmarshal([]byte(output), &jsonData) + assert.NoError(t, err, "Output should be valid JSON") + + // Verify required fields + assert.Contains(t, jsonData, "time", "JSON should contain time field") + assert.Contains(t, jsonData, "level", "JSON should contain level field") + assert.Contains(t, jsonData, "msg", "JSON should contain msg field") + assert.Contains(t, jsonData, "scope", "JSON should contain scope field") + + // Verify values + assert.Equal(t, "TRACE", jsonData["level"], "Level should be TRACE") + assert.Equal(t, "test message", jsonData["msg"], "Message should match") + assert.Equal(t, "trace-scope", jsonData["scope"], "Scope should match") +} + +func TestJSONLoggerStructuredOutput(t *testing.T) { + logger := newJSONLeveledLoggerForScope("test-scope", LogLevelInfo, os.Stderr) + var outBuf bytes.Buffer + logger.WithOutput(&outBuf) + + logger.Info("test message") + output := outBuf.String() + + // Verify it's valid JSON + var jsonData map[string]any + err := json.Unmarshal([]byte(output), &jsonData) + assert.NoError(t, err, "Output should be valid JSON") + + // Verify required fields + assert.Contains(t, jsonData, "time", "JSON should contain time field") + assert.Contains(t, jsonData, "level", "JSON should contain level field") + assert.Contains(t, jsonData, "msg", "JSON should contain msg field") + assert.Contains(t, jsonData, "scope", "JSON should contain scope field") + + // Verify values + assert.Equal(t, "INFO", jsonData["level"], "Level should be INFO") + assert.Equal(t, "test message", jsonData["msg"], "Message should match") + assert.Equal(t, "test-scope", jsonData["scope"], "Scope should match") +} + +func TestJSONLeveledLogger_logf_IncludesAdditionalArgs(t *testing.T) { + factory := newJSONLoggerFactory() + factory.writer = os.Stderr + factory.defaultLogLevel = LogLevelTrace + + l := factory.NewLogger("test-scope") + jl, ok := l.(*jsonLeveledLogger) + assert.True(t, ok, "Invalid logger type") + + var outBuf bytes.Buffer + jl.WithOutput(&outBuf) + + args := []any{ + "method", "GET", + "path", "/users", + "duration_ms", 15, + "ok", true, + } + + jl.logf(slog.LevelInfo, "Processing request", args...) + + raw := strings.TrimSpace(outBuf.String()) + + var jsonData map[string]any + err := json.Unmarshal([]byte(raw), &jsonData) + assert.NoError(t, err, "Output should be valid JSON") + + // base fields + assert.Equal(t, "Processing request", jsonData["msg"]) + assert.Equal(t, "INFO", jsonData["level"]) + assert.Equal(t, "test-scope", jsonData["scope"]) + + // additional args should appear as structured fields + assert.Equal(t, "GET", jsonData["method"]) + assert.Equal(t, "/users", jsonData["path"]) + assert.EqualValues(t, 15, jsonData["duration_ms"]) // json.Unmarshal numbers -> float64 + assert.Equal(t, true, jsonData["ok"]) +} + +func clearLogEnv(t *testing.T) { + t.Helper() + + for _, name := range []string{"DISABLE", "ERROR", "WARN", "INFO", "DEBUG", "TRACE"} { + t.Setenv("PION_LOG_"+name, "") + t.Setenv("PIONS_LOG_"+name, "") + } +} + +func unwrapJSONFactory(t *testing.T, factory LoggerFactory) *jsonLoggerFactory { + t.Helper() + + jf, ok := factory.(*jsonLoggerFactory) + assert.True(t, ok, "Factory should be jsonLoggerFactory") + + return jf +} + +func TestNewJSONLoggerFactory_AllSetsDefaultToMaxLevel(t *testing.T) { + clearLogEnv(t) + + t.Setenv("PION_LOG_INFO", "All") + t.Setenv("PION_LOG_DEBUG", "ALL") + t.Setenv("PION_LOG_TRACE", "all") + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory()) + + assert.Equal(t, LogLevelTrace, factory.defaultLogLevel) + assert.Equal(t, 0, len(factory.scopeLevels)) +} + +func TestNewJSONLoggerFactory_AllDoesNotLowerDefaultLevel(t *testing.T) { + clearLogEnv(t) + + t.Setenv("PION_LOG_DISABLE", "all") + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory()) + assert.Equal(t, LogLevelError, factory.defaultLogLevel) +} + +func TestNewJSONLoggerFactory_ScopesAreSplitAndLowercased(t *testing.T) { + clearLogEnv(t) + + t.Setenv("PION_LOG_DEBUG", "Foo,BAR") + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory()) + + assert.Equal(t, LogLevelError, factory.defaultLogLevel) + + assert.Equal(t, LogLevelDebug, factory.scopeLevels["foo"]) + assert.Equal(t, LogLevelDebug, factory.scopeLevels["bar"]) +} + +func TestNewJSONLoggerFactory_AllAndScopedInteract(t *testing.T) { + clearLogEnv(t) + + t.Setenv("PION_LOG_WARN", "all") + + t.Setenv("PION_LOG_DEBUG", "foo") + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory()) + + assert.Equal(t, LogLevelWarn, factory.defaultLogLevel) + assert.Equal(t, LogLevelDebug, factory.scopeLevels["foo"]) + + foo := factory.NewLogger("foo").(*jsonLeveledLogger) //nolint:forcetypeassert + bar := factory.NewLogger("bar").(*jsonLeveledLogger) //nolint:forcetypeassert + + assert.Equal(t, LogLevelDebug, foo.level.Get(), "scope override should win") + assert.Equal(t, LogLevelWarn, bar.level.Get(), "default should apply when no scope override") +} + +func TestNewJSONLoggerFactory_Fallback(t *testing.T) { + clearLogEnv(t) + + t.Setenv("PION_LOG_INFO", "") + t.Setenv("PIONS_LOG_INFO", "all") + + factory := unwrapJSONFactory(t, NewJSONLoggerFactory()) + assert.Equal(t, LogLevelInfo, factory.defaultLogLevel) +}