fixup tests

Signed-off-by: Vasiliy Tolstov <v.tolstov@unistack.org>

logger/logger_test.go

@@ -94,7 +94,7 @@ func TestRedirectStdLogger(t *testing.T) {
 	fn := RedirectStdLogger(l, ErrorLevel)
 	defer fn()
 	log.Print("test")
-	if !bytes.Contains(buf.Bytes(), []byte(`"level":"error","msg":"test"`)) {
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"error"`)) && bytes.Contains(buf.Bytes(), []byte(`"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"`)) {
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"error"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"test"`))) {
 		t.Fatalf("logger error, buf %s", buf.Bytes())
 	}
 }
@@ -123,17 +123,17 @@ func TestLogger(t *testing.T) {
 	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"`)) {
+
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"trace"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"trace_msg1"`))) {
 		t.Fatalf("logger tracer, buf %s", buf.Bytes())
 	}
-
-	if !bytes.Contains(buf.Bytes(), []byte(`"level":"warn","msg":"warn_msg1"`)) {
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"warn"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"warn_msg1"`))) {
 		t.Fatalf("logger warn, buf %s", buf.Bytes())
 	}
-	if !bytes.Contains(buf.Bytes(), []byte(`"level":"info","msg":"error message","error":"test"`)) {
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"info"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"error message","error":"test"`))) {
 		t.Fatalf("logger info, buf %s", buf.Bytes())
 	}
-	if !bytes.Contains(buf.Bytes(), []byte(`"level":"warn","msg":"first second"`)) {
+	if !(bytes.Contains(buf.Bytes(), []byte(`"level":"warn"`)) && bytes.Contains(buf.Bytes(), []byte(`"msg":"first second"`))) {
 		t.Fatalf("logger warn, buf %s", buf.Bytes())
 	}
 }

logger/slog.go

@@ -2,11 +2,13 @@ package logger
 
 import (
 	"context"
+	"log/slog"
 	"os"
+	"runtime"
+	"strconv"
+	"time"
 
 	"go.unistack.org/micro/v4/options"
-
-	"golang.org/x/exp/slog"
 )
 
 var (
@@ -20,6 +22,13 @@ var (
 
 var renameAttr = func(_ []string, a slog.Attr) slog.Attr {
 	switch a.Key {
+	case slog.SourceKey:
+		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:
@@ -72,6 +81,7 @@ func (s *slogLogger) Clone(opts ...options.Option) Logger {
 	handleOpt := &slog.HandlerOptions{
 		ReplaceAttr: renameAttr,
 		Level:       l.leveler,
+		AddSource:   true,
 	}
 	l.leveler.Set(loggerToSlogLevel(l.opts.Level))
 	handler := slog.NewJSONHandler(options.Out, handleOpt)
@@ -100,6 +110,7 @@ func (s *slogLogger) Fields(fields ...interface{}) Logger {
 	handleOpt := &slog.HandlerOptions{
 		ReplaceAttr: renameAttr,
 		Level:       s.leveler,
+		AddSource:   true,
 	}
 
 	handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
@@ -124,6 +135,7 @@ func (s *slogLogger) Init(opts ...options.Option) error {
 	handleOpt := &slog.HandlerOptions{
 		ReplaceAttr: renameAttr,
 		Level:       s.leveler,
+		AddSource:   true,
 	}
 	s.leveler.Set(loggerToSlogLevel(s.opts.Level))
 	handler := slog.NewJSONHandler(s.opts.Out, handleOpt)
@@ -136,33 +148,78 @@ func (s *slogLogger) Log(ctx context.Context, lvl Level, msg string, args ...any
 	if !s.V(lvl) {
 		return
 	}
-	slvl := loggerToSlogLevel(lvl)
-	s.slog.Log(ctx, slvl, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) Info(ctx context.Context, msg string, args ...interface{}) {
-	s.Log(ctx, InfoLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) Debug(ctx context.Context, msg string, args ...any) {
-	s.Log(ctx, DebugLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) Trace(ctx context.Context, msg string, args ...interface{}) {
-	s.Log(ctx, TraceLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) Error(ctx context.Context, msg string, args ...any) {
-	s.Log(ctx, ErrorLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) Fatal(ctx context.Context, msg string, args ...interface{}) {
-	s.Log(ctx, FatalLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 	os.Exit(1)
 }
 
 func (s *slogLogger) Warn(ctx context.Context, msg string, args ...any) {
-	s.Log(ctx, WarnLevel, msg, args...)
+	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...)
+	_ = s.slog.Handler().Handle(ctx, r)
 }
 
 func (s *slogLogger) String() string {

logger/stdlogger.go

@@ -12,7 +12,7 @@ type stdLogger struct {
 
 // NewStdLogger returns new *log.Logger baked by logger.Logger implementation
 func NewStdLogger(l Logger, level Level) *log.Logger {
-	return log.New(&stdLogger{l: l, level: level}, "" /* prefix */, 0 /* flags */)
+	return log.New(&stdLogger{l: l.Clone(WithCallerSkipCount(l.Options().CallerSkipCount + 1)), level: level}, "" /* prefix */, 0 /* flags */)
 }
 
 func (sl *stdLogger) Write(p []byte) (int, error) {