文章首先介绍了在开发过程中遇到Java进程CPU占用率过高的问题,并指出预发机器的使用情况与资源占用情况不符合预期。
通过查看进程中的线程资源占用情况,锁定高CPU占用的线程,并通过获取线程堆栈信息找到了问题的根源,即LoguUtil的255行存在一个死循环,并且调用了不合适的poll()方法。
通过对问题代码的修改和重新部署,验证了问题的解决方案,即修正了死循环的问题,使得Java进程的CPU占用恢复正常。
文章最后强调了开发需求时除了功能完整性验证外,还需注意性能影响的重要性,及时发现并解决问题。
本文记录了一次Java进程CPU占用率过高的问题和排查思路。
开发的时候登录OSS控制台预发机器,发现Java进程CPU占用率其高,按道理预发机器只是内部开发及产品会使用,根本不可能占用这么大的资源,第一反应就是,进程在某个地方死循环了。
猜测归猜测,还是要用事实说话。
第一步:top -Hp 15057 查看下进程中的线程资源占用情况
由上图可见,CPU时间片主要是被15393 这个线程给吃掉了, 所以目标锁定在 15393。
执行 printf "%x\n" 15393,计算出线程ID对应的16进制。
第二步:执行 sudo -u www jstack 15057,获取当前进程中各线程的调用栈
对比之前计算出来的二进制id:3c21,找到占用CPU资源最高的线程堆栈,如上图所示。
看样子是在LoguUtil的255行出了问题,赶紧定位到这一行看看:
这里写了一个死循环,并在255行调用了阻塞队列的poll(),很明显,方法调用错了,poll()在队列会空的时候会直接返回null,并不会阻塞等待,所以造成进程一直在这儿死循环。
那么为什么测试的时候没有发现呢?因为只要有日志,代码很难走到255行,之所以能发现这个问题,是因为我登录机器这段时间是在深夜,刚好没有日志。
将代码修改提交部署后,在登录机器看看CPU占用情况:
此时Java进程的CPU占用已经恢复正常了。
平时开发需求,除了验证基本的功能完整性之外,一定要注意对性能的影响,及时发现并解决问题。