Merge pull request 'tracer and logger improvements' (#312) from tracer-logger into v3

Reviewed-on: #312

logger/logger.go

@@ -6,6 +6,10 @@ import (
 	"os"
 )
 
+type ContextAttrFunc func(ctx context.Context) []interface{}
+
+var DefaultContextAttrFuncs []ContextAttrFunc
+
 var (
 	// DefaultLogger variable
 	DefaultLogger = NewLogger(WithLevel(ParseLevel(os.Getenv("MICRO_LOG_LEVEL"))))
@@ -67,76 +71,106 @@ type Logger interface {
 type Field interface{}
 
 // Info writes msg to default logger on info level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Info(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Info(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Info(ctx, args...)
 }
 
 // Error writes msg to default logger on error level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Error(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Error(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Error(ctx, args...)
 }
 
 // Debug writes msg to default logger on debug level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Debug(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Debug(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Debug(ctx, args...)
 }
 
 // Warn writes msg to default logger on warn level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Warn(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Warn(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Warn(ctx, args...)
 }
 
 // Trace writes msg to default logger on trace level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Trace(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Trace(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Trace(ctx, args...)
 }
 
 // Fatal writes msg to default logger on fatal level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Fatal(ctx context.Context, args ...interface{}) {
-	DefaultLogger.Fatal(ctx, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Fatal(ctx, args...)
 }
 
 // Infof writes formatted msg to default logger on info level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Infof(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Infof(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Infof(ctx, msg, args...)
 }
 
 // Errorf writes formatted msg to default logger on error level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Errorf(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Errorf(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Errorf(ctx, msg, args...)
 }
 
 // Debugf writes formatted msg to default logger on debug level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Debugf(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Debugf(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Debugf(ctx, msg, args...)
 }
 
 // Warnf writes formatted msg to default logger on warn level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Warnf(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Warnf(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Warnf(ctx, msg, args...)
 }
 
 // Tracef writes formatted msg to default logger on trace level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Tracef(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Tracef(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Tracef(ctx, msg, args...)
 }
 
 // Fatalf writes formatted msg to default logger on fatal level
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Fatalf(ctx context.Context, msg string, args ...interface{}) {
-	DefaultLogger.Fatalf(ctx, msg, args...)
+	DefaultLogger.Clone(WithCallerSkipCount(DefaultCallerSkipCount+1)).Fatalf(ctx, msg, args...)
 }
 
 // V returns true if passed level enabled in default logger
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func V(level Level) bool {
 	return DefaultLogger.V(level)
 }
 
 // Init initialize logger
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Init(opts ...Option) error {
 	return DefaultLogger.Init(opts...)
 }
 
 // Fields create logger with specific fields
+//
+// Deprecated: Dont use logger methods directly, use instance of logger to avoid additional allocations
 func Fields(fields ...interface{}) Logger {
 	return DefaultLogger.Fields(fields...)
 }

logger/options.go

@@ -3,6 +3,7 @@ package logger
 import (
 	"context"
 	"io"
+	"log/slog"
 	"os"
 )
 
@@ -19,10 +20,27 @@ type Options struct {
 	Name string
 	// Fields holds additional metadata
 	Fields []interface{}
+
 	// CallerSkipCount number of frmaes to skip
 	CallerSkipCount int
-	// Stacktrace controls writing of stacktaces on error
-	Stacktrace bool
+	// 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
+	// ErroreKey is the key used for the error of the log call
+	ErrorKey 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
+	// StacktraceKey is the key used for the stacktrace
+	StacktraceKey string
+	// AddStacktrace controls writing of stacktaces on error
+	AddStacktrace bool
+	// AddSource enabled writing source file and position in log
+	AddSource bool
 	// The logging level the logger should log
 	Level Level
 }
@@ -30,18 +48,31 @@ type Options struct {
 // NewOptions creates new options struct
 func NewOptions(opts ...Option) Options {
 	options := Options{
-		Level:           DefaultLevel,
-		Fields:          make([]interface{}, 0, 6),
-		Out:             os.Stderr,
-		CallerSkipCount: DefaultCallerSkipCount,
-		Context:         context.Background(),
+		Level:            DefaultLevel,
+		Fields:           make([]interface{}, 0, 6),
+		Out:              os.Stderr,
+		CallerSkipCount:  DefaultCallerSkipCount,
+		Context:          context.Background(),
+		ContextAttrFuncs: DefaultContextAttrFuncs,
+		AddSource:        true,
 	}
+
+	WithMicroKeys()(&options)
+
 	for _, o := range opts {
 		o(&options)
 	}
+
 	return options
 }
 
+// WithContextAttrFuncs appends default funcs for the context arrts filler
+func WithContextAttrFuncs(fncs ...ContextAttrFunc) Option {
+	return func(o *Options) {
+		o.ContextAttrFuncs = append(o.ContextAttrFuncs, fncs...)
+	}
+}
+
 // WithFields set default fields for the logger
 func WithFields(fields ...interface{}) Option {
 	return func(o *Options) {
@@ -63,10 +94,17 @@ func WithOutput(out io.Writer) Option {
 	}
 }
 
-// WithStacktrace controls writing stacktrace on error
-func WithStacktrace(v bool) Option {
+// WitAddStacktrace controls writing stacktrace on error
+func WithAddStacktrace(v bool) Option {
 	return func(o *Options) {
-		o.Stacktrace = v
+		o.AddStacktrace = v
+	}
+}
+
+// WitAddSource controls writing source file and pos in log
+func WithAddSource(v bool) Option {
+	return func(o *Options) {
+		o.AddSource = v
 	}
 }
 
@@ -90,3 +128,47 @@ func WithName(n string) Option {
 		o.Name = n
 	}
 }
+
+func WithZapKeys() Option {
+	return func(o *Options) {
+		o.TimeKey = "@timestamp"
+		o.LevelKey = "level"
+		o.MessageKey = "msg"
+		o.SourceKey = "caller"
+		o.StacktraceKey = "stacktrace"
+		o.ErrorKey = "error"
+	}
+}
+
+func WithZerologKeys() Option {
+	return func(o *Options) {
+		o.TimeKey = "time"
+		o.LevelKey = "level"
+		o.MessageKey = "message"
+		o.SourceKey = "caller"
+		o.StacktraceKey = "stacktrace"
+		o.ErrorKey = "error"
+	}
+}
+
+func WithSlogKeys() Option {
+	return func(o *Options) {
+		o.TimeKey = slog.TimeKey
+		o.LevelKey = slog.LevelKey
+		o.MessageKey = slog.MessageKey
+		o.SourceKey = slog.SourceKey
+		o.StacktraceKey = "stacktrace"
+		o.ErrorKey = "error"
+	}
+}
+
+func WithMicroKeys() Option {
+	return func(o *Options) {
+		o.TimeKey = "timestamp"
+		o.LevelKey = "level"
+		o.MessageKey = "msg"
+		o.SourceKey = "caller"
+		o.StacktraceKey = "stacktrace"
+		o.ErrorKey = "error"
+	}
+}

logger/slog/options.go

@@ -1,27 +0,0 @@
-package slog
-
-import "go.unistack.org/micro/v3/logger"
-
-type sourceKey struct{}
-
-func WithSourceKey(v string) logger.Option {
-	return logger.SetOption(sourceKey{}, v)
-}
-
-type timeKey struct{}
-
-func WithTimeKey(v string) logger.Option {
-	return logger.SetOption(timeKey{}, v)
-}
-
-type messageKey struct{}
-
-func WithMessageKey(v string) logger.Option {
-	return logger.SetOption(messageKey{}, v)
-}
-
-type levelKey struct{}
-
-func WithLevelKey(v string) logger.Option {
-	return logger.SetOption(levelKey{}, v)
-}

logger/slog/slog.go

@@ -17,13 +17,6 @@ import (
 
 var reTrace = regexp.MustCompile(`.*/slog/logger\.go.*\n`)
 
-var (
-	DefaultSourceKey  = slog.SourceKey
-	DefaultTimeKey    = slog.TimeKey
-	DefaultMessageKey = slog.MessageKey
-	DefaultLevelKey   = slog.LevelKey
-)
-
 var (
 	traceValue = slog.StringValue("trace")
 	debugValue = slog.StringValue("debug")
@@ -38,15 +31,15 @@ func (s *slogLogger) renameAttr(_ []string, a slog.Attr) slog.Attr {
 	case slog.SourceKey:
 		source := a.Value.Any().(*slog.Source)
 		a.Value = slog.StringValue(source.File + ":" + strconv.Itoa(source.Line))
-		a.Key = s.sourceKey
+		a.Key = s.opts.SourceKey
 	case slog.TimeKey:
-		a.Key = s.timeKey
+		a.Key = s.opts.TimeKey
 	case slog.MessageKey:
-		a.Key = s.messageKey
+		a.Key = s.opts.MessageKey
 	case slog.LevelKey:
 		level := a.Value.Any().(slog.Level)
 		lvl := slogToLoggerLevel(level)
-		a.Key = s.levelKey
+		a.Key = s.opts.LevelKey
 		switch {
 		case lvl < logger.DebugLevel:
 			a.Value = traceValue
@@ -69,14 +62,10 @@ func (s *slogLogger) renameAttr(_ []string, a slog.Attr) slog.Attr {
 }
 
 type slogLogger struct {
-	slog       *slog.Logger
-	leveler    *slog.LevelVar
-	levelKey   string
-	messageKey string
-	sourceKey  string
-	timeKey    string
-	opts       logger.Options
-	mu         sync.RWMutex
+	slog    *slog.Logger
+	leveler *slog.LevelVar
+	opts    logger.Options
+	mu      sync.RWMutex
 }
 
 func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger {
@@ -88,31 +77,14 @@ func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger {
 	}
 
 	l := &slogLogger{
-		opts:       options,
-		levelKey:   s.levelKey,
-		messageKey: s.messageKey,
-		sourceKey:  s.sourceKey,
-		timeKey:    s.timeKey,
-	}
-
-	if v, ok := l.opts.Context.Value(levelKey{}).(string); ok && v != "" {
-		l.levelKey = v
-	}
-	if v, ok := l.opts.Context.Value(messageKey{}).(string); ok && v != "" {
-		l.messageKey = v
-	}
-	if v, ok := l.opts.Context.Value(sourceKey{}).(string); ok && v != "" {
-		l.sourceKey = v
-	}
-	if v, ok := l.opts.Context.Value(timeKey{}).(string); ok && v != "" {
-		l.timeKey = v
+		opts: options,
 	}
 
 	l.leveler = new(slog.LevelVar)
 	handleOpt := &slog.HandlerOptions{
-		ReplaceAttr: s.renameAttr,
+		ReplaceAttr: l.renameAttr,
 		Level:       l.leveler,
-		AddSource:   true,
+		AddSource:   l.opts.AddSource,
 	}
 	l.leveler.Set(loggerToSlogLevel(l.opts.Level))
 	handler := slog.NewJSONHandler(options.Out, handleOpt)
@@ -137,61 +109,45 @@ func (s *slogLogger) Options() logger.Options {
 
 func (s *slogLogger) Fields(attrs ...interface{}) logger.Logger {
 	s.mu.RLock()
-	nl := &slogLogger{
-		opts:       s.opts,
-		levelKey:   s.levelKey,
-		messageKey: s.messageKey,
-		sourceKey:  s.sourceKey,
-		timeKey:    s.timeKey,
-	}
-	nl.leveler = new(slog.LevelVar)
-	nl.leveler.Set(s.leveler.Level())
+	l := &slogLogger{opts: s.opts}
+	l.leveler = new(slog.LevelVar)
+	l.leveler.Set(s.leveler.Level())
 
 	handleOpt := &slog.HandlerOptions{
-		ReplaceAttr: nl.renameAttr,
-		Level:       nl.leveler,
-		AddSource:   true,
+		ReplaceAttr: l.renameAttr,
+		Level:       l.leveler,
+		AddSource:   l.opts.AddSource,
 	}
 
 	handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
-	nl.slog = slog.New(handler).With(attrs...)
+	l.slog = slog.New(handler).With(attrs...)
 
 	s.mu.RUnlock()
 
-	return nl
+	return l
 }
 
 func (s *slogLogger) Init(opts ...logger.Option) error {
 	s.mu.Lock()
-	for _, o := range opts {
-		o(&s.opts)
+
+	if len(s.opts.ContextAttrFuncs) == 0 {
+		s.opts.ContextAttrFuncs = logger.DefaultContextAttrFuncs
 	}
 
-	if v, ok := s.opts.Context.Value(levelKey{}).(string); ok && v != "" {
-		s.levelKey = v
-	}
-	if v, ok := s.opts.Context.Value(messageKey{}).(string); ok && v != "" {
-		s.messageKey = v
-	}
-	if v, ok := s.opts.Context.Value(sourceKey{}).(string); ok && v != "" {
-		s.sourceKey = v
-	}
-	if v, ok := s.opts.Context.Value(timeKey{}).(string); ok && v != "" {
-		s.timeKey = v
+	for _, o := range opts {
+		o(&s.opts)
 	}
 
 	s.leveler = new(slog.LevelVar)
 	handleOpt := &slog.HandlerOptions{
 		ReplaceAttr: s.renameAttr,
 		Level:       s.leveler,
-		AddSource:   true,
+		AddSource:   s.opts.AddSource,
 	}
 	s.leveler.Set(loggerToSlogLevel(s.opts.Level))
 	handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
 	s.slog = slog.New(handler).With(s.opts.Fields...)
 
-	slog.SetDefault(s.slog)
-
 	s.mu.Unlock()
 
 	return nil
@@ -204,7 +160,35 @@ func (s *slogLogger) Log(ctx context.Context, lvl logger.Level, attrs ...interfa
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	if s.opts.AddStacktrace && lvl == logger.ErrorLevel {
+		stackInfo := make([]byte, 1024*1024)
+		if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
+			traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
+			if len(traceLines) != 0 {
+				attrs = append(attrs, slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1]))
+			}
+		}
+	}
+	r.Add(attrs[1:]...)
+	r.Attrs(func(a slog.Attr) bool {
+		if a.Key == s.opts.ErrorKey {
+			if span, ok := tracer.SpanFromContext(ctx); ok {
+				span.SetStatus(tracer.SpanStatusError, a.Value.String())
+				return false
+			}
+		}
+		return true
+	})
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -214,8 +198,36 @@ func (s *slogLogger) Logf(ctx context.Context, lvl logger.Level, msg string, att
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), loggerToSlogLevel(lvl), msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	if s.opts.AddStacktrace && lvl == logger.ErrorLevel {
+		stackInfo := make([]byte, 1024*1024)
+		if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
+			traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
+			if len(traceLines) != 0 {
+				attrs = append(attrs, (slog.String(s.opts.StacktraceKey, traceLines[len(traceLines)-1])))
+			}
+		}
+	}
+	r.Add(attrs[1:]...)
+	r.Attrs(func(a slog.Attr) bool {
+		if a.Key == s.opts.ErrorKey {
+			if span, ok := tracer.SpanFromContext(ctx); ok {
+				span.SetStatus(tracer.SpanStatusError, a.Value.String())
+				return false
+			}
+		}
+		return true
+	})
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -226,7 +238,17 @@ func (s *slogLogger) Info(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -236,8 +258,18 @@ func (s *slogLogger) Infof(ctx context.Context, msg string, attrs ...interface{}
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelInfo, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), slog.LevelInfo, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -248,7 +280,17 @@ func (s *slogLogger) Debug(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -258,8 +300,18 @@ func (s *slogLogger) Debugf(ctx context.Context, msg string, attrs ...interface{
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelDebug, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), slog.LevelDebug, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -270,7 +322,17 @@ func (s *slogLogger) Trace(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelDebug-1, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -280,8 +342,18 @@ func (s *slogLogger) Tracef(ctx context.Context, msg string, attrs ...interface{
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelDebug-1, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), slog.LevelDebug-1, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -292,18 +364,28 @@ func (s *slogLogger) Error(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	//	r.Add(attrs[1:]...)
-	if s.opts.Stacktrace {
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	if s.opts.AddStacktrace {
 		stackInfo := make([]byte, 1024*1024)
 		if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
 			traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
 			if len(traceLines) != 0 {
-				r.AddAttrs(slog.String("stacktrace", traceLines[len(traceLines)-1]))
+				attrs = append(attrs, slog.String("stacktrace", traceLines[len(traceLines)-1]))
 			}
 		}
 	}
+	r.Add(attrs[1:]...)
 	r.Attrs(func(a slog.Attr) bool {
-		if a.Key == "error" {
+		if a.Key == s.opts.ErrorKey {
 			if span, ok := tracer.SpanFromContext(ctx); ok {
 				span.SetStatus(tracer.SpanStatusError, a.Value.String())
 				return false
@@ -320,19 +402,29 @@ func (s *slogLogger) Errorf(ctx context.Context, msg string, attrs ...interface{
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelError, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
-	if s.opts.Stacktrace {
+	r := slog.NewRecord(time.Now(), slog.LevelError, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	if s.opts.AddStacktrace {
 		stackInfo := make([]byte, 1024*1024)
 		if stackSize := runtime.Stack(stackInfo, false); stackSize > 0 {
 			traceLines := reTrace.Split(string(stackInfo[:stackSize]), -1)
 			if len(traceLines) != 0 {
-				r.AddAttrs(slog.String("stacktrace", traceLines[len(traceLines)-1]))
+				attrs = append(attrs, slog.String("stacktrace", traceLines[len(traceLines)-1]))
 			}
 		}
 	}
+	r.Add(attrs...)
 	r.Attrs(func(a slog.Attr) bool {
-		if a.Key == "error" {
+		if a.Key == s.opts.ErrorKey {
 			if span, ok := tracer.SpanFromContext(ctx); ok {
 				span.SetStatus(tracer.SpanStatusError, a.Value.String())
 				return false
@@ -350,7 +442,17 @@ func (s *slogLogger) Fatal(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelError+1, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 	os.Exit(1)
 }
@@ -361,8 +463,18 @@ func (s *slogLogger) Fatalf(ctx context.Context, msg string, attrs ...interface{
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelError+1, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), slog.LevelError+1, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs...)
 	_ = s.slog.Handler().Handle(ctx, r)
 	os.Exit(1)
 }
@@ -374,7 +486,17 @@ func (s *slogLogger) Warn(ctx context.Context, attrs ...interface{}) {
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
 	r := slog.NewRecord(time.Now(), slog.LevelWarn, fmt.Sprintf("%s", attrs[0]), pcs[0])
-	// r.Add(attrs[1:]...)
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -384,8 +506,18 @@ func (s *slogLogger) Warnf(ctx context.Context, msg string, attrs ...interface{}
 	}
 	var pcs [1]uintptr
 	runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
-	r := slog.NewRecord(time.Now(), slog.LevelWarn, fmt.Sprintf(msg, attrs...), pcs[0])
-	// r.Add(attrs...)
+	r := slog.NewRecord(time.Now(), slog.LevelWarn, msg, pcs[0])
+	for _, fn := range s.opts.ContextAttrFuncs {
+		attrs = append(attrs, fn(ctx)...)
+	}
+
+	for idx, attr := range attrs {
+		if ve, ok := attr.(error); ok && ve != nil {
+			attrs[idx] = slog.String(s.opts.ErrorKey, ve.Error())
+			break
+		}
+	}
+	r.Add(attrs[1:]...)
 	_ = s.slog.Handler().Handle(ctx, r)
 }
 
@@ -399,24 +531,9 @@ func (s *slogLogger) String() string {
 
 func NewLogger(opts ...logger.Option) logger.Logger {
 	s := &slogLogger{
-		opts:       logger.NewOptions(opts...),
-		sourceKey:  DefaultSourceKey,
-		timeKey:    DefaultTimeKey,
-		messageKey: DefaultMessageKey,
-		levelKey:   DefaultLevelKey,
-	}
-	if v, ok := s.opts.Context.Value(levelKey{}).(string); ok && v != "" {
-		s.levelKey = v
-	}
-	if v, ok := s.opts.Context.Value(messageKey{}).(string); ok && v != "" {
-		s.messageKey = v
-	}
-	if v, ok := s.opts.Context.Value(sourceKey{}).(string); ok && v != "" {
-		s.sourceKey = v
-	}
-	if v, ok := s.opts.Context.Value(timeKey{}).(string); ok && v != "" {
-		s.timeKey = v
+		opts: logger.NewOptions(opts...),
 	}
+
 	return s
 }
 

logger/slog/slog_test.go

@@ -3,6 +3,7 @@ package slog
 import (
 	"bytes"
 	"context"
+	"fmt"
 	"log"
 	"testing"
 
@@ -17,10 +18,30 @@ func TestError(t *testing.T) {
 		t.Fatal(err)
 	}
 
-	l.Error(ctx, "message")
+	l.Error(ctx, "message", fmt.Errorf("error message"))
 	if !bytes.Contains(buf.Bytes(), []byte(`"stacktrace":"`)) {
 		t.Fatalf("logger stacktrace not works, buf contains: %s", buf.Bytes())
 	}
+	if !bytes.Contains(buf.Bytes(), []byte(`"error":"`)) {
+		t.Fatalf("logger error not works, buf contains: %s", buf.Bytes())
+	}
+}
+
+func TestErrorf(t *testing.T) {
+	ctx := context.TODO()
+	buf := bytes.NewBuffer(nil)
+	l := NewLogger(logger.WithLevel(logger.ErrorLevel), logger.WithOutput(buf), logger.WithStacktrace(true))
+	if err := l.Init(); err != nil {
+		t.Fatal(err)
+	}
+
+	l.Errorf(ctx, "message", fmt.Errorf("error message"))
+	if !bytes.Contains(buf.Bytes(), []byte(`"stacktrace":"`)) {
+		t.Fatalf("logger stacktrace not works, buf contains: %s", buf.Bytes())
+	}
+	if !bytes.Contains(buf.Bytes(), []byte(`"error":"`)) {
+		t.Fatalf("logger error not works, buf contains: %s", buf.Bytes())
+	}
 }
 
 func TestContext(t *testing.T) {

tracer/memory/memory.go

@@ -0,0 +1,139 @@
+package memory
+
+import (
+	"context"
+	"time"
+
+	"go.unistack.org/micro/v3/tracer"
+	"go.unistack.org/micro/v3/util/id"
+)
+
+var _ tracer.Tracer = (*Tracer)(nil)
+
+type Tracer struct {
+	opts  tracer.Options
+	spans []tracer.Span
+}
+
+func (t *Tracer) Spans() []tracer.Span {
+	return t.spans
+}
+
+func (t *Tracer) Start(ctx context.Context, name string, opts ...tracer.SpanOption) (context.Context, tracer.Span) {
+	options := tracer.NewSpanOptions(opts...)
+	span := &Span{
+		name:      name,
+		ctx:       ctx,
+		tracer:    t,
+		kind:      options.Kind,
+		startTime: time.Now(),
+	}
+	span.spanID.s, _ = id.New()
+	span.traceID.s, _ = id.New()
+	if span.ctx == nil {
+		span.ctx = context.Background()
+	}
+	t.spans = append(t.spans, span)
+	return tracer.NewSpanContext(ctx, span), span
+}
+
+func (t *Tracer) Flush(_ context.Context) error {
+	return nil
+}
+
+func (t *Tracer) Init(opts ...tracer.Option) error {
+	for _, o := range opts {
+		o(&t.opts)
+	}
+	return nil
+}
+
+func (t *Tracer) Name() string {
+	return t.opts.Name
+}
+
+type noopStringer struct {
+	s string
+}
+
+func (s noopStringer) String() string {
+	return s.s
+}
+
+type Span struct {
+	ctx        context.Context
+	tracer     tracer.Tracer
+	name       string
+	statusMsg  string
+	startTime  time.Time
+	finishTime time.Time
+	traceID    noopStringer
+	spanID     noopStringer
+	events     []*Event
+	labels     []interface{}
+	logs       []interface{}
+	kind       tracer.SpanKind
+	status     tracer.SpanStatus
+}
+
+func (s *Span) Finish(_ ...tracer.SpanOption) {
+	s.finishTime = time.Now()
+}
+
+func (s *Span) Context() context.Context {
+	return s.ctx
+}
+
+func (s *Span) Tracer() tracer.Tracer {
+	return s.tracer
+}
+
+type Event struct {
+	name   string
+	labels []interface{}
+}
+
+func (s *Span) AddEvent(name string, opts ...tracer.EventOption) {
+	options := tracer.NewEventOptions(opts...)
+	s.events = append(s.events, &Event{name: name, labels: options.Labels})
+}
+
+func (s *Span) SetName(name string) {
+	s.name = name
+}
+
+func (s *Span) AddLogs(kv ...interface{}) {
+	s.logs = append(s.logs, kv...)
+}
+
+func (s *Span) AddLabels(kv ...interface{}) {
+	s.labels = append(s.labels, kv...)
+}
+
+func (s *Span) Kind() tracer.SpanKind {
+	return s.kind
+}
+
+func (s *Span) TraceID() string {
+	return s.traceID.String()
+}
+
+func (s *Span) SpanID() string {
+	return s.spanID.String()
+}
+
+func (s *Span) Status() (tracer.SpanStatus, string) {
+	return s.status, s.statusMsg
+}
+
+func (s *Span) SetStatus(st tracer.SpanStatus, msg string) {
+	s.status = st
+	s.statusMsg = msg
+}
+
+// NewTracer returns new memory tracer
+func NewTracer(opts ...tracer.Option) *Tracer {
+	return &Tracer{
+		opts: tracer.NewOptions(opts...),
+	}
+}

tracer/memory/memory_test.go

@@ -0,0 +1,38 @@
+package memory
+
+import (
+	"bytes"
+	"context"
+	"fmt"
+	"strings"
+	"testing"
+
+	"go.unistack.org/micro/v3/logger"
+	"go.unistack.org/micro/v3/logger/slog"
+	"go.unistack.org/micro/v3/tracer"
+)
+
+func TestLoggerWithTracer(t *testing.T) {
+	ctx := context.TODO()
+	buf := bytes.NewBuffer(nil)
+	logger.DefaultLogger = slog.NewLogger(logger.WithOutput(buf))
+
+	if err := logger.Init(); err != nil {
+		t.Fatal(err)
+	}
+	var span tracer.Span
+	tr := NewTracer()
+	ctx, span = tr.Start(ctx, "test1")
+
+	logger.Error(ctx, "my test error", fmt.Errorf("error"))
+
+	if !strings.Contains(buf.String(), span.TraceID()) {
+		t.Fatalf("log does not contains trace id: %s", buf.Bytes())
+	}
+
+	_, _ = tr.Start(ctx, "test2")
+
+	for _, s := range tr.Spans() {
+		_ = s
+	}
+}

tracer/noop.go

@@ -2,6 +2,8 @@ package tracer
 
 import (
 	"context"
+
+	"go.unistack.org/micro/v3/util/id"
 )
 
 var _ Tracer = (*noopTracer)(nil)
@@ -24,6 +26,8 @@ func (t *noopTracer) Start(ctx context.Context, name string, opts ...SpanOption)
 		labels: options.Labels,
 		kind:   options.Kind,
 	}
+	span.spanID.s, _ = id.New()
+	span.traceID.s, _ = id.New()
 	if span.ctx == nil {
 		span.ctx = context.Background()
 	}
@@ -31,6 +35,14 @@ func (t *noopTracer) Start(ctx context.Context, name string, opts ...SpanOption)
 	return NewSpanContext(ctx, span), span
 }
 
+type noopStringer struct {
+	s string
+}
+
+func (s noopStringer) String() string {
+	return s.s
+}
+
 func (t *noopTracer) Flush(ctx context.Context) error {
 	return nil
 }
@@ -56,6 +68,8 @@ type noopSpan struct {
 	tracer    Tracer
 	name      string
 	statusMsg string
+	traceID   noopStringer
+	spanID    noopStringer
 	events    []*noopEvent
 	labels    []interface{}
 	logs      []interface{}
@@ -63,7 +77,15 @@ type noopSpan struct {
 	status    SpanStatus
 }
 
-func (s *noopSpan) Finish(opts ...SpanOption) {
+func (s *noopSpan) TraceID() string {
+	return s.traceID.String()
+}
+
+func (s *noopSpan) SpanID() string {
+	return s.spanID.String()
+}
+
+func (s *noopSpan) Finish(_ ...SpanOption) {
 }
 
 func (s *noopSpan) Context() context.Context {

tracer/tracer.go

@@ -5,11 +5,33 @@ import (
 	"context"
 	"fmt"
 	"sort"
+
+	"go.unistack.org/micro/v3/logger"
 )
 
 // DefaultTracer is the global default tracer
 var DefaultTracer = NewTracer()
 
+var (
+	// TraceIDKey is the key used for the trace id in the log call
+	TraceIDKey = "trace-id"
+	// SpanIDKey is the key used for the span id in the log call
+	SpanIDKey = "span-id"
+)
+
+func init() {
+	logger.DefaultContextAttrFuncs = append(logger.DefaultContextAttrFuncs,
+		func(ctx context.Context) []interface{} {
+			if span, ok := SpanFromContext(ctx); ok {
+				return []interface{}{
+					TraceIDKey, span.TraceID(),
+					SpanIDKey, span.SpanID(),
+				}
+			}
+			return nil
+		})
+}
+
 // Tracer is an interface for distributed tracing
 type Tracer interface {
 	// Name return tracer name
@@ -43,6 +65,10 @@ type Span interface {
 	AddLogs(kv ...interface{})
 	// Kind returns span kind
 	Kind() SpanKind
+	// TraceID returns trace id
+	TraceID() string
+	// SpanID returns span id
+	SpanID() string
 }
 
 // sort labels alphabeticaly by label name