日志与调试

开发过程中,知道 GORM 执行了什么 SQL 是调试的关键。生产环境,SQL 日志是排查问题的重要依据。这一章介绍 GORM 的日志配置和调试技巧。

Debug 模式

最简单的方式是用 Debug():

// 打印单条查询的 SQL
db.Debug().Where("name = ?", "张三").First(&user)
// SELECT * FROM `users` WHERE name = '张三' ORDER BY `users`.`id` LIMIT 1

Debug() 会把 SQL 打印到标准输出,开发时很方便。

全局日志配置

不想每个查询都加 Debug(),可以全局配置:

db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})

日志级别:

logger.Silent  // 不打印
logger.Error   // 只打印错误
logger.Warn    // 打印警告和错误
logger.Info    // 打印所有 SQL

自定义 Logger

GORM 的 Logger 接口:

type Interface interface {
    LogMode(LogLevel) Interface
    Info(context.Context, string, ...interface{})
    Warn(context.Context, string, ...interface{})
    Error(context.Context, string, ...interface{})
    Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error)
}

实现一个写入文件的 Logger:

type FileWriter struct {
    logger.Writer
}

func NewFileWriter(filename string) *FileWriter {
    file, _ := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
    return &FileWriter{Writer: logger.Writer{Writer: file}}
}

db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.New(NewFileWriter("sql.log"), logger.Config{
        SlowThreshold: time.Second,
        LogLevel:      logger.Info,
        Colorful:      false,
    }),
})

慢查询日志

GORM 内置慢查询记录:

db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Warn).LogMode(logger.Warn),
})

// 或者自定义阈值
newLogger := logger.New(
    log.New(os.Stdout, "\r\n", log.LstdFlags),
    logger.Config{
        SlowThreshold: 200 * time.Millisecond,  // 慢查询阈值
        LogLevel:      logger.Warn,
    },
)
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{Logger: newLogger})

超过阈值的查询会被标记为慢查询。

日志格式

GORM 默认日志格式:

[2024-01-15 10:30:45]  [2.35ms]  [rows:10]  SELECT * FROM `users` WHERE age > 18

包含时间、耗时、影响行数、SQL 语句。

自定义格式可以实现 Logger 接口的 Trace 方法:

func (l *MyLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
    elapsed := time.Since(begin)
    sql, rows := fc()
    
    if err != nil {
        l.Error(ctx, "[%.3fms] [rows:%d] %s | ERROR: %v", float64(elapsed.Nanoseconds())/1e6, rows, sql, err)
    } else if elapsed > l.SlowThreshold {
        l.Warn(ctx, "[%.3fms] [rows:%d] %s | SLOW QUERY", float64(elapsed.Nanoseconds())/1e6, rows, sql)
    } else {
        l.Info(ctx, "[%.3fms] [rows:%d] %s", float64(elapsed.Nanoseconds())/1e6, rows, sql)
    }
}

集成日志框架

项目中一般用 logrus、zap 等日志框架,可以集成:

// 使用 zap
type ZapLogger struct {
    *zap.SugaredLogger
    logger.Config
}

func (l *ZapLogger) LogMode(level logger.LogLevel) logger.Interface {
    newLogger := *l
    newLogger.LogLevel = level
    return &newLogger
}

func (l *ZapLogger) Info(ctx context.Context, msg string, data ...interface{}) {
    if l.LogLevel >= logger.Info {
        l.SugaredLogger.Infof(msg, data...)
    }
}

// 其他方法类似...

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: &ZapLogger{
        SugaredLogger: zap.L().Sugar(),
        Config: logger.Config{
            SlowThreshold: time.Second,
            LogLevel:      logger.Info,
        },
    },
})

获取执行的 SQL

有时需要在代码里拿到执行的 SQL:

stmt := db.Session(&gorm.Session{DryRun: true}).
    Where("name = ?", "张三").
    First(&user).
    Statement

sql := stmt.SQL.String()
fmt.Println(sql)  // SELECT * FROM `users` WHERE name = ? LIMIT 1

// 拿到带参数的 SQL(不推荐用于生产,有注入风险)
sqlDB, _ := db.DB()
var result []map[string]interface{}
db.Raw("EXPLAIN " + sql).Scan(&result)

DryRun 模式只生成 SQL 不执行。

Context 传递 Trace ID

分布式追踪需要在日志中带上 Trace ID:

// 中间件设置 context
func TraceMiddleware() gin.HandlerFunc {
    return func(c *gin.Context) {
        traceID := c.GetHeader("X-Trace-ID")
        if traceID == "" {
            traceID = uuid.New().String()
        }
        ctx := context.WithValue(c.Request.Context(), "trace_id", traceID)
        c.Request = c.Request.WithContext(ctx)
        c.Next()
    }
}

// Logger 中读取
func (l *MyLogger) Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error) {
    traceID, _ := ctx.Value("trace_id").(string)
    // 日志中带上 traceID
}

生产环境日志建议

  1. 不要打印所有 SQL:数据量大时日志会爆炸,只记录慢查询和错误。

  2. 结构化日志:用 JSON 格式,方便日志平台分析。

  3. 敏感信息脱敏:密码、手机号等不要明文出现在日志。

  4. 日志采样:高并发场景可以采样记录,比如只记录 1% 的查询。

  5. 异步写入:日志写入不要阻塞业务,用 channel 异步处理。

type AsyncLogger struct {
    ch chan logEntry
    logger.Interface
}

type logEntry struct {
    level   logger.LogLevel
    message string
}

func (l *AsyncLogger) Info(ctx context.Context, msg string, data ...interface{}) {
    l.ch <- logEntry{level: logger.Info, message: fmt.Sprintf(msg, data...)}
}

// 后台 goroutine 消费 channel 写入

调试技巧

查看关联查询的 SQL

db.Debug().Preload("Orders").Preload("Orders.Items").Find(&users)

会打印多条 SQL,可以清楚看到预加载的行为。

分析查询计划

var result []map[string]interface{}
db.Raw("EXPLAIN SELECT * FROM users WHERE status = ?", "active").Scan(&result)
fmt.Printf("%+v\n", result)

检查索引使用情况

db.Raw("EXPLAIN ANALYZE SELECT * FROM orders WHERE user_id = ?", 1).Scan(&result)

总结

日志是调试和排障的利器:

  1. 开发环境用 Debug() 快速定位问题
  2. 生产环境记录慢查询和错误
  3. 集成项目日志框架,统一管理
  4. 注意日志量和敏感信息
  5. 结合 Context 做分布式追踪

好的日志配置能让你快速定位问题,差的配置可能让问题石沉大海。