4. 慢查询日志配置：MySQL慢查询日志开启、Go应用中慢查询日志采集、日志格式解析

慢查询日志是数据库性能优化的第一道防线。在生产环境中，没有慢查询日志的优化如同盲人摸象。本节将系统讲解MySQL慢查询日志的开启策略、Go应用中的采集方案以及日志格式的深度解析。

4.1 MySQL慢查询日志开启与配置

MySQL慢查询日志记录了执行时间超过指定阈值（long_query_time）的SQL语句。合理的配置是采集高质量慢查询数据的前提。

4.1.1 核心参数配置

4.1.2 动态开启与验证

-- 动态开启慢查询日志（无需重启）
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = ON;

-- 验证配置生效
SHOW VARIABLES LIKE 'slow_query_log%';
SHOW VARIABLES LIKE 'long_query_time';
SHOW VARIABLES LIKE 'log_queries_not_using_indexes';

-- 手动触发一条慢查询用于测试
SELECT SLEEP(2);

4.2 Go应用中慢查询日志采集

在Go应用中，慢查询日志的采集通常有两种模式：代理采集模式和应用内嵌模式。代理模式对应用无侵入，但需要额外部署；内嵌模式更灵活，适合精细化监控。

4.2.1 代理采集模式（以ProxySQL为例）

ProxySQL作为数据库中间件，可以统一采集后端MySQL的慢查询日志，并提供查询规则、限流等功能。

-- ProxySQL配置慢查询采集
SET mysql-set_query_digests = 1;
SET mysql-query_digests_max_digest_length = 2048;

-- 开启慢查询日志捕获
SET mysql-slow_query_log = 1;
SET mysql-slow_query_log_file = '/var/lib/proxysql/slow.log';
SET mysql-long_query_time = 1000;  -- 单位：毫秒

-- 查看采集到的慢查询统计
SELECT digest, digest_text, count_star, sum_time, sum_rows_examined
FROM stats_mysql_query_digest
WHERE sum_time > 1000000  -- 总耗时超过1秒
ORDER BY sum_time DESC
LIMIT 10;

4.2.2 应用内嵌模式（Go原生采集）

在Go应用中，通过自定义 database/sql 的 DB 包装器或使用ORM钩子，可以精确采集每个查询的执行时间。

// 自定义慢查询采集包装器
type SlowQueryCollector struct {
    db        *sql.DB
    threshold time.Duration // 慢查询阈值
    logger    *log.Logger   // 日志输出
}

func (c *SlowQueryCollector) QueryContext(ctx context.Context, query string, args ...interface{}) (*sql.Rows, error) {
    start := time.Now()
    rows, err := c.db.QueryContext(ctx, query, args...)
    elapsed := time.Since(start)

    if elapsed > c.threshold {
        c.logger.Printf("[SLOW_QUERY] duration=%v query=%s args=%v error=%v",
            elapsed, query, args, err)
    }
    return rows, err
}

// 使用示例
collector := &SlowQueryCollector{
    db:        db,
    threshold: 500 * time.Millisecond,
    logger:    log.New(os.Stdout, "[DB] ", log.LstdFlags),
}
rows, _ := collector.QueryContext(ctx, "SELECT * FROM orders WHERE user_id = ?", 12345)

4.3 慢查询日志格式解析

MySQL慢查询日志的格式包含丰富的诊断信息。理解每个字段的含义，是精准定位性能瓶颈的基础。

4.3.1 标准日志格式字段

# Time: 2025-03-15T10:30:45.123456Z
# User@Host: app_user[app_user] @  [10.0.1.100]  Id: 12345
# Query_time: 2.345678  Lock_time: 0.001234  Rows_sent: 100  Rows_examined: 50000
# Thread_id: 12345  Schema: ecommerce  Last_errno: 0  Killed: 0
# Query_time_distribution:
#   1. micro: 0, 2. ms: 0, 3. slow: 1, 4. very_slow: 0
SET timestamp=1742020245;
SELECT o.id, o.amount, u.name
FROM orders o
JOIN users u ON o.user_id = u.id
WHERE o.status = 'pending'
ORDER BY o.created_at DESC
LIMIT 100;

4.3.2 日志解析工具与自动化

手动逐条查看慢查询日志效率极低，推荐使用 pt-query-digest 或自建解析流水线。

# 使用 pt-query-digest 分析慢查询日志
pt-query-digest /var/log/mysql/slow.log --limit=20 --since="2025-03-15 00:00:00"

# 输出示例（摘要部分）
# Profile
# Rank Query ID                            Response time    Calls R/Call  V/M   Item
# ==== =================================== ================ ===== ======= ===== =====
#    1 0xABCDEF1234567890                  125.6789 45.2%    120  1.0473  0.01  SELECT orders
#    2 0x1234567890ABCDEF                  89.1234  32.1%     85  1.0485  0.02  SELECT users
#    3 0xDEADBEEF12345678                  45.6789  16.4%     50  0.9136  0.01  INSERT logs

在Go应用中，可以集成 go-mysql-slow-query-parser 库实现实时解析：

import "github.com/siddontang/go-mysql/slowquery"

// 解析慢查询日志行
func parseSlowLogLine(line string) (*slowquery.SlowQuery, error) {
    parser := slowquery.NewSlowQueryParser()
    sq, err := parser.Parse(line)
    if err != nil {
        return nil, err
    }
    return sq, nil
}

// 使用示例
sq, _ := parseSlowLogLine("# Query_time: 2.345678  Lock_time: 0.001234  Rows_sent: 100  Rows_examined: 50000")
fmt.Printf("QueryTime: %v, RowsExamined: %d\n", sq.QueryTime, sq.RowsExamined)

4.4 慢查询日志采集架构

下图展示了从MySQL生成日志到Go应用采集、解析、存储的完整链路。

4.5 常见问题与避坑指南

• 日志文件轮转：MySQL不会自动轮转慢查询日志，建议使用 logrotate 或定时任务按天切割，避免单个日志文件过大导致磁盘爆满。
• 性能影响：开启 log_queries_not_using_indexes 后，大量全表扫描查询会被记录，可能产生海量日志。建议先开启 long_query_time 过滤，再逐步开启此参数。
• 时区问题：慢查询日志中的 Time 字段默认使用UTC时间，建议在MySQL配置中设置 log_timestamps = SYSTEM 或统一转换为业务时区。
• 连接池干扰：Go应用内嵌采集时，如果连接池配置了 SetConnMaxLifetime，慢查询可能包含连接重建的时间，需要区分“SQL执行慢”和“连接获取慢”。