【GC分析】Java GC日志查看「建议收藏」

2022-02-16 08:10:34 浏览数 (1)

大家好,我是架构君,一个会写代码吟诗的架构师。今天说一说【GC分析】Java GC日志查看「建议收藏」,希望能够帮助大家进步!!!

Java中的GC有哪几种类型?

参数

描述

UseSerialGC

虚拟机运行在Client模式的默认值,打开此开关参数后, 使用Serial Serial Old收集器组合进行垃圾收集。

UseParNewGC

打开此开关参数后,使用ParNew Serial Old收集器组合进行垃圾收集。

UseConcMarkSweepGC

打开此开关参数后,使用ParNew CMS Serial Old收集器组合进行垃圾收集。Serial Old作为CMS收集器出现Concurrent Mode Failure的备用垃圾收集器。

UseParallelGC

虚拟机运行在Server模式的默认值,打开此开关参数后,使用Parallel Scavenge Serial Old收集器组合进行垃圾收集。

UseParallelOldGC

打开此开关参数后,使用Parallel Scavenge Parallel Old收集器组合进行垃圾收集。

在Java程序启动完成后,通过jps观察进程来查询到当前运行的java进程,使用

代码语言:javascript复制
jinfo –flag UseSerialGC 进程

的方式可以定位其使用的gc策略,因为这些参数都是boolean型的常量,如果使用该种gc策略会出现+号,否则-号。

使用-XX: 上述GC策略可以开启对应的GC策略。

GC日志查看

可以通过在java命令种加入参数来指定对应的gc类型,打印gc日志信息并输出至文件等策略。

GC的日志是以替换的方式(>)写入的,而不是追加(>>),如果下次写入到同一个文件中的话,以前的GC内容会被清空。

对应的参数列表

代码语言:javascript复制
此代码由Java架构师必看网-架构君整理
-XX: PrintGC 输出GC日志
-XX: PrintGCDetails 输出GC的详细日志
-XX: PrintGCTimeStamps 输出GC的时间戳(以基准时间的形式)
-XX: PrintGCDateStamps 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234 0800)
-XX: PrintHeapAtGC 在进行GC的前后打印出堆的信息
-Xloggc:../logs/gc.log 日志文件的输出路径

例如:eclipse.ini中配置下面代码启动后会在同一目录下生成gc.log

代码语言:javascript复制
-Xloggc:gc.log
-XX: PrintGCTimeStamps
-XX: PrintGCDetails

这里使用如下的参数来进行日志的打印:

代码语言:javascript复制
此代码由Java架构师必看网-架构君整理
-XX: PrintGCDateStamps -XX: PrintGCDetails -Xloggc:./gclogs

对于新生代回收的一行日志,其基本内容如下:

代码语言:javascript复制
2014-07-18T16:02:17.606 0800: 611.633: [GC 611.633: [DefNew: 843458K->2K(948864K), 0.0059180 secs] 2186589K->1343132K(3057292K), 0.0059490 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

其含义大概如下:

代码语言:javascript复制
2014-07-18T16:02:17.606 0800(当前时间戳): 611.633(时间戳): [GC(表示Young GC) 611.633: [DefNew(单线程Serial年轻代GC): 843458K(年轻代垃圾回收前的大小)->2K(年轻代回收后的大小)(948864K(年轻代总大小)), 0.0059180 secs(本次回收的时间)] 2186589K(整个堆回收前的大小)->1343132K(整个堆回收后的大小)(3057292K(堆总大小)), 0.0059490 secs(回收时间)] [Times: user=0.00(用户耗时) sys=0.00(系统耗时), real=0.00 secs(实际耗时)]

老年代回收的日志如下:

代码语言:javascript复制
2014-07-18T16:19:16.794 0800: 1630.821: [GC 1630.821: [DefNew: 1005567K->111679K(1005568K), 0.9152360 secs]1631.736: [Tenured:
2573912K->1340650K(2574068K), 1.8511050 secs] 3122548K->1340650K(3579636K), [Perm : 17882K->17882K(21248K)], 2.7854350 secs] [Times: user=2.57 sys=0.22, real=2.79 secs]

gc日志中的最后貌似是系统运行完成前的快照:

代码语言:javascript复制
Heap
 def new generation   total 1005568K, used 111158K [0x00000006fae00000, 0x000000073f110000, 0x0000000750350000)
  eden space 893888K,  12% used [0x00000006fae00000, 0x0000000701710e90, 0x00000007316f0000)
  from space 111680K,   3% used [0x0000000738400000, 0x000000073877c9b0, 0x000000073f110000)
  to   space 111680K,   0% used [0x00000007316f0000, 0x00000007316f0000, 0x0000000738400000)
 tenured generation   total 2234420K, used 1347671K [0x0000000750350000, 0x00000007d895d000, 0x00000007fae00000)
   the space 2234420K,  60% used [0x0000000750350000, 0x00000007a2765cb8, 0x00000007a2765e00, 0x00000007d895d000)
 compacting perm gen  total 21248K, used 17994K [0x00000007fae00000, 0x00000007fc2c0000, 0x0000000800000000)
   the space 21248K,  84% used [0x00000007fae00000, 0x00000007fbf92a50, 0x00000007fbf92c00, 0x00000007fc2c0000)
No shared spaces configured.

GC日志的离线分析

可以使用一些离线的工具来对GC日志进行分析,比如sun的gchisto( https://java.net/projects/gchisto),gcviewer( https://github.com/chewiebug/GCViewer ),这些都是开源的工具,用户可以直接通过版本控制工具下载其源码,进行离线分析。

下面就已gcviewer为例,简要分析一下gc日志的离线分析,gcviewer源代码工程是maven结构的,可以直接用maven进行package,这里编译的是1.34版本,本版本的快照已经上传至附件中。

需要说明的是,gcviewer支持多种参数生成的gc日志,直接通过java –jar的方式运行,加载生成的gc日志即可:

------------------------第二种理解-----------------------

首先,给出一个日志输出的例子:

参数设置为:

-XX: PrintGCDetails -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:NewSize=10M -XX:MaxNewSize=10M

参数解释:

-XX: PrintGCDetails 启用日志

-XX:-UseAdaptiveSizePolicy 禁用动态调整,使SurvivorRatio可以起作用

-XX:SurvivorRatio=8 设置Eden:Survivior=8

-XX:NewSize=10M -XX:MaxNewSize=10M 设置整个新生代的大小为10M

默认垃圾收集器为:Parallel Scavenge

输出结果为:

代码语言:javascript复制
[GC [PSYoungGen: 4423K->320K(9216K)] 4423K->320K(58880K), 0.0011900 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
 [Full GC (System) [PSYoungGen: 320K->0K(9216K)] [ParOldGen: 0K->222K(49664K)] 320K->222K(58880K) [PSPermGen: 2458K->2456K(21248K)], 0.0073610 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 
 Heap
  PSYoungGen      total 9216K, used 491K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
   eden space 8192K, 6% used [0x00000000ff600000,0x00000000ff67af50,0x00000000ffe00000)
   from space 1024K, 0% used [0x00000000ffe00000,0x00000000ffe00000,0x00000000fff00000)
   to   space 1024K, 0% used [0x00000000fff00000,0x00000000fff00000,0x0000000100000000)
  ParOldGen       total 49664K, used 222K [0x00000000c5800000, 0x00000000c8880000, 0x00000000ff600000)
   object space 49664K, 0% used [0x00000000c5800000,0x00000000c58378a0,0x00000000c8880000)
  PSPermGen       total 21248K, used 2466K [0x00000000c0600000, 0x00000000c1ac0000, 0x00000000c5800000)
   object space 21248K, 11% used [0x00000000c0600000,0x00000000c0868b48,0x00000000c1ac0000)
 

前半段分析:

GC (minor )日志

Full GC 日志

后半段分析:

对照上面的图,GC日志中的PSYoungGen(PS是指Parallel Scavenge)为Eden FromSpace,而整个YoungGeneration为Eden FromSpace ToSpace。

我们设置的新生代大小为10240K,这包括9216K大小的PSYoungGen和1024K大小的ToSpace。其中,PSYoungGen中的Eden:FromSpace为8:1,

这包括8192K的Eden和1024K的FromSpace。

关于老年代和永久代的输出比较简单,不再详述。

更详细描述参见官方文档:http://www.oracle.com/technetwork/java/javase/gc-tuning-6-140523.html

最后注意,如果新生代的空间不能刚好按比例划分,则可能有一定的误差。比如,将上述的参数中SurvivorRatio改为10,则输出如下:

代码语言:javascript复制
[GC [PSYoungGen: 4439K->320K(9408K)] 4439K->320K(59072K), 0.0010120 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
 [Full GC (System) [PSYoungGen: 320K->0K(9408K)] [ParOldGen: 0K->222K(49664K)] 320K->222K(59072K) [PSPermGen: 2458K->2456K(21248K)], 0.0095710 secs] [Times: user=0.02 sys=0.00, real=0.00 secs] 
 Heap
  PSYoungGen      total 9408K, used 514K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
   eden space 8576K, 6% used [0x00000000ff600000,0x00000000ff680b78,0x00000000ffe60000)
   from space 832K, 0% used [0x00000000ffe60000,0x00000000ffe60000,0x00000000fff30000)
   to   space 832K, 0% used [0x00000000fff30000,0x00000000fff30000,0x0000000100000000)
  ParOldGen       total 49664K, used 222K [0x00000000c5800000, 0x00000000c8880000, 0x00000000ff600000)
   object space 49664K, 0% used [0x00000000c5800000,0x00000000c58378a0,0x00000000c8880000)
  PSPermGen       total 21248K, used 2466K [0x00000000c0600000, 0x00000000c1ac0000, 0x00000000c5800000)
   object space 21248K, 11% used [0x00000000c0600000,0x00000000c0868b48,0x00000000c1ac0000)

可以看到新生代的相关数值是有一定误差的

GC日志时间分析: http://www.cnblogs.com/senlinyang/p/8717611.html

0 人点赞