From 660c1c6b3d4d96377ece72d28b1178027f9b3f3e Mon Sep 17 00:00:00 2001 From: Phu Ngo <12547020+NgoKimPhu@users.noreply.github.com> Date: Thu, 28 Dec 2023 18:43:08 +0700 Subject: [PATCH] feat: add context aware logger --- batcher.go | 27 +++++---- batcher_test.go | 5 +- http.go | 4 +- klog/klog.go | 144 ++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 165 insertions(+), 15 deletions(-) create mode 100644 klog/klog.go diff --git a/batcher.go b/batcher.go index 481c6f9..056d5e8 100644 --- a/batcher.go +++ b/batcher.go @@ -8,8 +8,9 @@ import ( "sync/atomic" "time" - "github.com/KyberNetwork/logger" "github.com/pkg/errors" + + "github.com/KyberNetwork/kutils/klog" ) //go:generate mockgen -source=batcher.go -destination mocks/mocks.go -package mocks @@ -77,7 +78,8 @@ func (c *ChanTask[R]) Result() (R, error) { func (c *ChanTask[R]) Resolve(ret R, err error) { select { case <-c.done: - logger.Errorf("ChanTask.Resolve|called twice, ignored|c.Ret=%v,c.Err=%v|Ret=%v,Err=%v", c.Ret, c.Err, ret, err) + klog.Errorf(c.ctx, "ChanTask.Resolve|called twice, ignored|c.Ret=%v,c.Err=%v|Ret=%v,Err=%v", + c.Ret, c.Err, ret, err) default: c.Ret, c.Err = ret, err close(c.done) @@ -143,7 +145,8 @@ func (b *ChanBatcher[T, R]) batchFnWithRecover(tasks []T) { if p == nil { return } - logger.Errorf("ChanBatcher.goBatchFn|recovered from panic: %v\n%s", p, string(debug.Stack())) + klog.Errorf(context.Background(), "ChanBatcher.goBatchFn|recovered from panic: %v\n%s", + p, string(debug.Stack())) var ret R for _, task := range tasks { if task.IsDone() { @@ -164,7 +167,8 @@ func (b *ChanBatcher[T, R]) batchFnWithRecover(tasks []T) { func (b *ChanBatcher[T, R]) worker() { defer func() { if p := recover(); p != nil { - logger.Errorf("ChanBatcher.worker|recovered from panic: %v\n%s", p, string(debug.Stack())) + klog.Errorf(context.Background(), "ChanBatcher.worker|recovered from panic: %v\n%s", + p, string(debug.Stack())) } }() var tasks []T @@ -176,12 +180,13 @@ func (b *ChanBatcher[T, R]) worker() { if len(tasks) == 0 { break } - logger.Debugf("ChanBatcher.worker|timer|%d tasks", len(tasks)) + klog.Debugf(tasks[0].Ctx(), "ChanBatcher.worker|timer|%d tasks", len(tasks)) go b.batchFnWithRecover(tasks) tasks = tasks[:0:0] case task, ok := <-b.taskCh: + ctx := task.Ctx() if !ok { - logger.Debugf("ChanBatcher.worker|closed|%d tasks", len(tasks)) + klog.Debugf(ctx, "ChanBatcher.worker|closed|%d tasks", len(tasks)) if len(tasks) > 0 { go b.batchFnWithRecover(tasks) } @@ -189,16 +194,16 @@ func (b *ChanBatcher[T, R]) worker() { } if !task.IsDone() { select { - case <-task.Ctx().Done(): - logger.Infof("ChanBatcher.worker|skip|task=%v", task) - task.Resolve(*new(R), task.Ctx().Err()) + case <-ctx.Done(): + klog.Infof(ctx, "ChanBatcher.worker|skip|task=%v", task) + task.Resolve(*new(R), ctx.Err()) continue default: } } duration, batchCount := b.batchCfg() if len(tasks) == 0 { - logger.Debugf("ChanBatcher.worker|timer start|duration=%s", duration) + klog.Debugf(ctx, "ChanBatcher.worker|timer start|duration=%s", duration) if !batchTimer.Stop() { select { case <-batchTimer.C: @@ -209,7 +214,7 @@ func (b *ChanBatcher[T, R]) worker() { } tasks = append(tasks, task) if len(tasks) >= batchCount { - logger.Debugf("ChanBatcher.worker|max|%d tasks", len(tasks)) + klog.Debugf(ctx, "ChanBatcher.worker|max|%d tasks", len(tasks)) go b.batchFnWithRecover(tasks) tasks = tasks[:0:0] } diff --git a/batcher_test.go b/batcher_test.go index 19bb166..8368aab 100644 --- a/batcher_test.go +++ b/batcher_test.go @@ -7,9 +7,10 @@ import ( "testing" "time" - "github.com/KyberNetwork/logger" "github.com/pkg/errors" "github.com/stretchr/testify/assert" + + "github.com/KyberNetwork/kutils/klog" ) func TestChanBatcher(t *testing.T) { @@ -70,7 +71,7 @@ func TestChanBatcher(t *testing.T) { batcher.Batch(tasks[i]) } // 1k: 2.561804ms; 1M: 2.62s - average overhead per task = 2.6µs - logger.Warnf("done %d tasks in %v", taskCnt, time.Since(start)) + klog.Warnf(ctx, "done %d tasks in %v", taskCnt, time.Since(start)) for i := 0; i < taskCnt; i++ { ret, err := tasks[i].Result() assert.NoError(t, err) diff --git a/http.go b/http.go index 5fd7a12..942a7d5 100644 --- a/http.go +++ b/http.go @@ -6,10 +6,10 @@ import ( "net/http" "time" - "github.com/KyberNetwork/kutils/internal/json" - "github.com/go-resty/resty/v2" "github.com/hashicorp/go-retryablehttp" + + "github.com/KyberNetwork/kutils/internal/json" ) type HttpCfg struct { diff --git a/klog/klog.go b/klog/klog.go new file mode 100644 index 0000000..c92539d --- /dev/null +++ b/klog/klog.go @@ -0,0 +1,144 @@ +package klog + +import ( + "context" + + "github.com/KyberNetwork/logger" +) + +func DefaultLogger() Logger { + return logger.DefaultLogger() +} + +type Logger logger.Logger + +var log logger.Logger + +type Configuration struct { + EnableConsole bool + EnableJSONFormat bool + ConsoleLevel string + EnableFile bool + FileJSONFormat bool + FileLevel string + FileLocation string +} + +type LoggerBackend logger.LoggerBackend + +const ( + // LoggerBackendZap logging using Uber's zap backend + LoggerBackendZap = LoggerBackend(logger.LoggerBackendZap) + // LoggerBackendLogrus logging using logrus backend + LoggerBackendLogrus = LoggerBackend(logger.LoggerBackendLogrus) +) + +func InitLogger(config Configuration, backend LoggerBackend) (Logger, error) { + var err error + log, err = logger.InitLogger(logger.Configuration{ + EnableConsole: config.EnableConsole, + EnableJSONFormat: config.EnableJSONFormat, + ConsoleLevel: config.ConsoleLevel, + EnableFile: config.EnableFile, + FileJSONFormat: config.FileJSONFormat, + FileLevel: config.FileLevel, + FileLocation: config.FileLocation, + }, logger.LoggerBackend(backend)) + return log, err +} + +func Log() Logger { + if log == nil { + log = DefaultLogger() + } + return log +} + +func NewLogger(config Configuration, backend LoggerBackend) (Logger, error) { + return logger.NewLogger(logger.Configuration{ + EnableConsole: config.EnableConsole, + EnableJSONFormat: config.EnableJSONFormat, + ConsoleLevel: config.ConsoleLevel, + EnableFile: config.EnableFile, + FileJSONFormat: config.FileJSONFormat, + FileLevel: config.FileLevel, + FileLocation: config.FileLocation, + }, logger.LoggerBackend(backend)) +} + +type CtxKeyLogger struct{} + +var ctxKeyLogger CtxKeyLogger + +func LoggerFromCtx(ctx context.Context) Logger { + if ctx == nil { + return Log() + } + ctxLog, _ := ctx.Value(ctxKeyLogger).(Logger) + if ctxLog != nil { + return ctxLog + } + return Log() +} + +func CtxWithLogger(ctx context.Context, log Logger) context.Context { + return context.WithValue(ctx, ctxKeyLogger, log) +} + +func Debug(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Debug(msg) +} + +func Debugf(ctx context.Context, format string, args ...any) { + LoggerFromCtx(ctx).Debugf(format, args...) +} + +func Info(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Info(msg) +} + +func Infof(ctx context.Context, format string, args ...any) { + LoggerFromCtx(ctx).Infof(format, args...) +} + +func Infoln(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Infoln(msg) +} + +func Warn(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Warn(msg) +} + +func Warnf(ctx context.Context, format string, args ...any) { + LoggerFromCtx(ctx).Warnf(format, args...) +} + +func Error(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Error(msg) +} + +func Errorf(ctx context.Context, format string, args ...any) { + LoggerFromCtx(ctx).Errorf(format, args...) +} + +func Fatal(ctx context.Context, msg string) { + LoggerFromCtx(ctx).Fatal(msg) +} + +func Fatalf(ctx context.Context, format string, args ...any) { + LoggerFromCtx(ctx).Fatalf(format, args...) +} + +type Fields logger.Fields + +func WithFields(ctx context.Context, keyValues Fields) Logger { + return LoggerFromCtx(ctx).WithFields(logger.Fields(keyValues)) +} + +func GetDelegate(ctx context.Context) any { + return LoggerFromCtx(ctx).GetDelegate() +} + +func SetLogLevel(ctx context.Context, level string) error { + return LoggerFromCtx(ctx).SetLogLevel(level) +}