1、GC日志分析
為了在內存溢出時排查原因,可以在JVM啟動時加一些參數來控制,當JVM內存出問題時可以通過分析記錄下來的GC日志,GC的頻率和每次GC回收了哪些內存。
GC的日志輸入有以下參數
1)-verbose:gc 可以輔助輸出一些詳細的GC信息
2)-XX:+PrintGCDetails 輸出GC的詳細信息
3)-XX:+PrintGCApplicationStoppedTime 輸出GC造成應用程序暫停的時間
4)-XX:+PrintGCDateStamps 輸出GC發生的時間信息
5)-XX:PrintHeapAtGC 在GC前后輸出堆中各個區域的大小
6)-Xloggc:[file] 將GC信息輸出到單獨的文件
每種GC方式輸出日志的形式不同,除CMS的日志和其他GC方式差異較大外,其余GC方式的日志可以抽象成如下方式
[GC [<collector>: <starting occupancy1> -> <ending occupancy1> (total size1) , <pause time1> secs]
<starting occupancy2> -> <ending occupancy2> (total size2) , <pause time2> secs] ]
說明如下
1)<collectot>GC 表示垃圾收集器的名稱
2)<starting occupancy1> 表示Young區在GC前占用的內存
3)<ending occupancy1> 表示Young區在GC后占用的內存
4)(total size1) 表示Young區的總內存大小
5)<pause time1> 表示Young區局部收集時JVM暫停處理的時間 secs表示單位秒
6)<starting occupancy2> 表示Heap在GC前占用的內存
7)<ending occupancy2> 表示Heap在GC后占用的內存
8)(total size2) 表示Heap的總內存
9)<pause time2> 表示在GC過程中JVM暫停處理的總時間
可以根據日志來判斷是否存在內存泄漏的問題:
<starting occupancy1> - <ending occupancy1> 和 <starting occupancy2> - <ending occupancy2> 比較
1、如果前者差等於后者差,表明Young區GC 對象100%被回收,沒有對象進入 Old區或者Perm區
2、如果前者大於后者,那么差值就是這次GC對象進入Old或者Perm區的大小
如果隨着時間的的延長,<ending occupancy2>的大小一直在增長,而且Full GC很頻繁,那么很可能就是內存泄漏導致的。
2、堆快照文件分析
如果是OOM,可能有兩方面的原因
1、內存分配過小,不滿足程序運行所需要的內存
2、內存泄漏(FullGC頻繁,回收后Heap占用的內存不斷增長)
以下Java命令在JDK的bin目錄下執行
1、導出堆dump文件分析
1)jps -m -l 命令找到我們服務的進程
2)jmap -dump:format=b,file=[filename] [pid] jmap(Memory Map for Java)來記錄下堆的內存快照,然后利用第三方工具如eclipse 插件MAT、IBM HeapAnalyzer來分析整個Heap的對象關聯情況。
IBM HeapAnalyzer:Steps
① Download: https://public.dhe.ibm.com/software/websphere/appserv/support/tools/HeapAnalyzer/ha457.jar
② Open a terminal or command prompt and change directory to where you downloaded the JAR file.
③ Ensure that Java is on your PATH to run the tool.
④ Launch the tool (increase -Xmx based on your available RAM):java -Xmx2g -jar ha*.jar
如果內存耗盡可直接導致JVM退出,可以通過參數
-XX:+HeapDumpOnOutOfMemoryError 來配置當內存耗盡時記錄下當時的內存快照
-XX:HeapDumpPath 指定內存快照文件的路徑 文件快照的名稱格式為 java_[pid].hprof
2、在線分析
1)jps -m -l 命令找到我們服務的進程
2)使用jmap -heap pid查看進程堆內存使用情況,包括使用的GC算法、堆配置參數和各代中堆內存使用情況。如:
./jmap -heap 27675 Attaching to process ID 27675, please wait... Debugger attached successfully. Server compiler detected. JVM version is 25.202-b08 using parallel threads in the new generation. using thread-local object allocation. Concurrent Mark-Sweep GC Heap Configuration: MinHeapFreeRatio = 40 MaxHeapFreeRatio = 70 MaxHeapSize = 536870912 (512.0MB) NewSize = 268435456 (256.0MB) MaxNewSize = 268435456 (256.0MB) OldSize = 268435456 (256.0MB) NewRatio = 2 SurvivorRatio = 3 MetaspaceSize = 21807104 (20.796875MB) CompressedClassSpaceSize = 939524096 (896.0MB) MaxMetaspaceSize = 1073741824 (1024.0MB) G1HeapRegionSize = 0 (0.0MB) Heap Usage: New Generation (Eden + 1 Survivor Space): capacity = 214761472 (204.8125MB) used = 5953088 (5.67730712890625MB) free = 208808384 (199.13519287109375MB) 2.7719534349252366% used Eden Space: capacity = 161087488 (153.625MB) used = 5953088 (5.67730712890625MB) free = 155134400 (147.94769287109375MB) 3.695562004170057% used From Space: capacity = 53673984 (51.1875MB) used = 0 (0.0MB) free = 53673984 (51.1875MB) 0.0% used To Space: capacity = 53673984 (51.1875MB) used = 0 (0.0MB) free = 53673984 (51.1875MB) 0.0% used concurrent mark-sweep generation: capacity = 268435456 (256.0MB) used = 75364008 (71.87271881103516MB) free = 193071448 (184.12728118896484MB) 28.075280785560608% used 28582 interned Strings occupying 3079592 bytes.
3) 使用 jmap -histo[:live] pid 查看堆內存中的對象數目、大小統計直方圖,如果帶上live則只統計活對象,如:
./jmap -histo:live 27675|less num #instances #bytes class name ---------------------------------------------- 1: 277691 32177840 [C 2: 198142 4755408 java.lang.String
3、JVM Crash 日志分析
TODO
JVM性能監控和故障處理
通過工具導出和處理分析 運行日志、異常堆棧、GC日志、線程快照(threaddump/javacore文件)、堆轉儲快照(headdump/hprof文件)等
jps:JVM process status tool,顯示指定系統內所有的HotSpot虛擬機進程
jstat:JVM statistics Monitoring Tool,收集HotSpot虛擬機各方面的運行數據
jinfo:Configuration Info for java,顯示虛擬機配置信息
jmap:Memory map for Java,生成虛擬機的內存轉儲快照(heapdump文件)
jhat:JVM Heap Dump Browser,用於分析heapdump文件,它會建立一個http/html服務器,讓用戶可以在瀏覽器上查看分析結果
jstack:Stack trace for Java,顯示虛擬機的線程快照
jps:(Jvm Process Status )和linux中ps命令相似,可列出正在運行的虛擬機進程,並顯示虛擬機執行主類和這些進程的唯一ID(Local Virtual Machine Identifier LVMID)
格式:jps [option] [hostid(主機名)]
參數:
-l 輸出主類的全路徑
-v 輸出虛擬機進程啟動是的JVM參數
-m 輸出傳入main方法的參數
一般使用 jps -m -l 來查看虛擬機進程
jstat:用於監視虛擬機各種運行狀態信息的命令行工具,它可以顯示本地或者遠程虛擬機進程中的類加載、內存、垃圾收集、JIT編譯等運行數據,是定位虛擬機性能問題的首選工具。
格式:jstat [ option vmid [interval] [count] ]
interval和count是查詢間隔和次數,如果忽略這兩個參數則只查詢一次
選項:
-class 監視類裝載、卸載數量、總空間以及類裝載消耗時間
-gc 監視Java堆狀況,包含Eden區,兩個Survivor區、老年代、永久代等的容量,已用空間,GC時間等信息。
如: jstat -gc 27675 250 4 采樣時間間隔為250ms,采樣數為4:
jstat -gc 27675 250 4
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
52416.0 52416.0 0.0 0.0 157312.0 37334.0 262144.0 73597.7 129932.0 77136.4 9824.0 9141.6 325 6.017 7 1.032 7.050
52416.0 52416.0 0.0 0.0 157312.0 37334.0 262144.0 73597.7 129932.0 77136.4 9824.0 9141.6 325 6.017 7 1.032 7.050
52416.0 52416.0 0.0 0.0 157312.0 37334.0 262144.0 73597.7 129932.0 77136.4 9824.0 9141.6 325 6.017 7 1.032 7.050
52416.0 52416.0 0.0 0.0 157312.0 37334.0 262144.0 73597.7 129932.0 77136.4 9824.0 9141.6 325 6.017 7 1.032 7.050
S0C、S1C、S0U、S1U:Survivor 0/1區容量(Capacity)和使用量(Used)
EC、EU:Eden區容量和使用量
OC、OU:年老代容量和使用量
PC、PU:永久代容量和使用量
YGC、YGT:年輕代GC次數和GC耗時
FGC、FGCT:Full GC次數和Full GC耗時
GCT:GC總耗時
jmap:Java內存映射工具,用於生成堆存儲快照heapdump,生成堆快照還可以通過設置參數使在OOM異常之后自動生成堆dump文件。
jmap還可查詢finalize執行隊列、Java堆和永久代的詳細信息(空間使用率,使用哪種收集器等)。
格式:jmap [option] vmid
option參數
-dump:format=b,file=[filename] 生成堆轉儲快照
-heap 顯示Java堆詳細信息,如使用哪種收集器、參數配置、分代狀況等。
如:jmap -dump:format=b,file=/home/dump.hprof [pid]
jhat:與jmap搭配使用,分析jmap生成的堆轉儲快照文件。一般不會直接使用jhat命令分析dump文件,一是不會直接在應用服務器上分析dump文件,因為分析耗時耗資源,二是jhat分析結果比較簡陋,可用VisualVM,MAT等工具
jstack:Java堆棧跟蹤工具,用戶生成虛擬機當前時刻的線程快照,線程快照就是當前虛擬機內每一條線程正在執行的方法堆棧的集合,生成快照的主要目的是定位線程出現長時間等待的原因,如線程間死鎖、死循環、請求外部資源(如sql)導致的長時間等待等。
線程出現停頓的時候通過jstack來查看各個線程的調用堆棧,就可以知道沒有響應的線程到底在后台做什么事情或者等待什么資源
格式:jstack [option] vmid
option參數:
-F:強制輸出線程堆棧
-l:除堆棧外顯示關於鎖的附加信息
-m:可顯示調用本地方法的堆棧
JDK1.5之后的Thread類新增了getAllStackTraces()方法用戶獲取虛擬機中所有線程的StackTraceElement對象。和jstack功能類似
public static Map<Thread,StackTraceElement[]> getAllStackTraces() 返回從 Thread 到 StackTraceElement 數組的一個 Map,代表相應線程的堆棧跟蹤。 、
總結:
如果要定位OOM問題使用jps和jmap組合命令,先用jps或者linux的ps命令查看虛擬機進程的vmid,然后用jamp命令生成堆快照文件,最后使用工具分析dump文件定位問題。
如果要定位線程響應時間過長的問題,使用jps和jstack命令,先用jps或者linux的ps命令查看虛擬機進程的vmid,然后用jstack命令查看線程堆棧信息
JVM調優
JVM調優是通過分析GC日志等來分析java內存和垃圾回收的情況,來調整各內存區域內存占比和垃圾回收策略。
GC優化的根本原因
垃圾收集器的工作就是清除Java創建的對象,垃圾收集器需要清理的對象數量以及要執行的GC數量均取決於已創建的對象數量。因此,為了使你的系統在GC上表現良好,首先需要在保證功能的基礎上減少創建對象的數量。
如:養成如下的良好的編碼習慣
1、使用StringBuffer或StringBuilder來代替String
2、盡量少輸出日志
GC優化的兩個目的
1、減少Full GC的頻率
2、減少Full GC的執行時間
1、減少Full GC的頻率——將進入老年代的對象數量降到最低
充分使用系統資源,減少GC停頓時間和停頓次數,由於Full GC的停頓時間遠比Minor GC的停頓時間長,因此要控制Full GC的頻率。
控制Full GC的頻率的關鍵是將進入老年代的對象數量降到最低。因此要看應用中的絕大多數對象是否符合“朝生夕滅”的原則,即大多數的對象的生存時間都不應太長,尤其是不能有成批量的、長時間存活的對象產生,這樣這些對象在Minor GC就會被回收,不會進入老年代,這樣才能保證老年代的穩定。
比如對於十幾小時乃至一天才出現一次Full GC的系統可以通過定時任務的方式在夜間觸發Full GC。
如果FullGC次數過多可能是下面的原因:
1、內存占用高:代碼中創建了大量的對象導致內存泄漏,不能回收內存,創建新對象導致空間不足觸發fullGC
2、內存占用不高:可能是顯示的調用System.gc()次數太多導致的fullGC,可以通過添加-XX:+DisableExplicitGC來禁用JVM對顯式GC的響應
2、減少Full GC的時間
Full GC的停頓時間遠比Minor GC的停頓時間長,因此,如果在Full GC上花費過多的時間(超過1s), 將可能出現超時錯誤。
1)如果通過減小老年代內存來減少Full GC時間,可能會引起OutOfMemoryError或者導致Full GC的頻率升高。
2)如果通過增加老年代內存來降低Full GC的頻率,Full GC的時間可能因此增加。
因此,你需要把老年代的大小設置成一個“合適”的值。
影響GC性能的因素:
1)-XX:NewRatio 新生代和老年代的內存比(默認1:2),這個參數將對GC性能產生重要的影響
2)垃圾收集器的類型
什么時候需要進行GC優化?
通過監控GC狀態,然后分析GC監控結果來判斷是否需要進行GC優化。
如果GC執行時間滿足下列所有條件,就沒有必要進行GC優化了:
1)Minor GC執行非常迅速(50ms以內)
2)Minor GC沒有頻繁執行(大約10s執行一次)
3)Full GC執行非常迅速(1s以內)
4)Full GC沒有頻繁執行(大約10min執行一次)
GC優化是一個不斷嘗試並逐漸調試的過程。在每次設置完GC參數后,要收集數據,並收集至少24個小時之后再進行結果分析。
一些JVM調優經驗
1、開啟GC日志:開啟GC日志對性能的影響微乎其微,但是能幫助我們快速排查問題。-XX:+PrintGCTimeStamps -XX:+PrintGCDetails -Xloggc:gc.log
2、開啟JVM溢出時自動生成堆內存快照,方便排查問題,-XX:+HeapDumpOnOutOfMemoryError
3、設置-Xms=-Xmx:堆內存大小固定,可以使得堆相對穩定,減少GC的次數和耗時
4、設置 -XX:+DisableExplicitGC 禁止系統System.gc(),防止手動誤觸發FGC問題
END.