Merge pull request 'logger: improvements' (#270) from logtrace into master

Reviewed-on: #270

logger/logger.go

@@ -1,5 +1,5 @@
 // Package logger provides a log interface
-package logger // import "go.unistack.org/micro/v4/logger"
+package logger
 
 import (
 	"context"
@@ -8,19 +8,22 @@ import (
 	"go.unistack.org/micro/v4/options"
 )
 
+type ContextAttrFunc func(ctx context.Context) []interface{}
+
+var DefaultContextAttrFuncs []ContextAttrFunc
+
 var (
 	// 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 = InfoLevel
 	// DefaultCallerSkipCount used by logger
 	DefaultCallerSkipCount = 2
 )
 
-type ContextAttrFunc func(ctx context.Context) []interface{}
-
-var DefaultContextAttrFuncs []ContextAttrFunc
-
 // Logger is a generic logging interface
 type Logger interface {
 	// Init initialises options

logger/options.go

@@ -2,12 +2,14 @@ package logger
 
 import (
 	"context"
+	"fmt"
 	"io"
 	"os"
 	"reflect"
 
 	"go.unistack.org/micro/v4/options"
 	rutil "go.unistack.org/micro/v4/util/reflect"
+	"golang.org/x/exp/slog"
 )
 
 // Options holds logger options
@@ -26,6 +28,14 @@ type Options struct {
 	CallerSkipCount int
 	// ContextAttrFuncs contains funcs that executed before log func on context
 	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
@@ -38,6 +48,9 @@ func NewOptions(opts ...options.Option) Options {
 		Context:          context.Background(),
 		ContextAttrFuncs: DefaultContextAttrFuncs,
 	}
+
+	WithMicroKeys()(&options)
+
 	for _, o := range opts {
 		o(&options)
 	}
@@ -45,18 +58,19 @@ func NewOptions(opts ...options.Option) Options {
 }
 
 // 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 {
 		v, err := options.Get(src, ".ContextAttrFuncs")
 		if err != nil {
 			return err
 		} 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)
-		for _, l := range attrs {
+		for _, l := range fncs {
 			cv = reflect.Append(cv, reflect.ValueOf(l))
 		}
+		fmt.Printf("EEEE %#+v\n", cv.Interface())
 		return options.Set(src, cv.Interface(), ".ContextAttrFuncs")
 	}
 }
@@ -88,3 +102,79 @@ func WithCallerSkipCount(c int) options.Option {
 		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
+	}
+}

logger/slog.go

@@ -117,12 +117,14 @@ func (s *slogLogger) Attrs(attrs ...interface{}) Logger {
 }
 
 func (s *slogLogger) Init(opts ...options.Option) error {
+	if len(s.opts.ContextAttrFuncs) == 0 {
+		s.opts.ContextAttrFuncs = DefaultContextAttrFuncs
+	}
 	for _, o := range opts {
 		if err := o(&s.opts); err != nil {
 			return err
 		}
 	}
-
 	if slog, ok := s.opts.Context.Value(loggerKey{}).(*slog.Logger); ok {
 		s.slog = slog
 		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]
 	r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelDebug, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelDebug-1, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelError+1, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = 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]
 	r := slog.NewRecord(time.Now(), slog.LevelWarn, msg, pcs[0])
 	for _, fn := range s.opts.ContextAttrFuncs {
-		attrs = append(attrs, fn(ctx))
+		attrs = append(attrs, fn(ctx)...)
 	}
 	r.Add(attrs...)
 	_ = s.slog.Handler().Handle(ctx, r)

tracer/noop.go

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

tracer/tracer_test.go

@@ -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")
+	}
+}