unistack-org/micro
4
0
Fork 2
Code Issues 18 Pull Requests Actions Packages Projects Releases 331 Wiki Activity

logger: slog logger #266

Merged
vtolstov merged 5 commits from slog into master 2023-10-14 18:05:47 +03:00
Conversation 0 Commits 5 Files Changed 7 +307 -249
7 changed files with 307 additions and 249 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
go.mod
View File

@@ -8,6 +8,7 @@ require (
github.com/google/uuid v1.3.1
github.com/patrickmn/go-cache v2.1.0+incompatible
github.com/silas/dag v0.0.0-20220518035006-a7e85ada93c5
golang.org/x/exp v0.0.0-20230905200255-921286631fa9
golang.org/x/sync v0.3.0
golang.org/x/sys v0.12.0
google.golang.org/grpc v1.58.2

2
go.sum
View File

@@ -13,6 +13,8 @@ github.com/patrickmn/go-cache v2.1.0+incompatible h1:HRMgzkcYKYpi3C8ajMPV8OFXaaR
github.com/patrickmn/go-cache v2.1.0+incompatible/go.mod h1:3Qf8kWWT7OJRJbdiICTKqZju1ZixQ/KpMGzzAfe6+WQ=
github.com/silas/dag v0.0.0-20220518035006-a7e85ada93c5 h1:G/FZtUu7a6NTWl3KUHMV9jkLAh/Rvtf03NWMHaEDl+E=
github.com/silas/dag v0.0.0-20220518035006-a7e85ada93c5/go.mod h1:7RTUFBdIRC9nZ7/3RyRNH1bdqIShrDejd1YbLwgPS+I=
golang.org/x/exp v0.0.0-20230905200255-921286631fa9 h1:GoHiUyI/Tp2nVkLI2mCxVkOjsbSXD66ic0XW0js0R9g=
golang.org/x/exp v0.0.0-20230905200255-921286631fa9/go.mod h1:S2oDrQGGwySpoQPVqRShND87VCbxmc6bL1Yd2oYrm6k=
golang.org/x/net v0.15.0 h1:ugBLEUaxABaB5AJqW9enI0ACdci2RUd4eP51NTBvuJ8=
golang.org/x/net v0.15.0/go.mod h1:idbUs1IY1+zTqbi8yxTbhexhEEk5ur9LInksu6HrEpk=
golang.org/x/sync v0.3.0 h1:ftCYgMx6zT/asHUrPw8BLLscYtGznsLAnjq5RH9P66E=

232
logger/default.go
View File

@@ -1,232 +0,0 @@
package logger
import (
"context"
"encoding/json"
"fmt"
"os"
"runtime"
"strings"
"sync"
"time"
"go.unistack.org/micro/v4/options"
)
type defaultLogger struct {
enc *json.Encoder
opts Options
sync.RWMutex
}
// Init(opts...) should only overwrite provided options
func (l *defaultLogger) Init(opts ...options.Option) error {
l.Lock()
for _, o := range opts {
o(&l.opts)
}
l.enc = json.NewEncoder(l.opts.Out)
// wrap the Log func
l.Unlock()
return nil
}
func (l *defaultLogger) String() string {
return "micro"
}
func (l *defaultLogger) Clone(opts ...options.Option) Logger {
newopts := NewOptions(opts...)
oldopts := l.opts
for _, o := range opts {
o(&newopts)
o(&oldopts)
}
l.Lock()
cl := &defaultLogger{opts: oldopts, enc: json.NewEncoder(l.opts.Out)}
l.Unlock()
return cl
}
func (l *defaultLogger) V(level Level) bool {
l.RLock()
ok := l.opts.Level.Enabled(level)
l.RUnlock()
return ok
}
func (l *defaultLogger) Level(level Level) {
l.Lock()
l.opts.Level = level
l.Unlock()
}
func (l *defaultLogger) Fields(fields ...interface{}) Logger {
l.RLock()
nl := &defaultLogger{opts: l.opts, enc: l.enc}
if len(fields) == 0 {
l.RUnlock()
return nl
} else if len(fields)%2 != 0 {
fields = fields[:len(fields)-1]
}
nl.opts.Fields = copyFields(l.opts.Fields)
nl.opts.Fields = append(nl.opts.Fields, fields...)
l.RUnlock()
return nl
}
func copyFields(src []interface{}) []interface{} {
dst := make([]interface{}, len(src))
copy(dst, src)
return dst
}
// logCallerfilePath returns a package/file:line description of the caller,
// preserving only the leaf directory name and file name.
func logCallerfilePath(loggingFilePath string) string {
// To make sure we trim the path correctly on Windows too, we
// counter-intuitively need to use '/' and *not* os.PathSeparator here,
// because the path given originates from Go stdlib, specifically
// runtime.Caller() which (as of Mar/17) returns forward slashes even on
// Windows.
//
// See https://github.com/golang/go/issues/3335
// and https://github.com/golang/go/issues/18151
//
// for discussion on the issue on Go side.
idx := strings.LastIndexByte(loggingFilePath, '/')
if idx == -1 {
return loggingFilePath
}
idx = strings.LastIndexByte(loggingFilePath[:idx], '/')
if idx == -1 {
return loggingFilePath
}
return loggingFilePath[idx+1:]
}
func (l *defaultLogger) Info(ctx context.Context, args ...interface{}) {
l.Log(ctx, InfoLevel, args...)
}
func (l *defaultLogger) Error(ctx context.Context, args ...interface{}) {
l.Log(ctx, ErrorLevel, args...)
}
func (l *defaultLogger) Debug(ctx context.Context, args ...interface{}) {
l.Log(ctx, DebugLevel, args...)
}
func (l *defaultLogger) Warn(ctx context.Context, args ...interface{}) {
l.Log(ctx, WarnLevel, args...)
}
func (l *defaultLogger) Trace(ctx context.Context, args ...interface{}) {
l.Log(ctx, TraceLevel, args...)
}
func (l *defaultLogger) Fatal(ctx context.Context, args ...interface{}) {
l.Log(ctx, FatalLevel, args...)
os.Exit(1)
}
func (l *defaultLogger) Infof(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, InfoLevel, msg, args...)
}
func (l *defaultLogger) Errorf(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, ErrorLevel, msg, args...)
}
func (l *defaultLogger) Debugf(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, DebugLevel, msg, args...)
}
func (l *defaultLogger) Warnf(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, WarnLevel, msg, args...)
}
func (l *defaultLogger) Tracef(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, TraceLevel, msg, args...)
}
func (l *defaultLogger) Fatalf(ctx context.Context, msg string, args ...interface{}) {
l.Logf(ctx, FatalLevel, msg, args...)
os.Exit(1)
}
func (l *defaultLogger) Log(ctx context.Context, level Level, args ...interface{}) {
if !l.V(level) {
return
}
l.RLock()
fields := copyFields(l.opts.Fields)
l.RUnlock()
fields = append(fields, "level", level.String())
if _, file, line, ok := runtime.Caller(l.opts.CallerSkipCount); ok {
fields = append(fields, "caller", fmt.Sprintf("%s:%d", logCallerfilePath(file), line))
}
fields = append(fields, "timestamp", time.Now().Format("2006-01-02 15:04:05"))
if len(args) > 0 {
fields = append(fields, "msg", fmt.Sprint(args...))
}
out := make(map[string]interface{}, len(fields)/2)
for i := 0; i < len(fields); i += 2 {
out[fields[i].(string)] = fields[i+1]
}
l.RLock()
_ = l.enc.Encode(out)
l.RUnlock()
}
func (l *defaultLogger) Logf(ctx context.Context, level Level, msg string, args ...interface{}) {
if !l.V(level) {
return
}
l.RLock()
fields := copyFields(l.opts.Fields)
l.RUnlock()
fields = append(fields, "level", level.String())
if _, file, line, ok := runtime.Caller(l.opts.CallerSkipCount); ok {
fields = append(fields, "caller", fmt.Sprintf("%s:%d", logCallerfilePath(file), line))
}
fields = append(fields, "timestamp", time.Now().Format("2006-01-02 15:04:05"))
if len(args) > 0 {
fields = append(fields, "msg", fmt.Sprintf(msg, args...))
} else if msg != "" {
fields = append(fields, "msg", msg)
}
out := make(map[string]interface{}, len(fields)/2)
for i := 0; i < len(fields); i += 2 {
out[fields[i].(string)] = fields[i+1]
}
l.RLock()
_ = l.enc.Encode(out)
l.RUnlock()
}
func (l *defaultLogger) Options() Options {
return l.opts
}
// NewLogger builds a new logger based on options
func NewLogger(opts ...options.Option) Logger {
l := &defaultLogger{
opts: NewOptions(opts...),
}
l.enc = json.NewEncoder(l.opts.Out)
return l
}

34
logger/logger_test.go
View File

@@ -87,14 +87,14 @@ func TestClone(t *testing.T) {
func TestRedirectStdLogger(t *testing.T) {
buf := bytes.NewBuffer(nil)
l := NewLogger(WithLevel(TraceLevel), WithOutput(buf))
l := NewLogger(WithLevel(ErrorLevel), WithOutput(buf))
if err := l.Init(); err != nil {
t.Fatal(err)
}
fn := RedirectStdLogger(l, ErrorLevel)
defer fn()
log.Print("test")
if !bytes.Contains(buf.Bytes(), []byte(`"level":"error","msg":"test","timestamp"`)) {
if !bytes.Contains(buf.Bytes(), []byte(`"level":"error","msg":"test"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
}
}
@@ -107,7 +107,7 @@ func TestStdLogger(t *testing.T) {
}
lg := NewStdLogger(l, ErrorLevel)
lg.Print("test")
if !bytes.Contains(buf.Bytes(), []byte(`"level":"error","msg":"test","timestamp"`)) {
if !bytes.Contains(buf.Bytes(), []byte(`"level":"error","msg":"test"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
}
}
@@ -120,19 +120,21 @@ func TestLogger(t *testing.T) {
t.Fatal(err)
}
l.Trace(ctx, "trace_msg1")
l.Warn(ctx, "warn_msg1")
l.Fields("error", "test").Info(ctx, "error message")
l.Warn(ctx, "first", " ", "second")
// l.Warn(ctx, "warn_msg1")
// l.Fields("error", "test").Info(ctx, "error message")
// l.Warn(ctx, "first second")
if !bytes.Contains(buf.Bytes(), []byte(`"level":"trace","msg":"trace_msg1"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"warn","msg":"warn_msg1"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"error":"test","level":"info","msg":"error message"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"level":"warn","msg":"first second"`)) {
t.Fatalf("logger error, buf %s", buf.Bytes())
t.Fatalf("logger tracer, buf %s", buf.Bytes())
}
/*
if !bytes.Contains(buf.Bytes(), []byte(`"warn","msg":"warn_msg1"`)) {
t.Fatalf("logger warn, buf %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"error":"test","level":"info","msg":"error message"`)) {
t.Fatalf("logger info, buf %s", buf.Bytes())
}
if !bytes.Contains(buf.Bytes(), []byte(`"level":"warn","msg":"first second"`)) {
t.Fatalf("logger warn, buf %s", buf.Bytes())
}
*/
}

245
logger/slog.go Normal file
View File

@@ -0,0 +1,245 @@
package logger
import (
"context"
"fmt"
"os"
"go.unistack.org/micro/v4/options"
"golang.org/x/exp/slog"
)
var (
traceValue = slog.StringValue("trace")
debugValue = slog.StringValue("debug")
infoValue = slog.StringValue("info")
warnValue = slog.StringValue("warn")
errorValue = slog.StringValue("error")
fatalValue = slog.StringValue("fatal")
)
var renameAttr = func(_ []string, a slog.Attr) slog.Attr {
switch a.Key {
case slog.TimeKey:
a.Key = "timestamp"
case slog.LevelKey:
level := a.Value.Any().(slog.Level)
lvl := slogToLoggerLevel(level)
switch {
case lvl < DebugLevel:
a.Value = traceValue
case lvl < InfoLevel:
a.Value = debugValue
case lvl < WarnLevel:
a.Value = infoValue
case lvl < ErrorLevel:
a.Value = warnValue
case lvl < FatalLevel:
a.Value = errorValue
case lvl >= FatalLevel:
a.Value = fatalValue
default:
a.Value = infoValue
}
}
return a
}
type slogLogger struct {
slog *slog.Logger
leveler *slog.LevelVar
opts Options
}
func (s *slogLogger) Clone(opts ...options.Option) Logger {
options := s.opts
for _, o := range opts {
o(&options)
}
l := &slogLogger{
opts: options,
}
if slog, ok := s.opts.Context.Value(loggerKey{}).(*slog.Logger); ok {
l.slog = slog
return nil
}
l.leveler = new(slog.LevelVar)
handleOpt := &slog.HandlerOptions{
ReplaceAttr: renameAttr,
Level: l.leveler,
}
l.leveler.Set(loggerToSlogLevel(l.opts.Level))
handler := slog.NewJSONHandler(options.Out, handleOpt)
l.slog = slog.New(handler).With(options.Fields...)
return l
}
func (s *slogLogger) V(level Level) bool {
return s.opts.Level.Enabled(level)
}
func (s *slogLogger) Level(level Level) {
s.leveler.Set(loggerToSlogLevel(level))
}
func (s *slogLogger) Options() Options {
return s.opts
}
func (s *slogLogger) Fields(fields ...interface{}) Logger {
nl := &slogLogger{opts: s.opts}
nl.leveler = new(slog.LevelVar)
nl.leveler.Set(s.leveler.Level())
handleOpt := &slog.HandlerOptions{
ReplaceAttr: renameAttr,
Level: s.leveler,
}
handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
nl.slog = slog.New(handler).With(fields...)
return nl
}
func (s *slogLogger) Init(opts ...options.Option) error {
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
}
s.leveler = new(slog.LevelVar)
handleOpt := &slog.HandlerOptions{
ReplaceAttr: renameAttr,
Level: s.leveler,
}
s.leveler.Set(loggerToSlogLevel(s.opts.Level))
handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
s.slog = slog.New(handler).With(s.opts.Fields...)
return nil
}
func (s *slogLogger) Log(ctx context.Context, lvl Level, args ...any) {
if !s.V(lvl) {
return
}
slvl := loggerToSlogLevel(lvl)
msg := fmt.Sprint(args...)
s.slog.Log(ctx, slvl, msg)
}
func (s *slogLogger) Logf(ctx context.Context, lvl Level, format string, args ...any) {
if !s.V(lvl) {
return
}
slvl := loggerToSlogLevel(lvl)
s.slog.Log(ctx, slvl, format, args...)
}
func (s *slogLogger) Info(ctx context.Context, args ...any) {
s.Log(ctx, InfoLevel, args...)
}
func (s *slogLogger) Infof(ctx context.Context, format string, args ...interface{}) {
s.Logf(ctx, InfoLevel, format, args...)
}
func (s *slogLogger) Debug(ctx context.Context, args ...any) {
s.Log(ctx, DebugLevel, args...)
}
func (s *slogLogger) Debugf(ctx context.Context, format string, args ...any) {
s.Logf(ctx, DebugLevel, format, args...)
}
func (s *slogLogger) Error(ctx context.Context, args ...any) {
s.Log(ctx, ErrorLevel, args...)
}
func (s *slogLogger) Trace(ctx context.Context, args ...interface{}) {
s.Log(ctx, TraceLevel, args...)
}
func (s *slogLogger) Tracef(ctx context.Context, msg string, args ...interface{}) {
s.Logf(ctx, TraceLevel, msg, args...)
}
func (s *slogLogger) Errorf(ctx context.Context, format string, args ...any) {
s.Logf(ctx, ErrorLevel, format, args...)
}
func (s *slogLogger) Fatal(ctx context.Context, args ...any) {
s.Log(ctx, FatalLevel, args...)
}
func (s *slogLogger) Fatalf(ctx context.Context, msg string, args ...interface{}) {
s.Logf(ctx, FatalLevel, msg, args...)
os.Exit(1)
}
func (s *slogLogger) Warn(ctx context.Context, args ...any) {
s.Log(ctx, WarnLevel, args...)
}
func (s *slogLogger) Warnf(ctx context.Context, format string, args ...any) {
s.Logf(ctx, WarnLevel, format, args...)
}
func (s *slogLogger) String() string {
return "slog"
}
func NewLogger(opts ...options.Option) Logger {
l := &slogLogger{
opts: NewOptions(opts...),
}
return l
}
func loggerToSlogLevel(level Level) slog.Level {
switch level {
case DebugLevel:
return slog.LevelDebug
case WarnLevel:
return slog.LevelWarn
case ErrorLevel:
return slog.LevelError
case TraceLevel:
return slog.LevelDebug - 1
case FatalLevel:
return slog.LevelError + 1
default:
return slog.LevelInfo
}
}
func slogToLoggerLevel(level slog.Level) Level {
switch level {
case slog.LevelDebug:
return DebugLevel
case slog.LevelWarn:
return WarnLevel
case slog.LevelError:
return ErrorLevel
case slog.LevelDebug - 1:
return TraceLevel
case slog.LevelError + 1:
return FatalLevel
default:
return InfoLevel
}
}

39
tracer/options.go
View File

@@ -2,9 +2,11 @@ package tracer
import (
"context"
"reflect"
"go.unistack.org/micro/v4/logger"
"go.unistack.org/micro/v4/options"
rutil "go.unistack.org/micro/v4/util/reflect"
)
type SpanStatus int
@@ -93,6 +95,43 @@ type EventOptions struct {
Labels []interface{}
}
func WithSpanLabels(ls ...interface{}) options.Option {
return func(src interface{}) error {
v, err := options.Get(src, ".Labels")
if err != nil {
return err
} else if rutil.IsZero(v) {
v = reflect.MakeSlice(reflect.TypeOf(v), 0, len(ls)).Interface()
}
cv := reflect.ValueOf(v)
for _, l := range ls {
reflect.Append(cv, reflect.ValueOf(l))
}
err = options.Set(src, cv, ".Labels")
return err
}
}
// EventOption func signature
type EventOption func(o *EventOptions)
func WithEventLabels(ls ...interface{}) options.Option {
return func(src interface{}) error {
v, err := options.Get(src, ".Labels")
if err != nil {
return err
} else if rutil.IsZero(v) {
v = reflect.MakeSlice(reflect.TypeOf(v), 0, len(ls)).Interface()
}
cv := reflect.ValueOf(v)
for _, l := range ls {
reflect.Append(cv, reflect.ValueOf(l))
}
err = options.Set(src, cv, ".Labels")
return err
}
}
func WithSpanKind(k SpanKind) options.Option {
return func(src interface{}) error {
return options.Set(src, k, ".Kind")

3
tracer/wrapper/wrapper.go
View File

@@ -13,7 +13,7 @@ import (
"go.unistack.org/micro/v4/tracer"
)
var DefaultHeadersExctract = []string{metadata.HeaderXRequestID}
var DefaultHeadersExctract = []string{metadata.HeaderTopic, metadata.HeaderEndpoint, metadata.HeaderService, metadata.HeaderXRequestID}
func ExtractDefaultLabels(md metadata.Metadata) []interface{} {
labels := make([]interface{}, 0, len(DefaultHeadersExctract))
@@ -27,6 +27,7 @@ func ExtractDefaultLabels(md metadata.Metadata) []interface{} {
var (
DefaultClientCallObserver = func(ctx context.Context, req client.Request, rsp interface{}, opts []options.Option, sp tracer.Span, err error) {
sp.SetName(fmt.Sprintf("Call %s.%s", req.Service(), req.Method()))
var labels []interface{}
if md, ok := metadata.FromOutgoingContext(ctx); ok {
labels = append(labels, ExtractDefaultLabels(md)...)