本文将对Java线程栈分析中,CPU利用率持续升高这一常见场景进行分析。
异常现象
某日接到业务同学反馈异常如下:
1.业务放量过程中,cpu持续升高,不清楚具体的原因。
2.系统代码主要在等待下游返回结果,本地并没有复杂的处理逻辑。
线程栈分析
业务同学保留了现场的jstack log(线程栈日志)。上传线程栈日志并通过ATP线程栈分析。打开方法热度视图,它会聚合出那一刻Java进程内所有线程调用方法的热度信息:
火焰图显示共 1,085 个线程,其中占比最大的调用栈为 ThreadPoolExecutor.getTask → LinkedBlockingQueue.take → LockSupport.park,表明大部分线程处于线程池等待任务的阻塞状态,右侧较小的分支对应实际执行业务的热点方法。
选择最热的方法(即最深的那条柱)。
根据方法名可以看出最热的方法是反序列化,序列化过程中会使用URLClassLoader加载类:
Hessian2Input.readObject();
...
ClassLoader.loadClass();
URLClassLoader.loadClass();
URLClassPath.getResource();
URLClassPath.getNextLoader();
URLClassPath.getLoader();URLClassLoader里面有个ucp(URLClassPath),它记录了当前URLClassLoader类加载器加载了哪些jar包,在类加载过程中,它会遍历所有jar包,然后逐个打开jar包并查找里面是否存在期望的类。再结合业务同学的反馈,大概有500多个jar包,所以根据线程栈分析得出的初步猜测是:在反序列化过程中遇到未加载的类,然后触发URLClassLoader从500多个jar包中遍历查找类,这个查找过程导致了CPU利用率持续升高。
根据上述的栈名称,我们从jstack log中找到对应线程:
该线程为 SOFA-SEV-BOLT-BIZ-12199-19-T256(nid=4675, jid=1068),状态为 RUNNABLE。
可以看到类加载过程中有三个地方加锁了,查看这些锁:
在同步器 Tab 中可以看到一条同步器记录:地址 0x71723a000,对象 java.lang.Object,状态 LOCKED:1,持有该锁的线程名为 SOFA-SEV-BOLT-BIZ-12199-19-T256(jid=1068),线程状态为 RUNNABLE。
会发现实际上有两把锁,其中一个被递归加锁,更重要的是锁的持有者都是1068线程,另外没有其他线程在等待该锁,说明锁没有竞争,类查找过程仅1068一个线程在进行。
分析结论
所以我们可以更进一步得知,只有一个线程在执行高频的jar包遍历寻找类操作。根据这个猜测的结论,只要类找到,或者说反序列化结束,CPU利用率就应该会下降。和业务同学反馈后得知,序列化在持续进行。这也验证了我们的猜测,因为只有反序列化在持续进行,CPU利用率才会持续上涨。
将这个猜测反馈给业务同学,他们从日志中发现,确实是因为有个类一直找不到,然后每次都在反序列化的时候再重新找,找不到也只会打个日志。到此,分析基本就结束了,剩下的工作是业务同学优化代码,解决该类找不到的问题。
common-error.log: 2023-01-31 00:06:36,079 ERROR SOFA-SEV-BOLT-BIZ-12199-17-T239 - RPC-020050006: [com.alipay.sofa.rpc.codec.sofahessian.MultipleClassLoaderSofaSerializerFactory]: 反序列化时无法找到[com.alipay.ucdp.sdk.model.Template]类,ClassLoader为[org.springframework.boot.loader.LaunchedURLClassLoader@6fa2448b]
common-error.log: 2023-01-31 00:06:36,080 ERROR SOFA-SEV-BOLT-BIZ-12199-17-T239 - RPC-020050006: [com.alipay.sofa.rpc.codec.sofahessian.MultipleClassLoaderSofaSerializerFactory]: 反序列化时无法找到[com.alipay.ucdp.sdk.model.Template]类,ClassLoader为[org.springframework.boot.loader.LaunchedURLClassLoader@6fa2448b]
common-error.log: 2023-01-31 00:06:36,082 ERROR SOFA-SEV-BOLT-BIZ-12199-17-T239 - RPC-020050006: [com.alipay.sofa.rpc.codec.sofahessian.MultipleClassLoaderSofaSerializerFactory]: 反序列化时无法找到[com.alipay.ucdp.sdk.model.Template]类,ClassLoader为[org.springframework.boot.loader.LaunchedURLClassLoader@6fa2448b]