JVM性能——开启回收日志和实时查看GC信息
JDK版本:OpenJDK 1.8.0_352-b08
操作系统:CentOS 7
如果文章内出现测试数据测试代码
depth:23
关于JVM的其他文章
JVM性能——垃圾回收器的优化策略
JVM性能——垃圾回收器的介绍
JVM性能——开启回收日志和实时查看GC信息
JVM性能——JVM调优参数列表
开启GC日志
GC的日志默认是关闭状态,需要进行手动打开
开启简单日志
-XX:+PrintGC
开启了简单GC日志,每一次YGC和FGC都会输出一行信息:GC之前和GC之后已使用的堆空间,再然后是当前的堆容量,最后是GC持续的时间(以秒计)
[GC 246656K->243120K(376320K), 0.0929090 secs][Full GC 243120K->241951K(629760K), 1.5589690 secs]
这里只使用简单模式的日志,实际上我们很少去配置简单日志,这种日志输出的内容很少,很难判断GC时发生了什么。
详细日志
-XX:+PrintGCDetails
开启详细日志后,会打印更多的内容
[GC [PSYoungGen: 142816K->10752K(142848K)] 246648K->243136K(375296K), 0.0935090 secs][Times: user=0.55 sys=0.10, real=0.09 secs]
开启带时间戳的日志
打开时间戳的显示,可以让我们定位到对应时间GC情况,也方便我们观察GC各个阶段启动的时间和间隔。方便我们排查GC中哪些地方出现了问题,如果去调优。使用-XX:+PrintGCTimeStamps
开启打印时间戳的,时间戳的时间为相对于JVM启动时间为0开始的值
-XX:+PrintGCTimeStamps
打印时间戳的详细日志,时间戳是实际时间,需要进行日志格式化,虽然会有时间格式化的性能损耗,但是好在GC的日志不算很多。
XX:+PrintGCDateStamps
个人经验,对于仅仅需要对GC内容进行调优的操作来说开启-XX:+PrintGCTimeStamps
可能更方便。
设置GC日志路径
需要注意,如果设置的路径并不存在,JVM启动后并不会输出日志
-Xloggc:filename
设置滚动日志
使用滚动日志可以控制GC日志的数据量,但是需要注意GC在写满最后一个日志文件后会将新的内容写到日志的第一个文件中,所以一个运行很长时间JVM产生的GC日志中最早的内容可能会被覆盖
GC的滚动日志默认关闭,需要设置-XX:+UseGCLogFileRotation
打开。开启滚动日志后默认的文件数目无限制,默认的日志文件大小是无限制。可以使用下面的参数限制文件数量和大小。
-XX:NumberOfGCLogFiles=N
设置文件数量
-XX:GCLogFileSize=N
设置每个GC日志文件大小
滚动日志的写逻辑
- 最开始日志会被记录到
gc.log.0.current
文件中 - 第一个文件满了之后会将其重命名为
gc.log.0
然后开始记录gc.log1.current
- 当文件数满了之后会,删除
gc.log.0
并开始记录到新的gc.log.0.current
文件中·
最终日志内容
上面介绍内容最终可以合并为这样的命令
-Xloggc:gc.log -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=8 -XX:GCLogFileSize=8m
除了上面内容开启日志还可以添加下面的参数
添加参数 | 作用 |
---|---|
-XX:+PrintGCDateStamps | 打印 gc 发生的时间戳(日期格式) |
-XX:+PrintGCTimeStamps | 打印 gc 发生的时间戳 |
-XX:+PrintTenuringDistribution | 打印 gc 发生时的分代信息 |
-XX:+PrintGCApplicationStoppedTime | 打印 gc 停顿时长 |
-XX:+PrintGCApplicationConcurrentTime | 打印 gc 间隔的服务运行时长 |
-XX:+PrintGCDetails | 打印 gc 详情,包括 gc 前/内存等 |
-Xloggc:…/gclogs/gc.log.date | 指定 gc log 的路径 |
-XX:+PrintHeapAtGC | GC 后打印堆数据 |
-XX:+PrintGCApplicationStoppedTime | 打印 STW(服务暂停) 时间 |
-XX:+PrintReferenceGC | 打印 Reference 处理信息(强引用/弱引用/软引用/虚引用/finalize ) |
-Xloggc:/path/to/gc-%t.log | 使用时间戳命名文件 |
分析日志
开启日志后我们可以得到下面的日志内容,这一部分主要是JVM的环境信息和JVM的启动命令
Java HotSpot(TM) 64-Bit Server VM (25.40-b25) for windows-amd64 JRE (1.8.0_40-b26), built on Mar 7 2015 13:51:59 by "java_re" with MS VC++ 10.0 (VS2010)
Memory: 4k page, physical 16546088k(6018572k free), swap 34371880k(20170036k free)
CommandLine flags: -XX:GCLogFileSize=8388608 -XX:InitialHeapSize=264737408 -XX:MaxHeapSize=4235798528 -XX:NumberOfGCLogFiles=8 -XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseGCLogFileRotation -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
......
一些关键术语在不同的GC日志上是一样的
GC:日志中的GC指的是指的是 Minor GC
或者Young GC(YGC)
。在分代垃圾回收器中新生代被填满后会进行YGC
Full GC:日志中的Full GC
指的是用于清理整个堆空间,相比YGC这是一个非常消耗时间的操作
GC消耗时间:GC的时间消耗主要是关注real中的数据,对于前两个参数指的是CPU消耗时间,但是实际上因为多核的存在时间消耗时间是小于CPU时间的
一般GC的时候会携带GC的原因
Allocation Failure
这是当堆分配内存失败的时候引发的GC,一般是对应分代满导致的,是最常见的GC原因Metadata GC Threshold
元空间的GC,一般出现在服务启动的时候,初期JVM申请的元空间较小,在启动的时候随着内容加载需要不断的扩大元空间导致的GC。Ergonomics
开启了UseAdaptiveSizePolicy,JVM自己进行自适应调整引发的GC
可以添加更多参数打印更多内容
添加-XX:+PrintHeapAtGC
后我们可以看到每次GC后更详细的空间清理效果,这对于我们更加细致的分析空间使用有更好的帮助
{Heap before GC invocations=40 (full 5):
PSYoungGen total 1160704K, used 1137346K [0x000000076bd80000, 0x00000007c0000000, 0x00000007c0000000)
eden space 981504K, 100% used [0x000000076bd80000,0x00000007a7c00000,0x00000007a7c00000)
from space 179200K, 86% used [0x00000007b5100000,0x00000007be930948,0x00000007c0000000)
to space 198656K, 0% used [0x00000007a7c00000,0x00000007a7c00000,0x00000007b3e00000)
ParOldGen total 812544K, used 425659K [0x00000006c3800000, 0x00000006f5180000, 0x000000076bd80000)
object space 812544K, 52% used [0x00000006c3800000,0x00000006dd7aee98,0x00000006f5180000)
Metaspace used 143092K, capacity 148676K, committed 149080K, reserved 1179648K
class space used 17538K, capacity 18667K, committed 18776K, reserved 1048576K
47.024: [GC (Allocation Failure) [PSYoungGen: 1137346K->163171K(1144832K)] 1563005K->588838K(1957376K), 0.0418296 secs] [Times: user=0.34 sys=0.01, real=0.04 secs]
Heap after GC invocations=40 (full 5):
PSYoungGen total 1144832K, used 163171K [0x000000076bd80000, 0x00000007c0000000, 0x00000007c0000000)
eden space 981504K, 0% used [0x000000076bd80000,0x000000076bd80000,0x00000007a7c00000)
from space 163328K, 99% used [0x00000007a7c00000,0x00000007b1b58cf8,0x00000007b1b80000)
to space 217088K, 0% used [0x00000007b2c00000,0x00000007b2c00000,0x00000007c0000000)
ParOldGen total 812544K, used 425667K [0x00000006c3800000, 0x00000006f5180000, 0x000000076bd80000)
object space 812544K, 52% used [0x00000006c3800000,0x00000006dd7b0e98,0x00000006f5180000)
Metaspace used 143092K, capacity 148676K, committed 149080K, reserved 1179648K
class space used 17538K, capacity 18667K, committed 18776K, reserved 1048576K
}
Serial日志
Serial是最基础的垃圾回收器,其日志会简单很多
27.775: [GC (Allocation Failure) 27.775: [ParNew: 153344K->17023K(153344K), 0.0297733 secs] 840919K->716568K(1031552K), 0.0298356 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
## 时间戳(基于JVM启动时间开始,为0):[GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小), GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
16.935: [GC (Allocation Failure) [PSYoungGen: 268064K->64512K(284672K)] 724584K->577312K(984064K), 0.0641592 secs] [Times: user=0.25 sys=0.01, real=0.06 secs]
......
## 时间戳(基于JVM启动时间开始,为0):[Full GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] [老年代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小),[元数据区: GC前->GC后(该区总大小)], GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
17.123: [Full GC (Ergonomics) [PSYoungGen: 64512K->0K(181248K)] [ParOldGen: 592712K->538414K(699392K)] 657224K->538414K(880640K), [Metaspace: 3178K->3178K(1056768K)], 0.5827661 secs] [Times: user=2.32 sys=0.00, real=0.59 secs]
Parallel日志
作为Serial
的多线程版本,看到的日志内容和Serial
并没有太大差别。
## 时间戳(基于JVM启动时间开始,为0):[GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小), GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
9.987: [GC (Metadata GC Threshold) [PSYoungGen: 82140K->8352K(389632K)] 143035K->69255K(540160K), 0.0052497 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
## 时间戳(基于JVM启动时间开始,为0):[Full GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] [老年代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小),[元数据区: GC前->GC后(该区总大小)], GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
20.228: [Full GC (Metadata GC Threshold) [PSYoungGen: 34406K->0K(673280K)] [ParOldGen: 142960K->143875K(423424K)] 177367K->143875K(1096704K), [Metaspace: 94775K->94775K(1134592K)], 0.1531552 secs] [Times: user=0.92 sys=0.00, real=0.15 secs]
## 时间戳(基于JVM启动时间开始,为0):[GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小), GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
64.750: [GC (Allocation Failure) [PSYoungGen: 786432K->8757K(917504K)] 786432K->8838K(3014656K), 0.0064866 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
ConcMarkSweep日志
后面的回收器,在启动YGC和FGC的时候都存在一个并发周期,在并发周期中又存在不同的阶段。不同的阶段中有的阶段存在STW。所以通过分析并发周期的濒临和STW的时间来对收集器进行优化
## 此阶段表示CMS已经开始初始标记
## 开始时间: [GC (GC阶段) [1 CMS-initial-mark: 当前老年代大小(老年代可用总空间大小)] 当前使用堆大小(堆总空间大小), 0.0094830 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
3.104: [GC (CMS Initial Mark) [1 CMS-initial-mark: 359454K(707840K)] 398926K(1014528K), 0.0094830 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
## 此时开始并发标记阶段,因为不是暂停的所以中间会穿插YGC
3.114: [CMS-concurrent-mark-start]
## 时间戳(基于JVM启动时间开始,为0):[GC (发生GC的原因) [新生代: GC前->GC后(该区总大小)] 堆区GC前->GC后(堆区总大小), GC所用的时间] [Times: 用户态耗费的时间 sys是内核态耗费的时间, real=实际花费的时间]
3.161: [GC (Allocation Failure) 3.161: [ParNew: 306688K->8511K(306688K), 0.0314696 secs] 666142K->402013K(1014528K), 0.0315284 secs] [Times: user=0.12 sys=0.00, real=0.04 secs]
......
## 此时并发标记结束
3.584: [CMS-concurrent-mark: 0.427/0.471 secs] [Times: user=1.00 sys=0.00, real=0.47 secs]
## 此时预清理阶段开始
3.584: [CMS-concurrent-preclean-start]
3.585: [CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
## 可中断的预清理开始,因为是可以中断的所以也会穿插YGC
3.585: [CMS-concurrent-abortable-preclean-start]
3.630: [GC (Allocation Failure) 3.630: [ParNew: 272646K->4K(306688K), 0.0010589 secs] 666148K->393506K(1014528K), 0.0011269 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
......
## 可中断的预清理结束
4.103: [CMS-concurrent-abortable-preclean: 0.007/0.518 secs] [Times: user=0.55 sys=0.00, real=0.52 secs]
## 最终标记开始最终标记
## 开始时间: [GC (GC阶段) [年轻代: 使用量 (总量)]
4.103: [GC (CMS Final Remark) [YG occupancy: 5456 K (306688 K)]
## 开始时间: [标记活动对象耗时 , 0.0015436 secs]
4.103: [Rescan (parallel) , 0.0015436 secs]
## 开始时间: [weak refs processing, 0.0000190 secs]
4.105: [处理弱引用时间, 0.0000190 secs]
## 开始时间: [类卸载时间, 0.0002399 secs]
4.105: [class unloading, 0.0002399 secs]
## 开始时间: [清理符号(保存类级元数据)时间, 0.0002682 secs]
4.105: [scrub symbol table, 0.0002682 secs]
## 开始时间: [清理字符串(内部化字符串)时间, 0.0000932 secs][1 CMS-remark: 老年代使用量 (总量)] 堆使用量(总量), 0.0022104 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
4.105: [scrub string table, 0.0000932 secs][1 CMS-remark: 393502K(707840K)] 398958K(1014528K), 0.0022104 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
## 开始清理阶段清除阶段,会和YGC并行产生
4.106: [CMS-concurrent-sweep-start]
4.156: [GC (Allocation Failure) 4.156: [ParNew: 272644K->4K(306688K), 0.0011464 secs] 666146K->393506K(1014528K), 0.0011886 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
......
4.249: [CMS-concurrent-sweep: 0.139/0.143 secs] [Times: user=0.29 sys=0.00, real=0.14 secs]
## 重置CMS数据结构开始新一轮并发回收周期
4.249: [CMS-concurrent-reset-start]
4.252: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
G1日志
G1的日志相比之前回收器的日志,会打印更多的东西,结构也越来越倾向后续版本的日志风格。
YGC
下面是一次YGC的输出内容
## 开始进行YGC
2.377: [GC pause (G1 Evacuation Pause) (young), 0.0254900 secs]
## 清理耗时,并行的GC任务线程数
[Parallel Time: 24.6 ms, GC Workers: 4]
## Min 第一个垃圾收集线程开始工作时 JVM 启动经过的时间
## Max 最有一个垃圾收集线程开始工作时 JVM 启动后经过的时间
## Diff 启动差值差距过大的时候表示机器上其他的进程正在从 JVM 垃圾收集进程中抢占 CPU 资源
[GC Worker Start (ms): Min: 2377.6, Avg: 2379.1, Max: 2383.1, Diff: 5.6]
## 扫描 root 集合花费的时间
[Ext Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2]
## 更新RSet
[Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
## 表示 Update RS 这个过程中处理了多少个日志缓冲区
[Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 1]
## 扫描每个新生代分区的 RSet
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
## 扫描代码中的 Root 节点花费的时间
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
## 将当前分区中存活的对象拷贝到新的分区中 时间
[Object Copy (ms): Min: 18.3, Avg: 22.2, Max: 23.7, Diff: 5.4, Sum: 89.0]
## 当一个垃圾收集线程完成任务时,它会进入一个临界区,并尝试帮助其他垃圾线程完成任务,min 表示该垃圾收集线程什么时候尝试Termination
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
## 再次尝试 terminate
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4]
## 垃圾收集线程完成其他任务的时间
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
## 每个垃圾收集线程的最小、最大、平均、差值和总共的时间
[GC Worker Total (ms): Min: 18.3, Avg: 22.3, Max: 23.8, Diff: 5.6, Sum: 89.2]
## 垃圾回收结束时间
[GC Worker End (ms): Min: 2401.4, Avg: 2401.4, Max: 2401.4, Diff: 0.0]
## 释放用于管理并行活动的数据结构
[Code Root Fixup: 0.0 ms]
## 清理更多的数据结构
[Code Root Purge: 0.0 ms]
## 清理 card table
[Clear CT: 0.2 ms]
## 其他活动
[Other: 0.6 ms]
## 选择要进行回收的分区放入 CSet 中
[Choose CSet: 0.0 ms]
## 处理Java 中的 软引用、弱引用、fianl、phantom、JNI
[Ref Proc: 0.2 ms]
## 遍历所有引用,将不能回收的放入 pending 表
[Ref Enq: 0.0 ms]
## 在回收过程中被修改的 card 将会被重置为“脏卡”
[Redirty Cards: 0.3 ms]
## 大对象可以在新生代收集的时候被回收
[Humongous Register: 0.0 ms]
## 确保巨型对象可以被回收、释放该巨型对象所占的分区、重置分区类型、将分区还给 free 列表、更新空闲空间大小时间
[Humongous Reclaim: 0.0 ms]
## 将要释放的分区还回 free 列表
[Free CSet: 0.0 ms]
## GC前后 Eden使用量(总容量) survivors 区前后使用量 JVM堆GC前后内存使用量(总容量)
[Eden: 52224.0K(52224.0K)->0.0B(45056.0K) Survivors: 0.0B->7168.0K Heap: 278.2M(1024.0M)->290.0M(1024.0M)]
## 时间
[Times: user=0.09 sys=0.00, real=0.03 secs]
并发GC的流程
并发GC的时候,会在后面表明GC的阶段
## 开始进行初始标记
[Times: user=0.13 sys=0.00, real=0.03 secs]
15.214: [GC pause (G1 Evacuation Pause) (young) (initial-mark), 0.0079992 secs]
[Parallel Time: 5.6 ms, GC Workers: 4]
......
[Eden: 324.0M(324.0M)->0.0B(379.0M) Survivors: 51200.0K->9216.0K Heap: 846.7M(1024.0M)->481.7M(1024.0M)]
[Times: user=0.02 sys=0.00, real=0.01 secs]
## 开始进行根区域扫描
15.223: [GC concurrent-root-region-scan-start]
15.231: [GC concurrent-root-region-scan-end, 0.0085091 secs]
## 开始进行并发标记
15.231: [GC concurrent-mark-start]
16.257: [GC concurrent-mark-end, 1.0253542 secs]
## 开始进行重新标记(最终标记)
16.257: [GC remark 16.257: [Finalize Marking, 0.0003073 secs] 16.257: [GC ref-proc, 0.0001121 secs] 16.257: [Unloading, 0.0006524 secs], 0.0022019 secs]
[Times: user=0.00 sys=0.00, real=0.01 secs]
## 开始进行清理阶段
16.260: [GC cleanup 792M->721M(1024M), 0.0012676 secs]
[Times: user=0.00 sys=0.00, real=0.00 secs]
16.261: [GC concurrent-cleanup-start]
16.261: [GC concurrent-cleanup-end, 0.0000275 secs]
Full GC
如果出现的Full GC 则需要考虑堆设置或者程序出现了问题。G1 的 Full GC 是单线程的并且会STW。所以尽量避免出现 Full GC
## Full GC
## GC原因
9.886: [Full GC (Allocation Failure) 511M->289M(512M), 0.7627054 secs]
## Eden、Survivors,堆区,元数据区使用量(总量)变化
[Eden: 0.0B(25.0M)->0.0B(96.0M) Survivors: 0.0B->0.0B Heap: 511.5M(512.0M)->289.4M(512.0M)], [Metaspace: 2663K->2663K(1056768K)]
[Times: user=0.86 sys=0.02, real=0.76 secs]
10.649: [GC concurrent-mark-abort]
使用工具分析
对于GC日志,我们可以分析某一次或者某一段时间的GC信息,但是仅仅通过某一次的记录去进行JVM的调整,显然会存在比较大的误差。如果我们将范围扩大到一个较长的运行周期,非常多的GC记录我们用人工去统计显然不现实。这里我们可以使用工具对GC日志进行分析。
我这里使用的是https://gceasy.io/进行日志分析,只需要将日志上传,就可以将日志数据转换为图表这样我们可以以一种全局的视角来观察这段时间的GC情况。
文件上传
获取报告
实时查看
如果没有配置GC日志但是希望查看GC信息的时候我们可以通过
jstat
命令来作为一种临时观察JVM的GC情况方式
使用jstat
我们可以查看JVM的GC情况,虽然打印的只是很短时间的内容,但是可以通过保持监控还是可以观察一段时间内GC信息。
命令格式
jstat [Options] pid [interval] [count]
pid:当前运行的 java进程号
interval:间隔时间,单位为秒或者毫秒
count:打印次数,如果缺省则打印无数次
Options参数可以配置的内容
参数 | 说明 |
---|---|
-gc | 统计 jdk gc时 heap信息,以使用空间字节数表示 |
-gcutil | 统计 gc时, heap情况,以使用空间的百分比表示 |
-class | 统计 class loader行为信息 |
-compile | 统计编译行为信息 |
-gccapacity | 统计不同 generations(新生代,老年代,持久代)的 heap容量情况 |
-gccause | 统计引起 gc的事件 |
-gcnew | 统计 gc时,新生代的情况 |
-gcnewcapacity | 统计 gc时,新生代 heap容量 |
-gcold | 统计 gc时,老年代的情况 |
-gcoldcapacity | 统计 gc时,老年代 heap容量 |
-gcpermcapacity | 统计 gc时, permanent区 heap容量 |
执行结果
实际执行并保持监控后我们可以看到下面的结果
## 每5 秒一次显示进程号为 12538的 java进成的 GC情况,结果如下图
jstat -gc 12538 5000
[root@WH-DSJ014 logs]# jstat -gc 12283 5000
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
47104.0 62976.0 0.0 0.0 922624.0 411026.5 2097152.0 188698.0 163968.0 157779.1 21160.0 19788.1 64 1.845 5 1.453 3.297
47104.0 62976.0 0.0 0.0 922624.0 411043.8 2097152.0 188698.0 163968.0 157779.1 21160.0 19788.1 64 1.845 5 1.453 3.297
47104.0 62976.0 0.0 0.0 922624.0 413697.3 2097152.0 188698.0 163968.0 157779.1 21160.0 19788.1 64 1.845 5 1.453 3.297
47104.0 62976.0 0.0 0.0 922624.0 415353.0 2097152.0 188698.0 163968.0 157779.1 21160.0 19788.1 64 1.845 5 1.453 3.297
47104.0 62976.0 0.0 0.0 922624.0 415799.8 2097152.0 188698.0 163968.0 157779.1 21160.0 19788.1 64 1.845 5 1.453 3.297
结果说明
输出内容对应值的说明可以参照下面表格进行分析。虽然我们没办法看到具体GC的过程,但是根据这些数据我们可以了解到JVM正在发生的事情,以及压力出现在哪个分代。
参数 | 说明 |
---|---|
S0C | 第一个幸存区的大小 |
S1C | 第二个幸存区的大小 |
S0U | 第一个幸存区的使用大小 |
S1U | 第二个幸存区的使用大小 |
EC | 伊甸园区的大小 |
EU | 伊甸园区的使用大小 |
OC | 老年代大小 |
OU | 老年代使用大小 |
MC | 方法区大小 |
MU | 方法区使用大小 |
CCSC | 压缩类空间大小 |
CCSU | 压缩类空间使用大小 |
YGC | 年轻代垃圾回收次数 |
YGCT | 年轻代垃圾回收消耗时间 |
FGC | 老年代垃圾回收次数 |
FGCT | 老年代垃圾回收消耗时间 |
GCT | 垃圾回收消耗总时间 |