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] <pid>
        (to connect to running process)
    jinfo [option] <executable <core>
        (to connect to a core file)
    jinfo [option] [server_id@]<remote server IP or hostname>
        (to connect to remote debug server)

where <option> is one of:
    -flag <name>         to print the value of the named VM flag
    -flag [+|-]<name>    to enable or disable the named VM flag
    -flag <name>=<value> to set the named VM flag to the given value
    -flags               to print VM flags
    -sysprops            to print Java system properties
    <no option>          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。