6 个 Java 工具,轻松分析定位 JVM 问题!
你可能一開始會比較畏懼使用復雜的工具去排查問題,又或者是打開了工具感覺無從下手,但是隨著實踐越來越多,對 Java 程序和各種框架的運作越來越熟悉,你會發現使用這些工具越來越順手。
這篇文章中介紹下如何使用?JDK?自帶工具來分析和定位 Java 程序的問題。
使用 JDK 自帶工具查看 JVM 情況
JDK 自帶了很多命令行甚至是圖形界面工具,幫助我們查看 JVM 的一些信息。比如,在我的機器上運行?ls?命令,可以看到 JDK 8 提供了非常多的工具或程序:
接下來,我會與你介紹些常用的監控工具。你也可以先通過下面這張圖了解下各種工具的基本作用:
為了測試這些工具,我們先來寫一段代碼:啟動 10 個死循環的線程,每個線程分配一個 10MB 左右的字符串,然后休眠 10 秒。可以想象到,這個程序會對 GC 造成壓力:
//啟動10個線程 IntStream.rangeClosed(1,?10).mapToObj(i?->?new?Thread(()?->?{while?(true)?{//每一個線程都是一個死循環,休眠10秒,打印10M數據String?payload?=?IntStream.rangeClosed(1,?10000000).mapToObj(__?->?"a").collect(Collectors.joining(""))?+?UUID.randomUUID().toString();try?{TimeUnit.SECONDS.sleep(10);}?catch?(InterruptedException?e)?{e.printStackTrace();}System.out.println(payload.length());} })).forEach(Thread::start);TimeUnit.HOURS.sleep(1);修改 pom.xml,配置 spring-boot-maven-plugin 插件打包的 Java 程序的 main 方法類:
<plugin><groupId>org.springframework.boot</groupId><artifactId>spring-boot-maven-plugin</artifactId><configuration><mainClass>org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication</mainClass></configuration> </plugin>然后使用 java -jar 啟動進程,設置 JVM 參數,讓堆最小最大都是 1GB:
java?-jar?common-mistakes-0.0.1-SNAPSHOT.jar?-Xms1g?-Xmx1g完成這些準備工作后,我們就可以使用 JDK 提供的工具,來觀察分析這個測試程序了。
jps
首先,使用 jps 得到 Java 進程列表,這會比使用 ps 來的方便:
???~?jps 12707 22261?Launcher 23864?common-mistakes-0.0.1-SNAPSHOT.jar 15608?RemoteMavenServer36 23243?Main 23868?Jps 22893?KotlinCompileDaemonjinfo
然后,可以使用 jinfo 打印 JVM 的各種參數:
???~?jinfo?23864 Java?System?Properties: #Wed?Jan?29?12:49:47?CST?2020 ... user.name=zhuye path.separator=\: os.version=10.15.2 java.runtime.name=Java(TM)?SE?Runtime?Environment file.encoding=UTF-8 java.vm.name=Java?HotSpot(TM)?64-Bit?Server?VM ...VM?Flags: -XX:CICompilerCount=4?-XX:ConcGCThreads=2?-XX:G1ConcRefinementThreads=8?-XX:G1HeapRegionSize=1048576?-XX:GCDrainStackTargetSize=64?-XX:InitialHeapSize=268435456?-XX:MarkStackSize=4194304?-XX:MaxHeapSize=4294967296?-XX:MaxNewSize=2576351232?-XX:MinHeapDeltaBytes=1048576?-XX:NonNMethodCodeHeapSize=5835340?-XX:NonProfiledCodeHeapSize=122911450?-XX:ProfiledCodeHeapSize=122911450?-XX:ReservedCodeCacheSize=251658240?-XX:+SegmentedCodeCache?-XX:+UseCompressedClassPointers?-XX:+UseCompressedOops?-XX:+UseG1GCVM?Arguments: java_command:?common-mistakes-0.0.1-SNAPSHOT.jar?-Xms1g?-Xmx1g java_class_path?(initial):?common-mistakes-0.0.1-SNAPSHOT.jar Launcher?Type:?SUN_STANDARD查看第 15 行和 19 行可以發現,我們設置 JVM 參數的方式不對,-Xms1g 和 -Xmx1g 這兩個參數被當成了 Java 程序的啟動參數,整個 JVM 目前最大內存是 4GB 左右,而不是 1GB。
因此,當我們懷疑 JVM 的配置很不正常的時候,要第一時間使用工具來確認參數。除了使用工具確認 JVM 參數外,你也可以打印 VM 參數和程序參數:
System.out.println("VM?options"); System.out.println(ManagementFactory.getRuntimeMXBean().getInputArguments().stream().collect(Collectors.joining(System.lineSeparator()))); System.out.println("Program?arguments"); System.out.println(Arrays.stream(args).collect(Collectors.joining(System.lineSeparator())));把 JVM 參數放到 -jar 之前,重新啟動程序,可以看到如下輸出,從輸出也可以確認這次 JVM 參數的配置正確了:
???target?git:(master)???java?-Xms1g?-Xmx1g?-jar?common-mistakes-0.0.1-SNAPSHOT.jar?test VM?options -Xms1g -Xmx1g Program?arguments testjvisualvm
然后,啟動另一個重量級工具 jvisualvm 觀察一下程序,可以在概述面板再次確認 JVM 參數設置成功了:
繼續觀察監視面板可以看到,JVM 的 GC 活動基本是 10 秒發生一次,堆內存在 250MB 到 900MB 之間波動,活動線程數是 22。我們可以在監視面板看到 JVM 的基本情況,也可以直接在這里進行手動 GC 和堆 Dump 操作:
jconsole如果希望看到各個內存區的 GC 曲線圖,可以使用 jconsole 觀察。jconsole 也是一個綜合性圖形界面監控工具,比 jvisualvm 更方便的一點是,可以用曲線的形式監控各種數據,包括 MBean 中的屬性值:
jstat
同樣,如果沒有條件使用圖形界面(畢竟在 Linux 服務器上,我們主要使用命令行工具),又希望看到 GC 趨勢的話,我們可以使用 jstat 工具。
jstat 工具允許以固定的監控頻次輸出 JVM 的各種監控指標,比如使用 -gcutil 輸出 GC 和內存占用匯總信息,每隔 5 秒輸出一次,輸出 100 次,可以看到 Young GC 比較頻繁,而 Full GC 基本 10 秒一次:
???~?jstat?-gcutil?23940?5000?100S0?????S1?????E??????O??????M?????CCS????YGC?????YGCT????FGC????FGCT????CGC????CGCT?????GCT0.00?100.00???0.36??87.63??94.30??81.06????539???14.021????33????3.972???837????0.976???18.9680.00?100.00???0.60??69.51??94.30??81.06????540???14.029????33????3.972???839????0.978???18.9790.00???0.00???0.50??99.81??94.27??81.03????548???14.143????34????4.002???840????0.981???19.1260.00?100.00???0.59??70.47??94.27??81.03????549???14.177????34????4.002???844????0.985???19.1640.00?100.00???0.57??99.85??94.32??81.09????550???14.204????34????4.002???845????0.990???19.1960.00?100.00???0.65??77.69??94.32??81.09????559???14.469????36????4.198???847????0.993???19.6590.00?100.00???0.65??77.69??94.32??81.09????559???14.469????36????4.198???847????0.993???19.6590.00?100.00???0.70??35.54??94.32??81.09????567???14.763????37????4.378???853????1.001???20.1420.00?100.00???0.70??41.22??94.32??81.09????567???14.763????37????4.378???853????1.001???20.1420.00?100.00???1.89??96.76??94.32??81.09????574???14.943????38????4.487???859????1.007???20.4380.00?100.00???1.39??39.20??94.32??81.09????575???14.946????38????4.487???861????1.010???20.442“其中,S0 表示 Survivor0 區占用百分比,S1 表示 Survivor1 區占用百分比,E 表示 Eden 區占用百分比,O 表示老年代占用百分比,M 表示元數據區占用百分比,YGC 表示年輕代回收次數,YGCT 表示年輕代回收耗時,FGC 表示老年代回收次數,FGCT 表示老年代回收耗時。
”jstat 命令的參數眾多,包含 -class、-compiler、-gc 等。Java 8、Linux/Unix 平臺 jstat 工具的完整介紹,你可以查看這里。jstat 定時輸出的特性,可以方便我們持續觀察程序的各項指標。
繼續來到線程面板可以看到,大量以 Thread 開頭的線程基本都是有節奏的 10 秒運行一下,其他時間都在休眠,和我們的代碼邏輯匹配:
點擊面板的線程 Dump 按鈕,可以查看線程瞬時的線程棧:
jstack
通過命令行工具 jstack,也可以實現抓取線程棧的操作:
???~?jstack?23940 2020-01-29?13:08:15 Full?thread?dump?Java?HotSpot(TM)?64-Bit?Server?VM?(11.0.3+12-LTS?mixed?mode):..."main"?#1?prio=5?os_prio=31?cpu=440.66ms?elapsed=574.86s?tid=0x00007ffdd9800000?nid=0x2803?waiting?on?condition??[0x0000700003849000]java.lang.Thread.State:?TIMED_WAITING?(sleeping)at?java.lang.Thread.sleep(java.base@11.0.3/Native?Method)at?java.lang.Thread.sleep(java.base@11.0.3/Thread.java:339)at?java.util.concurrent.TimeUnit.sleep(java.base@11.0.3/TimeUnit.java:446)at?org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.main(CommonMistakesApplication.java:41)at?jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@11.0.3/Native?Method)at?jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@11.0.3/NativeMethodAccessorImpl.java:62)at?jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@11.0.3/DelegatingMethodAccessorImpl.java:43)at?java.lang.reflect.Method.invoke(java.base@11.0.3/Method.java:566)at?org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)at?org.springframework.boot.loader.Launcher.launch(Launcher.java:87)at?org.springframework.boot.loader.Launcher.launch(Launcher.java:51)at?org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:52)"Thread-1"?#13?prio=5?os_prio=31?cpu=17851.77ms?elapsed=574.41s?tid=0x00007ffdda029000?nid=0x9803?waiting?on?condition??[0x000070000539d000]java.lang.Thread.State:?TIMED_WAITING?(sleeping)at?java.lang.Thread.sleep(java.base@11.0.3/Native?Method)at?java.lang.Thread.sleep(java.base@11.0.3/Thread.java:339)at?java.util.concurrent.TimeUnit.sleep(java.base@11.0.3/TimeUnit.java:446)at?org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication.lambda$null$1(CommonMistakesApplication.java:33)at?org.geekbang.time.commonmistakes.troubleshootingtools.jdktool.CommonMistakesApplication$$Lambda$41/0x00000008000a8c40.run(Unknown?Source)at?java.lang.Thread.run(java.base@11.0.3/Thread.java:834)...抓取后可以使用類似fastthread(https://fastthread.io/)這樣的在線分析工具來分析線程棧。
jcmd
最后,我們來看一下 Java HotSpot 虛擬機的 NMT 功能。
通過 NMT,我們可以觀察細粒度內存使用情況,設置 -XX:NativeMemoryTracking=summary/detail 可以開啟 NMT 功能,開啟后可以使用 jcmd 工具查看 NMT 數據。
我們重新啟動一次程序,這次加上 JVM 參數以 detail 方式開啟 NMT:
-Xms1g?-Xmx1g?-XX:ThreadStackSize=256k?-XX:NativeMemoryTracking=detail在這里,我們還增加了 -XX:ThreadStackSize 參數,并將其值設置為 256k,也就是期望把線程棧設置為 256KB。我們通過 NMT 觀察一下設置是否成功。
啟動程序后執行如下 jcmd 命令,以概要形式輸出 NMT 結果。可以看到,當前有 32 個線程,線程棧總共保留了差不多 4GB 左右的內存。我們明明配置線程棧最大 256KB 啊,為什么會出現 4GB 這么夸張的數字呢,到底哪里出了問題呢?
???~?jcmd?24404?VM.native_memory?summary 24404:Native?Memory?Tracking:Total:?reserved=6635310KB,?committed=5337110KB -?????????????????Java?Heap?(reserved=1048576KB,?committed=1048576KB)(mmap:?reserved=1048576KB,?committed=1048576KB)-?????????????????????Class?(reserved=1066233KB,?committed=15097KB)(classes?#902)(malloc=9465KB?#908)(mmap:?reserved=1056768KB,?committed=5632KB)-????????????????????Thread?(reserved=4209797KB,?committed=4209797KB)(thread?#32)(stack:?reserved=4209664KB,?committed=4209664KB)(malloc=96KB?#165)(arena=37KB?#59)-??????????????????????Code?(reserved=249823KB,?committed=2759KB)(malloc=223KB?#730)(mmap:?reserved=249600KB,?committed=2536KB)-????????????????????????GC?(reserved=48700KB,?committed=48700KB)(malloc=10384KB?#135)(mmap:?reserved=38316KB,?committed=38316KB)-??????????????????Compiler?(reserved=186KB,?committed=186KB)(malloc=56KB?#105)(arena=131KB?#7)-??????????????????Internal?(reserved=9693KB,?committed=9693KB)(malloc=9661KB?#2585)(mmap:?reserved=32KB,?committed=32KB)-????????????????????Symbol?(reserved=2021KB,?committed=2021KB)(malloc=1182KB?#334)(arena=839KB?#1)-????Native?Memory?Tracking?(reserved=85KB,?committed=85KB)(malloc=5KB?#53)(tracking?overhead=80KB)-???????????????Arena?Chunk?(reserved=196KB,?committed=196KB)(malloc=196KB)重新以 VM.native_memory detail 參數運行 jcmd:
jcmd?24404?VM.native_memory?detail可以看到,有 16 個可疑線程,每一個線程保留了 262144KB 內存,也就是 256MB(通過下圖紅框可以看到,使用關鍵字 262144KB for Thread Stack from 搜索到了 16 個結果):
其實,ThreadStackSize 參數的單位是 KB,所以我們如果要設置線程棧 256KB,那么應該設置 256 而不是 256k。重新設置正確的參數后,使用 jcmd 再次驗證下:
除了用于查看 NMT 外,jcmd 還有許多功能。我們可以通過 help,看到它的所有功能:
jcmd?24781?help除了 jps、jinfo、jcmd、jstack、jstat、jconsole、jvisualvm 外,JDK 中還有一些工具,你可以通過官方文檔查看完整介紹。
“官方文檔:https://docs.oracle.com/javase/8/docs/technotes/tools/
”文章來源:https://time.geekbang.org/column/article/224816
完
往期推薦
手機APP的秘密,看的一清二楚!
入職微軟三個月了!
大城市卷不動了,我要回老家!
有道無術,術可成;有術無道,止于術
歡迎大家關注Java之道公眾號
好文章,我在看??
總結
以上是生活随笔為你收集整理的6 个 Java 工具,轻松分析定位 JVM 问题!的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: systemverilog硬件设计及建模
- 下一篇: golang mysql 自动建表_my