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

View File

@ -15,7 +15,7 @@ func TestContext(t *testing.T) {
t.Fatal(err)
}
nl, ok := FromContext(NewContext(ctx, l.Fields("key", "val")))
nl, ok := FromContext(NewContext(ctx, l.Attrs("key", "val")))
if !ok {
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()
buf := bytes.NewBuffer(nil)
l := NewLogger(WithLevel(TraceLevel), WithOutput(buf))
@ -33,7 +33,7 @@ func TestFields(t *testing.T) {
t.Fatal(err)
}
nl := l.Fields("key", "val")
nl := l.Attrs("key", "val")
nl.Info(ctx, "message")
if !bytes.Contains(buf.Bytes(), []byte(`"key":"val"`)) {
@ -49,7 +49,7 @@ func TestFromContextWithFields(t *testing.T) {
if err := l.Init(); err != nil {
t.Fatal(err)
}
nl := l.Fields("key", "val")
nl := l.Attrs("key", "val")
ctx = NewContext(ctx, nl)
@ -121,7 +121,7 @@ func TestLogger(t *testing.T) {
}
l.Trace(ctx, "trace_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")
if !(bytes.Contains(buf.Bytes(), []byte(`"level":"trace"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"trace_msg1"`))) {

View File

@ -4,8 +4,10 @@ import (
"context"
"io"
"os"
"reflect"
"go.unistack.org/micro/v4/options"
rutil "go.unistack.org/micro/v4/util/reflect"
)
// Options holds logger options
@ -14,24 +16,27 @@ type Options struct {
Out io.Writer
// Context holds exernal options
Context context.Context
// Fields holds additional metadata
Fields []interface{}
// Attrs holds additional attributes
Attrs []interface{}
// Name holds the logger name
Name string
// The logging level the logger should log
Level Level
// CallerSkipCount number of frmaes to skip
CallerSkipCount int
// ContextAttrFuncs contains funcs that executed before log func on context
ContextAttrFuncs []ContextAttrFunc
}
// NewOptions creates new options struct
func NewOptions(opts ...options.Option) Options {
options := Options{
Level: DefaultLevel,
Fields: make([]interface{}, 0, 6),
Attrs: make([]interface{}, 0, 6),
Out: os.Stderr,
CallerSkipCount: DefaultCallerSkipCount,
Context: context.Background(),
ContextAttrFuncs: DefaultContextAttrFuncs,
}
for _, o := range opts {
o(&options)
@ -39,10 +44,27 @@ func NewOptions(opts ...options.Option) Options {
return options
}
// WithFields set default fields for the logger
func WithFields(fields ...interface{}) options.Option {
// WithContextAttrFuncs appends default funcs for the context arrts filler
func WithContextAttrFuncs(attrs ...interface{}) options.Option {
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)
a.Value = slog.StringValue(source.File + ":" + strconv.Itoa(source.Line))
a.Key = "caller"
// add func?
// "trace": "<traceid>",
// "span": "<spanid>",
case slog.TimeKey:
a.Key = "timestamp"
case slog.LevelKey:
@ -85,7 +82,7 @@ func (s *slogLogger) Clone(opts ...options.Option) Logger {
}
l.leveler.Set(loggerToSlogLevel(l.opts.Level))
handler := slog.NewJSONHandler(options.Out, handleOpt)
l.slog = slog.New(handler).With(options.Fields...)
l.slog = slog.New(handler).With(options.Attrs...)
return l
}
@ -102,7 +99,7 @@ func (s *slogLogger) Options() Options {
return s.opts
}
func (s *slogLogger) Fields(fields ...interface{}) Logger {
func (s *slogLogger) Attrs(attrs ...interface{}) Logger {
nl := &slogLogger{opts: s.opts}
nl.leveler = new(slog.LevelVar)
nl.leveler.Set(s.leveler.Level())
@ -114,7 +111,7 @@ func (s *slogLogger) Fields(fields ...interface{}) Logger {
}
handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
nl.slog = slog.New(handler).With(fields...)
nl.slog = slog.New(handler).With(attrs...)
return nl
}
@ -139,86 +136,107 @@ func (s *slogLogger) Init(opts ...options.Option) error {
}
s.leveler.Set(loggerToSlogLevel(s.opts.Level))
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
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
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) {
return
}
var pcs [1]uintptr
runtime.Callers(s.opts.CallerSkipCount, pcs[:]) // skip [Callers, Infof]
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)
}

View File

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

View File

@ -6,6 +6,7 @@ import (
"fmt"
"sort"
"go.unistack.org/micro/v4/logger"
"go.unistack.org/micro/v4/options"
)
@ -45,6 +46,20 @@ type Span interface {
AddLogs(kv ...interface{})
// Kind returns span kind
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