性能问题定位记录-1

背景

性能压测时，部分docker cpu达到100%了，测试要求解决。

定位思路

cpu使用率有差异，本人认知内有2种情况：
1、负载不均衡
2、机器性能本身有差异

机器性能差异排查

可以通过GC日志，快速判断。如果回收相同的内存，使用的时间差异不大，那基本硬件规格是没问题的。详细可以参考之前的文章https://blog.csdn.net/shuxiaohua/article/details/147285269。

[2026-03-07T07:25:08.816+0000][info][gc]GC(925)PauseYoung(Normal)(G1 Evacuation Pause)761M->266M(3072M)6.012ms[2026-03-07T07:25:08.816+0000][info][gc,cpu]GC(925)User=0.02s Sys=0.00s Real=0.01s[2026-03-07T07:25:09.811+0000][info][gc,start]GC(926)PauseYoung(Normal)(G1 Evacuation Pause)[2026-03-07T07:25:09.812+0000][info][gc,task]GC(926)Using4workers of4forevacuation[2026-03-07T07:25:09.816+0000][info][gc,phases]GC(926)Pre Evacuate Collection Set:0.35ms[2026-03-07T07:25:09.816+0000][info][gc,phases]GC(926)Merge Heap Roots:0.13ms[2026-03-07T07:25:09.816+0000][info][gc,phases]GC(926)Evacuate Collection Set:3.04ms[2026-03-07T07:25:09.816+0000][info][gc,phases]GC(926)Post Evacuate Collection Set:1.11ms[2026-03-07T07:25:09.816+0000][info][gc,phases]GC(926)Other:0.09ms[2026-03-07T07:25:09.816+0000][info][gc,heap]GC(926)Eden regions:124->0(124)[2026-03-07T07:25:09.816+0000][info][gc,heap]GC(926)Survivor regions:1->1(16)[2026-03-07T07:25:09.816+0000][info][gc,heap]GC(926)Old regions:62->62[2026-03-07T07:25:09.816+0000][info][gc,heap]GC(926)Humongous regions:4->4[2026-03-07T07:25:09.816+0000][info][gc,metaspace]GC(926)Metaspace:226560K(229184K)->226560K(229184K)NonClass:200613K(201728K)->200613K(201728K)Class:25947K(27456K)->25947K(27456K)

[2026-03-07T07:24:58.229+0000][info][gc]GC(354)PauseYoung(Normal)(G1 Evacuation Pause)762M->266M(3072M)6.089ms[2026-03-07T07:24:58.229+0000][info][gc,cpu]GC(354)User=0.02s Sys=0.00s Real=0.01s[2026-03-07T07:25:00.964+0000][info][gc,start]GC(355)PauseYoung(Normal)(G1 Evacuation Pause)[2026-03-07T07:25:00.964+0000][info][gc,task]GC(355)Using4workers of4forevacuation[2026-03-07T07:25:00.970+0000][info][gc,phases]GC(355)Pre Evacuate Collection Set:0.34ms[2026-03-07T07:25:00.970+0000][info][gc,phases]GC(355)Merge Heap Roots:0.14ms[2026-03-07T07:25:00.970+0000][info][gc,phases]GC(355)Evacuate Collection Set:4.39ms[2026-03-07T07:25:00.970+0000][info][gc,phases]GC(355)Post Evacuate Collection Set:1.16ms[2026-03-07T07:25:00.970+0000][info][gc,phases]GC(355)Other:0.09ms[2026-03-07T07:25:00.970+0000][info][gc,heap]GC(355)Eden regions:124->0(124)[2026-03-07T07:25:00.970+0000][info][gc,heap]GC(355)Survivor regions:1->1(16)[2026-03-07T07:25:00.970+0000][info][gc,heap]GC(355)Old regions:61->61[2026-03-07T07:25:00.970+0000][info][gc,heap]GC(355)Humongous regions:6->6[2026-03-07T07:25:00.970+0000][info][gc,metaspace]GC(355)Metaspace:226151K(228736K)->226151K(228736K)NonClass:200227K(201344K)->200227K(201344K)Class:25924K(27392K)->25924K(27392K)

通过对比两台机器的GC日志，发现gc性能基本一致，因此排除该问题。

负载均衡排查

一般负载均衡都是用的轮训机制，所以就算有机器CPU高，也不可能一直高。
从监控来看，个人猜测是后台定时任务处理负载不均衡。比如有处理MQS消息，但是因为分片设置的比较少，只有部分服务承担消费任务。
通过top -H -p 进程号 发现top线程是都tomcat的http-nio-xx。因此可以排除上述猜测。（这里忘记截图了，所以没放图）

通过监控发现cpu高的输入流量也高，同时top命令也显示CPU高，单个线程的cpu使用率也高，同时正在执行请求的tomcat线程也多几个。从以上信息来看，应该负载均衡策略有问题。

查看ALB是否有启用Sticky Sessions（同一个会话的请求都打到一台机器上。），发现确实如此，关闭开开关后，cpu回到正常。

圈红的时间点是关闭了开关后的效果。

后记

此问题是帮隔壁项目组定位的，定位该问题并未花很长时间。上述过程有点轻描淡写，实际上是需要很多经验做支撑的。
我一开始并未怀疑是负载均衡问题，而是直接排查机器规格是否有差异。
一是因为，之前生产出过该问题。另外该系统生产环境使用的是spring cloud gateway做得负载均衡。spring cloud gateway默认的负载均衡策略是轮训，按说不应该某台机器cpu一直高。
因此排除机器差异后，就着手确认负载均衡问题。首先通过监控中的输入流量，确信确实负载不均衡。然后找了2台差异较大的docker，进去通过top命令发现，cpu高的docker单线程cpu（30%+）一直比低(11%)的高。
该现象，很像是计算量高的请求一直路由到同一台机器。
因此我使用jstack打印的线程，通过线程栈，确认瞬时处理的接口，证实上述猜测。
下图中圈红的是计算量明显大的接口，该机器cpu也是明显比另外一台高。

以上现象以我个人经验判断是，性能环境没有使用spring cloud gateway作为负载均衡，而是使用了集团的ALB做负载均衡，而且还开启了Sticky Sessions（以前集团让所有产品排查过该用户，要求大家关闭该开关，因为会导致负载不均衡）。不仅如此，猜测压测脚本同一个接口使用的是同一个账号进行压测的。
以上猜测都一一被证实。