wonder/cs-note

Fork 0

Files

T

wonder 30d312ac35 Init

2026-05-24 11:42:38 +08:00

13 KiB

Raw Blame History

tags, create time

日志与调试

概述

在生产环境中，你能看到的往往只有两条信息：API 返回了什么和数据库执行了什么。GORM 内置了灵活的日志系统，让你能够在不同环境下精准控制输出粒度——从「生产静默」到「开发透明」自由切换。

flowchart TD
    A["你的代码"] --> B["GORM SQL 生成"]
    B --> C{"Logger 配置"}
    
    C --> |Panic| D["出错了才输出<br/>生产默认值"]
    C --> |Error| E["只记录错误 SQL"]
    C --> |Warn| F["慢查询 + 错误"]
    C --> |Info| G["所有 SQL + 耗时<br/>开发推荐"]
    
    style A fill:#4FC08D,color:#fff
    style D fill:#EF4444,color:#fff
    style E fill:#F97316,color:#fff
    style F fill:#EAB308,color:#fff
    style G fill:#3B82F6,color:#fff

日志级别速览

GORM 的 logger.Interface 定义了四个级别：

级别	输出内容	适用环境
`Silent`	什么都不输出	压测、极端性能场景
`Error`	仅错误	稳定运行的生产环境
`Warn`	错误 + 慢查询	需要监控的生产环境
`Info`	所有 SQL + 参数 + 耗时	开发 / 调试环境

[!tip] 默认级别是 Panic（等同于 Silent） GORM 不会在运行时产生任何日志，除非你显式配置。这既保护隐私也减少磁盘 IO，但也意味着出了问题时需要临时调高日志级别来排查。

配置方式

基础用法

import (
    "gorm.io/gorm/logger"
    "time"
)

newLogger := logger.New(
    logger.Config{
        SlowThreshold:             200 * time.Millisecond, // 超过 200ms 视为慢查询
        Colorful:                  true,                   // 终端彩色输出
        IgnoreRecordNotFoundError: false,                  // 记录 ErrRecordNotFound
        LogLevel:                  logger.Info,            // 日志级别
    },
)

db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: newLogger,
})

自定义 Logger（对接 Zap / Logrus 等）

// 用 Zap 替代默认日志（需 import "context"、"zap"）
type ZapLogger struct {
    logger.Interface
    zapLogger *zap.Logger
}

func (z ZapLogger) LogMode(level logger.Level) logger.Interface {
    newLogger := z
    newLogger.Interface = z.Interface.LogMode(level)
    return newLogger
}

func (z ZapLogger) Info(ctx context.Context, msg string, data ...interface{}) {
    z.zapLogger.Sugar().Infow(msg, data...)
}

func (z ZapLogger) Warn(ctx context.Context, msg string, data ...interface{}) {
    z.zapLogger.Sugar().Warnw(msg, data...)
}

func (z ZapLogger) Error(ctx context.Context, msg string, data ...interface{}) {
    z.zapLogger.Sugar().Errorw(msg, data...)
}

// 使用
zapLogger, _ := zap.NewProduction()
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: ZapLogger{Interface: logger.Default, zapLogger: zapLogger},
})

SQL 日志格式解析

当启用 Info 级别时，你会看到类似这样的输出：

[info] ... [0.12ms] [rows:-] SELECT * FROM users WHERE id = 1

│   │    │         │       │        │
│   │    │         │       │        └── SQL 语句
│   │    │         │       └── 影响行数 (- 表示查询不确定)
│   │    │         └── 执行耗时
│   │    └── 操作标签（SELECT/INSERT/UPDATE/DELETE）
│   └── 文件位置: src/model/user.go:15
└── 日志级别

关键指标解读

字段	含义	关注点
`[0.12ms]`	单次执行耗时	超过 SlowThreshold 会用 WARN 标记
`[rows:42]`	影响/返回行数	SELECT 时为正数，INSERT/UPDATE/DELETE 为影响行数
`[rows:-]`	行数未知（通常是 SELECT）	无法提前知道，需执行后统计

Debug — 临时开启详细日志

不想改全局配置的情况下，可以用 Debug() 方法临时对单个查询开启全量日志：

// 只对这一条 SQL 输出详细信息
result := db.Debug().Where("status = ?", "active").Find(&users)
// 输出：[info] ... [1.23ms] [rows:150] SELECT * FROM users WHERE status='active'

// 对比：没有 Debug() 时可能完全看不到这条 SQL
result = db.Where("status = ?", "active").Find(&users)
// 无输出（如果 Logger 是 Silent/Error）

[!tip] Debug 的实际用途

快速定位问题 SQL：在一个复杂链式调用中，找到是哪一步生成的 SQL 不对

Code Review 时的验证：确认 GORM 确实生成了预期的 SQL 语句

单元测试：临时开日志但不修改全局配置

慢查询监控

设置慢查询阈值

// 超过 100ms 的 SQL 会被标记为 WARN
newLogger := logger.New(
    logger.Config{
        SlowThreshold:     100 * time.Millisecond,
        Colorful:          true,
        LogLevel:          logger.Warn,
    },
)

结合 Prometheus 做量化监控

import "github.com/prometheus/client_golang/prometheus"

var queryDuration = prometheus.NewHistogramVec(
    prometheus.HistogramOpts{
        Name: "gorm_query_duration_ms",
        Help: "GORM query duration in milliseconds",
    },
    []string{"operation", "table"},
)

// 在每个请求结束后采集（简化示例）
func RecordQueryDuration(op, table string, dur time.Duration) {
    queryDuration.WithLabelValues(op, table).Observe(dur.Seconds() * 1000)
}

[!question] 思考题什么时候该关注慢查询？100ms、500ms 还是 1s？

答案：取决于业务 SLA。对于 API 网关场景，单条 SQL 建议控制在 50ms 以内；对于离线批处理任务，可以放宽到秒级。关键是建立基线——先跑一周看 P95/P99 数据，再设定阈值。

常见调试技巧

打印最终 SQL（不执行）—— DryRun 模式

DryRun 模式会构建完整的 SQL 语句并输出到日志，但不实际连接数据库执行。这是最安全的调试方式：

// DryRun 模式：构建完整 SQL 并输出，但不实际执行
db.Session(&gorm.Session{DryRun: true}).First(&user, 1)
// 输出：[info] ... [rows:0] SELECT * FROM users WHERE id = ?
// 此时你可以拿到完整的 SQL 去客户端手动验证

// 配合复杂查询链 —— 确认 Join / Preload 生成的子查询是否正确
db.Session(&gorm.Session{
    DryRun: true,
}).Preload("Orders").Joins("Profile").Where("status = ?", "active").Find(&users)

[!question] DryRun vs Debug 有什么区别？

特性 DryRun Debug()

是否执行 SQL ❌ 不执行 ✅ 执行

适用场景 审计 SQL 语法、安全审查排查运行时产生的错误 SQL

性能开销 零（无网络 IO）有正常查询开销

能否看到关联表 SQL ✅ Preload/Joins 都输出 ✅ 同上

答案：用不同的场景。想确认 "这条链式调用会生成什么 SQL" → DryRun；想确认 "生产上跑的这条 SQL 到底慢在哪里" → Debug。实际项目中推荐在 CI/CD pipeline 中跑 DryRun 做 SQL 规范校验。

特性	`DryRun`	`Debug()`
是否执行 SQL	❌ 不执行	✅ 执行
适用场景	审计 SQL 语法、安全审查	排查运行时产生的错误 SQL
性能开销	零（无网络 IO）	有正常查询开销
能否看到关联表 SQL	✅ Preload/Joins 都输出	✅ 同上

DryRun 在单元测试中的妙用

func TestUserQuerySQL(t *testing.T) {
    // 用 SQLite 内存库创建独立 DB（不需要 MySQL/PG 服务）
    sqlDB, _ := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{})

    sql := sqlDB.ToSQL(func(tx *gorm.DB) *gorm.DB {
        return tx.Model(&User{}).
            Where("status = ?", "active").
            Order("created_at DESC").
            Limit(10).
            Find(&User{})
    })

    // 断言 SQL 中包含关键片段
    assert.Contains(t, sql, "WHERE status =")
    assert.Contains(t, sql, "ORDER BY created_at DESC")
    assert.Contains(t, sql, "LIMIT 10")
}

获取生成的 SQL 字符串（ToSQL）

GORM v2.4+ 提供了 ToSQL 方法，无需开启 DryRun 也能拿到最终的 SQL：

import "gorm.io/gorm/schema"

// 构建一个独立的 DB 实例（不连接数据库）
sqlDB, _ := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{})

// ToSQL 返回执行后的 SQL 字符串（不含参数展开）
sql := sqlDB.ToSQL(func(tx *gorm.DB) *gorm.DB {
    return tx.Model(&User{}).Where("name = ?", "john").Find(&User{})
})
fmt.Println(sql)
// SELECT * FROM `users` WHERE name = 'john'

[!tip] 何时需要拿原始 SQL？

生成 SQL 后交给他人审计：把 ORM 生成的语句导出给 DBA 审查索引使用情况

单元测试断言：对比预期 SQL 是否符合安全规范（如是否包含未参数化的拼接）

ORM 到原生迁移：性能优化时，从 GORM 逐步替换为 Raw SQL 的过渡手段

日志中加入 TraceID（链路追踪）

在生产环境中，单条 SQL 日志的价值取决于能否关联到完整请求链路。通过 context.Context 传递 TraceID 是行业标准做法：

type contextKey struct{}

// 中间件：从 HTTP Header 提取 trace_id 注入 Context
func TraceMiddleware(db *gorm.DB) func(next http.Handler) http.Handler {
    return func(next http.Handler) http.Handler {
        return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
            traceID := r.Header.Get("X-Trace-Id")
            if traceID == "" {
                traceID = generateUUID() // 兜底生成
            }
            ctx := context.WithValue(r.Context(), contextKey{}, traceID)

            // 用带 trace_id 的 Context 创建新的 DB 实例
            tracedDB := db.Session(&gorm.Session{Context: ctx})
            // 这里可以将 tracedDB 存到 Context 供 handler 使用
            _ = tracedDB

            next.ServeHTTP(w, r.WithContext(ctx))
        })
    }
}

// GORM 自定义 Logger：在日志中附加 TraceID
type TraceLogger struct {
    logger.Interface
}

func (t TraceLogger) Info(ctx context.Context, msg string, data ...interface{}) {
    if traceID, ok := ctx.Value(contextKey{}).(string); ok && traceID != "" {
        msg = fmt.Sprintf("[trace:%s] %s", traceID, msg)
    }
    t.Interface.Info(ctx, msg, data...)
}

[!tip] OpenTelemetry 集成要点如果你已接入 OpenTelemetry，可以直接复用 SpanContext 中的 trace ID，无需自己定义 context key：
import "go.opentelemetry.io/otel/trace"

func extractTraceID(ctx context.Context) string {
    span := trace.SpanFromContext(ctx)
    if span.SpanContext().IsValid() {
        return span.SpanContext().TraceID().String()
    }
    return ""
}

数据库方言对日志输出的影响

不同数据库驱动会影响最终生成的 SQL 语法和参数占位符：

驱动	参数占位符	字符串引号	日期格式
MySQL (`go-sql-driver/mysql`)	`?`	`'单引号'`	`'2026-04-28'`
PostgreSQL (`pgx`)	`$1`, `$2`...	`'单引号'`	`TIMESTAMP '...'`
SQLite (`mattn/go-sqlite3`)	`?`	`'单引号'` 或 `"双引号"`	`'...'`
SQL Server (`microsoft/mssql-go`)	`@p1`, `@p2`...	`'单引号'`	`DATETIME2 '...'`

[!note] DryRun 结果对比示例

// MySQL DryRun → SELECT * FROM users WHERE id = ?
// PostgreSQL DryRun → SELECT * FROM users WHERE id = $1
// SQL Server DryRun → SELECT * FROM users WHERE id = @p1
//
// 这意味着测试时要用对应驱动初始化 ToSQL/DryRun，否则拿到的 SQL 无法直接在其他数据库中执行。

常见调试技巧总结

flowchart TD
    Start["确定日志需求"] --> Env{"运行环境?"}
    
    Env --> |开发环境| Dev["Info 级别 + Colorful + SlowThreshold=200ms"]
    Env --> |测试环境| Test["Warn 级别 + SlowThreshold=100ms"]
    Env --> |生产环境| ProdQ{"需要实时监控?"}
    
    ProdQ --> |不需要| ProdSilent["Error 级别（默认）"]
    ProdQ --> |需要| ProdMonitor["Warn 级别 + 接入监控体系"]
    
    Dev --> Check{"特定查询需要调试?"}
    Test --> Check
    ProdMonitor --> Check
    
    Check --> |是| DebugOn["db.Debug() 临时开启"]
    Check --> |否| Done["配置完成 ✓"]
    
    style Start fill:#4FC08D,color:#fff
    style Dev fill:#3B82F6,color:#fff
    style ProdMonitor fill:#EAB308,color:#fff
    style Done fill:#A0AEC0,color:#fff

常见坑点速查

问题	原因	解决方案
生产环境日志太多导致磁盘爆满	Logger 级别设太高	生产用 Warn 或 Error
日志中没有 TraceID 难以定位	没传 Context	用 Session + Context 传递
DryRun 拿到的 SQL 参数是 `?`	预编译语句的参数未展开	这是正常行为，参数化查询安全性的体现
Debug() 影响了其他查询的输出	以为会改全局配置	`Debug()` 返回新 `*gorm.DB` 实例，不影响原对象
慢查询阈值设太低	正常查询也被标记为 slow	先收集基线数据再设定合理阈值
PostgreSQL 下 `?` 占位符报错	PG 使用 `$n` 占位符	切换驱动或注意不同驱动的 DryRun 输出差异
自定义 Logger 丢失默认行为	忘记实现所有四个方法	继承 `logger.Interface`，只覆盖需要的方法
并发场景下 Logger 线程不安全	多个 goroutine 同时写日志	使用 Zap、Logrus 等并发安全的日志库

13 KiB Raw Blame History Unescape Escape