本文记录了一次通过优化代码提高接口吞吐量的实践。在面临500/s吞吐量需求时，发现100并发下，接口吞吐量仅50，CPU使用率高达80%。通过分析，找到慢SQL和过多的线程创建问题，优化后吞吐量提升至近200，但CPU使用率依旧高。最终定位到Spring的多例Bean创建导致的性能瓶颈，并通过减少Bean创建和改进耗时统计方式提升性能。
-
景
-
分析过程
-
总结
背景
公司的一个ToB系统，因为客户使用的也不多，没啥并发要求，就一直没有经过压测。这两天来了一个“大客户”，对并发量提出了要求：核心接口与几个重点使用场景单节点吞吐量要满足最低500/s的要求。
当时一想，500/s吞吐量还不简单。Tomcat按照100个线程，那就是单线程1S内处理5个请求，200ms处理一个请求即可。这个没有问题，平时接口响应时间大部分都100ms左右，还不是分分钟满足的事情。
然而压测一开，100 的并发，吞吐量居然只有 50 ...
而且再一查，100的并发，CPU使用率居然接近 80% ...
从上图可以看到几个重要的信息。
最小值：表示我们非并发场景单次接口响应时长。还不足100ms。挺好!
最大值：并发场景下，由于各种锁或者其他串行操作，导致部分请求等待时长增加，接口整体响应时间变长。5秒钟。有点过分了！！！
再一看百分位，大部分的请求响应时间都在4s。无语了！！！
所以 1s钟的 吞吐量 单节点只有 50 。距离 500 差了10倍。难受！！！！
分析过程
定位“慢”原因
❝
这里暂时先忽略 CPU 占用率高的问题
❞
首先平均响应时间这么慢，肯定是有阻塞。先确定阻塞位置。重点检查几处：
-
锁 (同步锁、分布式锁、数据库锁)
-
耗时操作 (链接耗时、SQL耗时)
结合这些先配置耗时埋点。
-
接口响应时长统计。超过500ms打印告警日志。
-
接口内部远程调用耗时统计。200ms打印告警日志。
-
Redis访问耗时。超过10ms打印告警日志。
-
SQL执行耗时。超过100ms打印告警日志。
上述配置生效后，通过日志排查到接口存在慢SQL。具体SQL类似与这种：
<!-- 主要类似与库存扣减 每次-1 type 只有有限的几种且该表一共就几条数据（一种一条记录）-->
<!-- 压测时可以认为 type = 1 是写死的 -->
update table set field = field - 1 where type = 1 and filed > 1;
上述SQL相当于并发操作同一条数据，肯定存在锁等待。日志显示此处的等待耗时占接口总耗时 80% 以上。
二话不说先改为敬。因为是压测环境，直接改为异步执行，确认一下效果。
❝
PS：当时心里是这么想的：妥了，大功告成。就是这里的问题！绝壁是这个原因！优化一下就解决了。当然，如果这么简单就没有必要写这篇文章了...
❞
优化后的效果：
嗯...
emm...
好！这个优化还是很明显的，提升提升了近2倍。
此时已经感觉到有些不对了，慢SQL已经解决了（异步了~ 随便吧~ 你执行 10s我也不管了），虽然对吞吐量的提升没有预期的效果。但是数据是不会骗人的。
-
最大值：已经从
5s -> 2s -
百分位值：
4s -> 1s
这已经是很大的提升了。
继续定位“慢”的原因
通过第一阶段的“优化”，我们距离目标近了很多。废话不多说，继续下一步的排查。
我们继续看日志，此时日志出现类似下边这种情况：
2023-01-04 15:17:05:347 INFO **.**.**.***.50 [TID: 1s22s72s8ws9w00] **********************
2023-01-04 15:17:05:348 INFO **.*
最低0.47元/天 解锁文章
扫一扫
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
