慢SQL日志一天吞65G磁盘?加了动态采样率降到1.2G
凌晨两点,报警群里炸了。
"订单服务三台机器磁盘使用率全部超过 95%,其中一台已经 99%。下单接口开始超时,用户付不了款了。"
我迷迷糊糊掏出手机看了一眼,心头一紧。这是线上大促前夕,每秒几千单的交易量,磁盘满了意味着日志写不进去、服务随时可能挂掉。
赶紧登上服务器一看,/data/logs 目录占了整整 230G。顺着 du 一层层摸下去:
/data/logs/slow-sql/
├── 2026-06-20.log 68G
├── 2026-06-19.log 61G
├── 2026-06-18.log 55G
└── ...
好家伙,慢 SQL 日志每天能写六七十 G。
我们慢 SQL 阈值设的 500ms,全量记录每一条慢查询的完整 SQL、执行时间、调用堆栈。业务高峰期每秒几千个查询,大促期间并发一上来,哪怕只有 5% 的 SQL 超过 500ms,每天就是几百万条记录。
那一刻我突然意识到一个问题:我们到底需要记录这么多慢 SQL 吗?
一、全量记录的代价,不光是磁盘
回过头来看,全量慢 SQL 日志的代价远比磁盘空间要大:
磁盘 IO 争抢。 每一条慢 SQL 的日志写入都需要 write() 系统调用,高峰期日志线程跟业务线程争抢磁盘 IO。慢 SQL 越多,日志写得越多,磁盘 IO 越紧张,然后 SQL 就更慢,产生更多慢 SQL 日志。这是一个自加速的恶性循环。
有价值的信息被噪声淹没。 每天几百万条慢 SQL,真正需要优化的是哪些?是 COUNT(*) 全表扫了,还是某个 JOIN 走了错误的驱动表?全量 dump 出来之后,连 grep 都慢得怀疑人生,更要命的是——大量条目其实是同一个慢 SQL 模式重复了几十万次,你根本区分不出来。
凌晨告警只是因为磁盘快满了。 运维同学凌晨被叫起来清日志,这不应该是一个研发团队的"正常"工作流程。
老实说,如果再不从采样策略上动手,下次大促就不是清日志的问题了——是直接挂服务。
二、想清楚:我们需要慢 SQL 日志做什么?
冷静下来,退一步想一个根本问题:
慢 SQL 日志的终极目的到底是什么?
不是为了"记录一切",而是为了找到需要优化的那条 SQL。
那好,要达成这个目的,全量记录其实做过头了。真正需要的是:
- 覆盖度:每个慢 SQL 模式至少能被采样到一次
- 优先级:相同时间内出现频率越高的慢 SQL,越值得关注
- 可追溯:不仅知道 SQL 文本,还得知道是从哪个方法、哪个请求链路里触发的
- 不过度伤害系统:磁盘 IO 和存储成本可控
想清楚这四点,方案就呼之欲出了——动态采样率 + 异常堆栈聚合上报。
三、方案设计:从全量到智能采样
3.1 核心思路
不做全量记录。改为两层过滤:
第一层:动态采样率。 给每条慢 SQL 一个采样概率,而不是 100% 记录。同一条 SQL 出现次数越多,采样率越低——因为我们已经见过它了。
第二层:异常堆栈聚合。 不逐条记录,而是按 SQL 指纹 + 调用堆栈 做聚合,一段时间窗口内同一条 SQL 同一个调用来源只上报一次摘要。
就像你不会把每天吃过的每一顿饭都拍照存起来,但你一定会记住"上周那家火锅店,两个人花了 400 块没吃饱"。
3.2 架构概览
业务代码(MyBatis 拦截器 / AOP)
│
├── 1. 拦截 SQL 执行,判断耗时是否超过阈值
│
├── 2. 提取 SQL 指纹(参数化)
│ "SELECT * FROM user WHERE id=123" → "SELECT * FROM user WHERE id=?"
│
├── 3. 查询采样率(基于 SQL 指纹 + 时间窗口内的出现次数)
│ 首次出现 → 采样率 100%
│ 第 2~10 次 → 采样率 50%
│ 第 11~100 次 → 采样率 10%
│ 第 101 次以上 → 采样率 1%
│
├── 4. 命中采样 → 记录堆栈 + SQL 文本 → 聚合上报
│ 未命中采样 → 只更新计数器,不写日志
│
└── 5. 聚合模块定期(30s)把窗口内的数据上报到监控平台
四、具体实现
4.1 SQL 指纹提取
先把所有参数值替换为占位符,得到参数化的 SQL 模板:
public class SqlFingerprint {
private static final Pattern VALUE_PATTERN = Pattern.compile(
"'[^']*'|\\d+\\.?\\d*"
);
public static String fingerprint(String sql) {
// 去掉多余空格,统一小写
String normalized = sql.trim().replaceAll("\\s+", " ").toLowerCase();
// 参数值替换为 ?
return VALUE_PATTERN.matcher(normalized).replaceAll("?");
}
}
// 示例:
// IN: SELECT * FROM orders WHERE user_id = 12836 AND status = 'PAID'
// OUT: select * from orders where user_id = ? and status = ?
4.2 动态采样率实现
核心逻辑:Caffeine 缓存 + 原子计数器。每条 SQL 指纹在时间窗口内的出现次数决定了它的采样概率。
public class AdaptiveSampler {
// 10 分钟窗口,同一 SQL 指纹的出现次数
private final Cache<String, AtomicInteger> counterCache = Caffeine.newBuilder()
.expireAfterWrite(10, TimeUnit.MINUTES)
.maximumSize(100_000)
.build();
/**
* 返回该 SQL 本次是否应该被采样
*/
public boolean shouldSample(String sqlFingerprint) {
AtomicInteger counter = counterCache.get(sqlFingerprint,
k -> new AtomicInteger(0));
int count = counter.incrementAndGet();
// 根据出现次数计算采样率
double rate;
if (count <= 1) rate = 1.0; // 第一次出现,100% 采样
else if (count <= 10) rate = 0.5; // 前 10 次,50% 采样
else if (count <= 100) rate = 0.1; // 前 100 次,10%
else rate = 0.01; // 之后,1%
return ThreadLocalRandom.current().nextDouble() < rate;
}
}
为什么这么设计?第一天出现的新慢 SQL 你想第一时间知道——100% 采集。但同样的 SQL 如果已经出现了一万次,你知道它存在就够了,不需要每一万条都存档。
4.3 异常堆栈聚合
光知道 SQL 文本还不够。同一条 SELECT * FROM order WHERE user_id = ?,可能从订单详情页触发,也可能从批量导出接口触发——优化策略完全不同。
public class SlowSqlEvent {
private String sqlFingerprint; // SQL 指纹
private String callerStackTrace; // 调用方堆栈(截取前 N 层)
private long firstOccurTime; // 本窗口首次出现时间
private long lastOccurTime; // 最近出现时间
private int totalCount; // 窗口内出现次数
private long maxElapsed; // 最大耗时(ms)
private long avgElapsed; // 平均耗时(ms)
private String sampleSql; // 一条样本 SQL(带真实参数)
}
public class StackTraceAggregator {
// SQL 指纹 + 调用方类名(前3层)作为聚合 key
public String aggregateKey(SlowSqlEvent event) {
return event.getSqlFingerprint() + "|" + extractTopCaller(event.getCallerStackTrace());
}
private String extractTopCaller(String stackTrace) {
// 取堆栈前 3 层调用方类名作为分组维度
return Arrays.stream(stackTrace.split("\n"))
.limit(3)
.map(line -> line.trim().replaceAll("\\(.*\\)", ""))
.collect(Collectors.joining(" -> "));
}
}
聚合 key = SQL 指纹 + 前3层调用方类名。同一个 SQL 被不同业务入口触发时,会形成不同的聚合记录,互不干扰。
4.4 滑动窗口批量上报
不用每条都实时上报(那就跟全量没区别了)。用滑动窗口攒一批,30 秒统一上报一次:
@Component
public class SlowSqlReporter {
// 窗口:30 秒
private final ConcurrentHashMap<String, SlowSqlEvent> window = new ConcurrentHashMap<>();
@Scheduled(fixedRate = 30_000)
public void flush() {
if (window.isEmpty()) return;
// 快照 + 清空
Map<String, SlowSqlEvent> snapshot = new HashMap<>(window);
window.clear();
// 批量上报到监控平台
monitorClient.batchReport(new ArrayList<>(snapshot.values()));
}
public void record(SlowSqlEvent event) {
String key = aggregator.aggregateKey(event);
window.merge(key, event, (existing, incoming) -> {
existing.setTotalCount(existing.getTotalCount() + 1);
existing.setLastOccurTime(incoming.getLastOccurTime());
existing.setMaxElapsed(Math.max(existing.getMaxElapsed(), incoming.getMaxElapsed()));
// 保留第一条作为样本
return existing;
});
}
}
五、MyBatis 拦截器集成
对大多数 Java 项目来说,最自然的切入点是 MyBatis 的 Interceptor:
@Intercepts({
@Signature(type = StatementHandler.class, method = "query",
args = {Statement.class, ResultHandler.class}),
@Signature(type = StatementHandler.class, method = "update",
args = {Statement.class})
})
public class SlowSqlInterceptor implements Interceptor {
@Override
public Object intercept(Invocation invocation) throws Throwable {
long start = System.currentTimeMillis();
try {
return invocation.proceed();
} finally {
long elapsed = System.currentTimeMillis() - start;
if (elapsed >= slowThreshold) {
handleSlowSql(invocation, elapsed);
}
}
}
private void handleSlowSql(Invocation invocation, long elapsed) {
String sql = extractSql(invocation);
String fingerprint = SqlFingerprint.fingerprint(sql);
// 动态采样
if (!sampler.shouldSample(fingerprint)) {
return; // 不采样,跳过,磁盘零开销
}
// 采样命中:采集堆栈并聚合上报
SlowSqlEvent event = new SlowSqlEvent();
event.setSqlFingerprint(fingerprint);
event.setSampleSql(sql);
event.setCallerStackTrace(getStackTrace());
event.setMaxElapsed(elapsed);
event.setAvgElapsed(elapsed);
reporter.record(event);
}
}
六、效果对比
上线一周后,拉出前后数据对比:
| 指标 | 上线前(全量) | 上线后(采样) | 变化 |
|---|---|---|---|
| 日均慢 SQL 日志量 | 65G | 1.2G | ↓ 98% |
| 磁盘 IO 占用(日志写入) | 45% | 3% | ↓ 93% |
| 慢 SQL 告警延迟 | 平均 8 分钟 | 平均 30 秒 | ↑ 16x |
| 可发现的慢 SQL 模式 | 100%(但全是噪声) | 100%(聚合后一目了然) | — |
| 凌晨磁盘满告警 | 每隔 2-3 天一次 | 0 次 | ✅ |
最关键的一个变化:慢 SQL 治理变快了。
全量日志时代,DBA 收到告警后要从几百 G 日志里找问题 SQL,大海捞针一样。现在聚合视图一打开,Top 10 慢 SQL 模式直接排好序,每个模式背后是哪个方法触发的、执行了多少次、最大耗时多少,一目了然。
七、踩过的坑
说几个实现过程中容易栽跟头的地方:
坑一:SQL 指纹的正则别太懒。 IN (1, 2, 3) 这种要把括号里的参数列表整体替换,不是每个数字单独替换成 ?,否则指纹会裂变。
坑二:堆栈别全量收集。 Thread.currentThread().getStackTrace() 在 QPS 很高时本身就是性能瓶颈。只收集前 5-8 层就够用了,不需要完整的几百层。
坑三:采样率降太快。 如果同一条 SQL 的第一次只因为数据库刚好在做 checkpoint 而跑超时,第二次就降采样率了,你可能永远看不到它的真实表现。建议下限别低于 1%,加一个冷却恢复——如果一个小时内这条 SQL 没再出现过,采样率恢复。
坑四:别忘了接监控大盘。 采样方案上线后没有可视化大盘,你根本不知道哪些 SQL 被采样到了、哪些被漏掉了。接 Prometheus / Grafana 或者公司内部监控,用图表说话。
全量慢 SQL 日志属于那种"刚开始觉得没毛病,等出事已经晚了"的设计。业务量小的时候一天几百 M,没人当回事。等量上来以后某天凌晨磁盘爆了,监控告警响个不停,才发现问题。
动态采样 + 堆栈聚合说到底就一句话:什么信息值得被记下来? 一天出现十万次的那条慢 SQL,你知道它存在、知道它从哪来的、知道它有多慢,够了。不需要十万条都存着。
慢接口日志、异常日志、链路追踪——这些高频但价值密度不均匀的日志数据,都可以用类似的思路处理。
你在线上被日志撑爆过磁盘吗?有什么离谱的经历,评论区聊聊。
标题:慢SQL日志一天吞65G磁盘?加了动态采样率降到1.2G
作者:jiangyi
地址:http://www.jiangyi.space/articles/2026/06/21/1782007359325.html
公众号:服务端技术精选
评论