日志系统模块原理说明

基于1.31 本文档深入解析日志系统模块的设计原理和核心实现，涵盖 SQL 日志记录、性能分析、调用栈追踪等核心内容。学习完本文档后，您将能够彻底理解 GORM 日志系统的工作机制，并能够实现自定义 Logger 来满足各种日志需求。

文档目录

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
09-logger.md
├── 一、设计原理
│   ├── 1.1 模块定位
│   ├── 1.2 设计目的
│   ├── 1.3 结构安排依据
│   └── 1.4 与其他模块的逻辑关系
│
├── 二、核心数据结构
│   ├── 2.1 LogLevel 枚举 (logger.go:34-46)
│   │   ├── 枚举定义
│   │   ├── 级别说明
│   │   └── 使用示例
│   ├── 2.2 Interface 接口 (logger.go:62-69)
│   │   ├── 接口定义
│   │   ├── 方法说明
│   │   └── 接口设计原理
│   ├── 2.3 Config 结构体 (logger.go:53-60)
│   │   ├── 结构体定义
│   │   ├── 字段说明
│   │   └── 配置示例
│   ├── 2.4 logger 结构体 (logger.go:122-127)
│   │   ├── 结构体定义
│   │   └── 字段说明
│   ├── 2.5 Writer 接口 (logger.go:48-51)
│   │   ├── 接口定义
│   │   └── 实现示例
│   └── 2.6 traceRecorder 结构体 (logger.go:200-206)
│       │   ├── 结构体定义
│       │   └── 用途说明
│
├── 三、日志核心实现
│   ├── 3.1 New() 函数 (logger.go:90-120)
│   │   ├── 完整源码
│   │   ├── 格式化字符串构建
│   │   └── 颜色配置
│   ├── 3.2 LogMode() 方法 (logger.go:129-134)
│   │   ├── 完整源码
│   │   └── 级别切换机制
│   ├── 3.3 Trace() 方法 (logger.go:157-190)
│   │   ├── 完整源码
│   │   ├── 执行流程详解
│   │   └── 决策逻辑
│   ├── 3.4 Info/Warn/Error() 方法
│   │   ├── Info() (logger.go:136-141)
│   │   ├── Warn() (logger.go:143-148)
│   │   └── Error() (logger.go:150-155)
│   └── 3.5 ParamsFilter() 方法 (logger.go:192-198)
│       ├── 完整源码
│       └── 参数过滤机制
│
├── 四、SQL 解释机制
│   ├── 4.1 Dialector.Explain() 方法
│   │   ├── 方法签名
│   │   ├── 参数占位符
│   │   └── 数据库差异
│   ├── 4.2 参数值格式化
│   │   ├── 字符串格式化
│   │   ├── 时间格式化
│   │   └── NULL 值处理
│   └── 4.3 敏感参数过滤
│       ├── ParamsFilter 接口
│       └── 实现示例
│
├── 五、调用栈追踪
│   ├── 5.1 FileWithLineNum() 实现
│   │   ├── runtime.Caller 原理
│   │   ├── 过滤逻辑
│   │   └── 完整源码
│   ├── 5.2 调用栈追踪配置
│   │   ├── 启用追踪
│   │   └── 禁用追踪
│   └── 5.3 性能考虑
│       ├── 追踪开销
│       └── 优化建议
│
├── 六、实战代码示例
│   ├── 6.1 基础配置示例
│   │   ├── 开发环境配置
│   │   ├── 生产环境配置
│   │   └── 测试环境配置
│   ├── 6.2 自定义 Logger 示例
│   │   ├── 文件 Logger
│   │   ├── JSON Logger
│   │   └── 结构化 Logger
│   ├── 6.3 慢查询检测示例
│   │   ├── 基础配置
│   │   ├── 动态配置
│   │   └── 告警集成
│   ├── 6.4 日志集成示例
│   │   ├── 集成 logrus
│   │   ├── 集成 zap
│   │   └── 集成 fluentd
│   ├── 6.5 Recorder 使用示例
│   │   ├── SQL 记录
│   │   ├── 单元测试
│   │   └── SQL 审计
│   └── 6.6 完整日志系统示例
│       ├── 分环境配置
│       ├── 日志轮转
│       └── 日志聚合
│
├── 七、可视化流程图
│   ├── 7.1 Trace() 完整执行流程图
│   ├── 7.2 日志级别决策树
│   ├── 7.3 SQL 解释流程图
│   ├── 7.4 调用栈追踪流程图
│   └── 7.5 日志系统架构图
│
├── 八、最佳实践与故障排查
│   ├── 8.1 配置最佳实践
│   │   ├── 开发环境最佳实践
│   │   ├── 生产环境最佳实践
│   │   └── 测试环境最佳实践
│   ├── 8.2 性能优化
│   │   ├── 减少日志开销
│   │   ├── 异步日志
│   │   └── 日志采样
│   ├── 8.3 安全建议
│   │   ├── 敏感数据过滤
│   │   ├── SQL 注入防护
│   │   └── 日志脱敏
│   ├── 8.4 常见问题与解决方案
│   │   ├── 日志不输出问题
│   │   ├── 性能问题
│   │   ├── 调用栈不准确问题
│   │   └── 颜色显示问题
│   └── 8.5 日志分析策略
│       ├── 慢查询分析
│       ├── 错误日志分析
│       └── 行为模式分析
│
└── 九、学习验证
    ├── 9.1 知识自测
    │   ├── 基础题 (10 道)
    │   ├── 进阶题 (8 道)
    │   └── 实战题 (5 道)
    └── 9.2 实践练习
        ├── 练习 1: 实现自定义 JSON Logger
        ├── 练习 2: 实现日志聚合系统
        └── 练习 3: 实现 SQL 审计系统

一、设计原理

1.1 模块定位

在整体架构中的位置

日志系统模块是 GORM 的可观测性层，负责记录 SQL 执行信息、性能指标和调用上下文。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
┌─────────────────────────────────────────────────────────────┐
│                   SQL 执行                                   │
│  db.Find(&users).Where("age > ?", 18)                       │
└────────────────────────┬────────────────────────────────────┘
                         │
                         ▼
┌─────────────────────────────────────────────────────────────┐
│              日志记录 (本模块) ★                              │
│  ┌────────────────────────────────────────────────────┐     │
│  │  Trace(ctx, begin, fc, error)                       │     │
│  │  ├─ 计算耗时 elapsed = time.Since(begin)            │     │
│  │  ├─ 获取 SQL 和行数 sql, rows = fc()                │     │
│  │  ├─ 判断日志级别                                    │     │
│  │  ├─ 慢查询检测 elapsed > SlowThreshold               │     │
│  │  └─ 格式化输出                                      │     │
│  └────────────────────────────────────────────────────┘     │
│                                                             │
│  日志组件:                                                   │
│  ┌──────────┐  ┌──────────┐  ┌──────────┐  ┌──────────┐   │
│  │ SQL 记录 │  │参数记录  │  │耗时记录  │  │调用栈记录│   │
│  │          │  │          │  │          │  │          │   │
│  └──────────┘  └──────────┘  └──────────┘  └──────────┘   │
└────────────────────────┬────────────────────────────────────┘
                         │
                         ▼
┌─────────────────────────────────────────────────────────────┐
│                   日志输出                                    │
│  ┌────────────────────────────────────────────────────┐     │
│  │ [2024-01-01 10:00:00]                                 │     │
│  │ [3.45ms] SELECT * FROM users WHERE age > 18           │     │
│  │ [10 rows affected or returned]                        │     │
│  │ [main.go:45] main.main()                             │     │
│  └────────────────────────────────────────────────────┘     │
└─────────────────────────────────────────────────────────────┘

核心价值

日志系统模块的核心价值在于：

  1. 调试支持: 记录 SQL 语句和参数，便于调试
  2. 性能分析: 记录执行时间，检测慢查询
  3. 问题诊断: 记录错误和调用栈，快速定位问题
  4. 可观测性: 提供运行时行为的完整视图

1.2 设计目的

问题 1: 如何记录 SQL 执行的完整上下文？

  • 挑战: 需要记录 SQL 语句、参数、执行时间、行数等
  • 挑战: 需要在不显著影响性能的前提下记录
  • 挑战: 需要支持不同级别的日志详细度

解决方案: Trace 方法 + 延迟计算

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
// 问题场景: 记录 SQL 执行

// 方案 1: 立即记录 (问题: 性能影响大)
func Execute(sql string, params ...interface{}) {
    startTime := time.Now()
    // 执行 SQL
    result := db.Exec(sql, params...)
    // 记录日志
    log.Printf("SQL: %s, Params: %v, Time: %v", sql, params, time.Since(startTime))
}

// 方案 2: 延迟计算 (GORM 方案)
func Execute(fc func() (string, int64)) {
    startTime := time.Now()
    // 执行 SQL
    result := db.Exec(...)
    // 延迟计算 SQL 和行数
    db.Logger.Trace(ctx, startTime, fc, err)
}

// Trace 方法实现
func (l *logger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    elapsed := time.Since(begin)  // 计算耗时
    sql, rows := fc()             // 延迟获取 SQL 和行数

    // 根据日志级别决定输出
    if l.LogLevel == Silent {
        return
    }

    if err != nil && l.LogLevel >= Error {
        l.Error(ctx, err, elapsed, sql, rows...)
    } else if elapsed > l.SlowThreshold && l.SlowThreshold != 0 {
        l.Slow(ctx, elapsed, sql, rows...)
    } else if l.LogLevel >= Info {
        l.Info(ctx, elapsed, sql, rows...)
    }
}

问题 2: 如何实现可配置的日志详细度？

  • 挑战: 不同环境需要不同的日志级别
  • 挑战: 需要支持动态切换日志级别
  • 挑战: 需要支持自定义日志格式

解决方案: LogLevel 枚举 + 接口抽象

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
// 日志级别定义
type LogLevel int

const (
    Silent LogLevel = iota + 1  // 静默，不记录任何日志
    Error                        // 只记录错误
    Warn                         // 记录错误和警告
    Info                         // 记录所有信息
)

// 日志接口
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() (string, int64), err error)
}

// 使用示例
// 开发环境: 详细日志
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})

// 生产环境: 只记录错误和慢查询
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Error),
})

问题 3: 如何追踪 SQL 的调用来源？

  • 挑战: 需要记录是哪段代码触发了 SQL
  • 挑战: 需要过滤 GORM 内部调用
  • 挑战: 需要在不显著影响性能的前提下获取调用栈

解决方案: runtime.Caller + 过滤逻辑

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
// 调用栈追踪
func (l *logger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    // ...

    // 获取调用文件和行号
    if l.IgnoreRecordNotFoundError {
        // 使用 FileWithLineNum 获取调用位置
        sql += fmt.Sprintf(" [%s]", utils.FileWithLineNum())
    }

    // ...
}

// FileWithLineNum 实现
func FileWithLineNum() string {
    // 跳过 GORM 内部调用
    for i := 2; i < 15; i++ {
        _, file, line, ok := runtime.Caller(i)
        if !ok {
            break
        }
        // 过滤 GORM 内部文件
        if !strings.Contains(file, "/gorm/") {
            return fmt.Sprintf("%v:%v", file, line)
        }
    }
    return ""
}

1.3 结构安排依据

3 天学习时间的科学分配

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
Day 1: 日志基础 (核心概念)
  目标: 理解日志的基本概念和使用
  重点:
    - Logger 接口
    - 日志级别
    - Trace 方法

Day 2: 高级日志 (核心机制)
  目标: 理解日志的内部实现
  重点:
    - SQL 解释机制
    - 慢查询检测
    - 调用栈追踪

Day 3: 扩展应用 (最佳实践)
  目标: 掌握自定义 Logger 实现
  重点:
    - 自定义 Logger
    - 集成日志库
    - 日志聚合分析

由浅入深的学习路径

1
2
3
4
5
6
7
8
9
10
11
12
13
14
第 1 层: 使用层 (如何使用)
  ├─ 配置日志级别
  ├─ 使用默认 Logger
  └─ 查看日志输出

第 2 层: 机制层 (如何工作)
  ├─ Trace 方法实现
  ├─ SQL 解释原理
  └─ 调用栈追踪

第 3 层: 原理层 (为什么这样设计)
  ├─ 日志级别设计
  ├─ 性能考虑
  └─ 可扩展性设计

1.4 与其他模块的逻辑关系

依赖关系

  • 依赖所有模块: 需要记录所有模块的操作
  • 依赖 Context: 使用 context 传递日志上下文

支撑关系

  • 支撑调试: 提供 SQL 执行的可视化
  • 支撑性能分析: 记录执行时间
  • 支撑问题诊断: 记录错误和调用栈

模块交互图

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
日志模块 ↔ 其他模块:

┌─────────────────────────┐
│  所有其他模块            │
│  - 查询构建              │
│  - 回调系统              │
│  - 关联查询              │
└──────────┬──────────────┘
           │
           ▼
┌─────────────────────────────┐
│      日志模块                │
│  ┌───────────────────────┐  │
│  │ Trace()               │  │
│  │ ├─ 记录 SQL            │  │
│  │ ├─ 记录参数            │  │
│  │ ├─ 记录耗时            │  │
│  │ ├─ 记录行数            │  │
│  │ └─ 记录调用栈          │  │
│  └───────────────────────┘  │
└──────────┬──────────────────┘
           │
           ├─→ 标准输出
           ├─→ 文件
           └─→ 日志系统

二、核心数据结构

2.1 LogLevel 枚举 (logger.go:34-46)

枚举定义

1
2
3
4
5
6
7
8
9
10
11
12
13
// LogLevel log level
type LogLevel int

const (
	// Silent silent log level
	Silent LogLevel = iota + 1
	// Error error log level
	Error
	// Warn warn log level
	Warn
	// Info info log level
	Info
)

级别说明

级别 值 记录内容 使用场景 性能影响
Silent 1 不记录任何日志 生产环境、性能敏感场景 无
Error 2 只记录 SQL 错误 生产环境监控 最小
Warn 3 记录错误和慢查询 生产环境监控 小
Info 4 记录所有 SQL 开发环境、调试 较大

使用示例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
import "gorm.io/gorm/logger"

// Silent 模式：完全静默
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Silent),
})

// Error 模式：只记录错误
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Error),
})

// Warn 模式：记录错误和慢查询
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Warn),
})

// Info 模式：记录所有 SQL
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Info),
})

2.2 Interface 接口 (logger.go:62-69)

接口定义

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
// Interface logger interface
type Interface interface {
	// 设置日志级别，返回新的 Logger 实例
	LogMode(LogLevel) Interface

	// 记录信息级别日志
	Info(context.Context, string, ...interface{})

	// 记录警告级别日志
	Warn(context.Context, string, ...interface{})

	// 记录错误级别日志
	Error(context.Context, string, ...interface{})

	// 追踪 SQL 执行 (核心方法)
	Trace(ctx context.Context, begin time.Time, fc func() (sql string, rowsAffected int64), err error)
}

方法说明

LogMode(LogLevel) Interface

  • 设置日志级别
  • 返回新的 Logger 实例（不可变模式）
  • 支持链式调用

Info/Warn/Error(context.Context, string, …interface{})

  • 基础日志记录方法
  • 第一个参数是 context.Context，用于传递上下文信息
  • 第二个参数是消息
  • 后续参数是格式化参数

Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error)

  • 核心 SQL 追踪方法
  • 使用延迟计算函数 fc 获取 SQL 和行数
  • 根据日志级别、错误、耗时决定是否记录

接口设计原理

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
Logger 接口设计原理:

┌─────────────────────────────────────────────────────────────┐
│                     Logger 接口                               │
├─────────────────────────────────────────────────────────────┤
│                                                               │
│  ┌─────────────────────────────────────────────────────┐    │
│  │             配置方法                                  │    │
│  │  LogMode(LogLevel) → 设置日志级别                     │    │
│  │                       返回新实例                       │    │
│  └─────────────────────────────────────────────────────┘    │
│                          ↓                                   │
│  ┌─────────────────────────────────────────────────────┐    │
│  │             基础日志方法                              │    │
│  │  Info()  → 记录信息级别日志                           │    │
│  │  Warn()  → 记录警告级别日志                           │    │
│  │  Error() → 记录错误级别日志                           │    │
│  └─────────────────────────────────────────────────────┘    │
│                          ↓                                   │
│  ┌─────────────────────────────────────────────────────┐    │
│  │             核心 SQL 追踪                             │    │
│  │  Trace() → 追踪 SQL 执行                              │    │
│  │           ├─ 记录 SQL 语句                             │    │
│  │           ├─ 记录执行参数                             │    │
│  │           ├─ 记录执行时间                             │    │
│  │           ├─ 记录影响行数                             │    │
│  │           └─ 记录调用位置                             │    │
│  └─────────────────────────────────────────────────────┘    │
│                                                               │
│  设计原则:                                                    │
│  1. 接口简洁：只有 5 个方法，易于实现                        │
│  2. 不可变性：LogMode 返回新实例，避免副作用                  │
│  3. 延迟计算：Trace 使用函数参数，按需获取 SQL                │
│  4. 上下文传递：所有方法接收 context.Context                  │
│                                                               │
└─────────────────────────────────────────────────────────────┘

2.3 Config 结构体 (logger.go:53-60)

结构体定义

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
// Config logger config
type Config struct {
	// 慢查询阈值，超过此时间的 SQL 会被记录为慢查询
	SlowThreshold time.Duration

	// 是否启用彩色输出
	Colorful bool

	// 是否忽略 ErrRecordNotFound 错误
	IgnoreRecordNotFoundError bool

	// 是否只记录参数化 SQL（不替换参数值）
	ParameterizedQueries bool

	// 日志级别
	LogLevel LogLevel
}

字段说明

SlowThreshold time.Duration

  • 慢查询阈值
  • 默认值: 200ms
  • 设置为 0 表示禁用慢查询检测

Colorful bool

  • 是否启用彩色输出
  • 使用 ANSI 颜色代码
  • 生产环境建议禁用

IgnoreRecordNotFoundError bool

  • 是否忽略记录未找到错误
  • 默认值: false
  • 设置为 true 时，ErrRecordNotFound 不会触发 Error 日志

ParameterizedQueries bool

  • 是否只记录参数化 SQL
  • 设置为 true 时，不替换参数值
  • 格式: SELECT * FROM users WHERE id = ?
  • 设置为 false 时，会替换参数值
  • 格式: SELECT * FROM users WHERE id = 1

LogLevel LogLevel

  • 日志级别
  • 默认值: Warn
  • 决定记录哪些日志

配置示例

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
import "gorm.io/gorm/logger"

// 基础配置
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold: 200 * time.Millisecond,     // 慢查询阈值
		LogLevel:      logger.Info,                 // 日志级别
		Colorful:      false,                      // 禁用彩色
	}),
})

// 开发环境配置
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             time.Second,     // 1 秒
		LogLevel:                  logger.Info,     // 所有 SQL
		Colorful:                  true,           // 彩色输出
		IgnoreRecordNotFoundError: true,           // 忽略未找到
	}),
})

// 生产环境配置
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:        500 * time.Millisecond,  // 500ms
		LogLevel:             logger.Warn,             // 错误和慢查询
		Colorful:             false,                  // 禁用彩色
		ParameterizedQueries: true,                  // 参数化 SQL
	}),
})

// 只记录参数化 SQL（用于安全审计）
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		LogLevel:             logger.Info,
		ParameterizedQueries: true,  // 不记录参数值
	}),
})

2.4 logger 结构体 (logger.go:122-127)

结构体定义

1
2
3
4
5
6
type logger struct {
	Writer    // 嵌入 Writer 接口
	Config    // 嵌入 Config
	infoStr, warnStr, errStr            string  // 基础日志格式字符串
	traceStr, traceErrStr, traceWarnStr string  // SQL 追踪格式字符串
}

字段说明

Writer

  • 嵌入的 Writer 接口
  • 提供 Printf 方法
  • 默认实现: log.New(os.Stdout, "\r\n", log.LstdFlags)

Config

  • 嵌入的 Config 结构体
  • 包含所有配置选项

infoStr, warnStr, errStr

  • 基础日志格式字符串
  • 包含颜色代码（如果启用）
  • 示例: "\033[32m%s\n\033[0m\033[32m[info] \033[0m"

traceStr, traceErrStr, traceWarnStr

  • SQL 追踪格式字符串
  • 包含时间、行数、SQL 的占位符
  • 示例: "\033[32m%s\n\033[0m\033[33m[%.3fms] \033[34;1m[rows:%v]\033[0m %s"

2.5 Writer 接口 (logger.go:48-51)

接口定义

1
2
3
4
// Writer log writer interface
type Writer interface {
	Printf(string, ...interface{})
}

实现示例

标准库 log.Logger

1
2
3
4
5
6
7
import "log"

// 标准库 log.Logger 实现了 Writer 接口
writer := log.New(os.Stdout, "\r\n", log.LstdFlags)

// 使用
logger.New(writer, logger.Config{})

自定义 Writer

1
2
3
4
5
6
7
8
9
10
11
12
13
// 自定义 Writer：写入文件
type FileWriter struct {
	file *os.File
}

func (w *FileWriter) Printf(format string, args ...interface{}) {
	fmt.Fprintf(w.file, format, args...)
}

// 使用
file, _ := os.OpenFile("gorm.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
writer := &FileWriter{file: file}
logger.New(writer, logger.Config{})

多输出 Writer

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
// 多输出 Writer：同时写入多个目标
type MultiWriter struct {
	writers []Writer
}

func (w *MultiWriter) Printf(format string, args ...interface{}) {
	for _, writer := range w.writers {
		writer.Printf(format, args...)
	}
}

// 使用
multiWriter := &MultiWriter{
	writers: []Writer{
		log.New(os.Stdout, "\r\n", log.LstdFlags),
		log.New(logFile, "\r\n", log.LstdFlags),
	},
}
logger.New(multiWriter, logger.Config{})

2.6 traceRecorder 结构体 (logger.go:200-206)

结构体定义

1
2
3
4
5
6
7
type traceRecorder struct {
	Interface              // 嵌入 Logger 接口
	BeginAt      time.Time // 开始时间
	SQL          string    // SQL 语句
	RowsAffected int64     // 影响行数
	Err          error     // 错误
}

用途说明

SQL 记录

  • 记录所有执行的 SQL
  • 用于调试和审计

单元测试

  • 验证生成的 SQL 是否正确
  • 验证参数是否正确
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
// 使用 Recorder 进行单元测试
func TestUserQuery(t *testing.T) {
	db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
		Logger: logger.Recorder,
	})

	// 执行查询
	var users []User
	db.Find(&users)

	// 获取记录的 SQL
	sql := logger.Recorder.SQL
	fmt.Println(sql)
	// 输出: SELECT * FROM `users`
}

SQL 审计

  • 记录所有 SQL 操作
  • 用于安全审计

三、日志核心实现

3.1 New() 函数 (logger.go:90-120)

完整源码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
// New initialize logger
func New(writer Writer, config Config) Interface {
	var (
		infoStr      = "%s\n[info] "
		warnStr      = "%s\n[warn] "
		errStr       = "%s\n[error] "
		traceStr     = "%s\n[%.3fms] [rows:%v] %s"
		traceWarnStr = "%s %s\n[%.3fms] [rows:%v] %s"
		traceErrStr  = "%s %s\n[%.3fms] [rows:%v] %s"
	)

	if config.Colorful {
		// 彩色格式字符串
		infoStr = Green + "%s\n" + Reset + Green + "[info] " + Reset
		warnStr = BlueBold + "%s\n" + Reset + Magenta + "[warn] " + Reset
		errStr = Magenta + "%s\n" + Reset + Red + "[error] " + Reset
		traceStr = Green + "%s\n" + Reset + Yellow + "[%.3fms] " + BlueBold + "[rows:%v]" + Reset + " %s"
		traceWarnStr = Green + "%s " + Yellow + "%s\n" + Reset + RedBold + "[%.3fms] " + Yellow + "[rows:%v]" + Magenta + " %s" + Reset
		traceErrStr = RedBold + "%s " + MagentaBold + "%s\n" + Reset + Yellow + "[%.3fms] " + BlueBold + "[rows:%v]" + Reset + " %s"
	}

	return &logger{
		Writer:       writer,
		Config:       config,
		infoStr:      infoStr,
		warnStr:      warnStr,
		errStr:       errStr,
		traceStr:     traceStr,
		traceWarnStr: traceWarnStr,
		traceErrStr:  traceErrStr,
	}
}

格式化字符串构建

非彩色模式

1
2
3
4
5
6
infoStr:      "%s\n[info] "
warnStr:      "%s\n[warn] "
errStr:       "%s\n[error] "
traceStr:     "%s\n[%.3fms] [rows:%v] %s"
traceWarnStr: "%s %s\n[%.3fms] [rows:%v] %s"
traceErrStr:  "%s %s\n[%.3fms] [rows:%v] %s"

彩色模式

1
2
3
4
5
6
infoStr:      "\033[32m%s\n\033[0m\033[32m[info] \033[0m"
warnStr:      "\033[34;1m%s\n\033[0m\033[35m[warn] \033[0m"
errStr:       "\033[35m%s\n\033[0m\033[31m[error] \033[0m"
traceStr:     "\033[32m%s\n\033[0m\033[33m[%.3fms] \033[34;1m[rows:%v]\033[0m %s"
traceWarnStr: "\033[32m%s \033[33m%s\n\033[0m\033[31;1m[%.3fms] \033[33m[rows:%v]\033[35m %s\033[0m"
traceErrStr:  "\033[31;1m%s \033[35;1m%s\n\033[0m\033[33m[%.3fms] \033[34;1m[rows:%v]\033[0m %s"

ANSI 颜色代码

代码 颜色 用途
\033[32m 绿色 Info 级别
\033[34;1m 蓝色加粗 Warn 级别前缀
\033[35m 洋红色 Warn 消息
\033[31m 红色 Error 级别
\033[33m 黄色 执行时间
\033[0m 重置 重置颜色

3.2 LogMode() 方法 (logger.go:129-134)

完整源码

1
2
3
4
5
6
// LogMode log mode
func (l *logger) LogMode(level LogLevel) Interface {
	newlogger := *l           // 创建副本
	newlogger.LogLevel = level // 修改日志级别
	return &newlogger          // 返回新实例
}

级别切换机制

1
2
3
4
5
6
7
8
9
10
11
12
13
14
LogMode() 调用流程:

db.Logger.LogMode(logger.Info)
    │
    ├─► 1. 创建 logger 副本
    │   └─ newlogger := *l
    │       └─ 复制所有字段 (Writer, Config, 格式字符串)
    │
    ├─► 2. 修改日志级别
    │   └─ newlogger.LogLevel = level
    │
    └─► 3. 返回新实例
        └─ return &newlogger
            └─ 原实例保持不变

不可变性优势

  • 原实例不受影响
  • 线程安全
  • 支持链式调用

3.3 Trace() 方法 (logger.go:157-190)

完整源码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
// Trace print sql message
//
//nolint:cyclop
func (l *logger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	// === 1. 检查日志级别 ===
	if l.LogLevel <= Silent {
		return  // Silent 模式，直接返回
	}

	// === 2. 计算执行耗时 ===
	elapsed := time.Since(begin)

	// === 3. 根据条件决定记录 ===
	switch {
	case err != nil && l.LogLevel >= Error && (!errors.Is(err, ErrRecordNotFound) || !l.IgnoreRecordNotFoundError):
		// === 有错误且日志级别 >= Error ===
		sql, rows := fc()  // 延迟获取 SQL 和行数
		if rows == -1 {
			l.Printf(l.traceErrStr, utils.FileWithLineNum(), err, float64(elapsed.Nanoseconds())/1e6, "-", sql)
		} else {
			l.Printf(l.traceErrStr, utils.FileWithLineNum(), err, float64(elapsed.Nanoseconds())/1e6, rows, sql)
		}

	case elapsed > l.SlowThreshold && l.SlowThreshold != 0 && l.LogLevel >= Warn:
		// === 慢查询 ===
		sql, rows := fc()  // 延迟获取 SQL 和行数
		slowLog := fmt.Sprintf("SLOW SQL >= %v", l.SlowThreshold)
		if rows == -1 {
			l.Printf(l.traceWarnStr, utils.FileWithLineNum(), slowLog, float64(elapsed.Nanoseconds())/1e6, "-", sql)
		} else {
			l.Printf(l.traceWarnStr, utils.FileWithLineNum(), slowLog, float64(elapsed.Nanoseconds())/1e6, rows, sql)
		}

	case l.LogLevel == Info:
		// === Info 级别，记录所有 SQL ===
		sql, rows := fc()  // 延迟获取 SQL 和行数
		if rows == -1 {
			l.Printf(l.traceStr, utils.FileWithLineNum(), float64(elapsed.Nanoseconds())/1e6, "-", sql)
		} else {
			l.Printf(l.traceStr, utils.FileWithLineNum(), float64(elapsed.Nanoseconds())/1e6, rows, sql)
		}
	}
	// === 其他情况不记录 ===
}

执行流程详解

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
Trace() 完整执行流程:

Trace(ctx, begin, fc, err)
    │
    ├─► 1. 检查日志级别
    │   └─ if l.LogLevel <= Silent
    │       └─ return (不记录)
    │
    ├─► 2. 计算耗时
    │   └─ elapsed := time.Since(begin)
    │
    ├─► 3. 判断记录条件
    │   │
    │   ├─► 3a. 有错误?
    │   │   └─ err != nil && l.LogLevel >= Error
    │   │       └─ 是否忽略 ErrRecordNotFound?
    │   │           └─ 调用 fc() 获取 SQL 和行数
    │   │           └─ Printf(traceErrStr, ...)
    │   │
    │   ├─► 3b. 是慢查询?
    │   │   └─ elapsed > l.SlowThreshold && l.SlowThreshold != 0
    │   │       └─ l.LogLevel >= Warn
    │   │           └─ 调用 fc() 获取 SQL 和行数
    │   │           └─ Printf(traceWarnStr, ...)
    │   │
    │   └─► 3c. Info 级别?
    │       └─ l.LogLevel == Info
    │           └─ 调用 fc() 获取 SQL 和行数
    │           └─ Printf(traceStr, ...)
    │
    └─► 4. 其他情况
        └─ 不记录任何日志

决策逻辑

优先级

  1. 错误日志 (最高优先级)
  2. 慢查询日志
  3. Info 日志 (最低优先级)

条件检查顺序

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
1. err != nil?
   Yes AND l.LogLevel >= Error?
     Yes AND (err != ErrRecordNotFound OR !l.IgnoreRecordNotFoundError)?
       Yes → 记录错误日志
       No  → 继续

2. elapsed > l.SlowThreshold?
   Yes AND l.SlowThreshold != 0?
     Yes AND l.LogLevel >= Warn?
       Yes → 记录慢查询日志
       No  → 继续

3. l.LogLevel == Info?
   Yes → 记录所有 SQL
   No  → 不记录

二、核心原理

2.1 关键概念

概念 1: Logger 接口

定义: Logger 是日志系统的核心接口。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
type Interface interface {
    // 设置日志级别，返回新的 Logger 实例
    LogMode(LogLevel) Interface

    // 记录信息级别日志
    Info(ctx context.Context, msg string, data ...interface{})

    // 记录警告级别日志
    Warn(ctx context.Context, msg string, data ...interface{})

    // 记录错误级别日志
    Error(ctx context.Context, msg string, data ...interface{})

    // 追踪 SQL 执行
    Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error)
}

// ParamsFilter 接口: 过滤敏感参数
type ParamsFilter interface {
    ParamsFilter(ctx context.Context, sql string, params ...interface{}) (string, []interface{})
}

接口设计原理:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
Logger 接口设计:

┌─────────────────────────────────────────────────────────────┐
│                     Logger 接口                               │
├─────────────────────────────────────────────────────────────┤
│  配置方法                                                   │
│  └─ LogMode(LogLevel) → 设置日志级别                       │
├─────────────────────────────────────────────────────────────┤
│  基础日志方法                                               │
│  ├─ Info()  → 记录信息级别日志                               │
│  ├─ Warn()  → 记录警告级别日志                               │
│  └─ Error() → 记录错误级别日志                               │
├─────────────────────────────────────────────────────────────┤
│  核心 SQL 追踪                                              │
│  └─ Trace() → 追踪 SQL 执行                                 │
│              ├─ 记录 SQL 语句                                │
│              ├─ 记录执行参数                                 │
│              ├─ 记录执行时间                                 │
│              ├─ 记录影响行数                                 │
│              └─ 记录调用位置                                 │
└─────────────────────────────────────────────────────────────┘

概念 2: LogLevel 枚举

定义: LogLevel 定义了四个日志级别。

1
2
3
4
5
6
7
8
type LogLevel int

const (
    Silent LogLevel = iota + 1  // 1: 静默模式
    Error                        // 2: 只记录错误
    Warn                         // 3: 记录错误和警告
    Info                         // 4: 记录所有信息
)

日志级别对比:

级别 值 记录内容 使用场景 性能影响
Silent 1 不记录任何日志 生产环境、性能敏感 无
Error 2 只记录 SQL 错误 生产环境 最小
Warn 3 记录错误和慢查询 生产环境、监控 小
Info 4 记录所有 SQL 开发环境、调试 较大

日志级别决策树:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
Trace 方法执行流程:
    │
    ├─► 1. 检查日志级别
    │       └─ if l.LogLevel == Silent
    │           └─ 直接返回，不记录任何日志
    │
    ├─► 2. 检查是否有错误
    │       └─ if err != nil && l.LogLevel >= Error
    │           └─ 调用 Error() 记录错误
    │
    ├─► 3. 检查是否是慢查询
    │       └─ if elapsed > l.SlowThreshold && l.SlowThreshold != 0
    │           └─ 调用 Warn() 记录慢查询
    │
    ├─► 4. 检查是否是 Info 级别
    │       └─ if l.LogLevel >= Info
    │           └─ 调用 Info() 记录所有 SQL
    │
    └─► 5. 否则不记录

使用示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
// 开发环境: 详细日志
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})

// 日志输出:
// [2024-01-01 10:00:00] [3.45ms] SELECT * FROM users WHERE age > 18
// [2024-01-01 10:00:01] [1.23ms] INSERT INTO users (name) VALUES ('John')

// 生产环境: 只记录错误
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Error),
})

// 日志输出:
// [2024-01-01 10:00:00] [5.67ms] ERROR: SQL: SELECT * FROM non_existent_table
// Error: Table 'db.non_existent_table' doesn't exist

// 慢查询检测
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Warn),
}).Set("gorm:threshold", 200 * time.Millisecond)

// 日志输出:
// [2024-01-01 10:00:00] [250.45ms] SLOW SQL >= 200ms
// [200.45ms] [rows:1000] SELECT * FROM large_table JOIN another_table

概念 3: Trace 方法详解

定义: Trace 是记录 SQL 执行的核心方法。

方法签名:

1
func (l *logger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error)

参数说明:

参数 类型 说明 示例
ctx context.Context 上下文，用于传递请求信息 request.Context()
begin time.Time SQL 执行开始时间 time.Now()
fc func() (string, int64) 延迟计算函数，返回 SQL 和行数 func() { return sql, rows }
err error SQL 执行错误 sql.ErrNoRows

实现流程:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
func (l logger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    // === 1. 计算执行耗时 ===
    elapsed := time.Since(begin)

    // === 2. 延迟获取 SQL 和行数 ===
    sql, rows := fc()
    if sql == "" {
        sql = "[empty SQL]"
    }

    // === 3. 过滤敏感参数 ===
    fields := l.fields
    if l.colorful && l.InfoColor != nil {
        fields = l.InfoColor
    }

    // === 4. 根据条件记录日志 ===
    switch {
    case err != nil && l.LogLevel >= Error:
        // 有错误且日志级别 >= Error
        if l.IgnoreRecordNotFoundError && errors.Is(err, gorm.ErrRecordNotFound) {
            return
        }
        l.log(ctx, ErrorLevel, err, elapsed, sql, rows, fields...)

    case elapsed > l.SlowThreshold && l.SlowThreshold != 0 && l.LogLevel > Silent:
        // 超过慢查询阈值
        l.log(ctx, WarnLevel, err, elapsed, sql, rows, fields...)

    case l.LogLevel >= Info:
        // Info 级别，记录所有 SQL
        l.log(ctx, InfoLevel, err, elapsed, sql, rows, fields...)
    }

    return
}

延迟计算的优势:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
// 不使用延迟计算 (性能差)
func Trace(ctx context.Context, begin time.Time, sql string, rows int64, err error) {
    elapsed := time.Since(begin)
    // 无论日志级别如何，都已经获取了 sql 和 rows
    // 这可能涉及不必要的字符串格式化
}

// 使用延迟计算 (性能好)
func Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    elapsed := time.Since(begin)
    // 只在需要记录日志时才调用 fc()
    if l.LogLevel >= Info {
        sql, rows := fc()  // 延迟计算
        l.log(sql, rows)
    }
}

概念 4: SQL 解释机制

定义: SQL 解释将参数化 SQL 转换为可读的完整 SQL。

原始 SQL:

1
2
3
4
5
-- 参数化 SQL (prepared statement)
SELECT * FROM users WHERE age > ? AND name = ?

-- 参数值
[18, "John"]

解释后的 SQL:

1
2
-- 可读 SQL (explained SQL)
SELECT * FROM users WHERE age > 18 AND name = 'John'

实现原理:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
// SQL 解释器
func ExplainSQL(sql string, args ...interface{}) string {
    // === 1. 参数计数 ===
    paramCount := strings.Count(sql, "?")
    if paramCount != len(args) {
        return sql + " [参数数量不匹配]"
    }

    // === 2. 逐个替换参数 ===
    result := sql
    for _, arg := range args {
        // 查找第一个 "?"
        idx := strings.Index(result, "?")
        if idx == -1 {
            break
        }

        // 格式化参数
        var formatted string
        switch v := arg.(type) {
        case string:
            formatted = fmt.Sprintf("'%v'", escapeString(v))
        case time.Time:
            formatted = fmt.Sprintf("'%v'", v.Format("2006-01-02 15:04:05"))
        case nil:
            formatted = "NULL"
        default:
            formatted = fmt.Sprintf("%v", v)
        }

        // 替换 "?"
        result = result[:idx] + formatted + result[idx+1:]
    }

    return result
}

// 字符串转义
func escapeString(s string) string {
    s = strings.ReplaceAll(s, "'", "''")
    s = strings.ReplaceAll(s, "\\", "\\\\")
    return s
}

Dialector.Explain 方法:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
// Dialector 接口
type Dialector interface {
    Explain(sql string, vars ...interface{}) string
}

// MySQL 实现
func (d MySQL) Explain(sql string, vars ...interface{}) string {
    // MySQL 特定的参数占位符
    return d.ExplainSQL(sql, vars...)
}

// PostgreSQL 实现
func (d Postgres) Explain(sql string, vars ...interface{}) string {
    // PostgreSQL 使用 $1, $2 作为占位符
    return d.ExplainSQL(sql, vars...)
}

// SQLite 实现
func (d SQLite) Explain(sql string, vars ...interface{}) string {
    // SQLite 使用 ? 或 $1, $2 作为占位符
    return d.ExplainSQL(sql, vars...)
}

敏感参数过滤:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
// ParamsFilter 接口
type ParamsFilter interface {
    ParamsFilter(ctx context.Context, sql string, params ...interface{}) (string, []interface{})
}

// 实现: 过滤密码字段
type SensitiveParamsFilter struct{}

func (f SensitiveParamsFilter) ParamsFilter(ctx context.Context, sql string, params ...interface{}) (string, []interface{}) {
    // 检测是否是 INSERT/UPDATE 语句
    if strings.Contains(strings.ToUpper(sql), "INSERT") || strings.Contains(strings.ToUpper(sql), "UPDATE") {
        // 过滤密码参数
        for i, param := range params {
            if s, ok := param.(string); ok && strings.Contains(strings.ToLower(s), "password") {
                params[i] = "***FILTERED***"
            }
        }
    }
    return sql, params
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})
db.Use(&SensitiveParamsFilter{})

// 输出:
// INSERT INTO users (name, password) VALUES ('John', '***FILTERED***')

概念 5: 调用栈追踪

定义: 调用栈追踪记录 SQL 执行的代码位置。

实现原理:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
// FileWithLineNum 获取调用文件和行号
func FileWithLineNum() string {
    // === 遍历调用栈 ===
    for i := 2; i < 15; i++ {
        _, file, line, ok := runtime.Caller(i)
        if !ok {
            break
        }

        // === 过滤 GORM 内部调用 ===
        // 过滤条件:
        // 1. 不包含 "/gorm/" 路径
        // 2. 不是测试文件
        // 3. 不是 runtime 主函数
        if strings.Contains(file, "/gorm/") {
            continue
        }

        // === 返回第一个非 GORM 调用 ===
        return fmt.Sprintf("%v:%v", file, line)
    }

    return ""
}

调用栈示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
// 用户代码
func main() {
    db.Find(&users)  // ← 记录 main.go:45
}

// GORM 内部调用链:
// main.go:45 (main.main)
//   ↓
// gorm.go:123 (DB.Find)
//   ↓
// finisher_api.go:234 (DB.Find)
//   ↓
// callbacks.go:56 (processor.Execute)
//   ↓
// query.go:78 (Query)
//   ↓
// [记录] main.go:45 (第一个非 GORM 调用)

配置调用栈追踪:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
// 启用调用栈追踪
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})

// 日志输出:
// [2024-01-01 10:00:00] [3.45ms] SELECT * FROM users [main.go:45]

// 禁用调用栈追踪 (提高性能)
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info).SkipCallerLookup(true),
})

// 日志输出:
// [2024-01-01 10:00:00] [3.45ms] SELECT * FROM users

2.2 理论基础

理论 1: 结构化日志

定义: 结构化日志使用机器可读的格式（通常是 JSON）记录日志。

传统日志 vs 结构化日志:

1
2
3
4
5
6
7
8
9
10
11
12
13
// 传统日志 (文本格式)
[2024-01-01 10:00:00] [3.45ms] SELECT * FROM users WHERE age > 18 [main.go:45]

// 结构化日志 (JSON 格式)
{
  "timestamp": "2024-01-01T10:00:00Z",
  "level": "info",
  "duration_ms": 3.45,
  "sql": "SELECT * FROM users WHERE age > 18",
  "rows": 10,
  "file": "main.go:45",
  "function": "main.main"
}

结构化日志的优势:

优势 说明 示例
机器可读 便于日志系统解析和查询 jq ‘.duration_ms > 10’
结构化 字段含义明确，便于过滤 level=”error”
可扩展 容易添加新字段 添加 request_id 字段
可聚合 便于日志聚合分析 统计平均响应时间

实现结构化 Logger:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
// 结构化日志模型
type LogEntry struct {
    Timestamp time.Time `json:"timestamp"`
    Level     string    `json:"level"`
    Duration  float64   `json:"duration_ms"`
    SQL       string    `json:"sql"`
    Rows      int64     `json:"rows,omitempty"`
    File      string    `json:"file,omitempty"`
    Error     string    `json:"error,omitempty"`
}

// JSON Logger
type JSONLogger struct {
    logger.Interface
    writer io.Writer
}

func (l *JSONLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    elapsed := time.Since(begin)
    sql, rows := fc()

    entry := LogEntry{
        Timestamp: time.Now(),
        Level:     "info",
        Duration:  float64(elapsed.Milliseconds()),
        SQL:       sql,
        Rows:      rows,
    }

    if err != nil {
        entry.Level = "error"
        entry.Error = err.Error()
    }

    // JSON 编码并输出
    json.NewEncoder(l.writer).Encode(entry)
    return
}

理论 2: 慢查询检测

定义: 慢查询检测记录执行时间超过阈值的 SQL。

慢查询阈值配置:

1
2
3
4
5
6
7
8
9
10
11
12
13
// 方式 1: 全局配置
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Warn),
    SlowThreshold: 200 * time.Millisecond,  // 200ms
})

// 方式 2: 动态配置
db = db.Session(&gorm.Session{
    Logger: logger.Default.LogMode(logger.Warn).SlowThreshold(200 * time.Millisecond),
})

// 方式 3: 全局变量设置
logger.Default.SlowThreshold = 200 * time.Millisecond

慢查询日志输出:

1
2
3
// 慢查询输出格式
[2024-01-01 10:00:00] [250.45ms] SLOW SQL >= 200ms
[250.45ms] [rows:1000] SELECT * FROM large_table JOIN another_table ON large_table.id = another_table.table_id WHERE large_table.created_at > '2024-01-01'

慢查询分析策略:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
慢查询优化流程:

1. 识别慢查询
   ├─ 设置合理阈值 (如 200ms)
   ├─ 记录慢查询日志
   └─ 分析日志找出高频慢查询

2. 分析执行计划
   ├─ 使用 EXPLAIN 分析 SQL
   ├─ 检查是否使用索引
   └─ 检查扫描行数

3. 优化 SQL
   ├─ 添加缺失的索引
   ├─ 重写复杂查询
   └─ 使用预加载 (Preload) 代替循环查询

4. 验证优化效果
   ├─ 对比优化前后执行时间
   ├─ 检查是否还有其他慢查询
   └─ 持续监控

理论 3: 日志聚合与分析

定义: 日志聚是将分散的日志收集到中心化的日志系统。

常用日志系统:

日志系统 特点 适用场景
ELK Stack Elasticsearch + Logstash + Kibana 大规模日志分析
Grafana Loki 轻量级、成本效益高 Kubernetes 环境
Fluentd 统一日志层 多语言环境
Sentry 错误追踪 错误监控

集成示例: Fluentd

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
// Fluentd Logger
type FluentdLogger struct {
    logger.Interface
    tag   string
    host  string
    port  int
}

func (l *FluentdLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    elapsed := time.Since(begin)
    sql, rows := fc()

    // 发送到 Fluentd
    log := map[string]interface{}{
        "timestamp": time.Now(),
        "sql":       sql,
        "duration":  elapsed.Milliseconds(),
        "rows":      rows,
        "error":     err,
    }

    // 使用 fluentd-go 发送日志
    // fluentd.Post(l.tag, log)

    return
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: &FluentdLogger{
        tag:  "gorm.sql",
        host: "fluentd",
        port: 24224,
    },
})

2.3 学习方法

方法 1: 实验法

实验 1: 观察不同日志级别的输出

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
// Silent: 无日志
db.LogMode(logger.Silent).Find(&users)
// (无输出)

// Error: 只记录错误
db.LogMode(logger.Error).Find(&users)
// (无输出，假设查询成功)

// Warn: 记录慢查询
db.Set("gorm:threshold", 1*time.Millisecond).LogMode(logger.Warn).Find(&users)
// 如果查询时间 > 1ms，会记录

// Info: 记录所有 SQL
db.LogMode(logger.Info).Find(&users)
// [2024-01-01 10:00:00] [3.45ms] SELECT * FROM users

实验 2: 测试调用栈追踪

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
func GetUser(id uint) (User, error) {
    var user User
    // 这里会记录当前文件和行号
    err := db.First(&user, id).Error
    return user, err
}

func main() {
    GetUser(1)
}

// 日志输出:
// [2024-01-01 10:00:00] [2.34ms] SELECT * FROM users WHERE id = 1 AND `users`.`deleted_at` IS NULL ORDER BY `users`.`id` LIMIT 1 [main.go:15]
//                                                                        ↑
//                                                                    调用位置

方法 2: 对比法

对比不同 Logger 实现:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
// 默认 Logger (控制台输出)
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: logger.Default.LogMode(logger.Info),
})

// 自定义 Logger (JSON 输出到文件)
type CustomLogger struct {
    logger.Interface
    file *os.File
}

func (l *CustomLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
    // 记录 JSON 格式到文件
    // ...
}

db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
    Logger: &CustomLogger{
        file: logFile,
    },
})

2.4 实施策略

策略 1: 分层学习

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
第 1 层: 理解基本概念 (Day 1)
  目标: 理解日志的基本概念
  内容:
    - Logger 接口
    - 日志级别
    - Trace 方法
  验证:
    - 能配置日志级别
    - 能使用默认 Logger
    - 能查看日志输出

第 2 层: 掌握高级日志 (Day 2)
  目标: 理解日志的内部实现
  内容:
    - SQL 解释机制
    - 慢查询检测
    - 调用栈追踪
  验证:
    - 能理解 Trace 实现
    - 能配置慢查询阈值
    - 能追踪调用位置

第 3 层: 应用扩展 (Day 3)
  目标: 掌握自定义 Logger 实现
  内容:
    - 自定义 Logger
    - 集成日志库
    - 日志聚合分析
  验证:
    - 能实现自定义 Logger
    - 能集成第三方日志库
    - 能设计日志策略

策略 2: 场景驱动

场景序列:

  1. 开发调试

    • 使用 Info 级别
    • 记录所有 SQL
    • 启用调用栈追踪

  2. 性能分析

    • 配置慢查询阈值
    • 记录执行时间
    • 分析慢查询

  3. 生产监控

    • 使用 Error 级别
    • 集成日志系统
    • 设置告警规则

六、实战代码示例

6.1 基础配置示例

开发环境配置

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
package main

import (
	"gorm.io/gorm"
	"gorm.io/driver/mysql"
	"gorm.io/gorm/logger"
	"log"
	"os"
)

func main() {
	dsn := "user:password@tcp(127.0.0.1:3306)/dbname?charset=utf8mb4&parseTime=True&loc=Local"

	// 开发环境配置
	db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{
		Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
			SlowThreshold:             time.Second,      // 1 秒
			LogLevel:                  logger.Info,       // 记录所有 SQL
			Colorful:                  true,            // 彩色输出
			IgnoreRecordNotFoundError: true,            // 忽略未找到
		}),
	})
	if err != nil {
		panic("连接数据库失败")
	}

	// 使用数据库
	var users []User
	db.Find(&users)
	// 输出: [32mmain.go:45
[0m [32m[info] [0m [32m2024-01-01 10:00:00
[0m [33m[3.45ms] [34;1m[rows:10][0m SELECT * FROM `users`
}

生产环境配置

1
2
3
4
5
6
7
8
9
10
// 生产环境配置
db, err := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             500 * time.Millisecond,  // 500ms
		LogLevel:                  logger.Warn,              // 错误和慢查询
		Colorful:                  false,                   // 禁用彩色
		ParameterizedQueries:      true,                   // 参数化 SQL
		IgnoreRecordNotFoundError: true,                   // 忽略未找到
	}),
})

测试环境配置

1
2
3
4
5
6
7
8
9
// 测试环境配置
db, err := gorm.Open(mysql.Open("test.db"), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             100 * time.Millisecond,  // 100ms
		LogLevel:                  logger.Info,              // 详细日志
		Colorful:                  false,                   // 禁用彩色
		IgnoreRecordNotFoundError: false,                  // 不忽略错误
	}),
})

6.2 自定义 Logger 示例

文件 Logger

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
// 文件 Logger：将日志写入文件
type FileLogger struct {
	logger.Interface
	file *os.File
}

func NewFileLogger(filename string) logger.Interface {
	file, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
	if err != nil {
		panic(err)
	}

	return &FileLogger{
		Interface: logger.Default,
		file:      file,
	}
}

func (l *FileLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	// 写入文件
	logEntry := fmt.Sprintf("[%s] [%.3fms] [rows:%v] %s\n",
		time.Now().Format("2006-01-02 15:04:05"),
		float64(elapsed.Nanoseconds())/1e6,
		rows,
		sql,
	)
	l.file.WriteString(logEntry)

	return nil
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: NewFileLogger("gorm.log"),
})

JSON Logger

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
// JSON Logger：输出 JSON 格式日志
type JSONLogger struct {
	logger.Interface
	writer io.Writer
}

type LogEntry struct {
	Timestamp string  `json:"timestamp"`
	Level     string  `json:"level"`
	Duration  float64 `json:"duration_ms"`
	SQL       string  `json:"sql"`
	Rows      int64   `json:"rows,omitempty"`
	Error     string  `json:"error,omitempty"`
	File      string  `json:"file,omitempty"`
}

func NewJSONLogger(writer io.Writer) logger.Interface {
	return &JSONLogger{
		Interface: logger.Discard, // 不使用默认 logger
		writer:    writer,
	}
}

func (l *JSONLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	entry := LogEntry{
		Timestamp: time.Now().Format(time.RFC3339),
		Level:     "info",
		Duration:  float64(elapsed.Nanoseconds()) / 1e6,
		SQL:       sql,
		Rows:      rows,
	}

	if err != nil {
		entry.Level = "error"
		entry.Error = err.Error()
	}

	// JSON 编码并输出
	json.NewEncoder(l.writer).Encode(entry)
	return nil
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: NewJSONLogger(os.Stdout),
})

结构化 Logger（集成 zap）

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
import (
	"go.uber.org/zap"
	"go.uber.org/zap/zapcore"
	"gorm.io/gorm/logger"
)

// ZapLogger：集成 uber-go/zap
type ZapLogger struct {
	logger.Interface
	logger *zap.Logger
	sugar  *zap.SugaredLogger
}

func NewZapLogger(logLevel zapcore.Level) logger.Interface {
	zapLogger, _ := zap.NewProduction()
	if logLevel == zapcore.DebugLevel {
		zapLogger, _ = zap.NewDevelopment()
	}

	return &ZapLogger{
		Interface: logger.Discard,
		logger:    zapLogger,
		sugar:     zapLogger.Sugar(),
	}
}

func (l *ZapLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	if err != nil {
		l.sugar.Errorw("SQL Error",
			"duration", elapsed,
			"sql", sql,
			"rows", rows,
			"error", err,
		)
	} else if elapsed > 200*time.Millisecond {
		l.sugar.Warnw("Slow SQL",
			"duration", elapsed,
			"sql", sql,
			"rows", rows,
		)
	} else {
		l.sugar.Debugw("SQL",
			"duration", elapsed,
			"sql", sql,
			"rows", rows,
		)
	}

	return nil
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: NewZapLogger(zapcore.InfoLevel),
})

6.3 慢查询检测示例

基础配置

1
2
3
4
5
6
7
8
9
10
11
// 配置慢查询阈值
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold: 200 * time.Millisecond,  // 200ms
		LogLevel:      logger.Warn,              // 记录慢查询
	}),
})

// 执行查询
var users []User
db.Find(&users)  // 如果耗时 > 200ms，会记录为慢查询

动态配置

1
2
3
4
5
6
7
// 动态设置慢查询阈值
db = db.Session(&gorm.Session{
	Logger: logger.Default.LogMode(logger.Warn).SlowThreshold(200 * time.Millisecond),
})

// 或者直接修改
logger.Default.SlowThreshold = 200 * time.Millisecond

告警集成

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
// 慢查询告警 Logger
type AlertLogger struct {
	logger.Interface
	webhookURL string
}

func (l *AlertLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	// 检查是否是慢查询
	if elapsed > 200*time.Millisecond {
		// 发送告警
		alert := map[string]interface{}{
			"timestamp": time.Now(),
			"duration":  elapsed.Milliseconds(),
			"sql":       sql,
			"rows":      rows,
		}

		// 发送到 webhook
		http.Post(l.webhookURL, "application/json", jsonBody(alert))
	}

	// 调用原始 logger
	return l.Interface.Trace(ctx, begin, fc, err)
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: &AlertLogger{
		Interface:  logger.Default.LogMode(logger.Warn),
		webhookURL: "https://hooks.slack.com/...",
	},
})

6.4 日志集成示例

集成 logrus

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
import (
	"github.com/sirupsen/logrus"
	"gorm.io/gorm/logger"
)

// LogrusLogger
type LogrusLogger struct {
	logger.Interface
	logger *logrus.Logger
}

func NewLogrusLogger(logrusLogger *logrus.Logger) logger.Interface {
	return &LogrusLogger{
		Interface: logger.Discard,
		logger:    logrusLogger,
	}
}

func (l *LogrusLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	fields := logrus.Fields{
		"duration": elapsed,
		"sql":      sql,
		"rows":     rows,
	}

	if err != nil {
		l.logger.WithFields(fields).WithError(err).Error("SQL Error")
	} else if elapsed > 200*time.Millisecond {
		l.logger.WithFields(fields).Warn("Slow SQL")
	} else {
		l.logger.WithFields(fields).Debug("SQL")
	}

	return nil
}

// 使用
logrusLogger := logrus.New()
logrusLogger.SetFormatter(&logrus.JSONFormatter{})

db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: NewLogrusLogger(logrusLogger),
})

集成 fluentd

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
// FluentdLogger：发送日志到 fluentd
type FluentdLogger struct {
	logger.Interface
	tag  string
	host string
	port int
}

func (l *FluentdLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	logData := map[string]interface{}{
		"timestamp": time.Now(),
		"duration":  elapsed.Milliseconds(),
		"sql":       sql,
		"rows":      rows,
	}

	if err != nil {
		logData["level"] = "error"
		logData["error"] = err.Error()
	}

	// 发送到 fluentd (使用 fluentd-go)
	// fluentd.Post(l.tag, logData)

	return nil
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: &FluentdLogger{
		Interface: logger.Default.LogMode(logger.Info),
		tag:       "gorm.sql",
		host:      "fluentd",
		port:      24224,
	},
})

6.5 Recorder 使用示例

SQL 记录

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
// 使用 Recorder 记录 SQL
recorder := logger.Recorder.New()
db, _ := gorm.Open(sqlite.Open("test.db"), &gorm.Config{
	Logger: recorder,
})

// 执行查询
var user User
db.First(&user, 1)

// 获取记录的 SQL
fmt.Println("SQL:", recorder.SQL)
fmt.Println("Rows:", recorder.RowsAffected)
fmt.Println("Error:", recorder.Err)
fmt.Println("Duration:", time.Since(recorder.BeginAt))

单元测试

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
func TestUserQuery(t *testing.T) {
	// 使用 Recorder
	recorder := logger.Recorder.New()
	db, _ := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{
		Logger: recorder,
	})

	// 自动迁移
	db.AutoMigrate(&User{})

	// 执行查询
	var user User
	db.First(&user, 1)

	// 验证 SQL
	assert.Equal(t, "SELECT * FROM `users` WHERE `users`.`id` = ? ORDER BY `users`.`id` LIMIT 1", recorder.SQL)
	assert.Equal(t, int64(1), recorder.RowsAffected)
	assert.Nil(t, recorder.Err)
}

SQL 审计

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
// SQL 审计 Logger
type AuditLogger struct {
	logger.Interface
	auditLog []SQLAudit
}

type SQLAudit struct {
	Timestamp time.Time
	SQL       string
	Rows      int64
	Duration  time.Duration
	User      string // 来自 context
}

func (l *AuditLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	// 记录审计日志
	audit := SQLAudit{
		Timestamp: time.Now(),
		SQL:       sql,
		Rows:      rows,
		Duration:  elapsed,
	}
	l.auditLog = append(l.auditLog, audit)

	// 调用原始 logger
	return l.Interface.Trace(ctx, begin, fc, err)
}

func (l *AuditLogger) GetAuditLog() []SQLAudit {
	return l.auditLog
}

// 使用
auditLogger := &AuditLogger{
	Interface: logger.Default.LogMode(logger.Silent),
}

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

// 执行操作
db.Create(&User{Name: "John"})
db.Find(&users)

// 获取审计日志
audits := auditLogger.GetAuditLog()
for _, audit := range audits {
	fmt.Printf("SQL: %s, Duration: %v\n", audit.SQL, audit.Duration)
}

七、可视化流程图

7.1 Trace() 完整执行流程图

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
Trace(ctx, begin, fc, err)
        │
        ▼
┌───────────────────────────┐
│ 检查日志级别               │
│ LogLevel <= Silent?       │
└──────┬────────────────────┘
       │
       ├─ Yes → return (不记录)
       │
       ▼ No
┌───────────────────────────┐
│ 计算执行耗时               │
│ elapsed = time.Since      │
└──────┬────────────────────┘
       │
       ▼
┌───────────────────────────┐
│ 判断记录条件               │
└──────┬────────────────────┘
       │
       ├─► err != nil && LogLevel >= Error?
       │   └─ Yes ──────────────┐
       │                       │
       │                       ▼
       │              ┌──────────────────────┐
       │              │ 调用 fc() 获取 SQL    │
       │              │ Printf(traceErrStr)   │
       │              └──────────────────────┘
       │
       ├─► elapsed > SlowThreshold && SlowThreshold != 0 && LogLevel >= Warn?
       │   └─ Yes ──────────────┐
       │                       │
       │                       ▼
       │              ┌──────────────────────┐
       │              │ 调用 fc() 获取 SQL    │
       │              │ slowLog = "SLOW SQL" │
       │              │ Printf(traceWarnStr)  │
       │              └──────────────────────┘
       │
       └─► LogLevel == Info?
           └─ Yes ──────────────┐
                                 │
                                 ▼
                        ┌──────────────────────┐
                        │ 调用 fc() 获取 SQL    │
                        │ Printf(traceStr)      │
                        └──────────────────────┘

7.2 日志级别决策树

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
SQL 执行完成
    │
    ├─► err != nil?
    │   ├─ Yes → LogLevel >= Error?
    │   │   ├─ Yes → (err != ErrRecordNotFound OR !IgnoreRecordNotFound)?
    │   │   │   ├─ Yes → 记录错误日志
    │   │   │   └─ No  → 继续
    │   │   └─ No  → 继续
    │   │
    ├─► elapsed > SlowThreshold && SlowThreshold != 0?
    │   ├─ Yes → LogLevel >= Warn?
    │   │   ├─ Yes → 记录慢查询日志
    │   │   └─ No  → 继续
    │   │
    └─► LogLevel == Info?
        ├─ Yes → 记录所有 SQL
        └─ No  → 不记录

7.3 日志系统架构图

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
GORM 日志系统架构:

┌──────────────────────────────────────────────────────────┐
│                        用户代码                             │
│  db.Find(&users)                                         │
└───────────────────────┬──────────────────────────────────┘
                        │
                        ▼
┌──────────────────────────────────────────────────────────┐
│                    GORM Core                              │
│  ┌────────────────────────────────────────────────────┐ │
│  │  callback.Execute()                                 │ │
│  │    │                                                │ │
│  │    ▼                                                │ │
│  │  ┌─────────────────────────────────────────────┐  │ │
│  │  │  开始计时                                    │  │ │
│  │  │  begin := time.Now()                        │  │ │
│  │  │  defer logger.Trace(ctx, begin, fc, err)   │  │ │
│  │  └─────────────────────────────────────────────┘  │ │
│  │                                                     │ │
│  │  ┌─────────────────────────────────────────────┐  │ │
│  │  │  执行 SQL                                   │  │ │
│  │  │  result := db.Exec(...)                      │  │ │
│  │  └─────────────────────────────────────────────┘  │ │
│  └────────────────────────────────────────────────────┘ │
└───────────────────────┬──────────────────────────────────┘
                        │
                        ▼
┌──────────────────────────────────────────────────────────┐
│                  logger.Trace()                           │
│  ┌────────────────────────────────────────────────────┐ │
│  │  1. 计算耗时                                      │ │
│  │     elapsed := time.Since(begin)                 │ │
│  │                                                    │ │
│  │  2. 延迟获取 SQL                                  │ │
│  │     sql, rows := fc()                            │ │
│  │                                                    │ │
│  │  3. 决定是否记录                                  │ │
│  │     ├─ 错误? → Error()                            │ │
│  │     ├─ 慢查询? → Warn()                           │ │
│  │     └─ Info? → Info()                             │ │
│  └────────────────────────────────────────────────────┘ │
└───────────────────────┬──────────────────────────────────┘
                        │
                        ▼
┌──────────────────────────────────────────────────────────┐
│                    Writer                                │
│  ┌────────────────────────────────────────────────────┐ │
│  │  Printf(format, args...)                          │ │
│  │    ↓                                               │ │
│  │  ┌────────────┬────────────┬────────────┐         │ │
│  │  │ 控制台     │ 文件       │ 日志系统    │         │ │
│  │  └────────────┴────────────┴────────────┘         │ │
│  └────────────────────────────────────────────────────┘ │
└──────────────────────────────────────────────────────────┘

八、最佳实践与故障排查

8.1 配置最佳实践

开发环境最佳实践

1
2
3
4
5
6
7
8
9
10
// 开发环境：详细日志，彩色输出
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             200 * time.Millisecond,  // 200ms
		LogLevel:                  logger.Info,             // 所有 SQL
		Colorful:                  true,                   // 彩色
		IgnoreRecordNotFoundError: true,                   // 忽略未找到
		ParameterizedQueries:      false,                  // 替换参数
	}),
})

生产环境最佳实践

1
2
3
4
5
6
7
8
9
10
// 生产环境：错误和慢查询，禁用彩色
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             500 * time.Millisecond,  // 500ms
		LogLevel:                  logger.Warn,             // 错误和慢查询
		Colorful:                  false,                  // 禁用彩色
		IgnoreRecordNotFoundError: true,                   // 忽略未找到
		ParameterizedQueries:      true,                   // 参数化 SQL
	}),
})

测试环境最佳实践

1
2
3
4
5
6
7
8
9
10
// 测试环境：Info 级别，禁用彩色
db, _ := gorm.Open(sqlite.Open(":memory:"), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		SlowThreshold:             100 * time.Millisecond,  // 100ms
		LogLevel:                  logger.Info,             // 详细日志
		Colorful:                  false,                  // 禁用彩色
		IgnoreRecordNotFoundError: false,                  // 不忽略错误
		ParameterizedQueries:      false,                  // 替换参数
	}),
})

8.2 性能优化

减少日志开销

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
// 1. 使用 Silent 模式
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Silent),
})

// 2. 禁用调用栈追踪
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Info),
})

// 通过 SkipCallerLookup 禁用（需要实现）
// 注意：标准 Logger 没有此方法，需要自定义实现

// 3. 使用参数化 SQL
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		ParameterizedQueries: true,  // 不替换参数，减少字符串操作
	}),
})

异步日志

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
// 异步 Logger：使用 goroutine 异步写入日志
type AsyncLogger struct {
	logger.Interface
	logChan chan string
	quit    chan struct{}
	wg      sync.WaitGroup
}

func NewAsyncLogger(writer Writer) *AsyncLogger {
	al := &AsyncLogger{
		Interface: logger.Default.LogMode(logger.Info),
		logChan:  make(chan string, 1000),
		quit:     make(chan struct{}),
	}

	// 启动写入 goroutine
	al.wg.Add(1)
	go func() {
		defer al.wg.Done()
		for {
			select {
			case log := <-al.logChan:
				writer.Printf(log)
			case <-al.quit:
				return
			}
		}
	}()

	return al
}

func (l *AsyncLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	// 异步写入
	l.logChan <- fmt.Sprintf("[%.3fms] [rows:%v] %s\n",
		float64(elapsed.Nanoseconds())/1e6, rows, sql)

	return nil
}

func (l *AsyncLogger) Close() {
	close(l.quit)
	l.wg.Wait()
}

日志采样

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
// 采样 Logger：只记录部分日志
type SamplingLogger struct {
	logger.Interface
	rate float64 // 采样率 0.0 - 1.0
}

func (l *SamplingLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	// 随机采样
	if rand.Float64() > l.rate {
		return  // 不记录
	}

	// 记录日志
	return l.Interface.Trace(ctx, begin, fc, err)
}

// 使用：只记录 10% 的日志
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: &SamplingLogger{
		Interface: logger.Default.LogMode(logger.Info),
		rate:      0.1,  // 10% 采样率
	},
})

8.3 安全建议

敏感数据过滤

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
// 敏感参数过滤器
type SensitiveDataFilter struct {
	logger.Interface
	sensitiveFields map[string]bool
}

func (f *SensitiveDataFilter) ParamsFilter(ctx context.Context, sql string, params ...interface{}) (string, []interface{}) {
	// 检测敏感字段
	if strings.Contains(strings.ToLower(sql), "password") {
		for i, param := range params {
			if _, ok := param.(string); ok {
				params[i] = "***"
			}
		}
	}

	return sql, params
}

// 使用
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: &SensitiveDataFilter{
		Interface:        logger.Default.LogMode(logger.Info),
		sensitiveFields: map[string]bool{
			"password": true,
			"token":     true,
			"secret":    true,
		},
	},
})

SQL 注入防护

1
2
3
4
5
6
7
8
9
// 注意：GORM 使用参数化查询，已经防止 SQL 注入
// 但是日志中记录的 SQL 需要确保安全

// 安全的日志记录：始终使用参数化 SQL
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		ParameterizedQueries: true,  // 只记录参数化 SQL
	}),
})

日志脱敏

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
// 脱敏 Logger
type MaskingLogger struct {
	logger.Interface
	maskFunc func(string) string
}

func (l *MaskingLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	// 脱敏处理 SQL
	maskedSQL := l.maskFunc(sql)

	// 记录脱敏后的日志
	l.Printf("[%.3fms] [rows:%v] %s\n",
		float64(elapsed.Nanoseconds())/1e6, rows, maskedSQL)

	return nil
}

// 脱敏函数
func maskSQL(sql string) string {
	// 移除敏感数据
	// 例如：移除字符串字面量中的值
	return sql
}

8.4 常见问题与解决方案

日志不输出问题

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
// 问题：设置日志级别后没有日志输出

// 原因 1：日志级别设置错误
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Silent),  // Silent 模式不会输出任何日志
})

// 解决方案：使用正确的日志级别
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Info),
})

// 原因 2：使用了错误的 logger 实例
db.Session(&gorm.Session{
	Logger: logger.Default.LogMode(logger.Silent),  // Session 级别的 logger
})

// 解决方案：使用全局 logger
db.LogMode(logger.Info)

性能问题

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
// 问题：日志严重影响性能

// 原因 1：Info 级别在高并发场景下
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Info),  // 记录所有 SQL
})

// 解决方案：使用 Warn 级别
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.Default.LogMode(logger.Warn),  // 只记录错误和慢查询
})

// 原因 2：调用栈追踪开销大
// FileWithLineNum() 会遍历调用栈

// 解决方案：自定义 Logger，禁用调用栈追踪
type NoCallerLogger struct {
	logger.Interface
}

func (l *NoCallerLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	l.Printf("[%.3fms] [rows:%v] %s\n",
		float64(elapsed.Nanoseconds())/1e6, rows, sql)

	return nil
}

颜色显示问题

1
2
3
4
5
6
7
8
9
10
11
12
13
// 问题：在 IDE 或日志系统中颜色显示异常

// 原因：某些终端不支持 ANSI 颜色代码

// 解决方案：禁用彩色输出
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
	Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
		Colorful: false,  // 禁用彩色
	}),
})

// 或者使用环境变量
// NO_COLOR=1 go run main.go

九、学习验证

9.1 知识自测

基础题

  1. 以下哪个是正确的日志级别排序（从低到高）？

    • A. Info, Warn, Error, Silent
    • B. Silent, Error, Warn, Info
    • C. Silent, Info, Warn, Error
    • D. Error, Warn, Info, Silent

    答案: B

  2. Trace 方法的 fc 参数的作用是什么？

    • A. 直接获取 SQL 和行数
    • B. 延迟获取 SQL 和行数
    • C. 执行 SQL 查询
    • D. 记录日志

    答案: B

  3. 如何启用慢查询检测？

    • A. 设置 LogLevel 为 Info
    • B. 设置 SlowThreshold 大于 0
    • C. 设置 Colorful 为 true
    • D. 设置 IgnoreRecordNotFoundError 为 true

    答案: B

  4. 哪种日志级别对性能影响最小？

    • A. Info
    • B. Warn
    • C. Error
    • D. Silent

    答案: D

  5. 如何只记录参数化 SQL（不替换参数值）？

    • A. 设置 LogLevel 为 Silent
    • B. 设置 ParameterizedQueries 为 true
    • C. 设置 IgnoreRecordNotFoundError 为 true
    • D. 设置 SlowThreshold 为 0

    答案: B

进阶题

  1. 分析以下代码的日志输出

    1
    2
    3
    4
    5
    6
    7
    8
    db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
        Logger: logger.New(log.New(os.Stdout, "\r\n", log.LstdFlags), logger.Config{
            SlowThreshold: 100 * time.Millisecond,
            LogLevel:      logger.Warn,
            Colorful:      false,
        }),
    })
    db.Find(&users)

    假设查询耗时 50ms，是否有日志输出？

    答案: 没有日志输出。虽然设置了 LogLevel 为 Warn，但查询耗时 50ms，小于 SlowThreshold 100ms，且没有错误，所以不会记录日志。

  2. 如何实现一个自定义 Logger，将日志写入文件？

    答案:

    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    13
    14
    15
    type FileLogger struct {
        logger.Interface
        file *os.File
    }

    func (l *FileLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
        elapsed := time.Since(begin)
        sql, rows := fc()

        logEntry := fmt.Sprintf("[%s] [%.3fms] [rows:%v] %s\n",
            time.Now().Format("2006-01-02 15:04:05"),
            float64(elapsed.Nanoseconds())/1e6, rows, sql)
        l.file.WriteString(logEntry)
        return nil
    }

实战题

  1. 实现一个完整的 JSON Logger
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
type JSONLogger struct {
	logger.Interface
	writer io.Writer
}

func (l *JSONLogger) Trace(ctx context.Context, begin time.Time, fc func() (string, int64), err error) {
	elapsed := time.Since(begin)
	sql, rows := fc()

	entry := map[string]interface{}{
		"timestamp": time.Now().Format(time.RFC3339),
		"duration":  float64(elapsed.Nanoseconds()) / 1e6,
		"sql":       sql,
		"rows":      rows,
	}

	if err != nil {
		entry["level"] = "error"
		entry["error"] = err.Error()
	} else {
		entry["level"] = "info"
	}

	json.NewEncoder(l.writer).Encode(entry)
	return nil
}

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

9.2 实践练习

练习 1: 实现自定义 JSON Logger

创建一个输出 JSON 格式日志的 Logger，要求:

  • 包含时间戳、日志级别、执行时间、SQL、行数
  • 支持错误日志
  • 输出到标准输出

验收标准:

  • 输出格式正确的 JSON
  • 包含所有必需字段
  • 错误时包含错误信息

三、学习路径建议

3.1 前置知识检查

知识点 要求 检验方式
Go 反射 了解 runtime.Caller 能编写简单的反射代码
Go 接口 理解接口设计 能定义和实现接口
SQL 基础 理解参数化查询 能区分原始 SQL 和参数化 SQL
日志系统 了解日志级别 能解释不同级别的用途

3.2 学习时间分配

内容 理论 实践 产出
Day 1: 日志基础 2h 1.5h 配置示例
Day 2: 高级日志 1.5h 2h 慢查询检测
Day 3: 扩展应用 1.5h 2h 自定义 Logger

3.3 学习成果验收

理论验收:

  • 能解释 Logger 接口设计
  • 能说明 Trace 方法实现
  • 能理解 SQL 解释机制
  • 能对比不同日志级别

实践验收:

  • 能配置日志级别
  • 能实现自定义 Logger
  • 能检测慢查询
  • 能追踪调用位置

综合验收:

  • 能设计日志策略
  • 能集成日志系统
  • 能分析日志数据
  • 能向他人讲解日志系统