做JAVA開發的同學一定遇到過的爆表問題，看這裡解決
**歡迎大家前往[騰訊雲+社群](https://cloud.tencent.com/developer/?fromSource=waitui)，獲取更多騰訊海量技術實踐乾貨哦~** > 本文由[淨地](https://cloud.tencent.com/developer/user/1126000?fromSource=waitui)發表於[雲+社群專欄](https://cloud.tencent.com/developer/column/3994?fromSource=waitui) > 記一次Java線上伺服器CPU過載問題的排查過程，詳解排查過程中用到的Java效能監測工具：jvisualvm、jstack、jstat、jmap。 背景：Java線上服務執行一週後，某個週六晚上CPU使用率突然持續99%，Java程序處於假死狀態，不響應請求。秉著先恢復服務再排查問題的原則，在我連線VPN採用重啟大法後，CPU使用率恢復正常，服務也正常響應了，如下圖一所示： （圖一）CPU使用率圖 但是，當晚的併發量也沒有比平時高出許多，為什麼會突然出現這種CPU爆表的情況？帶著這個疑問，我走上了問題排查的道路。 首先，我查了相關的錯誤日誌，發現故障的時間段內有大量的ckv請求超時，但請求超時並不是ckv server的問題，而是ckv client的請求並沒有發出去。那麼，為什麼ckv client的請求沒有發出去呢？日誌並沒有提供更多的資訊給我。 於是，我在Java服務上開啟了JMX，本地採用jvisualvm來觀察Java程序執行時的堆疊記憶體、執行緒使用情況。JMX（Java Management Extensions，即Java管理擴充套件）是Java平臺上為應用程式、裝置、系統等植入管理功能的框架；jvisualvm是JDK內建的效能分析工具，位於JDK根目錄的bin資料夾下面，它可以通過JMX從Java程式獲取執行時的實時資料，從而進行動態的效能分析，如圖二所示： （圖二）jvisualvm 通過觀察Heap記憶體的使用情況，發現其是緩慢增加的，每隔一小段時間被GC回收，圖形呈鋸齒狀，似乎沒有什麼問題；Threads也沒有存在死鎖的問題，執行緒執行良好；在Sampler檢視Thread CPU Time的時候發現，log4j的非同步日誌執行緒佔用的CPU時間是最多的。於是，初步懷疑這是log4j的鍋。接著，我對專案程式碼進行了review，發現某些介面列印了大量的無用日誌，日誌級別使用也不規範。最後，我對專案的日誌進行了整體的梳理，優化後釋出上線，並繼續觀察。 我本以為問題已經解決了。然而，幾天後又出現了CPU爆表的情況，這時，我才發現自己錯怪了log4j。與上次爆表的情況不同，這次我在公司（表示很淡定），於是我機智地保留了一臺機器來做觀察，其他機器做重啟處理。現在，要開始我的表演了，具體如下： （1）登陸機器，用 top 命令檢視程序資源佔用情況。不出所料，Java程序把CPU撐爆了，如下圖三所示： （圖三）程序資源佔用情況 （2）Java程序把CPU都佔用完了，那麼具體是程序內的哪些執行緒佔用的呢？於是，我用了 top -H -p6902 （6902是Java程序的PID）命令找出了具體的執行緒資源佔用情況，如下圖四所示： （圖四）Java執行緒資源佔用情況 圖四中的PID為Java執行緒的id，可以看到id為6904、6905、6906、6907這四個執行緒基本把CPU資源全部吃完了。 （3）現在，我們已經拿到耗盡CPU資源的執行緒id了。這時，我們就可以使用jstack來查詢這些id對應的具體執行緒堆疊資訊了。jstack是JDK內建的堆疊跟蹤工具，位於JDK根目錄的bin資料夾下面，可用於列印的Java堆疊資訊。我用命令 jstack 6902 > jstack.txt （6902是Java程序的PID）打印出了Java程序的堆疊資訊放到jstack.txt檔案了；由於堆疊列印的執行緒的native id是十六機制的，所以，我把十進位制的執行緒id（6904、6905、6906、6907）轉化成十六進位制（0x1af8、0x1af9、0x1afa、0x1afb）；最後，通過 cat jstack.txt| grep -C 20 0x1af8 命令找到了具體的執行緒資訊，如下圖五所示： （圖五）執行緒堆疊資訊 通過圖五可以發現，把CPU佔滿的執行緒是GC的執行緒，Java的垃圾回收把CPU的資源耗盡了。 （4）現在，我們已經定位到是GC的問題了。那麼，我們就來看看GC的回收情況，我們可以通過jstat來觀察。jstat是JDK內建的JVM檢測統計工具，位於JDK根目錄的bin資料夾下面，可以對堆記憶體的使用情況進行實時統計。我使用了命令 jstat -gcutil 6902 2000 10 （6902是Java程序的PID）來觀察GC的執行資訊，如下圖六所示： （圖六）GC執行資訊 通過圖六可以知道，E（Eden區）跟O（Old區）的記憶體已經被耗盡了，FGC（Full GC）的次數高達6989次，FGCT（Full GC Time）的時間高達36453秒，即平均每次FGC的時間為：36453/6989 ≈ 5.21秒。也就是說，Java程序都把時間花在GC上了，所以就沒有時間來處理其他事情。 （5）GC出現圖六的這種情況，基本可以確認是在程式中存在記憶體洩露的問題。那麼，如何確定是哪些程式碼導致的這個問題呢？這時候，我們就可以使用jmap檢視Java的記憶體佔用資訊。jmap是JDK內建的記憶體對映工具，位於JDK根目錄的bin資料夾下面，可用於獲取java程序的記憶體對映資訊。通過命令 jmap -histo 6902 （6902是Java程序的PID）打印出了Java的記憶體佔用資訊，如下圖七所示： （圖七）Java記憶體佔用資訊 由圖七可以得到，佔用記憶體資源的TOP10類（[C 是指char[]，String類內部使用char[]來儲存資料）的名稱、例項數以及佔用記憶體大小（單位：byte），於是問題排查就變得非常簡單了。最後，通過review程式碼確定了問題所在： 1.部分介面使用到了L5QOSPacket這個L5的工具類沒有做單例，每次請求介面都會生成一個新的例項，浪費了大量的記憶體。 2. 程式碼裡邊用到的一個第三方提供的QcClient客戶端存在記憶體洩露問題，程式碼中不恰當地new了大量的物件，而且對儲存在ConcurrentHashMap的資料沒有做清除清理，從而導致資料一直累計，記憶體佔用持續增加。 解決以上兩個問題後，Heap記憶體的佔用維持在2.5G左右，已經沒有持續增長的跡象了，業務已正常執行。 以上就是我排查問題的整個過程，以及在這個過程中用到的一些Java效能監測工具。除了本文提及的jvisualvm、jstack、jstat、jmap這些工具，在JDK根目錄的bin資料夾下面還有其他許多非常有用的工具，例如：使用 jinfo 檢視Java程序相關資訊，感興趣的童鞋可以去研究下。 > **相關閱讀** > > [WCF系列教程之WCF服務配置](https://cloud.tencent.com/developer/article/1029542?fromSource=waitui) > > [php非同步執行](https://cloud.tencent.com/developer/article/1054820?fromSource=waitui) > > [黑客用Python：檢測並繞過Web應用程式防火牆](https://cloud.tencent.com/developer/article/1189214?fromSource=waitui) > > [【每日課程推薦】機器學習實戰！快速入門線上廣告業務及CTR相應知識](https://cloud.tencent.com/developer/edu/course-1128?fromSource=waitui) **此文已由作者授權騰訊雲+社群釋出，更多原文請[點選](https://cloud.tencent.com/developer/article/1158981?fromSource=waitui )** **搜尋關注公眾號「雲加社群」，第一時間獲取技術乾貨，關注後回覆1024 送你一份技術課程大禮包！** 海量技術實踐經驗，盡在[雲加社群](https://cloud.tencent.com/developer?fromSource=waitui)！