java排查一個(gè)線上死循環(huán)cpu暴漲的過(guò)程分析
問(wèn)題，打一個(gè)頁(yè)面cpu暴漲，打開(kāi)一次就漲100%,一會(huì)系統(tǒng)就卡的不行了。
排查方法，因?yàn)槭蔷€上的linux,沒(méi)有用jvm監(jiān)控工具rim鏈接上去。
只好用命令排查：
top cpu排序，一個(gè)java進(jìn)程cpu到500%了，什么鬼.....
查到對(duì)應(yīng)java進(jìn)程
jps || ps -aux | grep 端口
pid=13455
查看進(jìn)程中線程使用情況 T排序 查看cpu占用time最高的線程編號(hào)
top -Hp 13455
有個(gè)線程9877 的時(shí)間一直在爆漲
獲取線程十六進(jìn)制地址9877 （十六進(jìn)制一定要小寫）
printf "%x\n" 9877
執(zhí)行 jstack 13455|grep -10 2695（線程十六進(jìn)制號(hào)）
如果想查看完整信息，可導(dǎo)出文本，查找
jstack -l 9839 > jstack.log-9893
"qtp750044075-25" #25 prio=5 os_prio=0 tid=0x00007f83354e5000 nid=0x2695 runnable [0x00007f830e5d8000] java.lang.Thread.State: RUNNABLE at java.text.DateFormatSymbols.<init>(DateFormatSymbols.java:145) at sun.util.locale.provider.DateFormatSymbolsProviderImpl.getInstance(DateFormatSymbolsProviderImpl.java:85) at java.text.DateFormatSymbols.getProviderInstance(DateFormatSymbols.java:364) at java.text.DateFormatSymbols.getInstance(DateFormatSymbols.java:340) at java.util.Calendar.getDisplayName(Calendar.java:2110) at java.text.SimpleDateFormat.subFormat(SimpleDateFormat.java:1125) at java.text.SimpleDateFormat.format(SimpleDateFormat.java:966) at java.text.SimpleDateFormat.format(SimpleDateFormat.java:936) at java.text.DateFormat.format(DateFormat.java:345) at com.huiwan.gdata.modules.gdata.util.TimeUtil.getDay(TimeUtil.java:383) at com.huiwan.gdata.modules.gdata.publ.retain.service.impl.Retain3ServiceImpl.act(Retain3ServiceImpl.java:119) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) .......略 Locked ownable synchronizers: - None
定住到
Retain3ServiceImpl.java:119
這行，馬的，有人寫了個(gè)while循環(huán)，用字符串時(shí)間比較，之前表是date類型，后改為datetime類型，多了00:00:00永遠(yuǎn)也沒(méi)一樣的時(shí)間，一直在那while.....還搞了個(gè)json對(duì)象默認(rèn)加0......
改了這里的代碼，就好了，cpu就沒(méi)上去了.
補(bǔ)充知識(shí)：記一次線上Java程序?qū)е路?wù)器CPU占用率過(guò)高的問(wèn)題排除過(guò)程
1、故障現(xiàn)象
客服同事反饋平臺(tái)系統(tǒng)運(yùn)行緩慢，網(wǎng)頁(yè)卡頓嚴(yán)重，多次重啟系統(tǒng)后問(wèn)題依然存在，使用top命令查看服務(wù)器情況，發(fā)現(xiàn)CPU占用率過(guò)高。
2、CPU占用過(guò)高問(wèn)題定位
2.1、定位問(wèn)題進(jìn)程
使用top命令查看資源占用情況，發(fā)現(xiàn)pid為14063的進(jìn)程占用了大量的CPU資源，CPU占用率高達(dá)776.1%，內(nèi)存占用率也達(dá)到了29.8%
[ylp@ylp-web-01 ~]$ top top - 14:51:10 up 233 days, 11:40, 7 users, load average: 6.85, 5.62, 3.97 Tasks: 192 total, 2 running, 190 sleeping, 0 stopped, 0 zombie %Cpu(s): 97.3 us, 0.3 sy, 0.0 ni, 2.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem : 16268652 total, 5114392 free, 6907028 used, 4247232 buff/cache KiB Swap: 4063228 total, 3989708 free, 73520 used. 8751512 avail Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 14063 ylp 20 0 9260488 4.627g 11976 S 776.1 29.8 117:41.66 java
2.2、定位問(wèn)題線程
使用ps -mp pid -o THREAD,tid,time命令查看該進(jìn)程的線程情況，發(fā)現(xiàn)該進(jìn)程的多個(gè)線程占用率很高
[ylp@ylp-web-01 ~]$ ps -mp 14063 -o THREAD,tid,time USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME ylp 361 - - - - - - 02:05:58 ylp 0.0 19 - futex_ - - 14063 00:00:00 ylp 0.0 19 - poll_s - - 14064 00:00:00 ylp 44.5 19 - - - - 14065 00:15:30 ylp 44.5 19 - - - - 14066 00:15:30 ylp 44.4 19 - - - - 14067 00:15:29 ylp 44.5 19 - - - - 14068 00:15:30 ylp 44.5 19 - - - - 14069 00:15:30 ylp 44.5 19 - - - - 14070 00:15:30 ylp 44.5 19 - - - - 14071 00:15:30 ylp 44.6 19 - - - - 14072 00:15:32 ylp 2.2 19 - futex_ - - 14073 00:00:46 ylp 0.0 19 - futex_ - - 14074 00:00:00 ylp 0.0 19 - futex_ - - 14075 00:00:00 ylp 0.0 19 - futex_ - - 14076 00:00:00 ylp 0.7 19 - futex_ - - 14077 00:00:15
從輸出信息可以看出，14065~14072之間的線程CPU占用率都很高
2.3、查看問(wèn)題線程堆棧
挑選TID為14065的線程，查看該線程的堆棧情況，先將線程id轉(zhuǎn)為16進(jìn)制，使用printf "%x\n" tid命令進(jìn)行轉(zhuǎn)換
[ylp@ylp-web-01 ~]$ printf "%x\n" 14065
36f1
再使用jstack命令打印線程堆棧信息，命令格式：jstack pid |grep tid -A 30
[ylp@ylp-web-01 ~]$ jstack 14063 |grep 36f1 -A 30 "GC task thread#0 (ParallelGC)" prio=10 tid=0x00007fa35001e800 nid=0x36f1 runnable "GC task thread#1 (ParallelGC)" prio=10 tid=0x00007fa350020800 nid=0x36f2 runnable "GC task thread#2 (ParallelGC)" prio=10 tid=0x00007fa350022800 nid=0x36f3 runnable "GC task thread#3 (ParallelGC)" prio=10 tid=0x00007fa350024000 nid=0x36f4 runnable "GC task thread#4 (ParallelGC)" prio=10 tid=0x00007fa350026000 nid=0x36f5 runnable "GC task thread#5 (ParallelGC)" prio=10 tid=0x00007fa350028000 nid=0x36f6 runnable "GC task thread#6 (ParallelGC)" prio=10 tid=0x00007fa350029800 nid=0x36f7 runnable "GC task thread#7 (ParallelGC)" prio=10 tid=0x00007fa35002b800 nid=0x36f8 runnable "VM Periodic Task Thread" prio=10 tid=0x00007fa3500a8800 nid=0x3700 waiting on condition JNI global references: 392
從輸出信息可以看出，此線程是JVM的gc線程。此時(shí)可以基本確定是內(nèi)存不足或內(nèi)存泄露導(dǎo)致gc線程持續(xù)運(yùn)行，導(dǎo)致CPU占用過(guò)高。
所以接下來(lái)我們要找的內(nèi)存方面的問(wèn)題
3、內(nèi)存問(wèn)題定位
3.1、使用jstat -gcutil命令查看進(jìn)程的內(nèi)存情況
[ylp@ylp-web-01 ~]$ jstat -gcutil 14063 2000 10 S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 0.00 100.00 99.99 26.31 42 21.917 218 1484.830 1506.747 0.00 0.00 100.00 99.99 26.31 42 21.917 218 1484.830 1506.747 0.00 0.00 100.00 99.99 26.31 42 21.917 219 1496.567 1518.484 0.00 0.00 100.00 99.99 26.31 42 21.917 219 1496.567 1518.484 0.00 0.00 100.00 99.99 26.31 42 21.917 219 1496.567 1518.484 0.00 0.00 100.00 99.99 26.31 42 21.917 219 1496.567 1518.484 0.00 0.00 100.00 99.99 26.31 42 21.917 219 1496.567 1518.484 0.00 0.00 100.00 99.99 26.31 42 21.917 220 1505.439 1527.355 0.00 0.00 100.00 99.99 26.31 42 21.917 220 1505.439 1527.355 0.00 0.00 100.00 99.99 26.31 42 21.917 220 1505.439 1527.355
從輸出信息可以看出，Eden區(qū)內(nèi)存占用100%，Old區(qū)內(nèi)存占用99.99%，F(xiàn)ull GC的次數(shù)高達(dá)220次，并且頻繁Full GC，F(xiàn)ull GC的持續(xù)時(shí)間也特別長(zhǎng)，平均每次Full GC耗時(shí)6.8秒（1505.439/220）。根據(jù)這些信息，基本可以確定是程序代碼上出現(xiàn)了問(wèn)題，可能存在不合理創(chuàng)建對(duì)象的地方
3.2、分析堆棧
使用jstack命令查看進(jìn)程的堆棧情況
[ylp@ylp-web-01 ~]$ jstack 14063 >>jstack.out
把jstack.out文件從服務(wù)器拿到本地后，用編輯器查找?guī)в许?xiàng)目目錄并且線程狀態(tài)是RUNABLE的相關(guān)信息，從圖中可以看出ActivityUtil.java類的447行正在使用HashMap.put()方法
3.3、代碼定位
打開(kāi)項(xiàng)目工程，找到ActivityUtil類的477行，代碼如下：
找到相關(guān)同事了解后，這段代碼會(huì)從數(shù)據(jù)庫(kù)中獲取配置，并根據(jù)數(shù)據(jù)庫(kù)中remain的值進(jìn)行循環(huán)，在循環(huán)中會(huì)一直對(duì)HashMap進(jìn)行put操作。
查詢數(shù)據(jù)庫(kù)中的配置，發(fā)現(xiàn)remain的數(shù)量巨大
至此，問(wèn)題定位完畢。
以上這篇java排查一個(gè)線上死循環(huán)cpu暴漲的過(guò)程分析就是小編分享給大家的全部?jī)?nèi)容了，希望能給大家一個(gè)參考，也希望大家多多支持腳本之家。
相關(guān)文章
JAVA解決在@autowired,@Resource注入為null的情況
這篇文章主要介紹了JAVA解決在@autowired,@Resource注入為null的情況，具有很好的參考價(jià)值，希望對(duì)大家有所幫助。一起跟隨小編過(guò)來(lái)看看吧2020-10-10
這篇文章主要介紹了SpringCloud Stream介紹,本文通過(guò)實(shí)例代碼給大家介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值，需要的朋友可以參考下2021-03-03
這篇文章主要介紹了Flowable流程引擎API與服務(wù),引擎API是與Flowable交互的最常用手段,總?cè)肟邳c(diǎn)是ProcessEngine,使用ProcessEngine,可以獲得各種提供工作流或BPM方法的服務(wù),下面我們來(lái)詳細(xì)了解2023-10-10
今天小編就為大家分享一篇關(guān)于JAVA JDK8 List獲取屬性列表，小編覺(jué)得內(nèi)容挺不錯(cuò)的，現(xiàn)在分享給大家，具有很好的參考價(jià)值，需要的朋友一起跟隨小編來(lái)看看吧2018-12-12
springboot+hutool批量生成二維碼壓縮導(dǎo)出功能
這篇文章主要介紹了springboot+hutool批量生成二維碼壓縮導(dǎo)出功能,本文通過(guò)實(shí)例代碼給大家介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值，需要的朋友可以參考下2021-10-10
深入淺析Java中普通代碼塊、構(gòu)造代碼塊與靜態(tài)代碼塊
這篇文章主要介紹了Java中普通代碼塊、構(gòu)造代碼塊與靜態(tài)代碼塊的相關(guān)資料,靜態(tài)代碼塊>Main()>構(gòu)造代碼塊 。非常不錯(cuò)，具有參考借鑒價(jià)值，需要的朋友可以參考下2016-08-08
SpringBoot Import及自定義裝配實(shí)現(xiàn)方法解析
這篇文章主要介紹了SpringBoot Import及自定義裝配實(shí)現(xiàn)方法解析,文中通過(guò)示例代碼介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友可以參考下2020-08-08
springMVC 用戶登錄權(quán)限驗(yàn)證實(shí)現(xiàn)過(guò)程解析
這篇文章主要介紹了springMVC 用戶登錄權(quán)限驗(yàn)證實(shí)現(xiàn)過(guò)程解析,文中通過(guò)示例代碼介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友可以參考下2019-11-11
java保證一個(gè)方法只能執(zhí)行一次的問(wèn)題
這篇文章主要介紹了java保證一個(gè)方法只能執(zhí)行一次的問(wèn)題,具有很好的參考價(jià)值,希望對(duì)大家有所幫助,如有錯(cuò)誤或未考慮完全的地方,望不吝賜教2023-08-08
Java8如何將Array轉(zhuǎn)換為Stream的實(shí)現(xiàn)代碼
這篇文章主要介紹了Java8如何將Array轉(zhuǎn)換為Stream的實(shí)現(xiàn)代碼，文中通過(guò)示例代碼介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，需要的朋友們下面隨著小編來(lái)一起學(xué)習(xí)學(xué)習(xí)吧2019-09-09