goyave.dev/goyave/v5@v5.0.0-rc9.0.20240517145003-d3f977d0b9f3/database/log.go (about) 1 package database 2 3 import ( 4 "context" 5 "errors" 6 "fmt" 7 "regexp" 8 "runtime" 9 "strconv" 10 "strings" 11 "time" 12 13 stdslog "log/slog" 14 15 "github.com/samber/lo" 16 "gorm.io/gorm" 17 "gorm.io/gorm/logger" 18 "goyave.dev/goyave/v5/slog" 19 ) 20 21 var regexGormPath = regexp.MustCompile(`gorm.io/(.*?)@`) 22 23 // Logger adapter between `*slog.Logger` and GORM's logger. 24 type Logger struct { 25 slogger func() *slog.Logger 26 27 // SlowThreshold defines the minimum query execution time to be considered "slow". 28 // If a query takes more time than `SlowThreshold`, the query will be logged at the WARN level. 29 // If 0, disables query execution time checking. 30 SlowThreshold time.Duration 31 } 32 33 // NewLogger create a new `Logger` adapter between GORM and `*slog.Logger`. 34 // Use a `SlowThreshold` of 200ms. 35 func NewLogger(slogger func() *slog.Logger) *Logger { 36 return &Logger{ 37 slogger: slogger, 38 SlowThreshold: 200 * time.Millisecond, 39 } 40 } 41 42 // LogMode returns a copy of this logger. The level argument actually has 43 // no effect as it is handled by the underlying `*slog.Logger`. 44 func (l *Logger) LogMode(_ logger.LogLevel) logger.Interface { 45 newlogger := *l 46 return &newlogger 47 } 48 49 // Info logs at `LevelInfo`. 50 func (l Logger) Info(ctx context.Context, msg string, data ...any) { 51 if l.slogger == nil { 52 return 53 } 54 l.slogger().InfoWithSource(ctx, getSourceCaller(), fmt.Sprintf(msg, data...)) 55 } 56 57 // Warn logs at `LevelWarn`. 58 func (l Logger) Warn(ctx context.Context, msg string, data ...any) { 59 if l.slogger == nil { 60 return 61 } 62 l.slogger().WarnWithSource(ctx, getSourceCaller(), fmt.Sprintf(msg, data...)) 63 } 64 65 // Error logs at `LevelError`. 66 func (l Logger) Error(ctx context.Context, msg string, data ...any) { 67 if l.slogger == nil { 68 return 69 } 70 l.slogger().ErrorWithSource(ctx, getSourceCaller(), fmt.Errorf(msg, data...)) 71 } 72 73 // Trace SQL logs at 74 // - `LevelDebug` 75 // - `LevelWarn` if the query is slow 76 // - `LevelError` if the given error is not nil 77 func (l Logger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) { 78 if l.slogger == nil { 79 return 80 } 81 82 elapsed := time.Since(begin) 83 84 switch { 85 case err != nil && l.slogger().Enabled(ctx, stdslog.LevelError) && !errors.Is(err, gorm.ErrRecordNotFound): 86 sql, rows := fc() 87 l.slogger().ErrorWithSource(ctx, getSourceCaller(), fmt.Errorf("%s\n"+slog.Reset+slog.Yellow+"[%.3fms] "+slog.Blue+"[rows:%s]"+slog.Reset+" %s", err.Error(), float64(elapsed.Nanoseconds())/1e6, lo.Ternary(rows == -1, "-", strconv.FormatInt(rows, 10)), sql)) 88 case elapsed > l.SlowThreshold && l.SlowThreshold != 0 && l.slogger().Enabled(ctx, stdslog.LevelWarn): 89 sql, rows := fc() 90 slowLog := fmt.Sprintf("SLOW SQL >= %v", l.SlowThreshold) 91 l.slogger().WarnWithSource(ctx, getSourceCaller(), fmt.Sprintf("%s\n"+slog.Reset+slog.Red+"[%.3fms] "+slog.Blue+"[rows:%s]"+slog.Reset+" %s", slowLog, float64(elapsed.Nanoseconds())/1e6, lo.Ternary(rows == -1, "-", strconv.FormatInt(rows, 10)), sql)) 92 case l.slogger().Enabled(ctx, stdslog.LevelDebug): 93 sql, rows := fc() 94 l.slogger().DebugWithSource(ctx, getSourceCaller(), fmt.Sprintf(slog.Yellow+"[%.3fms] "+slog.Blue+"[rows:%s]"+slog.Reset+" %s", float64(elapsed.Nanoseconds())/1e6, lo.Ternary(rows == -1, "-", strconv.FormatInt(rows, 10)), sql)) 95 } 96 } 97 98 func getSourceCaller() uintptr { 99 // function copied from gorm/utils/utils.go 100 // the second caller usually from gorm internal, so set i start from 2 101 for i := 2; i < 15; i++ { 102 pc, file, _, ok := runtime.Caller(i) 103 if ok && (!regexGormPath.MatchString(file) || strings.HasSuffix(file, "_test.go")) { 104 return pc 105 } 106 } 107 108 return 0 109 }