慢查询基础:数据库慢查询日志的配置与解读(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、索引使用情况综合判断。
下图展示了从慢查询日志到根因定位的完整分析链路:
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。