267 lines
8.3 KiB
Markdown
267 lines
8.3 KiB
Markdown
|
---
|
|||
|
|
tags: [GORM, Go, ORM, 日志, Debug, SlowQueryThreshold, Logger]
|
|||
|
|
create time: 2026-04-28 00:00
|
|||
|
|
---
|
|||
|
|
|
|||
|
|
# 日志与调试
|
|||
|
|
|
|||
|
|
## 概述
|
|||
|
|
|
|||
|
|
在生产环境中，你能看到的往往只有两条信息：**API 返回了什么**和**数据库执行了什么**。GORM 内置了灵活的日志系统，让你能够在不同环境下精准控制输出粒度，从「生产静默」到「开发透明」自由切换。
|
|||
|
|
|
|||
|
|
```mermaid
|
|||
|
|
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 Start fill:#4FC08D,color:#fff
|
|||
|
|
style Info fill:#3B82F6,color:#fff
|
|||
|
|
style Panic fill:#EF4444,color:#fff
|
|||
|
|
```
|
|||
|
|
|
|||
|
|
## 日志级别速览
|
|||
|
|
|
|||
|
|
GORM 的 `logger.Interface` 定义了四个级别：
|
|||
|
|
|
|||
|
|
| 级别 | 输出内容 | 适用环境 |
|
|||
|
|
|------|---------|---------|
|
|||
|
|
| `Silent` | 什么都不输出 | 压测、极端性能场景 |
|
|||
|
|
| `Error` | 仅错误 | 稳定运行的生产环境 |
|
|||
|
|
| `Warn` | 错误 + 慢查询 | 需要监控的生产环境 |
|
|||
|
|
| `Info` | 所有 SQL + 参数 + 耗时 | 开发 / 调试环境 |
|
|||
|
|
|
|||
|
|
> [!tip] 默认级别是 `Panic`（等同于 Silent）
|
|||
|
|
> GORM **不会在运行时产生任何日志**，除非你显式配置。这既保护隐私也减少磁盘 IO，但也意味着出了问题时需要临时调高日志级别来排查。
|
|||
|
|
|
|||
|
|
## 配置方式
|
|||
|
|
|
|||
|
|
### 基础用法
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
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 等）
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
// 用 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()` 方法临时对单个查询开启全量日志：
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
// 只对这一条 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 语句
|
|||
|
|
> - **单元测试**：临时开日志但不修改全局配置
|
|||
|
|
|
|||
|
|
## 慢查询监控
|
|||
|
|
|
|||
|
|
### 设置慢查询阈值
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
// 超过 100ms 的 SQL 会被标记为 WARN
|
|||
|
|
newLogger := logger.New(
|
|||
|
|
logger.Config{
|
|||
|
|
SlowThreshold: 100 * time.Millisecond,
|
|||
|
|
Colorful: true,
|
|||
|
|
LogLevel: logger.Warn,
|
|||
|
|
},
|
|||
|
|
)
|
|||
|
|
```
|
|||
|
|
|
|||
|
|
### 结合 Prometheus 做量化监控
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
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（不执行）
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
// DryRun 模式：构建完整 SQL 并输出，但不实际执行
|
|||
|
|
db.Session(&gorm.Session{DryRun: true}).First(&user, 1)
|
|||
|
|
// 输出：[info] ... [rows:0] SELECT * FROM users WHERE id = 1 -- dry run
|
|||
|
|
// 此时你可以拿到完整的 SQL 去客户端手动验证
|
|||
|
|
```
|
|||
|
|
|
|||
|
|
### 获取生成的 SQL 字符串
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
// 使用 Statement 直接构造并获取 SQL
|
|||
|
|
stmt := db.Model(&User{}).Where("name = ?", "john").Statement
|
|||
|
|
db.Statement.Build(stmt.DB.Build("WHERE"))
|
|||
|
|
fmt.Println(stmt.SQL.String())
|
|||
|
|
// SELECT * FROM users WHERE name = 'john'
|
|||
|
|
```
|
|||
|
|
|
|||
|
|
### 日志中加入 TraceID（链路追踪）
|
|||
|
|
|
|||
|
|
```go
|
|||
|
|
func WithTraceID(db *gorm.DB, traceID string) *gorm.DB {
|
|||
|
|
return db.Session(&gorm.Session{
|
|||
|
|
Context: context.WithValue(context.Background(), "trace_id", traceID),
|
|||
|
|
})
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
// 自定义日志输出中包含 trace_id
|
|||
|
|
type TracedLogger struct {
|
|||
|
|
logger.Interface
|
|||
|
|
}
|
|||
|
|
|
|||
|
|
func (t TracedLogger) Info(ctx context.Context, msg string, data ...interface{}) {
|
|||
|
|
traceID, _ := ctx.Value("trace_id").(string)
|
|||
|
|
if traceID != "" {
|
|||
|
|
msg = fmt.Sprintf("[trace:%s] %s", traceID, msg)
|
|||
|
|
}
|
|||
|
|
t.Interface.Info(ctx, msg, data...)
|
|||
|
|
}
|
|||
|
|
```
|
|||
|
|
|
|||
|
|
## 日志配置决策图
|
|||
|
|
|
|||
|
|
```mermaid
|
|||
|
|
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 | 先收集基线数据再设定合理阈值 |
|
|||
|
|
|
|||
|
|
## 关联笔记
|
|||
|
|
|
|||
|
|
- [[01-安装与初始化]]
|
|||
|
|
- [[03-CRUD 操作]]
|
|||
|
|
- [[14-错误处理]]
|
|||
|
|
- [[15-性能优化]]
|