慢查询基础:数据库慢查询日志的配置与解读(MySQL/PostgreSQL为例)

慢查询日志是数据库性能诊断的“第一现场”。在微服务并发场景下,一条慢查询可能拖垮整个上游链路。本章以 MySQL 和 PostgreSQL 为例,讲解慢查询日志的开启、参数调优、日志格式解读以及常见误判场景。

2.1 慢查询日志的核心价值

慢查询日志记录执行时间超过预设阈值的 SQL 语句。其核心价值在于:

  • 定位瓶颈:直接暴露响应时间最长的 SQL,避免全量审计。
  • 量化趋势:通过慢查询数量变化,判断数据库负载是否恶化。
  • 关联链路:结合微服务 Trace ID,将慢查询映射到具体服务实例。
实践建议:生产环境建议长期开启慢查询日志(低阈值),并设置自动轮转,避免磁盘写满。

2.2 MySQL 慢查询日志配置

2.2.1 参数清单

参数名 默认值 推荐值(并发场景) 说明
slow_query_log OFF ON 开启慢查询日志
long_query_time 10.000000 1.000000 或 0.500000 阈值(秒),微服务建议 ≤1s
log_queries_not_using_indexes OFF ON 记录未使用索引的查询
log_slow_admin_statements OFF ON 记录慢管理语句(ALTER/ANALYZE)
slow_query_log_file hostname-slow.log /var/log/mysql/slow.log 日志文件路径
log_output FILE FILE,TABLE 同时写入文件和 mysql.slow_log 表

2.2.2 配置示例

-- 动态生效(无需重启)
SET GLOBAL slow_query_log = ON;
SET GLOBAL long_query_time = 1;
SET GLOBAL log_queries_not_using_indexes = ON;
SET GLOBAL log_slow_admin_statements = ON;
SET GLOBAL slow_query_log_file = '/var/log/mysql/slow.log';

-- 持久化到 my.cnf
[mysqld]
slow_query_log = 1
long_query_time = 1
log_queries_not_using_indexes = 1
log_slow_admin_statements = 1
slow_query_log_file = /var/log/mysql/slow.log
log_output = FILE,TABLE
注意:log_queries_not_using_indexes 会记录大量全表扫描查询,可能产生海量日志。建议在开发/预发环境开启,生产环境按需启用。

2.3 PostgreSQL 慢查询日志配置

2.3.1 参数清单

参数名 默认值 推荐值(并发场景) 说明
log_min_duration_statement -1(关闭) 1000(毫秒) 记录执行时间 ≥ 该值的语句
log_statement none ddl 记录 DDL 语句,避免误改结构
log_line_prefix %m [%p] %t [%p-%l] %u@%d 日志行前缀,包含时间/进程/用户/库
log_directory pg_log /var/log/postgresql 日志目录
log_filename postgresql-%Y-%m-%d.log postgresql-slow-%Y%m%d.log 按日轮转

2.3.2 配置示例

-- postgresql.conf 修改
log_min_duration_statement = 1000        -- 1秒
log_statement = 'ddl'
log_line_prefix = '%t [%p-%l] %u@%d '   -- 时间 进程-行号 用户@库名
log_directory = '/var/log/postgresql'
log_filename = 'postgresql-slow-%Y%m%d.log'
log_rotation_age = 1440                  -- 每天轮转
log_rotation_size = 100MB                -- 或达到100MB轮转
PostgreSQL 优势:log_line_prefix 可携带应用名(%a),便于在微服务中区分不同服务发起的查询。

2.4 慢查询日志解读

2.4.1 MySQL 日志格式

# Time: 2025-03-21T10:15:30.123456Z
# User@Host: app_user[app_user] @  [10.0.1.50]  Id: 12345
# Query_time: 2.345678  Lock_time: 0.001234  Rows_sent: 100  Rows_examined: 50000
SET timestamp=1742544930;
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;

关键字段解读:

  • Query_time:实际执行时间(2.35s),超过阈值。
  • Lock_time:锁等待时间(1.2ms),占比很小,说明非锁竞争。
  • Rows_examined:扫描 5 万行,仅返回 100 行,典型“扫描过多”问题。
  • Rows_sent:最终返回行数。

2.4.2 PostgreSQL 日志格式

2025-03-21 10:15:30.123 UTC [12345-1] app_user@mydb LOG:  duration: 2345.678 ms  statement: 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;

关键字段解读:

  • duration:2345.678 ms,即 2.35s。
  • [12345-1]:进程 ID 和行号,便于关联 pg_stat_activity。
  • app_user@mydb:用户和数据库名。

2.5 慢查询日志分析流程

核心原则:不要只看 Query_time,要结合 Rows_examined / Rows_sent 比例、Lock_time、索引使用情况综合判断。

下图展示了从慢查询日志到根因定位的完整分析链路:

慢查询日志分析链路 慢查询日志 解析提取 指标分类 扫描过多 锁等待 索引缺失 EXPLAIN 分析 索引优化 SQL 改写 验证与回滚 Rows_examined / Rows_sent 比值

2.6 常见误判场景

误判场景 日志表现 真实根因 验证方法
Query_time 高 = SQL 慢 Query_time: 5s, Lock_time: 4.8s 行锁/表锁竞争,非 SQL 执行慢 查看 Lock_time 占比,检查锁监控
Rows_examined 大 = 必须优化 Rows_examined: 100万, Rows_sent: 10万 业务需要全量扫描(如报表),无法避免 确认业务逻辑是否可分批
慢查询只出现在日志中 偶发慢查询,无规律 缓存未命中、IO 抖动、连接池饥饿 关联系统指标(IOPS/CPU/连接数)
索引已存在 = 不会慢 查询使用索引,但 Query_time 仍高 索引选择性差,回表次数多 EXPLAIN 查看 rows 和 Extra 字段
关键提醒:慢查询日志是“症状”而非“诊断”。必须结合 EXPLAIN、锁监控、系统指标和链路追踪才能定位根因。

2.7 日志管理最佳实践

  • 阈值动态调整:白天设置 1s,夜间维护窗口可放宽到 5s,避免误报。
  • 日志轮转:使用 logrotate 或数据库内置轮转,保留最近 7~30 天。
  • 集中采集:通过 Filebeat/Fluentd 将慢查询日志发送到 Elasticsearch,便于可视化分析。
  • 采样率控制:高并发场景可设置 log_slow_rate_limit(MySQL 8.0+),按比例记录。
  • 安全脱敏:慢查询日志可能包含用户数据,生产环境需脱敏或限制访问权限。
工具推荐:pt-query-digest(Percona Toolkit)可自动聚合慢查询,按总耗时/频率排序,快速定位“最痛”的 SQL。