From d66040ca126ee3bc29b4df265c9b67c2e9747169 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ziya=20=C3=96z=C3=A7elik?= Date: Fri, 8 Oct 2021 16:53:24 +0300 Subject: [PATCH] Logging with context values --- logger.go | 107 +++++++++++++++++++++++++++++++++++++++++++++++-- logger_test.go | 42 +++++++++++++++++++ options.go | 10 +++++ 3 files changed, 156 insertions(+), 3 deletions(-) diff --git a/logger.go b/logger.go index 087c74222..6e7c4c07e 100644 --- a/logger.go +++ b/logger.go @@ -21,13 +21,14 @@ package zap import ( + "context" "fmt" + "go.uber.org/zap/internal/bufferpool" + "go.uber.org/zap/zapcore" "io/ioutil" "os" + "runtime" "strings" - - "go.uber.org/zap/internal/bufferpool" - "go.uber.org/zap/zapcore" ) // A Logger provides fast, leveled, structured logging. All methods are safe @@ -52,6 +53,8 @@ type Logger struct { callerSkip int clock zapcore.Clock + + contextFunc func(ctx context.Context) []Field } // New constructs a new Logger from the provided zapcore.Core and Options. If @@ -242,6 +245,78 @@ func (log *Logger) Fatal(msg string, fields ...Field) { } } +// InfoCtx logs a message at InfoLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +func (log *Logger) InfoCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(InfoLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// WarnCtx logs a message at WarnLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +func (log *Logger) WarnCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(WarnLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// ErrorCtx logs a message at ErrorLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +func (log *Logger) ErrorCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(ErrorLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// DPanicCtx logs a message at DPanicLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +// +// If the logger is in development mode, it then panics (DPanic means +// "development panic"). This is useful for catching errors that are +// recoverable, but shouldn't ever happen. +func (log *Logger) DPanicCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(DPanicLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// PanicCtx logs a message at PanicLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +// +// The logger then panics, even if logging at PanicLevel is disabled. +func (log *Logger) PanicCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(PanicLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// FatalCtx logs a message at FatalLevel. The message includes any request context's fields +// and fields passed at the log site, as well as any fields accumulated on the logger. +// +// The logger then calls os.Exit(1), even if logging at FatalLevel is +// disabled. +func (log *Logger) FatalCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(FatalLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + +// DebugCtx logs a message at DebugLevel. The message includes any request context's fields +// and any fields passed at the log site, as well as any fields accumulated on the logger. +func (log *Logger) DebugCtx(ctx context.Context, msg string, fields ...Field) { + if ce := log.check(DebugLevel, msg); ce != nil { + generatedFields := log.generateFields(ctx, fields...) + ce.Write(generatedFields...) + } +} + // Sync calls the underlying Core's Sync method, flushing any buffered log // entries. Applications should take care to call Sync before exiting. func (log *Logger) Sync() error { @@ -361,3 +436,29 @@ func (log *Logger) check(lvl zapcore.Level, msg string) *zapcore.CheckedEntry { return ce } + +func (log *Logger) generateFields(ctx context.Context, fields ...Field) []Field { + if ctx != nil && log.contextFunc != nil { + contextFields := log.contextFunc(ctx) + return append(contextFields, fields...) + } + return nil +} + +// getCallerFrame gets caller frame. The argument skip is the number of stack +// frames to ascend, with 0 identifying the caller of getCallerFrame. The +// boolean ok is false if it was not possible to recover the information. +// +// Note: This implementation is similar to runtime.Caller, but it returns the whole frame. +func getCallerFrame(skip int) (frame runtime.Frame, ok bool) { + const skipOffset = 2 // skip getCallerFrame and Callers + + pc := make([]uintptr, 1) + numFrames := runtime.Callers(skip+skipOffset, pc) + if numFrames < 1 { + return + } + + frame, _ = runtime.CallersFrames(pc).Next() + return frame, frame.PC != 0 +} diff --git a/logger_test.go b/logger_test.go index 4b54ff470..f35c93820 100644 --- a/logger_test.go +++ b/logger_test.go @@ -21,6 +21,7 @@ package zap import ( + "context" "errors" "sync" "testing" @@ -600,6 +601,47 @@ func TestNopLogger(t *testing.T) { }) } +func TestRequestContext(t *testing.T) { + t.Run("Context option use while logger create", func(t *testing.T) { + t.Run("Context is not nil", func(t *testing.T) { + requestContextOption := Context(func(ctx context.Context) []Field { + var fields []Field + + if ctxRequestPath, ok := ctx.Value("Correlation-ID").(string); ok { + fields = append(fields, String("Correlation-ID", ctxRequestPath)) + } + + return fields + }) + logger, _ := NewProduction(requestContextOption) + + ctx := context.TODO() + ctx = context.WithValue(ctx, "Correlation-ID", "e9718aab-aa1a-4ad8-b1e6-690f6c43bd15") + + logger.InfoCtx(ctx, "Hello Zap Logger Community !!!") + logger.DebugCtx(ctx, "Hello Zap Logger Community !!!") + logger.ErrorCtx(ctx, "Hello Zap Logger Community !!!") + logger.WarnCtx(ctx, "Hello Zap Logger Community !!!") + logger.DPanicCtx(ctx, "Hello Zap Logger Community !!!") + }) + }) + + t.Run("Context option not use while logger create", func(t *testing.T) { + t.Run("Context is not nil", func(t *testing.T) { + logger, _ := NewProduction() + + ctx := context.TODO() + ctx = context.WithValue(ctx, "Correlation-ID", "e9718aab-aa1a-4ad8-b1e6-690f6c43bd15") + + logger.InfoCtx(ctx, "Hello Zap Logger Community !!!") + logger.DebugCtx(ctx, "Hello Zap Logger Community !!!") + logger.ErrorCtx(ctx, "Hello Zap Logger Community !!!") + logger.WarnCtx(ctx, "Hello Zap Logger Community !!!") + logger.DPanicCtx(ctx, "Hello Zap Logger Community !!!") + }) + }) +} + func infoLog(logger *Logger, msg string, fields ...Field) { logger.Info(msg, fields...) } diff --git a/options.go b/options.go index e9e66161f..2764be55f 100644 --- a/options.go +++ b/options.go @@ -21,6 +21,7 @@ package zap import ( + "context" "fmt" "go.uber.org/zap/zapcore" @@ -86,6 +87,15 @@ func Development() Option { }) } +// Context It is used to decide which of the values in the context will +// be used as the base log field. It takes a function as a parameter and +// this function does this job. +func Context(contextFunc func(ctx context.Context) []Field) Option { + return optionFunc(func(log *Logger) { + log.contextFunc = contextFunc + }) +} + // AddCaller configures the Logger to annotate each message with the filename, // line number, and function name of zap's caller. See also WithCaller. func AddCaller() Option {