logger: improvements #270

Merged
vtolstov merged 1 commits from logtrace into master 2023-10-17 01:00:22 +03:00
5 changed files with 150 additions and 23 deletions

View File

@ -1,5 +1,5 @@
// Package logger provides a log interface // Package logger provides a log interface
package logger // import "go.unistack.org/micro/v4/logger" package logger
import ( import (
"context" "context"
@ -8,19 +8,22 @@ import (
"go.unistack.org/micro/v4/options" "go.unistack.org/micro/v4/options"
) )
type ContextAttrFunc func(ctx context.Context) []interface{}
var DefaultContextAttrFuncs []ContextAttrFunc
var ( var (
// DefaultLogger variable // DefaultLogger variable
DefaultLogger = NewLogger(WithLevel(ParseLevel(os.Getenv("MICRO_LOG_LEVEL")))) DefaultLogger = NewLogger(
WithLevel(ParseLevel(os.Getenv("MICRO_LOG_LEVEL"))),
WithContextAttrFuncs(DefaultContextAttrFuncs...),
)
// DefaultLevel used by logger // DefaultLevel used by logger
DefaultLevel = InfoLevel DefaultLevel = InfoLevel
// DefaultCallerSkipCount used by logger // DefaultCallerSkipCount used by logger
DefaultCallerSkipCount = 2 DefaultCallerSkipCount = 2
) )
type ContextAttrFunc func(ctx context.Context) []interface{}
var DefaultContextAttrFuncs []ContextAttrFunc
// Logger is a generic logging interface // Logger is a generic logging interface
type Logger interface { type Logger interface {
// Init initialises options // Init initialises options

View File

@ -2,12 +2,14 @@ package logger
import ( import (
"context" "context"
"fmt"
"io" "io"
"os" "os"
"reflect" "reflect"
"go.unistack.org/micro/v4/options" "go.unistack.org/micro/v4/options"
rutil "go.unistack.org/micro/v4/util/reflect" rutil "go.unistack.org/micro/v4/util/reflect"
"golang.org/x/exp/slog"
) )
// Options holds logger options // Options holds logger options
@ -26,6 +28,14 @@ type Options struct {
CallerSkipCount int CallerSkipCount int
// ContextAttrFuncs contains funcs that executed before log func on context // ContextAttrFuncs contains funcs that executed before log func on context
ContextAttrFuncs []ContextAttrFunc ContextAttrFuncs []ContextAttrFunc
// TimeKey is the key used for the time of the log call
TimeKey string
// LevelKey is the key used for the level of the log call
LevelKey string
// MessageKey is the key used for the message of the log call
MessageKey string
// SourceKey is the key used for the source file and line of the log call
SourceKey string
} }
// NewOptions creates new options struct // NewOptions creates new options struct
@ -38,6 +48,9 @@ func NewOptions(opts ...options.Option) Options {
Context: context.Background(), Context: context.Background(),
ContextAttrFuncs: DefaultContextAttrFuncs, ContextAttrFuncs: DefaultContextAttrFuncs,
} }
WithMicroKeys()(&options)
for _, o := range opts { for _, o := range opts {
o(&options) o(&options)
} }
@ -45,18 +58,19 @@ func NewOptions(opts ...options.Option) Options {
} }
// WithContextAttrFuncs appends default funcs for the context arrts filler // WithContextAttrFuncs appends default funcs for the context arrts filler
func WithContextAttrFuncs(attrs ...interface{}) options.Option { func WithContextAttrFuncs(fncs ...ContextAttrFunc) options.Option {
return func(src interface{}) error { return func(src interface{}) error {
v, err := options.Get(src, ".ContextAttrFuncs") v, err := options.Get(src, ".ContextAttrFuncs")
if err != nil { if err != nil {
return err return err
} else if rutil.IsZero(v) { } else if rutil.IsZero(v) {
v = reflect.MakeSlice(reflect.TypeOf(v), 0, len(attrs)).Interface() v = reflect.MakeSlice(reflect.TypeOf(v), 0, len(fncs)).Interface()
} }
cv := reflect.ValueOf(v) cv := reflect.ValueOf(v)
for _, l := range attrs { for _, l := range fncs {
cv = reflect.Append(cv, reflect.ValueOf(l)) cv = reflect.Append(cv, reflect.ValueOf(l))
} }
fmt.Printf("EEEE %#+v\n", cv.Interface())
return options.Set(src, cv.Interface(), ".ContextAttrFuncs") return options.Set(src, cv.Interface(), ".ContextAttrFuncs")
} }
} }
@ -88,3 +102,79 @@ func WithCallerSkipCount(c int) options.Option {
return options.Set(src, c, ".CallerSkipCount") return options.Set(src, c, ".CallerSkipCount")
} }
} }
func WithZapKeys() options.Option {
return func(src interface{}) error {
var err error
if err = options.Set(src, "@timestamp", ".TimeKey"); err != nil {
return err
}
if err = options.Set(src, "level", ".LevelKey"); err != nil {
return err
}
if err = options.Set(src, "msg", ".MessageKey"); err != nil {
return err
}
if err = options.Set(src, "caller", ".SourceKey"); err != nil {
return err
}
return nil
}
}
func WithZerologKeys() options.Option {
return func(src interface{}) error {
var err error
if err = options.Set(src, "time", ".TimeKey"); err != nil {
return err
}
if err = options.Set(src, "level", ".LevelKey"); err != nil {
return err
}
if err = options.Set(src, "message", ".MessageKey"); err != nil {
return err
}
if err = options.Set(src, "caller", ".SourceKey"); err != nil {
return err
}
return nil
}
}
func WithSlogKeys() options.Option {
return func(src interface{}) error {
var err error
if err = options.Set(src, slog.TimeKey, ".TimeKey"); err != nil {
return err
}
if err = options.Set(src, slog.LevelKey, ".LevelKey"); err != nil {
return err
}
if err = options.Set(src, slog.MessageKey, ".MessageKey"); err != nil {
return err
}
if err = options.Set(src, slog.SourceKey, ".SourceKey"); err != nil {
return err
}
return nil
}
}
func WithMicroKeys() options.Option {
return func(src interface{}) error {
var err error
if err = options.Set(src, "timestamp", ".TimeKey"); err != nil {
return err
}
if err = options.Set(src, "level", ".LevelKey"); err != nil {
return err
}
if err = options.Set(src, "msg", ".MessageKey"); err != nil {
return err
}
if err = options.Set(src, "caller", ".SourceKey"); err != nil {
return err
}
return nil
}
}

View File

@ -117,12 +117,14 @@ func (s *slogLogger) Attrs(attrs ...interface{}) Logger {
} }
func (s *slogLogger) Init(opts ...options.Option) error { func (s *slogLogger) Init(opts ...options.Option) error {
if len(s.opts.ContextAttrFuncs) == 0 {
s.opts.ContextAttrFuncs = DefaultContextAttrFuncs
}
for _, o := range opts { for _, o := range opts {
if err := o(&s.opts); err != nil { if err := o(&s.opts); err != nil {
return err return err
} }
} }
if slog, ok := s.opts.Context.Value(loggerKey{}).(*slog.Logger); ok { if slog, ok := s.opts.Context.Value(loggerKey{}).(*slog.Logger); ok {
s.slog = slog s.slog = slog
return nil return nil
@ -149,7 +151,7 @@ func (s *slogLogger) Log(ctx context.Context, lvl Level, msg string, attrs ...in
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), msg, pcs[0]) r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -163,7 +165,7 @@ func (s *slogLogger) Info(ctx context.Context, msg string, attrs ...interface{})
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -177,7 +179,7 @@ func (s *slogLogger) Debug(ctx context.Context, msg string, attrs ...interface{}
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -191,7 +193,7 @@ func (s *slogLogger) Trace(ctx context.Context, msg string, attrs ...interface{}
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelDebug-1, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelDebug-1, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -205,7 +207,7 @@ func (s *slogLogger) Error(ctx context.Context, msg string, attrs ...interface{}
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -219,7 +221,7 @@ func (s *slogLogger) Fatal(ctx context.Context, msg string, attrs ...interface{}
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelError+1, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelError+1, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
@ -234,7 +236,7 @@ func (s *slogLogger) Warn(ctx context.Context, msg string, attrs ...interface{})
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof] runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
r := slog.NewRecord(time.Now(), slog.LevelWarn, msg, pcs[0]) r := slog.NewRecord(time.Now(), slog.LevelWarn, msg, pcs[0])
for _, fn := range s.opts.ContextAttrFuncs { for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx)) attrs = append(attrs, fn(ctx)...)
} }
r.Add(attrs...) r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)

View File

@ -27,8 +27,8 @@ func (t *noopTracer) Start(ctx context.Context, name string, opts ...options.Opt
labels: options.Labels, labels: options.Labels,
kind: options.Kind, kind: options.Kind,
} }
span.spanID, _ = id.New() span.spanID.s, _ = id.New()
span.traceID, _ = id.New() span.traceID.s, _ = id.New()
if span.ctx == nil { if span.ctx == nil {
span.ctx = context.Background() span.ctx = context.Background()
} }
@ -56,18 +56,26 @@ type noopEvent struct {
labels []interface{} labels []interface{}
} }
type noopStringer struct {
s string
}
func (s noopStringer) String() string {
return s.s
}
type noopSpan struct { type noopSpan struct {
ctx context.Context ctx context.Context
tracer Tracer tracer Tracer
name string name string
statusMsg string statusMsg string
traceID noopStringer
spanID noopStringer
events []*noopEvent events []*noopEvent
labels []interface{} labels []interface{}
logs []interface{} logs []interface{}
kind SpanKind kind SpanKind
status SpanStatus status SpanStatus
traceID string
spanID string
} }
func (s *noopSpan) Finish(opts ...options.Option) { func (s *noopSpan) Finish(opts ...options.Option) {
@ -103,11 +111,11 @@ func (s *noopSpan) Kind() SpanKind {
} }
func (s *noopSpan) TraceID() string { func (s *noopSpan) TraceID() string {
return s.traceID return s.traceID.String()
} }
func (s *noopSpan) SpanID() string { func (s *noopSpan) SpanID() string {
return s.spanID return s.spanID.String()
} }
func (s *noopSpan) Status() (SpanStatus, string) { func (s *noopSpan) Status() (SpanStatus, string) {

24
tracer/tracer_test.go Normal file
View File

@ -0,0 +1,24 @@
package tracer
import (
"bytes"
"context"
"strings"
"testing"
"go.unistack.org/micro/v4/logger"
)
func TestLoggerWithTracer(t *testing.T) {
ctx := context.TODO()
buf := bytes.NewBuffer(nil)
if err := logger.Init(logger.WithOutput(buf)); err != nil {
t.Fatal(err)
}
var span Span
ctx, span = DefaultTracer.Start(ctx, "test")
logger.Info(ctx, "msg")
if !strings.Contains(buf.String(), span.TraceID()) {
t.Fatalf("log does not contains tracer id")
}
}