java排查一个线上死循环cpu暴涨的过程分析
问题，打一个页面cpu暴涨，打开一次就涨100%,一会系统就卡的不行了。
排查方法，因为是线上的linux,没有用jvm监控工具rim链接上去。
只好用命令排查：
topcpu排序，一个java进程cpu到500%了，什么鬼.....
查到对应java进程
jps||ps-aux|grep端口
pid=13455
查看进程中线程使用情况T排序查看cpu占用time最高的线程编号
top-Hp13455
有个线程9877的时间一直在爆涨
获取线程十六进制地址9877（十六进制一定要小写）
printf"%x\n"9877
执行jstack13455|grep-102695（线程十六进制号）
如果想查看完整信息，可导出文本，查找
jstack-l9839>jstack.log-9893
"qtp750044075-25"#25prio=5os_prio=0tid=0x00007f83354e5000nid=0x2695runnable[0x00007f830e5d8000] java.lang.Thread.State:RUNNABLE atjava.text.DateFormatSymbols.(DateFormatSymbols.java:145) atsun.util.locale.provider.DateFormatSymbolsProviderImpl.getInstance(DateFormatSymbolsProviderImpl.java:85) atjava.text.DateFormatSymbols.getProviderInstance(DateFormatSymbols.java:364) atjava.text.DateFormatSymbols.getInstance(DateFormatSymbols.java:340) atjava.util.Calendar.getDisplayName(Calendar.java:2110) atjava.text.SimpleDateFormat.subFormat(SimpleDateFormat.java:1125) atjava.text.SimpleDateFormat.format(SimpleDateFormat.java:966) atjava.text.SimpleDateFormat.format(SimpleDateFormat.java:936) atjava.text.DateFormat.format(DateFormat.java:345) atcom.huiwan.gdata.modules.gdata.util.TimeUtil.getDay(TimeUtil.java:383) atcom.huiwan.gdata.modules.gdata.publ.retain.service.impl.Retain3ServiceImpl.act(Retain3ServiceImpl.java:119) atsun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethod) atsun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) atsun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) atjava.lang.reflect.Method.invoke(Method.java:498) atorg.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) .......略 Lockedownablesynchronizers: -None
定住到
Retain3ServiceImpl.java:119
这行，马的，有人写了个while循环，用字符串时间比较，之前表是date类型，后改为datetime类型，多了00:00:00永远也没一样的时间，一直在那while.....还搞了个json对象默认加0......
改了这里的代码，就好了，cpu就没上去了.
补充知识：记一次线上Java程序导致服务器CPU占用率过高的问题排除过程
1、故障现象
客服同事反馈平台系统运行缓慢，网页卡顿严重，多次重启系统后问题依然存在，使用top命令查看服务器情况，发现CPU占用率过高。
2、CPU占用过高问题定位
2.1、定位问题进程
使用top命令查看资源占用情况，发现pid为14063的进程占用了大量的CPU资源，CPU占用率高达776.1%，内存占用率也达到了29.8%
[ylp@ylp-web-01~]$top top-14:51:10up233days,11:40,7users,loadaverage:6.85,5.62,3.97 Tasks:192total,2running,190sleeping,0stopped,0zombie %Cpu(s):97.3us,0.3sy,0.0ni,2.5id,0.0wa,0.0hi,0.0si,0.0st KiBMem:16268652total,5114392free,6907028used,4247232buff/cache KiBSwap:4063228total,3989708free,73520used.8751512availMem PIDUSERPRNIVIRTRESSHRS%CPU%MEMTIME+COMMAND 14063ylp20092604884.627g11976S776.129.8117:41.66java
2.2、定位问题线程
使用ps-mppid-oTHREAD,tid,time命令查看该进程的线程情况，发现该进程的多个线程占用率很高
[ylp@ylp-web-01~]$ps-mp14063-oTHREAD,tid,time USER%CPUPRISCNTWCHANUSERSYSTEMTIDTIME ylp361------02:05:58 ylp0.019-futex_--1406300:00:00 ylp0.019-poll_s--1406400:00:00 ylp44.519----1406500:15:30 ylp44.519----1406600:15:30 ylp44.419----1406700:15:29 ylp44.519----1406800:15:30 ylp44.519----1406900:15:30 ylp44.519----1407000:15:30 ylp44.519----1407100:15:30 ylp44.619----1407200:15:32 ylp2.219-futex_--1407300:00:46 ylp0.019-futex_--1407400:00:00 ylp0.019-futex_--1407500:00:00 ylp0.019-futex_--1407600:00:00 ylp0.719-futex_--1407700:00:15
从输出信息可以看出，14065~14072之间的线程CPU占用率都很高
2.3、查看问题线程堆栈
挑选TID为14065的线程，查看该线程的堆栈情况，先将线程id转为16进制，使用printf"%x\n"tid命令进行转换
[ylp@ylp-web-01~]$printf"%x\n"14065
36f1
再使用jstack命令打印线程堆栈信息，命令格式：jstackpid|greptid-A30
[ylp@ylp-web-01~]$jstack14063|grep36f1-A30 "GCtaskthread#0(ParallelGC)"prio=10tid=0x00007fa35001e800nid=0x36f1runnable "GCtaskthread#1(ParallelGC)"prio=10tid=0x00007fa350020800nid=0x36f2runnable "GCtaskthread#2(ParallelGC)"prio=10tid=0x00007fa350022800nid=0x36f3runnable "GCtaskthread#3(ParallelGC)"prio=10tid=0x00007fa350024000nid=0x36f4runnable "GCtaskthread#4(ParallelGC)"prio=10tid=0x00007fa350026000nid=0x36f5runnable "GCtaskthread#5(ParallelGC)"prio=10tid=0x00007fa350028000nid=0x36f6runnable "GCtaskthread#6(ParallelGC)"prio=10tid=0x00007fa350029800nid=0x36f7runnable "GCtaskthread#7(ParallelGC)"prio=10tid=0x00007fa35002b800nid=0x36f8runnable "VMPeriodicTaskThread"prio=10tid=0x00007fa3500a8800nid=0x3700waitingoncondition JNIglobalreferences:392
从输出信息可以看出，此线程是JVM的gc线程。此时可以基本确定是内存不足或内存泄露导致gc线程持续运行，导致CPU占用过高。
所以接下来我们要找的内存方面的问题
3、内存问题定位
3.1、使用jstat-gcutil命令查看进程的内存情况
[ylp@ylp-web-01~]$jstat-gcutil14063200010 S0S1EOPYGCYGCTFGCFGCTGCT 0.000.00100.0099.9926.314221.9172181484.8301506.747 0.000.00100.0099.9926.314221.9172181484.8301506.747 0.000.00100.0099.9926.314221.9172191496.5671518.484 0.000.00100.0099.9926.314221.9172191496.5671518.484 0.000.00100.0099.9926.314221.9172191496.5671518.484 0.000.00100.0099.9926.314221.9172191496.5671518.484 0.000.00100.0099.9926.314221.9172191496.5671518.484 0.000.00100.0099.9926.314221.9172201505.4391527.355 0.000.00100.0099.9926.314221.9172201505.4391527.355 0.000.00100.0099.9926.314221.9172201505.4391527.355
从输出信息可以看出，Eden区内存占用100%，Old区内存占用99.99%，FullGC的次数高达220次，并且频繁FullGC，FullGC的持续时间也特别长，平均每次FullGC耗时6.8秒（1505.439/220）。根据这些信息，基本可以确定是程序代码上出现了问题，可能存在不合理创建对象的地方
3.2、分析堆栈
使用jstack命令查看进程的堆栈情况
[ylp@ylp-web-01~]$jstack14063>>jstack.out
把jstack.out文件从服务器拿到本地后，用编辑器查找带有项目目录并且线程状态是RUNABLE的相关信息，从图中可以看出ActivityUtil.java类的447行正在使用HashMap.put()方法
3.3、代码定位
打开项目工程，找到ActivityUtil类的477行，代码如下：
找到相关同事了解后，这段代码会从数据库中获取配置，并根据数据库中remain的值进行循环，在循环中会一直对HashMap进行put操作。
查询数据库中的配置，发现remain的数量巨大
至此，问题定位完毕。
以上这篇java排查一个线上死循环cpu暴涨的过程分析就是小编分享给大家的全部内容了，希望能给大家一个参考，也希望大家多多支持毛票票。
声明：本文内容来源于网络，版权归原作者所有，内容由互联网用户自发贡献自行上传，本网站不拥有所有权，未作人工编辑处理，也不承担相关法律责任。如果您发现有涉嫌版权的内容，欢迎发送邮件至：czq8825#qq.com（发邮件时，请将#更换为@）进行举报，并提供相关证据，一经查实，本站将立刻删除涉嫌侵权内容。