Java GC 日志解析

Posted 甜菜波波

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了Java GC 日志解析相关的知识,希望对你有一定的参考价值。

JVM 在Java应用程序优化中是不可缺少的一大重项,如何合理配置Java参数,如果验证配置参数的有效性,从GC日志中可以获得很重要的提示,以下是笔者对GC垃圾收集器默认开启的组合日志的部分的解析,希望能帮到想学习的同学O(∩_∩)O~~

工具/原料

 
  • jdk1.6
  • -XX:+PrintGCDetails
  • XX:+PrintGCTimeStamps
  • -Xloggc:filename
  • glassfish

方法/步骤

 
  1. 1

    Hotspot JVM GC 垃圾收集器的默认默认开启的组合为:

    技术分享图片
  2. 2

    使用GC日志命令行选项为:

    -XX:+PrintGCTimeStamps

    -XX:+PrintGCDetails

    -Xloggc:<filename>

  3. 3

    JVM 【-server】

    glassfish应用服务器  -server 启动 垃圾收集器默认组合方式为

    新生代:Parallel Scavenge 并行回收GC

    年老代和持久代:Parallel Old并行GC

  4. 4

    GC日志打印信息

    -XX:+PrintGCTimeStamps输出格式:

    289.556: [GC [PSYoungGen: 314113K->15937K(300928K)] 405513K->107901K(407680K), 0.0178568 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 

    293.271: [GC [PSYoungGen: 300865K->6577K(310720K)] 392829K->108873K(417472K), 0.0176464 secs] [Times: user=0.06 sys=0.00, real=0.01 secs] 

    详解:

    293.271是从jvm启动直到垃圾收集发生所经历的时间,GC表示这是一次Minor GC(新生代垃圾收集);[PSYoungGen: 300865K->6577K(310720K)] 提供了新生代空间的信息,PSYoungGen,表示新生代使用的是多线程垃圾收集器Parallel Scavenge。300865K表示垃圾收集之前新生代占用空间,6577K表示垃圾收集之后新生代的空间。新生代又细分为一个Eden区和两个Survivor区,Minor GC之后Eden区为空,6577K就是Survivor占用的空间。

    括号里的310720K表示整个年轻代的大小。

    392829K->108873K(417472K),表示垃圾收集之前(392829K)与之后(108873K)Java堆的大小(总堆417472K,堆大小包括新生代和年老代)

    由新生代和Java堆占用大小可以算出年老代占用空间,如,Java堆大小417472K,新生代大小310720K那么年老代占用空间是417472K-310720K=106752k;垃圾收集之前老年代占用的空间为392829K-300865K=91964k 垃圾收集之后老年代占用空间108873K-6577K=102296k.

    0.0176464 secs表示垃圾收集过程所消耗的时间。

     [Times: user=0.06 sys=0.00, real=0.01 secs] 提供cpu使用及时间消耗,user是用户模式垃圾收集消耗的cpu时间,实例中垃圾收集器消耗了0.06秒用户态cpu时间,sys是消耗系统态cpu时间,real是指垃圾收集器消耗的实际时间。

  5. 5

    -XX:+PrintGCDetails输出格式:

    293.289: [Full GC [PSYoungGen: 6577K->0K(310720K)] 

    [PSOldGen: 102295K->102198K(134208K)] 108873K->102198K(444928K) 

    [PSPermGen: 59082K->58479K(104192K)], 0.3332354 secs] 

    [Times: user=0.33 sys=0.00, real=0.33 secs] 

    说明:

    Full GC表示执行全局垃圾回收

    [PSYoungGen: 6577K->0K(310720K)] 提供新生代空间信息,解释同上

    [PSOldGen: 102295K->102198K(134208K)]提供了年老代空间信息;

    108873K->102198K(444928K)整个堆空间信息;

    [PSPermGen: 59082K->58479K(104192K)]提供了持久代空间信息;

  6. 6

    JVM【-client】

    glassfish应用服务器 默认 -client启动 垃圾收集器默认组合方式为

    新生代:Serial串行GC  (新生代使用-XX:+UseSerialGC收集器)

    年老代和持久代:Serial Old 串行GC

  7. 7

    GC日志打印信息:

     

    -XX:+PrintGCTimeStamps输出格式:

    9.007: [GC 9.007: [DefNew: 13526K->1060K(14400K), 0.0041350 secs] 44692K->32226K(46108K), 0.0041767 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 

    9.259: [GC 9.259: [DefNew: 13924K->1089K(14400K), 0.0042760 secs] 45090K->32650K(46108K), 0.0043143 secs] [Times: user=0.02 sys=0.00, real=0.02 secs] 

    说明:

    DefNew表示新生代使用Serial串行GC垃圾收集器,defNew提供新生代空间信息;

    DefNewGeneration 就是 default new generation

  8. 8

    -XX:+PrintGCDetails输出格式:

    9.348: [GC 9.348: [DefNew: 13953K->976K(14400K), 0.0040943 secs]9.352: [Tenured: 32163K->32220K(32220K), 0.1182207 secs] 45514K->32338K(46620K), [Perm : 30467K->30467K(65536K)], 0.1224318 secs] [Times: user=0.12 sys=0.00, real=0.13 secs] 

    DefNew:表示新生代使用Serial串行GC垃圾收集器,defNew提供新生代空间信息;

    Tenured:提供年老代空间信息;

    45514K->32338K(46620K):整个堆空间大小信息;

    Perm :提供持久代空间信息;

以上是关于Java GC 日志解析的主要内容,如果未能解决你的问题,请参考以下文章

JVM探秘:GC日志收集与分析

Java日志实战及解析-马如林-专题视频课程

Java日志实战及解析

无需解析日志即可从 Java 应用程序记录到 ELK

(转)Java 日志框架解析(下) - 最佳实践

java gc的日志在哪里看?