linux如何导出gc日志,JVM——jinfo命令使用及GC日志分析

关注：CodingTechWork，一起学习进步。

引言

在我们的日常开发过程中，可能不怎么关注JVM的GC，但是一旦我们开发的程序上线后，伴随着运行时间的拉长，各种线上问题就出现了，比如内存溢出，比如机器cpu和memory耗尽，除了查看程序的日志是否报错抛异常，排查是否有bug，而有时候就得先看看程序运行所需要的内存是否足够。这时，我们就需要GC日志来辅助查看。

GC类型

参数

新生代GC

老年代GC

-XX:+UseSerialGC

虚拟机运行在Client模式的默认值，Serial 串行GC

Serial Old串行GC

-XX:+UseParallelGC

虚拟机运行在Server模式的默认值，Parallel Scavenge并行回收GC

Parallel Old并行GC

-XX:+UseConcMarkSweepGC

ParNew并行GC

CMS并发GC，当出现Concurrent Mode Failure时采用Serial Old串行GC作为备用垃圾收集器

-XX:+UseParNewGC

ParNew并行GC

Serial Old串行GC

-XX:+UseParallelOldGC

Parallel Scavenge并行回收GC

Parallel Old并行GC

-XX:+UseConcMarkSweepGC

-XX:+UseParaNewGC

Serial串行GC

CMS并发GC，当出现Concurrent Mode Failure时采用Serial Old串行GC

jinfo使用

介绍

jinfo全称Java Configuration info，用于实时查看和调整JVM配置参数。

语法参数

[linux@01 ~]$ jinfo -help

Usage:

jinfo [option]

(to connect to running process)

jinfo [option]

(to connect to a core file)

jinfo [option] [server_id@]

(to connect to remote debug server)

where is one of:

-flag to print the value of the named VM flag

-flag [+|-] to enable or disable the named VM flag

-flag = to set the named VM flag to the given value

-flags to print VM flags

-sysprops to print Java system properties

to print both of the above

-h | -help to print this help message

示例

查看JVM运行参数

[linux@01 ~]$ jinfo -flags 15764

Attaching to process ID 15764, please wait...

Debugger attached successfully.

Server compiler detected.

JVM version is 25.65-b01

Non-default VM flags: -XX:CICompilerCount=12 -XX:InitialHeapSize=526385152 -XX:MaxHeapSize=8392802304 -XX:MaxNewSize=2797600768 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=175112192 -XX:OldSize=351272960 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC

Command line: -Djava.util.logging.config.file=/home/s1/tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -XX:MaxPermSize=1024m -Djdk.tls.ephemeralDHKeySize=2048 -Djava.protocol.handler.pkgs=org.apache.catalina.webresources -agentlib:jdwp=transport=dt_socket,address=8017,server=y,suspend=n -Ds1.conf.dir=/home/s1/conf -Dservice01.logs.dir=/home/s1/logs -Ds1.home.dir=/home/s1-Ds1.server.port=7005 -Ds1.http.port=7010 -Ds1.redirect.port=7443 -Ds1.ajp.port=7009 -Dcas.server.ip=10.x.x.x -Dcas.server.port=7010 -Dbdoc.http.ip=10.x.x.x -Ds1.mysql.address=10.x.x.x:3306 -Ds1.mysql.database.name=db01 -Ds1.mysql.user=s1 -Ds1.mysql.passwd=123456 -Dcatalina.base=/home/s1/tomcat -Dcatalina.home=/home/s1/tomcat -Djava.io.tmpdir=/home/s1/tomcat/temp

查看指定参数是否开启

[linux@01 ~]$ jinfo -flag UseSerialGC 15764

-XX:-UseSerialGC

[linux@01 ~]$

[linux@01 ~]$ jinfo -flag UseParNewGC 15764

-XX:-UseParNewGC

[linux@01 ~]$

[linux@01 ~]$ jinfo -flag UseConcMarkSweepGC 15764

-XX:-UseConcMarkSweepGC

[linux@01 ~]$

[linux@01 ~]$ jinfo -flag UseParallelGC 15764

-XX:+UseParallelGC

[linux@01 ~]$

[linux@01 ~]$ jinfo -flag UseParallelOldGC 15764

-XX:+UseParallelOldGC

查看指定配置参数值

[linux@01 ~]$ jinfo -flag MaxHeapSize 15764

-XX:MaxHeapSize=8392802304

增删配置参数

[linux@01 ~]$ jinfo -flag +PrintGC 17984

[linux@01 ~]$ jinfo -flag PrintGC 17984

-XX:+PrintGC

GC日志

GC日志常用参数

参数

说明

-XX:+PrintGC

输出GC日志

-XX:+PrintGCDetails

输出GC详细日志

-XX:+PrintGCDateStamps

以日期的形式输出GC的时间戳，如2021-01-14T20:20:59.125+0800

-XX:+PrintGCTimeStamps

以基准时间的形式输出GC的时间戳

-XX:+PrintHeapAtGC

在进行GC的前后打印出堆的信息

-XX:+PrintGCApplicationConcurrentTime

打印应用程序执行时间

-XX:+PrintGCApplicationStoppedTime

打印应用程序因GC而产生的停顿时间

-Xloggc:/var/logs/gc.log

以文件的方式保存GC日志

对象优先在Eden分配

我们先看一下gc的一个分代处理。

Eden分配

大多数情况下，对象在新生代Eden区中分配，当Eden区没有足够空间进行分配时，VM将发起一次Minor GC。

新生代总可用空间：Eden区 + 1个Survivor区的总容量。

新生代和老年代GC

新生代GC(Minor GC)和老年代GC(Major GC/ Full GC)

新生代GC：Minor GC指发生在新生代的垃圾收集动作，Java对象大多是朝生夕灭，Minor GC非常频繁，回收速度快。回收新生代，新生代中分为Eden空间和两块较小的Survivor空间，每次使用Eden和其中的一块Survivor。默认Eden : Survivor=8:1，Survivor不够时，老年代内存分配担保。新生代中，每次垃圾收集时都发现有大批对象死去，少量存活，选用复制算法。

老年代GC：Major GC指发生在老年代的GC，出现此GC，经常会伴随至少一次Minor GC，一般Major GC比Minor GC慢10倍以上。老年代中，对象存活率高、没有额外空间进行分配担保，使用“标记-清理”或者“标记-整理”。

GC日志示例分析

[Eden: 5888.0M(5888.0M)->0.0B(6592.0M) Survivors: 640.0M->672.0M Heap: 27.4G(32.0G)->21.7G(32.0G)]

[Times: user=2.55 sys=0.04, real=0.14 secs]

Eden: 5888.0M(5888.0M)->0.0B(6592.0M)：表示发生GC前，Eden空间大小是5888.0M,且空间全部被占用。发生GC发生之后，年轻代空间(Young Generation)下降到0，Eden空间增长到6592.0M。

Survivors: 640.0M->672.0M：表示发生GC前，Survivor存活区空间是640.0M。发生GC后，存活区空间增长到672.0M，表明对象从年轻代(Young Generation)提升到存活区空间(Survivor space)

Heap: 27.4G(32.0G)->21.7G(32.0G)：表示发生GC前，Heap堆空间大小是32.0G，被占用27.4G。发生GC后，堆大小仍然为32.0G，堆占用了21.7G(即(27.4G-21.7G)的对象被垃圾回收了)。

[Times: user=2.55 sys=0.04, real=0.14 secs]：

1)user表示CPU工作在用户态所花费的时间；

2)sys表示CPU工作在内核态所花费的时间；

3)real表示GC事件所花费的总时间。

一般，user+sys就是CPU花费的实际时间。

a)如果进程工作在多线程的环境下(垃圾回收通过并发执行)，一般该值会超过real，即：user + sys > real。

b)如果出现串行的垃圾回收，有可能观察到user + sys = real。

c)如果CPU资源匮乏、I/O操作繁忙，GC就会出现等待的情况，这时会出现user + sys < real。