diff --git a/log/constructors.go b/log/constructors.go index b8847c3..a09f769 100644 --- a/log/constructors.go +++ b/log/constructors.go @@ -2,116 +2,70 @@ package log import ( "fmt" + "os" "go.uber.org/zap" "go.uber.org/zap/zapcore" ) -type ( - // LoggerOption sets options to tune the behavior of a logger. - LoggerOption func(*loggerOptions) - - loggerOptions struct { - logLevel string - callerSkip int - isDevelopment bool - disableStackTrace bool - redirectStdLog bool - replaceGlobals bool - } -) - -var loggerDefaults = loggerOptions{ - logLevel: "info", - callerSkip: 1, -} - -func defaultLoggerOptions(opts []LoggerOption) loggerOptions { - if len(opts) == 0 { - return loggerDefaults - } - - o := loggerDefaults - for _, apply := range opts { - apply(&o) - } - - return o -} - -// WithLevel sets the log level. +// MustGetLogger creates a named zap logger, typically to inject into a service runtime as the root logger. // -// The level value must parse to a valid zapcore.Level, i.e. one of error, warn, info, debug values. -// The default level is "info". -func WithLevel(level string) LoggerOption { - return func(o *loggerOptions) { - o.logLevel = level - } -} - -// WithDisableStackTrace disable stack printing for this logger -func WithDisableStackTrace(disabled bool) LoggerOption { - return func(o *loggerOptions) { - o.disableStackTrace = disabled - } -} - -// WithCallerSkip sets the number of frames in the stack to skip. +// This function returns a configured zap.Logger and a closing function to sync logs upon exit. // -// By default, this is set to 1, so the logging function itself is skipped. -func WithCallerSkip(skipped int) LoggerOption { - return func(o *loggerOptions) { - o.callerSkip = skipped +// It panics upon failures, such as invalid log level, or incapacity to build the underlying logger. +func MustGetLogger(name string, opts ...LoggerOption) (*zap.Logger, func()) { + options := defaultLoggerOptions(opts) + lc := zap.NewProductionConfig() + if err := options.applyToConfig(&lc); err != nil { + panic(fmt.Sprintf("parsing log level: %v", err)) } -} -func WithRedirectStdLog(enabled bool) LoggerOption { - return func(o *loggerOptions) { - o.redirectStdLog = enabled - } -} + zlg := zap.Must( + lc.Build(zap.AddCallerSkip(options.callerSkip)), + ) + zlg = zlg.Named(name) + options.applyToLogger(zlg) -func WithReplaceGlobals(enabled bool) LoggerOption { - return func(o *loggerOptions) { - o.replaceGlobals = enabled - } + return zlg, func() { _ = zlg.Sync() } } -// MustGetLogger creates a named zap logger, typically to inject into a service runtime as the root logger. +// GetTestLoggerConfig is intended to be used in test programs, and inject +// a logger factory or its underlying *zap.Logger into the tested components. // -// This function returns a configured zap.Logger and a closing function to sync logs upon exit. -// -// It panics upon failures, such as invalid log level, or incapacity to build the underlying logger. -func MustGetLogger(name string, opts ...LoggerOption) (*zap.Logger, func()) { +// It is configurable from the "DEBUG_TEST" environment variable: if set, logging +// is enabled. Otherwise, logging is just muted, allowing to keep test verbosity low. +func GetTestLoggerConfig(opts ...LoggerOption) (Factory, *zap.Logger, error) { + isDebug := os.Getenv("DEBUG_TEST") != "" options := defaultLoggerOptions(opts) - lc := zap.NewProductionConfig() - if options.isDevelopment { - lc.Development = true + var zlg *zap.Logger + if !isDebug { + zlg = zap.NewNop() + return NewFactory(zlg), zlg, nil } - lvl, err := zapcore.ParseLevel(options.logLevel) + lc := zap.NewDevelopmentConfig() + lc.Level = zap.NewAtomicLevelAt(zap.DebugLevel) + lc.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder + lg, err := lc.Build(zap.AddCallerSkip(1)) if err != nil { - panic(fmt.Sprintf("parsing log level: %v", err)) + return Factory{}, nil, err } + options.applyToLogger(zlg) + zlg = lg - lc.Level = zap.NewAtomicLevelAt(lvl) - lc.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder - if options.disableStackTrace { - lc.DisableStacktrace = options.disableStackTrace - } + factory := NewFactory(zlg) - zlg := zap.Must(lc.Build(zap.AddCallerSkip(options.callerSkip))) - zlg = zlg.Named(name) - if options.replaceGlobals { - zap.ReplaceGlobals(zlg) - } + return factory, zlg, nil +} - if options.redirectStdLog { - zap.RedirectStdLog(zlg) +// MustGetTestLoggerConfig is a wrapper around GetTestLoggerConfig that panics +// if an error is encountered. +func MustGetTestLoggerConfig() (Factory, *zap.Logger) { + fl, zlg, err := GetTestLoggerConfig() + if err != nil { + panic(fmt.Sprintf("could not acquire test logger: %v", err)) } - return zlg, func() { - _ = zlg.Sync() - } + return fl, zlg } diff --git a/log/doc.go b/log/doc.go new file mode 100644 index 0000000..42e555c --- /dev/null +++ b/log/doc.go @@ -0,0 +1,2 @@ +// Package log exposes logging utilities based on go.uber.org/zap. +package log diff --git a/log/factory.go b/log/factory.go index 98fbd1d..eb359c8 100644 --- a/log/factory.go +++ b/log/factory.go @@ -12,8 +12,8 @@ import ( ) type ( - // Factory is the default logging wrapper that can create - // logger instances either contextless, or for a given context + // Factory is wrapper for a logger, which creates + // logger instances, either contextless or for a given context // (e.g. to propagate trace spans). // // A factory wraps a logger to propagate log entries as trace spans. @@ -39,41 +39,44 @@ func (b Factory) Bg() Logger { return logger{logger: b.logger} } +// Zap returns the underlying zap logger func (b Factory) Zap() *zap.Logger { return b.logger } // For returns a context-aware Logger. // -// If the context contains an OpenTracing span, all logging calls are also +// If the context contains a trace span (from go.opencensus.io/trace), all logging calls are also // echo-ed to that span. // // NOTE: for Datadog trace correlation, extra fields "dd.trace_id" and "dd.span_id" // fields are added to the log entry. func (b Factory) For(ctx context.Context) Logger { - if span := trace.FromContext(ctx); span != nil { // TODO: support opentracing - stx := span.SpanContext() - logger := b.logger.WithOptions(zap.AddCallerSkip(1)) + span := trace.FromContext(ctx) + if span == nil { // TODO: support opentracing + return b.Bg() + } + + stx := span.SpanContext() + logger := b.logger.WithOptions(zap.AddCallerSkip(1)) - if b.datadog { - // for datadog correlation, extract trace/span IDs as fields to add to the log entry. - // This corresponds to what the datadog opencensus exporter does: - // https://github.com/DataDog/opencensus-go-exporter-datadog/tree/master/span.go#L47 - traceID := binary.BigEndian.Uint64(stx.TraceID[8:]) - spanID := binary.BigEndian.Uint64(stx.SpanID[:]) - logger = logger.With( - zap.Uint64("dd.trace_id", traceID), - zap.Uint64("dd.span_id", spanID), - zap.Float64(ext.SamplingPriority, 1.00), - ) - } + if b.datadog { + // for datadog correlation, extract trace/span IDs as fields to add to the log entry. + // This corresponds to what the datadog opencensus exporter does: + // https://github.com/DataDog/opencensus-go-exporter-datadog/tree/master/span.go#L47 + traceID := binary.BigEndian.Uint64(stx.TraceID[8:]) + spanID := binary.BigEndian.Uint64(stx.SpanID[:]) + logger = logger.With( + zap.Uint64("dd.trace_id", traceID), + zap.Uint64("dd.span_id", spanID), + zap.Float64(ext.SamplingPriority, 1.00), + ) + } - return spanLogger{ - span: span, - logger: logger, - } + return spanLogger{ + span: span, + logger: logger, } - return b.Bg() } // With creates a child logger and optionally adds some context fields to that logger. diff --git a/log/logger.go b/log/logger.go index b1ea431..9bb1a94 100644 --- a/log/logger.go +++ b/log/logger.go @@ -1,9 +1,6 @@ package log import ( - "fmt" - "os" - "go.uber.org/zap" "go.uber.org/zap/zapcore" ) @@ -26,6 +23,7 @@ type ( } ) +// Zap returns the underlying zap logger func (l logger) Zap() *zap.Logger { return l.logger } @@ -59,46 +57,3 @@ func (l logger) Fatal(msg string, fields ...zapcore.Field) { func (l logger) With(fields ...zapcore.Field) Logger { return logger{logger: l.logger.With(fields...)} } - -// TODO: reorganize - -// MustGetTestLoggerConfig is a wrapper around GetTestLoggerConfig that panics -// if an error is encountered. -func MustGetTestLoggerConfig() (Factory, *zap.Logger) { - fl, zlg, err := GetTestLoggerConfig() - if err != nil { - panic(fmt.Sprintf("could not acquire test logger: %v", err)) - } - - return fl, zlg - -} - -// GetTestLoggerConfig is intended to be used in test programs, and inject -// a logger factory or its underlying *zap.Logger into the tested components. -// -// It is configurable from the "DEBUG_TEST" environment variable: if set, logging -// is enabled. Otherwise, logging is just muted, allowing to keep test verbosity low. -func GetTestLoggerConfig() (Factory, *zap.Logger, error) { - isDebug := os.Getenv("DEBUG_TEST") != "" - - var zlg *zap.Logger - if !isDebug { - zlg = zap.NewNop() - } else { - lc := zap.NewDevelopmentConfig() - lc.Level = zap.NewAtomicLevelAt(zap.DebugLevel) - lc.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder - lg, err := lc.Build(zap.AddCallerSkip(1)) - if err != nil { - return Factory{}, nil, err - } - zap.RedirectStdLog(lg) - - zlg = lg - } - - factory := NewFactory(zlg) - - return factory, zlg, nil -} diff --git a/log/logger_options.go b/log/logger_options.go new file mode 100644 index 0000000..0596e7e --- /dev/null +++ b/log/logger_options.go @@ -0,0 +1,118 @@ +package log + +import ( + "go.uber.org/zap" + "go.uber.org/zap/zapcore" +) + +type ( + // LoggerOption sets options to tune the behavior of a logger. + LoggerOption func(*loggerOptions) + + loggerOptions struct { + logLevel string + callerSkip int + isDevelopment bool + disableStackTrace bool + redirectStdLog bool + replaceGlobals bool + ignoreLevelErr bool + } +) + +var loggerDefaults = loggerOptions{ + logLevel: "info", + callerSkip: 1, +} + +func defaultLoggerOptions(opts []LoggerOption) loggerOptions { + if len(opts) == 0 { + return loggerDefaults + } + + o := loggerDefaults + for _, apply := range opts { + apply(&o) + } + + return o +} + +func (o loggerOptions) applyToConfig(lc *zap.Config) error { + if o.isDevelopment { + lc.Development = true + } + + lvl, err := zapcore.ParseLevel(o.logLevel) + if err != nil { + if o.ignoreLevelErr { + lvl, _ = zapcore.ParseLevel(loggerDefaults.logLevel) + } else { + return err + } + } + + lc.Level = zap.NewAtomicLevelAt(lvl) + lc.EncoderConfig.EncodeDuration = zapcore.StringDurationEncoder + if o.disableStackTrace { + lc.DisableStacktrace = o.disableStackTrace + } + + return nil +} + +func (o loggerOptions) applyToLogger(zlg *zap.Logger) { + if o.replaceGlobals { + zap.ReplaceGlobals(zlg) + } + + if o.redirectStdLog { + zap.RedirectStdLog(zlg) + } +} + +// WithLevel sets the log level. +// +// The level value must parse to a valid zapcore.Level, i.e. one of error, warn, info, debug values. +// The default level is "info". +func WithLevel(level string) LoggerOption { + return func(o *loggerOptions) { + o.logLevel = level + } +} + +// WithDisableStackTrace disable stack printing for this logger +func WithDisableStackTrace(disabled bool) LoggerOption { + return func(o *loggerOptions) { + o.disableStackTrace = disabled + } +} + +// WithCallerSkip sets the number of frames in the stack to skip. +// +// By default, this is set to 1, so the logging function itself is skipped. +func WithCallerSkip(skipped int) LoggerOption { + return func(o *loggerOptions) { + o.callerSkip = skipped + } +} + +func WithRedirectStdLog(enabled bool) LoggerOption { + return func(o *loggerOptions) { + o.redirectStdLog = enabled + } +} + +func WithReplaceGlobals(enabled bool) LoggerOption { + return func(o *loggerOptions) { + o.replaceGlobals = enabled + } +} + +// WithIgnoreErr ignores errors when parsing an invalid log level, +// and silently substitutes the default instead. +func WithIgnoreErr(enabled bool) LoggerOption { + return func(o *loggerOptions) { + o.ignoreLevelErr = enabled + } +} diff --git a/log/middleware.go b/log/middleware/middleware.go similarity index 82% rename from log/middleware.go rename to log/middleware/middleware.go index c31899d..f24ba3d 100644 --- a/log/middleware.go +++ b/log/middleware/middleware.go @@ -1,15 +1,16 @@ -package log +package middleware import ( "net/http" "time" "github.com/felixge/httpsnoop" + "github.com/fredbi/go-trace/log" "go.uber.org/zap" ) -// Requests provides a middleware that logs http requests with a tracing-aware logger Factory. -func Requests(lf Factory) func(http.Handler) http.Handler { +// LogRequests provides a middleware that logs http requests with a tracing-aware logger Factory. +func LogRequests(lf log.Factory) func(http.Handler) http.Handler { return func(next http.Handler) http.Handler { return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { start := time.Now() diff --git a/log/options.go b/log/options.go index 8d0095a..8a9c0a4 100644 --- a/log/options.go +++ b/log/options.go @@ -9,9 +9,14 @@ type ( } ) +var defaultFactoryOptions = options{} + func defaultOptions(opts []Option) options { - o := options{} + if len(opts) == 0 { + return defaultFactoryOptions + } + o := defaultFactoryOptions for _, apply := range opts { apply(&o) }