common/logger/logger.go
Ask Bjørn Hansen 66b51df2af feat(logger): add runtime log level control API
Add independent log level control for stderr and OTLP loggers.
Both can be configured via environment variables or programmatically
at runtime.

- Add SetLevel() and SetOTLPLevel() for runtime control
- Add ParseLevel() to convert strings to slog.Level
- Support LOG_LEVEL and OTLP_LOG_LEVEL env vars
- Maintain backward compatibility with DEBUG env var
- Add comprehensive test coverage
2025-09-06 05:21:33 -07:00

304 lines
9.9 KiB
Go

// Package logger provides structured logging with OpenTelemetry trace integration.
//
// This package offers multiple logging configurations for different deployment scenarios:
// - Text logging to stderr with optional timestamp removal for systemd
// - OTLP (OpenTelemetry Protocol) logging for observability pipelines
// - Multi-logger setup that outputs to both text and OTLP simultaneously
// - Context-aware logging with trace ID correlation
//
// The package automatically detects systemd environments and adjusts timestamp handling
// accordingly. It supports debug level configuration via environment variables and
// provides compatibility bridges for legacy logging interfaces.
//
// Key features:
// - Automatic OpenTelemetry trace and span ID inclusion in log entries
// - Configurable log levels via DEBUG environment variable (with optional prefix)
// - Systemd-compatible output (no timestamps when INVOCATION_ID is present)
// - Thread-safe logger setup with sync.Once protection
// - Context propagation for request-scoped logging
//
// Environment variables:
// - 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"
"strconv"
"sync"
"time"
slogtraceid "github.com/remychantenay/slog-otel"
slogmulti "github.com/samber/slog-multi"
"go.opentelemetry.io/contrib/bridges/otelslog"
"go.opentelemetry.io/otel/log/global"
otellog "go.opentelemetry.io/otel/sdk/log"
)
// ConfigPrefix allows customizing the environment variable prefix for configuration.
// When set, environment variables like DEBUG become {ConfigPrefix}_DEBUG.
// 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
multiLogger *slog.Logger
)
var (
setupText sync.Once // this sets the default
setupOtlp sync.Once // this never sets the default
setupMulti sync.Once // this sets the default, and will always run after the others
mu sync.Mutex
)
// 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)
}
// 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 {
logLevelVar = ConfigPrefix + "_" + logLevelVar
}
if levelStr := os.Getenv(logLevelVar); levelStr != "" {
if level, err := ParseLevel(levelStr); err == nil {
Level.Set(level)
}
}
// 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
log.Default().SetFlags(0)
logOptions.ReplaceAttr = logRemoveTime
}
logHandler := slogtraceid.OtelHandler{
Next: slog.NewTextHandler(os.Stderr, logOptions),
}
return logHandler
}
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()
// Use BatchProcessor with our custom exporter
processor := otellog.NewBatchProcessor(bufferingExp,
otellog.WithExportInterval(10*time.Second),
otellog.WithMaxQueueSize(2048),
otellog.WithExportMaxBatchSize(512),
)
// Create logger provider
provider := otellog.NewLoggerProvider(
otellog.WithProcessor(processor),
)
// Set global provider
global.SetLoggerProvider(provider)
// Create slog handler with level control
baseHandler := newLogFmtHandler(otelslog.NewHandler("common"))
handler := newOTLPLevelHandler(baseHandler)
otlpLogger = slog.New(handler)
})
return otlpLogger
}
// SetupMultiLogger creates a logger that outputs to both text (stderr) and OTLP simultaneously.
// This is useful for services that need both human-readable logs and structured observability data.
//
// The multi-logger combines:
// - Text handler: Stderr output with OpenTelemetry trace integration
// - OTLP handler: Structured logs sent via OpenTelemetry Protocol
//
// On first call, this logger becomes the default logger returned by Setup().
// The function is thread-safe and uses sync.Once to ensure single initialization.
func SetupMultiLogger() *slog.Logger {
setupMulti.Do(func() {
textHandler := Setup().Handler()
otlpHandler := setupOtlpLogger().Handler()
multiHandler := slogmulti.Fanout(
textHandler,
otlpHandler,
)
mu.Lock()
defer mu.Unlock()
multiLogger = slog.New(multiHandler)
slog.SetDefault(multiLogger)
})
return multiLogger
}
// SetupOLTP creates a logger that sends structured logs via OpenTelemetry Protocol.
// This logger is designed for observability pipelines and log aggregation systems.
//
// The OTLP logger formats log messages similarly to the text logger for better
// compatibility with Loki + Grafana, while still providing structured attributes.
// Log attributes are available both in the message format and as OTLP attributes.
//
// This logger does not become the default logger and must be used explicitly.
// It requires OpenTelemetry tracing configuration to be set up via the tracing package.
//
// See: https://github.com/grafana/loki/issues/14788 for formatting rationale.
func SetupOLTP() *slog.Logger {
return setupOtlpLogger()
}
// Setup creates and returns the standard text logger for the application.
// This is the primary logging function that most applications should use.
//
// Features:
// - Text formatting to stderr with human-readable output
// - Automatic OpenTelemetry trace_id and span_id inclusion when available
// - Systemd compatibility: omits timestamps when INVOCATION_ID environment variable is present
// - Debug level support via DEBUG environment variable (respects ConfigPrefix)
// - Thread-safe initialization with sync.Once
//
// On first call, this logger becomes the slog default logger. If SetupMultiLogger()
// has been called previously, Setup() returns the multi-logger instead of the text logger.
//
// The logger automatically detects execution context:
// - Systemd: Removes timestamps (systemd adds its own)
// - Debug mode: Enables debug level logging based on environment variables
// - OpenTelemetry: Includes trace correlation when tracing is active
func Setup() *slog.Logger {
setupText.Do(func() {
h := setupStdErrHandler()
textLogger = slog.New(h)
slog.SetDefault(textLogger)
})
mu.Lock()
defer mu.Unlock()
if multiLogger != nil {
return multiLogger
}
return textLogger
}
type loggerKey struct{}
// NewContext stores a logger in the context for request-scoped logging.
// This enables passing request-specific loggers (e.g., with request IDs,
// user context, or other correlation data) through the call stack.
//
// Use this to create context-aware logging where different parts of the
// application can access the same enriched logger instance.
//
// Example:
//
// logger := slog.With("request_id", requestID)
// ctx := logger.NewContext(ctx, logger)
// // Pass ctx to downstream functions
func NewContext(ctx context.Context, l *slog.Logger) context.Context {
return context.WithValue(ctx, loggerKey{}, l)
}
// FromContext retrieves a logger from the context.
// If no logger is stored in the context, it returns the default logger from Setup().
//
// This function provides a safe way to access context-scoped loggers without
// needing to check for nil values. It ensures that logging is always available,
// falling back to the application's standard logger configuration.
//
// Example:
//
// log := logger.FromContext(ctx)
// log.Info("processing request") // Uses context logger or default
func FromContext(ctx context.Context) *slog.Logger {
if l, ok := ctx.Value(loggerKey{}).(*slog.Logger); ok {
return l
}
return Setup()
}
func logRemoveTime(groups []string, a slog.Attr) slog.Attr {
// Remove time
if a.Key == slog.TimeKey && len(groups) == 0 {
return slog.Attr{}
}
return a
}