欢迎您访问
我们的官方技术分享网站
关注我们

—— 加入社群 ——
「十大城市」工作内推
「微信/QQ」技术讨论
「面试真题」随时领取
公众号名称:搜云库技术团队  公众号ID:souyunku
关注公众号后发送 口令 获取关闭弹窗地址
公众号每天中午 12:20 为你推送一篇技术文章

九、GC 性能优化 – 快速解读GC日志

[隐藏目录]

除了对作者表示感谢外,还需要感谢译者【铁锚】,谢谢两位的付出
出处:https://blog.csdn.net/renfufei/column/info/14851

本文是 Plumbr 发行的 Java垃圾收集指南 的部分内容。文中将介绍GC日志的输出格式, 以及如何解读GC日志, 从中提取有用的信息。我们通过 -XX:+UseSerialGC 选项,指定JVM使用串行垃圾收集器, 并使用下面的启动参数让 JVM 打印出详细的GC日志:

-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps

这样配置以后,发生GC时输出的日志就类似于下面这种格式(为了显示方便,已手工折行):

2015-05-26T14:45:37.987-0200: 151.126: 
  [GC (Allocation Failure) 151.126:
    [DefNew: 629119K->69888K(629120K), 0.0584157 secs]
    1619346K->1273247K(2027264K), 0.0585007 secs] 
  [Times: user=0.06 sys=0.00, real=0.06 secs]

2015-05-26T14:45:59.690-0200: 172.829: 
  [GC (Allocation Failure) 172.829: 
    [DefNew: 629120K->629120K(629120K), 0.0000372 secs]
    172.829: [Tenured: 1203359K->755802K(1398144K), 0.1855567 secs]
    1832479K->755802K(2027264K),
    [Metaspace: 6741K->6741K(1056768K)], 0.1856954 secs]
  [Times: user=0.18 sys=0.00, real=0.18 secs]

上面的GC日志暴露了JVM中的一些信息。事实上,这个日志片段中发生了 2 次垃圾回收事件(Garbage Collection events)。其中一次清理的是年轻代(Young generation), 而第二次处理的是整个堆内存。下面我们来看,如何解读第一次GC事件,发生在年轻代中的小型GC(Minor GC):

2015-05-26T14:45:37.987-02001:151.1262:

[GC3(Allocation Failure4)151.126:

[DefNew5:629119K->69888K6(629120K)7, 0.0584157 secs]
1619346K->1273247K8(2027264K)9,0.0585007 secs10]

[Times: user=0.06 sys=0.00, real=0.06 secs]11

1、 2015-05-26T14:45:37.987-0200 – GC事件(GC event)开始的时间点.
2、 151.126 – GC事件的开始时间,相对于JVM的启动时间,单位是秒(Measured in seconds).
3、 GC – 用来区分(distinguish)是 Minor GC 还是 Full GC 的标志(Flag). 这里的 GC 表明本次发生的是 Minor GC.
4、 Allocation Failure – 引起垃圾回收的原因. 本次GC是因为年轻代中没有任何合适的区域能够存放需要分配的数据结构而触发的.
5、 DefNew – 使用的垃圾收集器的名字. DefNew 这个名字代表的是: 单线程(single-threaded), 采用标记复制(mark-copy)算法的, 使整个JVM暂停运行(stop-the-world)的年轻代(Young generation) 垃圾收集器(garbage collector).
6、 629119K->69888K – 在本次垃圾收集之前和之后的年轻代内存使用情况(Usage).
7、 (629120K) – 年轻代的总的大小(Total size).
8、 1619346K->1273247K – 在本次垃圾收集之前和之后整个堆内存的使用情况(Total used heap).
9、 (2027264K) – 总的可用的堆内存(Total available heap).
10、 0.0585007 secs – GC事件的持续时间(Duration),单位是秒.
11、 [Times: user=0.06 sys=0.00, real=0.06 secs] – GC事件的持续时间,通过多种分类来进行衡量:

  • user – 此次垃圾回收, 垃圾收集线程消耗的所有CPU时间(Total CPU time).
  • sys – 操作系统调用(OS call) 以及等待系统事件的时间(waiting for system event)
  • real – 应用程序暂停的时间(Clock time). 由于串行垃圾收集器(Serial Garbage Collector)只会使用单个线程, 所以 real time 等于 user 以及 system time 的总和.

通过上面的分析, 我们可以计算出在垃圾收集期间, JVM 中的内存使用情况。在垃圾收集之前, 堆内存总的使用了 1.54G (1,619,346K)。其中, 年轻代使用了 614M(629,119k)。可以算出老年代使用的内存为: 967M(990,227K)。

下一组数据( -> 右边)中蕴含了更重要的结论, 年轻代的内存使用在垃圾回收后下降了 546M(559,231k), 但总的堆内存使用(total heap usage)只减少了 337M(346,099k). 通过这一点,我们可以计算出, 有 208M(213,132K) 的年轻代对象被提升到老年代(Old)中。

这个GC事件可以用下面的示意图来表示, 上方表示GC之前的内存使用情况, 下方表示结束后的内存使用情况:

img_1.png

如果你想学习更多, 请查看完整的 Java垃圾收集指南, 本示例是从其中抽取的。

原文链接: Understanding Garbage Collection Logs

翻译日期: 2015年10月18日

翻译人员: 铁锚 http://blog.csdn.net/renfufei

干货推荐

本站推荐:精选优质专栏

专栏汇总:Java并发

专栏汇总:Java8 新特性

专栏汇总:Java 9 新特性

附录:GC 性能优化 ,系列文章

一、GC 性能优化 – G1垃圾收集器入门
二、GC 性能优化 – 垃圾收集简介
三、GC 性能优化 – Java中的垃圾收集
四、GC 性能优化 – GC 算法(基础篇)
五、GC 性能优化 – GC 算法(实现篇)
六、GC 性能优化 – GC 调优(基础篇)
七、GC 性能优化 – GC 调优(工具篇)
八、GC 性能优化 – GC 调优(实战篇)
九、GC 性能优化 – 快速解读GC日志

赞(0) 打赏

版权归原创作者所有,任何形式转载请联系作者;搜云库技术团队 » 九、GC 性能优化 – 快速解读GC日志
本站:免责声明!

评论 抢沙发

  • 昵称 (必填)
  • 邮箱 (必填)
  • 网址

「 搜云库技术团队 」是一个专注于开发技术研究与知识分享的网站

关注我们联系我们

觉得文章有用就打赏一下文章作者

支付宝扫一扫打赏

微信扫一扫打赏