logger: add ability to fill fileds from context #269

Merged
vtolstov merged 1 commits from logger-slog into master 2023-10-16 23:44:26 +03:00
6 changed files with 133 additions and 64 deletions

View File

@ -17,6 +17,10 @@ var (
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
@ -29,57 +33,54 @@ type Logger interface {
Level(level Level) Level(level Level)
// The Logger options // The Logger options
Options() Options Options() Options
// Fields set fields to always be logged with keyval pairs // Attrs set attrs to always be logged with keyval pairs
Fields(fields ...interface{}) Logger Attrs(attrs ...interface{}) Logger
// Info level message // Info level message
Info(ctx context.Context, msg string, args ...interface{}) Info(ctx context.Context, msg string, attrs ...interface{})
// Tracef level message // Tracef level message
Trace(ctx context.Context, msg string, args ...interface{}) Trace(ctx context.Context, msg string, attrs ...interface{})
// Debug level message // Debug level message
Debug(ctx context.Context, msg string, args ...interface{}) Debug(ctx context.Context, msg string, attrs ...interface{})
// Warn level message // Warn level message
Warn(ctx context.Context, msg string, args ...interface{}) Warn(ctx context.Context, msg string, attrs ...interface{})
// Error level message // Error level message
Error(ctx context.Context, msg string, args ...interface{}) Error(ctx context.Context, msg string, attrs ...interface{})
// Fatal level message // Fatal level message
Fatal(ctx context.Context, msg string, args ...interface{}) Fatal(ctx context.Context, msg string, attrs ...interface{})
// Log logs message with needed level // Log logs message with needed level
Log(ctx context.Context, level Level, msg string, args ...interface{}) Log(ctx context.Context, level Level, msg string, attrs ...interface{})
// String returns the name of logger // String returns the name of logger
String() string String() string
} }
// Field contains keyval pair
type Field interface{}
// Info writes formatted msg to default logger on info level // Info writes formatted msg to default logger on info level
func Info(ctx context.Context, msg string, args ...interface{}) { func Info(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Info(ctx, msg, args...) DefaultLogger.Info(ctx, msg, attrs...)
} }
// Error writes formatted msg to default logger on error level // Error writes formatted msg to default logger on error level
func Error(ctx context.Context, msg string, args ...interface{}) { func Error(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Error(ctx, msg, args...) DefaultLogger.Error(ctx, msg, attrs...)
} }
// Debugf writes formatted msg to default logger on debug level // Debugf writes formatted msg to default logger on debug level
func Debugf(ctx context.Context, msg string, args ...interface{}) { func Debugf(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Debug(ctx, msg, args...) DefaultLogger.Debug(ctx, msg, attrs...)
} }
// Warn writes formatted msg to default logger on warn level // Warn writes formatted msg to default logger on warn level
func Warn(ctx context.Context, msg string, args ...interface{}) { func Warn(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Warn(ctx, msg, args...) DefaultLogger.Warn(ctx, msg, attrs...)
} }
// Trace writes formatted msg to default logger on trace level // Trace writes formatted msg to default logger on trace level
func Trace(ctx context.Context, msg string, args ...interface{}) { func Trace(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Trace(ctx, msg, args...) DefaultLogger.Trace(ctx, msg, attrs...)
} }
// Fatal writes formatted msg to default logger on fatal level // Fatal writes formatted msg to default logger on fatal level
func Fatal(ctx context.Context, msg string, args ...interface{}) { func Fatal(ctx context.Context, msg string, attrs ...interface{}) {
DefaultLogger.Fatal(ctx, msg, args...) DefaultLogger.Fatal(ctx, msg, attrs...)
} }
// V returns true if passed level enabled in default logger // V returns true if passed level enabled in default logger
@ -87,12 +88,12 @@ func V(level Level) bool {
return DefaultLogger.V(level) return DefaultLogger.V(level)
} }
// Init initialize logger // Init initialize default logger
func Init(opts ...options.Option) error { func Init(opts ...options.Option) error {
return DefaultLogger.Init(opts...) return DefaultLogger.Init(opts...)
} }
// Fields create logger with specific fields // Attrs create default logger with specific attrs
func Fields(fields ...interface{}) Logger { func Attrs(attrs ...interface{}) Logger {
return DefaultLogger.Fields(fields...) return DefaultLogger.Attrs(attrs...)
} }

View File

@ -15,7 +15,7 @@ func TestContext(t *testing.T) {
t.Fatal(err) t.Fatal(err)
} }
nl, ok := FromContext(NewContext(ctx, l.Fields("key", "val"))) nl, ok := FromContext(NewContext(ctx, l.Attrs("key", "val")))
if !ok { if !ok {
t.Fatal("context without logger") t.Fatal("context without logger")
} }
@ -25,7 +25,7 @@ func TestContext(t *testing.T) {
} }
} }
func TestFields(t *testing.T) { func TestAttrs(t *testing.T) {
ctx := context.TODO() ctx := context.TODO()
buf := bytes.NewBuffer(nil) buf := bytes.NewBuffer(nil)
l := NewLogger(WithLevel(TraceLevel), WithOutput(buf)) l := NewLogger(WithLevel(TraceLevel), WithOutput(buf))
@ -33,7 +33,7 @@ func TestFields(t *testing.T) {
t.Fatal(err) t.Fatal(err)
} }
nl := l.Fields("key", "val") nl := l.Attrs("key", "val")
nl.Info(ctx, "message") nl.Info(ctx, "message")
if !bytes.Contains(buf.Bytes(), []byte(`"key":"val"`)) { if !bytes.Contains(buf.Bytes(), []byte(`"key":"val"`)) {
@ -49,7 +49,7 @@ func TestFromContextWithFields(t *testing.T) {
if err := l.Init(); err != nil { if err := l.Init(); err != nil {
t.Fatal(err) t.Fatal(err)
} }
nl := l.Fields("key", "val") nl := l.Attrs("key", "val")
ctx = NewContext(ctx, nl) ctx = NewContext(ctx, nl)
@ -121,7 +121,7 @@ func TestLogger(t *testing.T) {
} }
l.Trace(ctx, "trace_msg1") l.Trace(ctx, "trace_msg1")
l.Warn(ctx, "warn_msg1") l.Warn(ctx, "warn_msg1")
l.Fields("error", "test").Info(ctx, "error message") l.Attrs("error", "test").Info(ctx, "error message")
l.Warn(ctx, "first second") l.Warn(ctx, "first second")
if !(bytes.Contains(buf.Bytes(), []byte(`"level":"trace"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"trace_msg1"`))) { if !(bytes.Contains(buf.Bytes(), []byte(`"level":"trace"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"trace_msg1"`))) {

View File

@ -4,8 +4,10 @@ import (
"context" "context"
"io" "io"
"os" "os"
"reflect"
"go.unistack.org/micro/v4/options" "go.unistack.org/micro/v4/options"
rutil "go.unistack.org/micro/v4/util/reflect"
) )
// Options holds logger options // Options holds logger options
@ -14,24 +16,27 @@ type Options struct {
Out io.Writer Out io.Writer
// Context holds exernal options // Context holds exernal options
Context context.Context Context context.Context
// Fields holds additional metadata // Attrs holds additional attributes
Fields []interface{} Attrs []interface{}
// Name holds the logger name // Name holds the logger name
Name string Name string
// The logging level the logger should log // The logging level the logger should log
Level Level Level Level
// CallerSkipCount number of frmaes to skip // CallerSkipCount number of frmaes to skip
CallerSkipCount int CallerSkipCount int
// ContextAttrFuncs contains funcs that executed before log func on context
ContextAttrFuncs []ContextAttrFunc
} }
// NewOptions creates new options struct // NewOptions creates new options struct
func NewOptions(opts ...options.Option) Options { func NewOptions(opts ...options.Option) Options {
options := Options{ options := Options{
Level: DefaultLevel, Level: DefaultLevel,
Fields: make([]interface{}, 0, 6), Attrs: make([]interface{}, 0, 6),
Out: os.Stderr, Out: os.Stderr,
CallerSkipCount: DefaultCallerSkipCount, CallerSkipCount: DefaultCallerSkipCount,
Context: context.Background(), Context: context.Background(),
ContextAttrFuncs: DefaultContextAttrFuncs,
} }
for _, o := range opts { for _, o := range opts {
o(&options) o(&options)
@ -39,10 +44,27 @@ func NewOptions(opts ...options.Option) Options {
return options return options
} }
// WithFields set default fields for the logger // WithContextAttrFuncs appends default funcs for the context arrts filler
func WithFields(fields ...interface{}) options.Option { func WithContextAttrFuncs(attrs ...interface{}) options.Option {
return func(src interface{}) error { return func(src interface{}) error {
return options.Set(src, fields, ".Fields") 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()
}
cv := reflect.ValueOf(v)
for _, l := range attrs {
cv = reflect.Append(cv, reflect.ValueOf(l))
}
return options.Set(src, cv.Interface(), ".ContextAttrFuncs")
}
}
// WithAttrs set default fields for the logger
func WithAttrs(attrs ...interface{}) options.Option {
return func(src interface{}) error {
return options.Set(src, attrs, ".Attrs")
} }
} }

View File

@ -26,9 +26,6 @@ var renameAttr = func(_ []string, a slog.Attr) slog.Attr {
source := a.Value.Any().(*slog.Source) source := a.Value.Any().(*slog.Source)
a.Value = slog.StringValue(source.File + ":" + strconv.Itoa(source.Line)) a.Value = slog.StringValue(source.File + ":" + strconv.Itoa(source.Line))
a.Key = "caller" a.Key = "caller"
// add func?
// "trace": "<traceid>",
// "span": "<spanid>",
case slog.TimeKey: case slog.TimeKey:
a.Key = "timestamp" a.Key = "timestamp"
case slog.LevelKey: case slog.LevelKey:
@ -85,7 +82,7 @@ func (s *slogLogger) Clone(opts ...options.Option) Logger {
} }
l.leveler.Set(loggerToSlogLevel(l.opts.Level)) l.leveler.Set(loggerToSlogLevel(l.opts.Level))
handler := slog.NewJSONHandler(options.Out, handleOpt) handler := slog.NewJSONHandler(options.Out, handleOpt)
l.slog = slog.New(handler).With(options.Fields...) l.slog = slog.New(handler).With(options.Attrs...)
return l return l
} }
@ -102,7 +99,7 @@ func (s *slogLogger) Options() Options {
return s.opts return s.opts
} }
func (s *slogLogger) Fields(fields ...interface{}) Logger { func (s *slogLogger) Attrs(attrs ...interface{}) Logger {
nl := &slogLogger{opts: s.opts} nl := &slogLogger{opts: s.opts}
nl.leveler = new(slog.LevelVar) nl.leveler = new(slog.LevelVar)
nl.leveler.Set(s.leveler.Level()) nl.leveler.Set(s.leveler.Level())
@ -114,7 +111,7 @@ func (s *slogLogger) Fields(fields ...interface{}) Logger {
} }
handler := slog.NewJSONHandler(s.opts.Out, handleOpt) handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
nl.slog = slog.New(handler).With(fields...) nl.slog = slog.New(handler).With(attrs...)
return nl return nl
} }
@ -139,86 +136,107 @@ func (s *slogLogger) Init(opts ...options.Option) error {
} }
s.leveler.Set(loggerToSlogLevel(s.opts.Level)) s.leveler.Set(loggerToSlogLevel(s.opts.Level))
handler := slog.NewJSONHandler(s.opts.Out, handleOpt) handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
s.slog = slog.New(handler).With(s.opts.Fields...) s.slog = slog.New(handler).With(s.opts.Attrs...)
return nil return nil
} }
func (s *slogLogger) Log(ctx context.Context, lvl Level, msg string, args ...any) { func (s *slogLogger) Log(ctx context.Context, lvl Level, msg string, attrs ...interface{}) {
if !s.V(lvl) { if !s.V(lvl) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
func (s *slogLogger) Info(ctx context.Context, msg string, args ...interface{}) { func (s *slogLogger) Info(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
func (s *slogLogger) Debug(ctx context.Context, msg string, args ...any) { func (s *slogLogger) Debug(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
func (s *slogLogger) Trace(ctx context.Context, msg string, args ...interface{}) { func (s *slogLogger) Trace(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
func (s *slogLogger) Error(ctx context.Context, msg string, args ...any) { func (s *slogLogger) Error(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }
func (s *slogLogger) Fatal(ctx context.Context, msg string, args ...interface{}) { func (s *slogLogger) Fatal(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
os.Exit(1) os.Exit(1)
} }
func (s *slogLogger) Warn(ctx context.Context, msg string, args ...any) { func (s *slogLogger) Warn(ctx context.Context, msg string, attrs ...interface{}) {
if !s.V(InfoLevel) { if !s.V(InfoLevel) {
return return
} }
var pcs [1]uintptr var pcs [1]uintptr
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])
r.Add(args...) for _, fn := range s.opts.ContextAttrFuncs {
attrs = append(attrs, fn(ctx))
}
r.Add(attrs...)
_ = s.slog.Handler().Handle(ctx, r) _ = s.slog.Handler().Handle(ctx, r)
} }

View File

@ -4,6 +4,7 @@ import (
"context" "context"
"go.unistack.org/micro/v4/options" "go.unistack.org/micro/v4/options"
"go.unistack.org/micro/v4/util/id"
) )
var _ Tracer = (*noopTracer)(nil) var _ Tracer = (*noopTracer)(nil)
@ -26,6 +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.traceID, _ = id.New()
if span.ctx == nil { if span.ctx == nil {
span.ctx = context.Background() span.ctx = context.Background()
} }
@ -63,6 +66,8 @@ type noopSpan struct {
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) {
@ -97,6 +102,14 @@ func (s *noopSpan) Kind() SpanKind {
return s.kind return s.kind
} }
func (s *noopSpan) TraceID() string {
return s.traceID
}
func (s *noopSpan) SpanID() string {
return s.spanID
}
func (s *noopSpan) Status() (SpanStatus, string) { func (s *noopSpan) Status() (SpanStatus, string) {
return s.status, s.statusMsg return s.status, s.statusMsg
} }

View File

@ -6,6 +6,7 @@ import (
"fmt" "fmt"
"sort" "sort"
"go.unistack.org/micro/v4/logger"
"go.unistack.org/micro/v4/options" "go.unistack.org/micro/v4/options"
) )
@ -45,6 +46,20 @@ type Span interface {
AddLogs(kv ...interface{}) AddLogs(kv ...interface{})
// Kind returns span kind // Kind returns span kind
Kind() SpanKind Kind() SpanKind
// TraceID returns trace id
TraceID() string
// SpanID returns span id
SpanID() string
}
func init() {
logger.DefaultContextAttrFuncs = append(logger.DefaultContextAttrFuncs, func(ctx context.Context) []interface{} {
span, ok := SpanFromContext(ctx)
if !ok || span == nil {
return nil
}
return []interface{}{"trace", span.TraceID(), "span", span.SpanID()}
})
} }
// sort labels alphabeticaly by label name // sort labels alphabeticaly by label name