Skip to content

Commit 2c3d109

Browse files
authored
Fix slog logger caller frame detection to output correct source file (#7610)
* Fix logger/slog output source file depth is incorrect * update: fix review issue
1 parent 4808ff5 commit 2c3d109

File tree

3 files changed

+69
-9
lines changed

3 files changed

+69
-9
lines changed

logger/slog.go

Lines changed: 22 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,8 @@ import (
88
"fmt"
99
"log/slog"
1010
"time"
11+
12+
"gorm.io/gorm/utils"
1113
)
1214

1315
type slogLogger struct {
@@ -37,19 +39,19 @@ func (l *slogLogger) LogMode(level LogLevel) Interface {
3739

3840
func (l *slogLogger) Info(ctx context.Context, msg string, data ...interface{}) {
3941
if l.LogLevel >= Info {
40-
l.Logger.InfoContext(ctx, msg, slog.Any("data", data))
42+
l.log(ctx, slog.LevelInfo, msg, slog.Any("data", data))
4143
}
4244
}
4345

4446
func (l *slogLogger) Warn(ctx context.Context, msg string, data ...interface{}) {
4547
if l.LogLevel >= Warn {
46-
l.Logger.WarnContext(ctx, msg, slog.Any("data", data))
48+
l.log(ctx, slog.LevelWarn, msg, slog.Any("data", data))
4749
}
4850
}
4951

5052
func (l *slogLogger) Error(ctx context.Context, msg string, data ...interface{}) {
5153
if l.LogLevel >= Error {
52-
l.Logger.ErrorContext(ctx, msg, slog.Any("data", data))
54+
l.log(ctx, slog.LevelError, msg, slog.Any("data", data))
5355
}
5456
}
5557

@@ -72,25 +74,39 @@ func (l *slogLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql
7274
switch {
7375
case err != nil && (!l.IgnoreRecordNotFoundError || !errors.Is(err, ErrRecordNotFound)):
7476
fields = append(fields, slog.String("error", err.Error()))
75-
l.Logger.ErrorContext(ctx, "SQL executed", slog.Attr{
77+
l.log(ctx, slog.LevelError, "SQL executed", slog.Attr{
7678
Key: "trace",
7779
Value: slog.GroupValue(fields...),
7880
})
7981

8082
case l.SlowThreshold != 0 && elapsed > l.SlowThreshold:
81-
l.Logger.WarnContext(ctx, "SQL executed", slog.Attr{
83+
l.log(ctx, slog.LevelWarn, "SQL executed", slog.Attr{
8284
Key: "trace",
8385
Value: slog.GroupValue(fields...),
8486
})
8587

8688
case l.LogLevel >= Info:
87-
l.Logger.InfoContext(ctx, "SQL executed", slog.Attr{
89+
l.log(ctx, slog.LevelInfo, "SQL executed", slog.Attr{
8890
Key: "trace",
8991
Value: slog.GroupValue(fields...),
9092
})
9193
}
9294
}
9395

96+
func (l *slogLogger) log(ctx context.Context, level slog.Level, msg string, args ...any) {
97+
if ctx == nil {
98+
ctx = context.Background()
99+
}
100+
101+
if !l.Logger.Enabled(ctx, level) {
102+
return
103+
}
104+
105+
r := slog.NewRecord(time.Now(), level, msg, utils.CallerFrame().PC)
106+
r.Add(args...)
107+
_ = l.Logger.Handler().Handle(ctx, r)
108+
}
109+
94110
// ParamsFilter filter params
95111
func (l *slogLogger) ParamsFilter(ctx context.Context, sql string, params ...interface{}) (string, []interface{}) {
96112
if l.Parameterized {

logger/slog_test.go

Lines changed: 30 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,30 @@
1+
//go:build go1.21
2+
3+
package logger
4+
5+
import (
6+
"bytes"
7+
"context"
8+
"log/slog"
9+
"strings"
10+
"testing"
11+
"time"
12+
)
13+
14+
func TestSlogLogger(t *testing.T) {
15+
buf := &bytes.Buffer{}
16+
handler := slog.NewTextHandler(buf, &slog.HandlerOptions{AddSource: true})
17+
logger := NewSlogLogger(slog.New(handler), Config{LogLevel: Info})
18+
19+
logger.Trace(context.Background(), time.Now(), func() (string, int64) {
20+
return "select count(*) from users", 0
21+
}, nil)
22+
23+
if strings.Contains(buf.String(), "gorm/logger/slog.go") {
24+
t.Error("Found internal slog.go reference in caller frame. Expected only test file references.")
25+
}
26+
27+
if !strings.Contains(buf.String(), "gorm/logger/slog_test.go") {
28+
t.Error("Missing expected test file reference. 'gorm/logger/slog_test.go' should appear in caller frames.")
29+
}
30+
}

utils/utils.go

Lines changed: 17 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -30,8 +30,12 @@ func sourceDir(file string) string {
3030
return filepath.ToSlash(s) + "/"
3131
}
3232

33-
// FileWithLineNum return the file name and line number of the current file
34-
func FileWithLineNum() string {
33+
// CallerFrame retrieves the first relevant stack frame outside of GORM's internal implementation files.
34+
// It skips:
35+
// - GORM's core source files (identified by gormSourceDir prefix)
36+
// - Exclude test files (*_test.go)
37+
// - go-gorm/gen's Generated files (*.gen.go)
38+
func CallerFrame() runtime.Frame {
3539
pcs := [13]uintptr{}
3640
// the third caller usually from gorm internal
3741
len := runtime.Callers(3, pcs[:])
@@ -41,10 +45,20 @@ func FileWithLineNum() string {
4145
frame, _ := frames.Next()
4246
if (!strings.HasPrefix(frame.File, gormSourceDir) ||
4347
strings.HasSuffix(frame.File, "_test.go")) && !strings.HasSuffix(frame.File, ".gen.go") {
44-
return string(strconv.AppendInt(append([]byte(frame.File), ':'), int64(frame.Line), 10))
48+
return frame
4549
}
4650
}
4751

52+
return runtime.Frame{}
53+
}
54+
55+
// FileWithLineNum return the file name and line number of the current file
56+
func FileWithLineNum() string {
57+
frame := CallerFrame()
58+
if frame.PC != 0 {
59+
return string(strconv.AppendInt(append([]byte(frame.File), ':'), int64(frame.Line), 10))
60+
}
61+
4862
return ""
4963
}
5064

0 commit comments

Comments
 (0)