快速解读GC日志(转)

本文是 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之前的内存使用情况, 下方表示结束后的内存使用情况:

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

原文链接: Understanding Garbage Collection Logs

翻译日期: 2015年10月18日

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

http://blog.csdn.net/renfufei/article/details/49230943

 

时间: 2024-09-22 17:21:23

快速解读GC日志(转)的相关文章

jvm GC日志解读

0.产生日志 0.1 IDE 运行下面代码会得到gc日志. 0.2 server -Xloggc:../gclogdir/logc.txt   指定gc日志的打印位置,注意必须指定到文件,不能为目录. 当应用重启时,会产生新的gc.log,旧的gc.log自动被重命名为形如 "gc.log.20161103103532"这样的格式. 1.Parallel Scavenge 这是一款年轻代GC器. 293.271: [GC [PSYoungGen: 300865K->6577K(3

WEB项目严重内存泄露-详见GC日志,谁有好的解决方法?

问题描述 一般三天就会outmemory,以上是一晚上我摘抄的部分GC输出,最下面六行是Full GC后的输出:[GC [PSYoungGen: 131072K->10667K(152896K)] 137699K->17295K(1551040K), 0.0210980 secs] [Times: user=0.06 sys=0.01, real=0.02 secs][GC [PSYoungGen: 141739K->16988K(152896K)] 148367K->23616K

java-关于GC日志打印,求高人解析

问题描述 关于GC日志打印,求高人解析 最近项目经常不正常的内存溢出,后面尝试打印了下GC日志 [CMS-concurrent-preclean: 0.348/0.351 secs] [Times: user=0.64 sys=0.02, real=0.35 secs] [CMS-concurrent-abortable-preclean: 0.054/0.054 secs] [Times: user=0.10 sys=0.00, real=0.05 secs] [GC[YG occupancy

GC日志的可视化分析

GC日志的格式不够友好,人看起来很费劲.所以给大家推荐两个好用的GUI分析工具,导入gc.log即可生成图文并茂报告的界面. GC日志如何得到?推荐使用以下命令: -Xloggc:/home/admin/logs/gc.log -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+UseG1GC -XX:MaxGCPauseMillis=300 下文中涉及到的链接,如果打不开,请尝试翻墙. 1.GCViewer 这是一个jar,支持java 1.6(ja

JVM实用参数(八)GC日志

原文地址:https://blog.codecentric.de/en/2014/01/useful-jvm-flags-part-8-gc-logging/ 作者:PATRICK PESCHLOW,译者:Greenster 校对:梁海舰 本系列的最后一部分是有关垃圾收集(GC)日志的JVM参数.GC日志是一个很重要的工具,它准确记录了每一次的GC的执行时间和执行结果,通过分析GC日志可以优化堆设置和GC设置,或者改进应用程序的对象分配模式. -XX:+PrintGC 参数-XX:+PrintG

【Best Practice】基于阿里云数加·StreamCompute快速构建网站日志实时分析大屏

本文偏向与实操层面的为大家介绍,如何基于阿里云数加StreamCompute.DataV快速构建网站日志实时分析. [什么场景适合用流计算] 流计算提供了针对流式数据实时分析的一站式工具链,对于大量流式数据存在实时分析.计算.处理的逻辑可以考虑通过流计算该任务.举例如下: 1. 针对实时营销活动,需要实时获取活动流量数据分析以了解活动的营销情况,此时可以上流计算. 2. 针对物联网设备监控,需要实时获取设备数据进行实时灾难监控,此时可以上流计算. 3. 对于手机APP数据实时分析,需要实时了解手

Java GC 日志详解(转)

Java GC日志可以通过 +PrintGCDetails开启 以ParallelGC为例 YoungGC日志解释如下(图片源地址:这里) : FullGC(图片源地址:这里): http://blog.csdn.net/alivetime/article/details/6895537  

mysql(slow-query)快速开启慢日志查询的方法

mysql(slow-query)快速开启慢日志查询的方法 mysql有一个功能就是可以log下来运行的比较慢的sql语句,默认是没有这个log的 打开 my.ini ,找到 [mysql] 在其下面添加 long_query_time = 2 log-slow-queries = D:/mysql/logs/slow.log #设置把日志写在那里,可以为空,系统会给 一个缺省的文件 #log-slow-queries = /var/youpath/slow.log linux下host_nam

logback: 通用、可靠、快速灵活的日志框架--配置样例

一.简介:       logback是一个可靠.通用.快速而又灵活的Java日志框架. 声称要取代log4j.Logback is intended as a successor to the popular log4j projec       logback当前分成三个模块:logback-core,logback- classic和logback-access.       logback-core是其它两个模块的基础模块.logback-classic是log4j的一个改良版本.