这是一次完整的排查记录,我尽量把每一步的数字都保留下来,因为我觉得这个过程比结论有意思——没有任何一步是决定性的,是六个小改动堆出来的结果。
起点
一个列表查询接口,平均耗时 2.9 秒,最慢的能到 6 秒。前端加了骨架屏也救不回来,用户投诉说点一下要等好久。
我做的第一件事不是看代码,是在方法里埋点。粗暴地在几个关键位置记时间戳,最后打一行日志。跑了半小时线上流量,拿到平均耗时的拆分:
- 数据库查询:2100 毫秒
- 内存中的数据组装:500 毫秒
- 结果序列化:300 毫秒
- 其他:不到 100 毫秒
这一步只花了二十分钟,但它决定了后面所有工作的顺序。如果没有它,我大概率会先去优化那个看起来很丑的组装逻辑,而那只占六分之一。
第一刀:干掉 N+1
打开数据库的慢查询和执行统计,发现一次接口调用产生了 203 次查询。主查询一次,然后对每条记录分别查了两次关联数据。经典的 N+1。
改成先批量取出所有主记录的 ID,再用两条带 IN 条件的语句一次性把关联数据全捞回来,在内存里组装成映射。
数据库耗时:2100 → 620 毫秒。这是收益最大的一刀。
第二刀:IN 条件太长
改完之后我发现慢查询日志里还有个东西:那条 IN 语句带了 200 个值,执行计划显示走了索引但扫描行数不小。更麻烦的是当页大小调到 500 时,IN 里有 500 个值,优化器直接放弃索引走了全表。
改成按 200 一批拆分,多发几条语句。听起来是倒退,实测反而更快,因为每条都能稳定走索引。
数据库耗时:620 → 380 毫秒。
第三刀:索引顺序错了
主查询的条件是「状态等于某值、创建时间在某区间、按创建时间倒序」,表上有个复合索引,但列的顺序是时间在前、状态在后。
这个顺序导致等值条件没法用来收窄,只能靠时间范围扫描,扫出来的行再逐条过滤状态。而符合状态条件的只占大约 4%。
把索引改成状态在前、时间在后之后,扫描行数从二十多万降到八千多。
数据库耗时:380 → 90 毫秒。到这里数据库部分基本可以收工了。
第四刀:嵌套循环
接下来是那 500 毫秒的组装逻辑。打开一看,是个双重循环:外层遍历 200 条主记录,内层遍历一个大约 3000 项的配置列表找匹配项。六十万次比较,每次比较里还做了字符串拼接。
把配置列表预先建成一个以匹配键为索引的映射,循环里直接查。
组装耗时:500 → 20 毫秒。这个改动只有五行,是整个过程里性价比最高的。
第五刀:返回了没人用的字段
序列化那 300 毫秒,源头是返回对象有 41 个字段,其中包含两个大文本字段。我去问前端,他们实际用到 12 个,那两个大文本一个都没用。
加了一个精简的返回结构,只带需要的字段。
序列化耗时:300 → 60 毫秒。顺带响应体从平均 480KB 降到 90KB,前端解析也快了。
第六刀:日志
最后剩下的杂项里,我发现有一处在循环里打了调试级别的日志,虽然级别没开,但拼接参数的字符串操作还是执行了。改成用参数占位的写法之后,又省了十几毫秒。
结果和反思
最终平均 180 毫秒左右,最慢的到 400 毫秒。从 2.9 秒到 0.18 秒,十六倍。
我事后总结了两点:
第一,没有银弹。六个改动,最大的一个贡献了一半,其余五个各贡献一点。如果我只做第一刀就收工,接口还有一秒多,用户照样觉得慢。性能优化是个累加游戏。
第二,埋点是最划算的投资。那二十分钟的埋点让我一次都没有走错方向。我后来把那些埋点保留下来,改成了正式的耗时指标上报,现在这个接口任何一段变慢,看板上直接能看出来是哪一段。
还有一点私心话:那个索引顺序的问题,建表的人是我。