From d1c6e121c16788082f36673a68cf8217c7b5ee75 Mon Sep 17 00:00:00 2001 From: Vasiliy Tolstov Date: Sun, 24 Nov 2024 15:31:40 +0300 Subject: [PATCH 1/3] logger/slog: fix Clone and Fields methods Signed-off-by: Vasiliy Tolstov --- logger/slog/slog.go | 26 ++++++------------ logger/slog/slog_test.go | 57 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 65 insertions(+), 18 deletions(-) diff --git a/logger/slog/slog.go b/logger/slog/slog.go index ee1fe17a..c851ccdc 100644 --- a/logger/slog/slog.go +++ b/logger/slog/slog.go @@ -76,24 +76,19 @@ type slogLogger struct { func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger { s.mu.RLock() options := s.opts + level := s.leveler.Level() s.mu.RUnlock() for _, o := range opts { o(&options) } - l := &slogLogger{ - opts: options, - } + l := &slogLogger{opts: options} l.leveler = new(slog.LevelVar) - handleOpt := &slog.HandlerOptions{ - ReplaceAttr: l.renameAttr, - Level: l.leveler, - AddSource: l.opts.AddSource, - } - l.leveler.Set(loggerToSlogLevel(l.opts.Level)) - l.handler = slog.New(slog.NewJSONHandler(options.Out, handleOpt)).With(options.Fields...).Handler() + l.leveler.Set(level) + attrs, _ := s.argsAttrs(l.opts.Fields) + l.handler = s.handler.WithAttrs(attrs) return l } @@ -110,7 +105,7 @@ func (s *slogLogger) Options() logger.Options { return s.opts } -func (s *slogLogger) Fields(attrs ...interface{}) logger.Logger { +func (s *slogLogger) Fields(fields ...interface{}) logger.Logger { s.mu.RLock() level := s.leveler.Level() options := s.opts @@ -120,13 +115,8 @@ func (s *slogLogger) Fields(attrs ...interface{}) logger.Logger { l.leveler = new(slog.LevelVar) l.leveler.Set(level) - handleOpt := &slog.HandlerOptions{ - ReplaceAttr: l.renameAttr, - Level: l.leveler, - AddSource: l.opts.AddSource, - } - - l.handler = slog.New(slog.NewJSONHandler(l.opts.Out, handleOpt)).With(attrs...).Handler() + attrs, _ := s.argsAttrs(fields) + l.handler = s.handler.WithAttrs(attrs) return l } diff --git a/logger/slog/slog_test.go b/logger/slog/slog_test.go index fc381892..d27de0f0 100644 --- a/logger/slog/slog_test.go +++ b/logger/slog/slog_test.go @@ -15,6 +15,56 @@ import ( "go.unistack.org/micro/v3/logger" ) +func TestMultipleFieldsWithLevel(t *testing.T) { + ctx := context.TODO() + buf := bytes.NewBuffer(nil) + l := NewLogger(logger.WithLevel(logger.InfoLevel), logger.WithOutput(buf)) + if err := l.Init(); err != nil { + t.Fatal(err) + } + + l = l.Fields("key", "val") + + l.Info(ctx, "msg1") + nl := l.Clone(logger.WithLevel(logger.DebugLevel)) + nl.Debug(ctx, "msg2") + l.Debug(ctx, "msg3") + if !bytes.Contains(buf.Bytes(), []byte(`"key":"val"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } + if !bytes.Contains(buf.Bytes(), []byte(`"msg1"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } + if !bytes.Contains(buf.Bytes(), []byte(`"msg2"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } + if bytes.Contains(buf.Bytes(), []byte(`"msg3"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } +} + +func TestMultipleFields(t *testing.T) { + ctx := context.TODO() + buf := bytes.NewBuffer(nil) + l := NewLogger(logger.WithLevel(logger.InfoLevel), logger.WithOutput(buf)) + if err := l.Init(); err != nil { + t.Fatal(err) + } + + l = l.Fields("key", "val") + + l = l.Fields("key1", "val1") + + l.Info(ctx, "msg") + + if !bytes.Contains(buf.Bytes(), []byte(`"key":"val"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } + if !bytes.Contains(buf.Bytes(), []byte(`"key1":"val1"`)) { + t.Fatalf("logger error not works, buf contains: %s", buf.Bytes()) + } +} + func TestError(t *testing.T) { ctx := context.TODO() buf := bytes.NewBuffer(nil) @@ -234,4 +284,11 @@ func Test_WithContextAttrFunc(t *testing.T) { if !(bytes.Contains(buf.Bytes(), []byte(`"source-service":"Test-System"`))) { t.Fatalf("logger info, buf %s", buf.Bytes()) } + buf.Reset() + imd, _ := metadata.FromIncomingContext(ctx) + l.Info(ctx, "test message1") + imd.Set("Source-Service", "Test-System2") + l.Info(ctx, "test message2") + + // t.Logf("xxx %s", buf.Bytes()) } From 49055a28eaab78c0cdd3fe724113d737eea3b4a0 Mon Sep 17 00:00:00 2001 From: Vasiliy Tolstov Date: Sun, 24 Nov 2024 23:28:15 +0300 Subject: [PATCH 2/3] logger/slog: wrap handler Signed-off-by: Vasiliy Tolstov --- logger/slog/slog.go | 67 +++++++++++++++++++++++++++++++-------------- 1 file changed, 47 insertions(+), 20 deletions(-) diff --git a/logger/slog/slog.go b/logger/slog/slog.go index c851ccdc..10a40533 100644 --- a/logger/slog/slog.go +++ b/logger/slog/slog.go @@ -31,6 +31,28 @@ var ( fatalValue = slog.StringValue("fatal") ) +type wrapper struct { + h slog.Handler + level logger.Level +} + +func (h *wrapper) Enabled(ctx context.Context, level slog.Level) bool { + lvl := slogToLoggerLevel(level) + return h.level.Enabled(lvl) +} + +func (h *wrapper) Handle(ctx context.Context, rec slog.Record) error { + return h.h.Handle(ctx, rec) +} + +func (h *wrapper) WithAttrs(attrs []slog.Attr) slog.Handler { + return h.WithAttrs(attrs) +} + +func (h *wrapper) WithGroup(name string) slog.Handler { + return h.WithGroup(name) +} + func (s *slogLogger) renameAttr(_ []string, a slog.Attr) slog.Attr { switch a.Key { case slog.SourceKey: @@ -68,7 +90,7 @@ func (s *slogLogger) renameAttr(_ []string, a slog.Attr) slog.Attr { type slogLogger struct { leveler *slog.LevelVar - handler slog.Handler + handler *wrapper opts logger.Options mu sync.RWMutex } @@ -76,19 +98,21 @@ type slogLogger struct { func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger { s.mu.RLock() options := s.opts - level := s.leveler.Level() s.mu.RUnlock() for _, o := range opts { o(&options) } - l := &slogLogger{opts: options} + if len(options.ContextAttrFuncs) == 0 { + options.ContextAttrFuncs = logger.DefaultContextAttrFuncs + } - l.leveler = new(slog.LevelVar) - l.leveler.Set(level) - attrs, _ := s.argsAttrs(l.opts.Fields) - l.handler = s.handler.WithAttrs(attrs) + attrs, _ := s.argsAttrs(options.Fields) + l := &slogLogger{ + handler: &wrapper{level: options.Level, h: s.handler.h.WithAttrs(attrs)}, + opts: options, + } return l } @@ -98,7 +122,9 @@ func (s *slogLogger) V(level logger.Level) bool { } func (s *slogLogger) Level(level logger.Level) { - s.leveler.Set(loggerToSlogLevel(level)) + s.mu.Lock() + s.opts.Level = level + s.mu.Unlock() } func (s *slogLogger) Options() logger.Options { @@ -107,16 +133,17 @@ func (s *slogLogger) Options() logger.Options { func (s *slogLogger) Fields(fields ...interface{}) logger.Logger { s.mu.RLock() - level := s.leveler.Level() options := s.opts s.mu.RUnlock() l := &slogLogger{opts: options} - l.leveler = new(slog.LevelVar) - l.leveler.Set(level) + + if len(options.ContextAttrFuncs) == 0 { + options.ContextAttrFuncs = logger.DefaultContextAttrFuncs + } attrs, _ := s.argsAttrs(fields) - l.handler = s.handler.WithAttrs(attrs) + l.handler = &wrapper{level: s.opts.Level, h: s.handler.h.WithAttrs(attrs)} return l } @@ -124,22 +151,22 @@ func (s *slogLogger) Fields(fields ...interface{}) logger.Logger { func (s *slogLogger) Init(opts ...logger.Option) error { s.mu.Lock() - if len(s.opts.ContextAttrFuncs) == 0 { - s.opts.ContextAttrFuncs = logger.DefaultContextAttrFuncs - } - for _, o := range opts { o(&s.opts) } - s.leveler = new(slog.LevelVar) + if len(s.opts.ContextAttrFuncs) == 0 { + s.opts.ContextAttrFuncs = logger.DefaultContextAttrFuncs + } + handleOpt := &slog.HandlerOptions{ ReplaceAttr: s.renameAttr, - Level: s.leveler, + Level: loggerToSlogLevel(logger.TraceLevel), AddSource: s.opts.AddSource, } - s.leveler.Set(loggerToSlogLevel(s.opts.Level)) - s.handler = slog.New(slog.NewJSONHandler(s.opts.Out, handleOpt)).With(s.opts.Fields...).Handler() + + attrs, _ := s.argsAttrs(s.opts.Fields) + s.handler = &wrapper{level: s.opts.Level, h: slog.NewJSONHandler(s.opts.Out, handleOpt).WithAttrs(attrs)} s.mu.Unlock() return nil From ad19fe2b90a0b664f9a2cede43bbabd4291b801c Mon Sep 17 00:00:00 2001 From: Vasiliy Tolstov Date: Sun, 24 Nov 2024 23:40:54 +0300 Subject: [PATCH 3/3] logger/slog: fix race condigtion with Enabled and Level Signed-off-by: Vasiliy Tolstov --- logger/slog/slog.go | 21 ++++++++++++++------- 1 file changed, 14 insertions(+), 7 deletions(-) diff --git a/logger/slog/slog.go b/logger/slog/slog.go index 10a40533..4d3e8c06 100644 --- a/logger/slog/slog.go +++ b/logger/slog/slog.go @@ -8,6 +8,7 @@ import ( "runtime" "strconv" "sync" + "sync/atomic" "go.unistack.org/micro/v3/logger" "go.unistack.org/micro/v3/semconv" @@ -33,12 +34,11 @@ var ( type wrapper struct { h slog.Handler - level logger.Level + level atomic.Int64 } func (h *wrapper) Enabled(ctx context.Context, level slog.Level) bool { - lvl := slogToLoggerLevel(level) - return h.level.Enabled(lvl) + return level >= slog.Level(int(h.level.Load())) } func (h *wrapper) Handle(ctx context.Context, rec slog.Record) error { @@ -110,20 +110,25 @@ func (s *slogLogger) Clone(opts ...logger.Option) logger.Logger { attrs, _ := s.argsAttrs(options.Fields) l := &slogLogger{ - handler: &wrapper{level: options.Level, h: s.handler.h.WithAttrs(attrs)}, + handler: &wrapper{h: s.handler.h.WithAttrs(attrs)}, opts: options, } + l.handler.level.Store(int64(loggerToSlogLevel(options.Level))) return l } func (s *slogLogger) V(level logger.Level) bool { - return s.opts.Level.Enabled(level) + s.mu.Lock() + v := s.opts.Level.Enabled(level) + s.mu.Unlock() + return v } func (s *slogLogger) Level(level logger.Level) { s.mu.Lock() s.opts.Level = level + s.handler.level.Store(int64(loggerToSlogLevel(level))) s.mu.Unlock() } @@ -143,7 +148,8 @@ func (s *slogLogger) Fields(fields ...interface{}) logger.Logger { } attrs, _ := s.argsAttrs(fields) - l.handler = &wrapper{level: s.opts.Level, h: s.handler.h.WithAttrs(attrs)} + l.handler = &wrapper{h: s.handler.h.WithAttrs(attrs)} + l.handler.level.Store(int64(loggerToSlogLevel(l.opts.Level))) return l } @@ -166,7 +172,8 @@ func (s *slogLogger) Init(opts ...logger.Option) error { } attrs, _ := s.argsAttrs(s.opts.Fields) - s.handler = &wrapper{level: s.opts.Level, h: slog.NewJSONHandler(s.opts.Out, handleOpt).WithAttrs(attrs)} + s.handler = &wrapper{h: slog.NewJSONHandler(s.opts.Out, handleOpt).WithAttrs(attrs)} + s.handler.level.Store(int64(loggerToSlogLevel(s.opts.Level))) s.mu.Unlock() return nil