内存分析

Heap Dump，称为堆转储文件，是Java进程在某个时间内的快照。在触发快照的时候保存了很多信息：Java对象和类信息。通常在写Heap Dump文件前会触发一次Full GC。

手动生成dump文件

jmap -dump:format=b,file=heap.hprof PID

自动生成dump文件

-Xmx10M -Xms10M  -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof

IDEA堆分析

IDEA打开heap.hprof文件

jvisualvm堆分析

jvisualvm打开heap.hprof文件

在线分析

在线网站分析：https://heaphero.io/

GC Roots

JVM中GC Roots的大致分类

Class：由System Class Loader、Boot Class Loader加载的类对象不会被回收。注意其它Class Loader实例加载的类对象不一定是GC root，除非这个类对象恰好是其它形式的GC root

Thread：线程，激活状态的线程

Stack Local：栈中的对象。每个线程都会分配一个栈，栈中的局部变量或者参数都是GC root，因为它们的引用随时可能被用到

JNI Local：JNI中的局部变量和参数引用的对象，可能在JNI中定义的，也可能在虚拟机中定义

JNI Global：JNI中的全局变量引用的对象，可能在JNI中定义的，也可能在虚拟机中定义

Monitor Used：用于保证同步的对象，例如wait()，notify()中使用的对象、锁等

Held by JVM：JVM持有的对象。JVM为特殊用途保留的对象，它与JVM的具体实现有关。
		     比如有System Class Loader, 一些Exceptions对象，和一些其它的Class Loader。

GC日志分析

分析日志信息，必须先获取GC日志文件。

生成GC日志

JVM配置参数：

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./gc.log

Java HotSpot(TM) 64-Bit Server VM (25.271-b09) for windows-amd64 JRE (1.8.0_271-b09), built on Sep 16 2020 19:14:59 by "" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 14557796k(2667636k free), swap 29237860k(13727924k free)
CommandLine flags: -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC 
2022-10-06T12:10:20.668+0800: 0.165: [GC (Allocation Failure) [PSYoungGen: 2048K->503K(2560K)] 2048K->927K(9728K), 0.0012906 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.723+0800: 0.220: [GC (Allocation Failure) [PSYoungGen: 2551K->511K(2560K)] 2975K->1572K(9728K), 0.0007088 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.776+0800: 0.273: [GC (Allocation Failure) [PSYoungGen: 2559K->511K(2560K)] 3620K->1977K(9728K), 0.0008578 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.829+0800: 0.326: [GC (Allocation Failure) [PSYoungGen: 2559K->495K(2560K)] 4025K->2315K(9728K), 0.0008893 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.846+0800: 0.343: [GC (Allocation Failure) [PSYoungGen: 2543K->511K(2560K)] 4363K->2507K(9728K), 0.0006121 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.869+0800: 0.366: [GC (Allocation Failure) [PSYoungGen: 2559K->511K(1536K)] 4555K->2656K(8704K), 0.0005243 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.874+0800: 0.371: [GC (Allocation Failure) [PSYoungGen: 1531K->384K(2048K)] 3676K->2816K(9216K), 0.0005493 secs] [Times: user=0.16 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.882+0800: 0.379: [GC (Allocation Failure) [PSYoungGen: 1395K->320K(2048K)] 3828K->2951K(9216K), 0.0004224 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.895+0800: 0.392: [GC (Allocation Failure) [PSYoungGen: 1337K->448K(2048K)] 3969K->3175K(9216K), 0.0006957 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:20.901+0800: 0.399: [GC (Allocation Failure) [PSYoungGen: 1472K->512K(2048K)] 4199K->3327K(9216K), 0.0004212 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:25.912+0800: 5.410: [GC (Allocation Failure) [PSYoungGen: 1536K->731K(2048K)] 4351K->3931K(9216K), 0.0007541 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:25.915+0800: 5.412: [GC (Allocation Failure) [PSYoungGen: 1755K->1013K(2048K)] 4955K->4677K(9216K), 0.0009722 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:25.916+0800: 5.413: [GC (Allocation Failure) [PSYoungGen: 2037K->992K(2048K)] 5701K->5304K(9216K), 0.0010417 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:25.918+0800: 5.415: [GC (Allocation Failure) [PSYoungGen: 2016K->1009K(2048K)] 6328K->5969K(9216K), 0.0012314 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:25.919+0800: 5.417: [GC (Allocation Failure) [PSYoungGen: 2033K->1024K(2048K)] 7931K->7409K(9216K), 0.0116549 secs] [Times: user=0.16 sys=0.00, real=0.01 secs] 
2022-10-06T12:10:25.931+0800: 5.428: [Full GC (Ergonomics) [PSYoungGen: 1024K->0K(2048K)] [ParOldGen: 6385K->5846K(7168K)] 7409K->5846K(9216K), [Metaspace: 4866K->4866K(1056768K)], 0.0637875 secs] [Times: user=0.34 sys=0.00, real=0.06 secs] 
2022-10-06T12:10:25.995+0800: 5.493: [GC (Allocation Failure) [PSYoungGen: 777K->928K(2048K)] 6623K->6774K(9216K), 0.0064231 secs] [Times: user=0.16 sys=0.00, real=0.01 secs] 
2022-10-06T12:10:26.002+0800: 5.499: [GC (Allocation Failure) [PSYoungGen: 928K->0K(2048K)] 6774K->6630K(9216K), 0.0059821 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
2022-10-06T12:10:26.008+0800: 5.505: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(2048K)] [ParOldGen: 6630K->6459K(7168K)] 6630K->6459K(9216K), [Metaspace: 4866K->4866K(1056768K)], 0.0668321 secs] [Times: user=0.50 sys=0.00, real=0.07 secs] 
2022-10-06T12:10:26.075+0800: 5.572: [GC (Allocation Failure) [PSYoungGen: 0K->0K(2048K)] 6459K->6459K(9216K), 0.0003321 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
2022-10-06T12:10:26.075+0800: 5.572: [Full GC (Allocation Failure) [PSYoungGen: 0K->0K(2048K)] [ParOldGen: 6459K->6459K(7168K)] 6459K->6459K(9216K), [Metaspace: 4866K->4866K(1056768K)], 0.0511498 secs] [Times: user=0.63 sys=0.00, real=0.05 secs] 
Heap
 PSYoungGen      total 2048K, used 70K [0x00000000ffd00000, 0x0000000100000000, 0x0000000100000000)
  eden space 1024K, 6% used [0x00000000ffd00000,0x00000000ffd11b38,0x00000000ffe00000)
  from space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
  to   space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
 ParOldGen       total 7168K, used 6459K [0x00000000ff600000, 0x00000000ffd00000, 0x00000000ffd00000)
  object space 7168K, 90% used [0x00000000ff600000,0x00000000ffc4ec90,0x00000000ffd00000)
 Metaspace       used 4898K, capacity 5132K, committed 5248K, reserved 1056768K
  class space    used 524K, capacity 564K, committed 640K, reserved 1048576K

Parallel GC日志收集器

查看gc.log文件，发现JVM参数：-XX:+UseParallelGC ，即默认使用是Parallel GC，该GC要求：吞吐量优先

参数说明：

[GC (Allocation Failure) [PSYoungGen: 2048K->503K(2560K)] 2048K->927K(9728K), 0.0012906 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

2048K->503K(2560K)： Young区回收前->Young区回收后->Young区总大小

2048K->927K(9728K): 整个堆回收前->整个堆回收后->整个堆总大小

CMS日志收集器

使用CMS(停顿时间优先)收集器

配置参数：

-XX:+PrintGCDetails -XX:+UseConcMarkSweepGC -Xloggc:cms-gc.log

日志内容：

Java HotSpot(TM) 64-Bit Server VM (25.271-b09) for windows-amd64 JRE (1.8.0_271-b09), built on Sep 16 2020 19:14:59 by "" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 14557796k(2202052k free), swap 29237860k(12792256k free)
CommandLine flags: -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:MaxNewSize=3497984 -XX:MaxTenuringThreshold=6 -XX:NewSize=3497984 -XX:OldPLABSize=16 -XX:OldSize=6987776 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC -XX:-UseLargePagesIndividualAllocation -XX:+UseParNewGC 
0.198: [GC (Allocation Failure) 0.198: [ParNew: 2752K->320K(3072K), 0.0020980 secs] 2752K->1005K(9920K), 0.0023048 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.272: [GC (Allocation Failure) 0.272: [ParNew: 2856K->320K(3072K), 0.0011966 secs] 3541K->1870K(9920K), 0.0012688 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.304: [GC (Allocation Failure) 0.304: [ParNew: 3072K->320K(3072K), 0.0006028 secs] 4622K->2169K(9920K), 0.0006390 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.329: [GC (Allocation Failure) 0.329: [ParNew: 3072K->244K(3072K), 0.0004766 secs] 4921K->2242K(9920K), 0.0005142 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.354: [GC (Allocation Failure) 0.354: [ParNew: 2996K->154K(3072K), 0.0004383 secs] 4994K->2230K(9920K), 0.0004734 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
0.381: [GC (Allocation Failure) 0.381: [ParNew: 2906K->320K(3072K), 0.0006602 secs] 4982K->2510K(9920K), 0.0006982 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
5.403: [GC (Allocation Failure) 5.404: [ParNew: 3072K->320K(3072K), 0.0057543 secs] 5262K->5044K(9920K), 0.0058035 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 
5.409: [GC (CMS Initial Mark) [1 CMS-initial-mark: 4724K(6848K)] 5153K(9920K), 0.0001237 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
5.410: [CMS-concurrent-mark-start]
5.410: [GC (Allocation Failure) 5.410: [ParNew: 2260K->2260K(3072K), 0.0000087 secs]5.410: [CMS5.416: [CMS-concurrent-mark: 0.002/0.007 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
 (concurrent mode failure): 4724K->6311K(6848K), 0.0153825 secs] 6984K->6311K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0154360 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 
5.426: [GC (Allocation Failure) 5.426: [ParNew: 2255K->2255K(3072K), 0.0000088 secs]5.426: [CMS: 6311K->6847K(6848K), 0.0114090 secs] 8566K->7840K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0114654 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
5.438: [GC (CMS Initial Mark) [1 CMS-initial-mark: 6847K(6848K)] 9247K(9920K), 0.0011841 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
5.439: [CMS-concurrent-mark-start]
5.441: [Full GC (Allocation Failure) 5.442: [CMS5.454: [CMS-concurrent-mark: 0.009/0.014 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
 (concurrent mode failure): 6847K->6847K(6848K), 0.0249136 secs] 9919K->9292K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0249739 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 
5.469: [Full GC (Allocation Failure) 5.469: [CMS: 6847K->6847K(6848K), 0.0118550 secs] 9919K->9919K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0119003 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
5.481: [GC (CMS Initial Mark) [1 CMS-initial-mark: 6847K(6848K)] 9919K(9920K), 0.0018492 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
5.482: [CMS-concurrent-mark-start]
5.483: [Full GC (Allocation Failure) 5.483: [CMS5.498: [CMS-concurrent-mark: 0.003/0.015 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
 (concurrent mode failure): 6847K->6847K(6848K), 0.0268790 secs] 9919K->9919K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0269172 secs] [Times: user=0.01 sys=0.00, real=0.03 secs] 
5.509: [Full GC (Allocation Failure) 5.509: [CMS: 6847K->6847K(6848K), 0.0121410 secs] 9919K->9919K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0121734 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 
5.522: [Full GC (Allocation Failure) 5.522: [CMS: 6847K->1767K(6848K), 0.0049601 secs] 9919K->1767K(9920K), [Metaspace: 4868K->4868K(1056768K)], 0.0050267 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Heap
 par new generation   total 3072K, used 92K [0x00000000ff600000, 0x00000000ff950000, 0x00000000ff950000)
  eden space 2752K,   3% used [0x00000000ff600000, 0x00000000ff617128, 0x00000000ff8b0000)
  from space 320K,   0% used [0x00000000ff900000, 0x00000000ff900000, 0x00000000ff950000)
  to   space 320K,   0% used [0x00000000ff8b0000, 0x00000000ff8b0000, 0x00000000ff900000)
 concurrent mark-sweep generation total 6848K, used 1767K [0x00000000ff950000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 4900K, capacity 5132K, committed 5248K, reserved 1056768K
  class space    used 524K, capacity 564K, committed 640K, reserved 1048576K

G1日志收集器

使用G1(停顿时间优先)收集器

配置参数

-XX:+UseG1GC -Xloggc:g1-gc.log

日志内容：

Java HotSpot(TM) 64-Bit Server VM (25.271-b09) for windows-amd64 JRE (1.8.0_271-b09), built on Sep 16 2020 19:14:59 by "" with MS VC++ 15.9 (VS2017)
Memory: 4k page, physical 14557796k(2150972k free), swap 29237860k(12972656k free)
CommandLine flags: -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=heap.hprof -XX:InitialHeapSize=10485760 -XX:MaxHeapSize=10485760 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:-UseLargePagesIndividualAllocation 
0.239: [GC pause (G1 Evacuation Pause) (young) 6144K->1804K(10M), 0.0014193 secs]
0.292: [GC pause (G1 Evacuation Pause) (young) 6924K->3262K(10M), 0.0015256 secs]
0.334: [GC pause (G1 Evacuation Pause) (young) 7358K->3035K(10M), 0.0009231 secs]
5.349: [GC pause (G1 Evacuation Pause) (young) 7131K->4865K(10M), 0.0019180 secs]
5.351: [GC pause (G1 Humongous Allocation) (young) (initial-mark) 5149K->6014K(10M), 0.0014205 secs]
5.353: [GC concurrent-root-region-scan-start]
5.353: [GC concurrent-root-region-scan-end, 0.0001935 secs]
5.353: [GC concurrent-mark-start]
5.355: [GC pause (G1 Evacuation Pause) (young)-- 8601K->8731K(10M), 0.0198795 secs]
5.375: [GC pause (G1 Evacuation Pause) (young)-- 9755K->9755K(10M), 0.0338486 secs]
5.409: [GC pause (G1 Evacuation Pause) (young) 9755K->9755K(10M), 0.0007821 secs]
5.410: [Full GC (Allocation Failure)  9755K->6430K(10M), 0.0110629 secs]
5.421: [GC pause (G1 Humongous Allocation) (young) 6470K->6476K(10M), 0.0009511 secs]
5.422: [GC concurrent-mark-abort]
5.422: [Full GC (Allocation Failure)  6476K->6468K(10M), 0.0089612 secs]
5.432: [GC pause (G1 Evacuation Pause) (young) (initial-mark)-- 8898K->8898K(10M), 0.0330744 secs]
5.465: [GC concurrent-root-region-scan-start]
5.465: [GC concurrent-root-region-scan-end, 0.0000038 secs]
5.465: [GC concurrent-mark-start]
5.465: [GC pause (G1 Evacuation Pause) (young) 8898K->8898K(10M), 0.0007418 secs]
5.466: [Full GC (Allocation Failure)  8898K->7897K(10M), 0.0134060 secs]
5.479: [GC concurrent-mark-abort]
5.479: [GC pause (G1 Humongous Allocation) (young) (initial-mark)-- 8796K->8796K(10M), 0.0299030 secs]
5.509: [GC concurrent-root-region-scan-start]
5.509: [GC concurrent-root-region-scan-end, 0.0000032 secs]
5.509: [GC concurrent-mark-start]
5.509: [GC pause (G1 Humongous Allocation) (young) 8796K->8796K(10M), 0.0007024 secs]
5.510: [Full GC (Allocation Failure)  8796K->8792K(10M), 0.0131801 secs]
5.523: [Full GC (Allocation Failure)  8792K->8792K(10M), 0.0131106 secs]
5.536: [GC concurrent-mark-abort]
5.537: [GC pause (G1 Evacuation Pause) (young) 8792K->8792K(10M), 0.0006725 secs]
5.538: [GC pause (G1 Evacuation Pause) (young) (initial-mark) 8792K->8792K(10M), 0.0005366 secs]
5.538: [GC concurrent-root-region-scan-start]
5.538: [GC concurrent-root-region-scan-end, 0.0000021 secs]
5.538: [GC concurrent-mark-start]
5.538: [Full GC (Allocation Failure)  8792K->1756K(10M), 0.0047575 secs]
5.543: [GC concurrent-mark-abort]