垃圾回收G1日志解析

G1垃圾回收器介绍

首先要搞清楚G1垃圾回收的过程

主要分为下面4个步骤：

初始标记（Initial Marking）由于常规标记对象是否直接关联到GC roots，过程简单，停顿时间短

并发标记（Concurrent Marking）由于可达性性分析，存在较长停顿

最终标记（Final Marking）由于把并发标记时漏掉的那部分垃圾内存标记起来，比较少，停顿时间短

筛选回收（Live Data Couting and Evacuation）对标记后的垃圾内存进行整理，按指定计划进行回收。

在下面的案例中，红色部分明确标明了这4个阶段。

日志分析案例

下面一段日志是我在spark计算任务中产生的垃圾回收日志：

2018-11-13T05:32:44.473+0800: 1.857: Application time: 0.2130324 seconds
2018-11-13T05:32:44.571+0800: 1.954: Application time: 0.0970449 seconds
2018-11-13T05:32:44.696+0800: 2.079: Application time: 0.1249397 seconds
2018-11-13T05:32:44.874+0800: 2.258: Application time: 0.1776871 seconds
 2.258: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold]
 2.258: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested]
2018-11-13T05:32:44.875+0800: 2.259: [GC pause (Metadata GC Threshold) (young) (initial-mark) 2.260:
[G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 10.00 ms,
remaining time: 190.00 ms, target pause time: 200.00 ms]
 2.260: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 60 regions, survivors: 0 regions, predicted young region time: 3605.71 ms]
 2.260: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 60 regions, survivors: 0 regions, old: 0 regions,
predicted pause time: 3615.71 ms, target pause time: 200.00 ms]
2018-11-13T05:32:44.948+0800: 2.331: [SoftReference, 0 refs, 0.0002103 secs]2018-11-13T05:32:44.948+0800: 2.332:
[WeakReference, 970 refs, 0.0005817 secs]2018-11-13T05:32:44.949+0800: 2.332: [FinalReference, 4265 refs, 0.0266394 secs]
2018-11-13T05:32:44.975+0800: 2.359: [PhantomReference, 0 refs, 3 refs, 0.0000585 secs]2018-11-13T05:32:44.976+0800: 2.359:
[JNI Weak Reference, 0.0001374 secs], 0.1040572 secs]
   [Parallel Time: 29.1 ms, GC Workers: 38]
      [GC Worker Start (ms): Min: 2260.1, Avg: 2265.0, Max: 2265.9, Diff: 5.8]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 18.2, Max: 22.7, Diff: 22.5, Sum: 691.2]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 8.6, Diff: 8.6, Sum: 10.0]
      [Object Copy (ms): Min: 0.0, Avg: 3.9, Max: 22.9, Diff: 22.9, Sum: 147.1]
      [Termination (ms): Min: 0.0, Avg: 1.3, Max: 2.3, Diff: 2.3, Sum: 50.3]
         [Termination Attempts: Min: 1, Avg: 3.0, Max: 17, Diff: 16, Sum: 115]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 1.6]
      [GC Worker Total (ms): Min: 22.7, Avg: 23.7, Max: 28.6, Diff: 5.9, Sum: 900.6]
      [GC Worker End (ms): Min: 2288.6, Avg: 2288.7, Max: 2288.8, Diff: 0.2]
   [Code Root Fixup: 1.0 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 1.0 ms]
   [Other: 72.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 68.9 ms]
      [Ref Enq: 0.2 ms]
      [Redirty Cards: 0.4 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.5 ms]
   [Eden: 240.0M(512.0M)->0.0B(496.0M) Survivors: 0.0B->16.0M Heap: 254.0M(10.0G)->31.7M(10.0G)]
 [Times: user=0.44 sys=0.09, real=0.11 secs]
2018-11-13T05:32:44.980+0800: 2.363: [GC concurrent-root-region-scan-start]
2018-11-13T05:32:44.996+0800: 2.380: [GC concurrent-root-region-scan-end, 0.0167701 secs]
2018-11-13T05:32:44.996+0800: 2.380: [GC concurrent-mark-start]
2018-11-13T05:32:45.013+0800: 2.396: [GC concurrent-mark-end, 0.0160995 secs]
2018-11-13T05:32:45.013+0800: 2.396: Application time: 0.0328728 seconds
2018-11-13T05:32:45.013+0800: 2.397: [GC remark 2018-11-13T05:32:45.013+0800: 2.397:
[Finalize Marking, 0.0331140 secs] 2018-11-13T05:32:45.047+0800: 2.430:
[GC ref-proc2018-11-13T05:32:45.047+0800: 2.430:
[SoftReference, 0 refs, 0.0001959 secs]2018-11-13T05:32:45.047+0800: 2.430:
[WeakReference, 0 refs, 0.0001148 secs]2018-11-13T05:32:45.047+0800: 2.430:
[FinalReference, 0 refs, 0.0001158 secs]2018-11-13T05:32:45.047+0800: 2.430:
[PhantomReference, 0 refs, 0 refs, 0.0002233 secs]2018-11-13T05:32:45.047+0800: 2.431:
[JNI Weak Reference, 0.0000572 secs], 0.0008127 secs] 2018-11-13T05:32:45.047+0800: 2.431: [Unloading, 0.0078450 secs], 0.0442183 secs]
 [Times: user=0.36 sys=0.01, real=0.05 secs]
2018-11-13T05:32:45.058+0800: 2.441: Application time: 0.0001231 seconds
2018-11-13T05:32:45.058+0800: 2.442: [GC cleanup 35M->35M(10G), 0.0134109 secs]
 [Times: user=0.04 sys=0.00, real=0.01 secs]
2018-11-13T05:32:45.144+0800: 2.528: Application time: 0.0721037 seconds
2018-11-13T05:32:45.392+0800: 2.775: Application time: 0.2464978 seconds
2018-11-13T05:32:45.805+0800: 3.188: Application time: 0.4129881 seconds
2018-11-13T05:32:46.806+0800: 4.190: Application time: 1.0001058 seconds

下面是每条日志含义解析：Application time： 应用程序时间

原文地址：https://www.cnblogs.com/geektcp/p/9951539.html

时间： 2024-08-29 22:23:30

垃圾回收G1日志解析的相关文章

Java虚拟机5：Java垃圾回收（GC）机制详解

http://www.cnblogs.com/xrq730/p/4836700.html 哪些内存需要回收? 哪些内存需要回收是垃圾回收机制第一个要考虑的问题,所谓“要回收的垃圾”无非就是那些不可能再被任何途径使用的对象.那么如何找到这些对象? 1.引用计数法这个算法的实现是,给对象中添加一个引用计数器,每当一个地方引用这个对象时,计数器值+1:当引用失效时,计数器值-1.任何时刻计数值为0的对象就是不可能再被使用的.这种算法使用场景很多,但是,Java中却没有使用这种算法,因为这种算法很

Java虚拟机学习5、Java垃圾回收（GC）机制详解

哪些内存需要回收? 哪些内存需要回收是垃圾回收机制第一个要考虑的问题,所谓“要回收的垃圾”无非就是那些不可能再被任何途径使用的对象.那么如何找到这些对象? 1.引用计数法这个算法的实现是,给对象中添加一个引用计数器,每当一个地方引用这个对象时,计数器值+1:当引用失效时,计数器值-1.任何时刻计数值为0的对象就是不可能再被使用的.这种算法使用场景很多,但是,Java中却没有使用这种算法,因为这种算法很难解决对象之间相互引用的情况.看一段代码 1 /** 2 * 虚拟机参数:-verbose:g

JVM的内存区域划分以及垃圾回收机制详解

在我们写Java代码时,大部分情况下是不用关心你New的对象是否被释放掉,或者什么时候被释放掉.因为JVM中有垃圾自动回收机制.在之前的博客中我们聊过Objective-C中的MRC(手动引用计数)以及ARC(自动引用计数)的内存管理方式,下方会对其进行回顾.而目前的JVM的内存回收机制则不是使用的引用计数,而是主要使用的"复制式回收"和"自适应回收". 当然除了上面是这两种算法外,还有其他是算法,下方也将会对其进行介绍.本篇博客,我们先简单聊一下JVM的区域划分,

JS高程中的垃圾回收机制与常见内存泄露的解决方法

起因是因为想了解闭包的内存泄露机制,然后想起<js高级程序设计>中有关于垃圾回收机制的解析,之前没有很懂,过一年回头再看就懂了,写篇博客与大家分享一下. #内存的生命周期: 分配你所需要的内存: 由于字符串.对象等没有固定的大小,js程序在每次创建字符串.对象的时候,程序都会分配内存来存储那个实体. 使用分配到的内存做点什么. 不需要时将其释放回归: 在不需要字符串.对象的时候,需要释放其所占用的内存,否则将会消耗完系统中所有可用的内存,造成系统崩溃,这就是垃圾回收机制所存在的意义. 所谓的内

GC垃圾回收 | 深入理解G1垃圾收集器和GC日志

来源:并发编程网链接:http://ifeve.com/深入理解G1垃圾收集器/ G1 GC是Jdk7的新特性之一.Jdk7+版本都可以自主配置G1作为JVM GC选项:作为JVM GC算法的一次重大升级.DK7u后G1已相对稳定.且未来计划替代CMS.所以有必要深入了解下: 不同于其他的分代回收算法.G1将堆空间划分成了互相独立的区块.每块区域既有可能属于O区.也有可能是Y区,且每类区域空间可以是不连续的(对比CMS的O区和Y区都必须是连续的).这种将O区划分成多块的理念源于:当并发后台线程寻

垃圾回收（4）G1的GC过程

G1日志 G1有详细的日志信息,建议使用下面的参数,当G1出问题,可以获取很多有用的信息 1.-xx:+PrintGCDateStamps 打印日期和正常云行时间2.-xx:+PrintGCDetails 打印G1详细信息3.-xx:+PrintAdaptiveSizePolicy 打印自适应调节策略:自适应策略:GC会根据中统计的GC时间.吞吐量.内存占用量,重新计算堆内存中各区大小4.-xx:+PrintTenuringDistribution 打印survivor region区域内的对象

JVM优化垃圾回收算法垃圾收集器 GC日志可视化查看

今日内容了解什么是垃圾回收掌握垃圾会回收的常见算法学习串行.并行.并发.G1垃圾收集器学习GC日志的可视化查看 1.什么是垃圾回收?程序的运行必然需要申请内存资源,无效的对象资源如果不及时处理就会一直占有内存资源,最终将导致内存溢出,所以对内存资源的管理是非常重要了. 1.1.C/C++语言的垃圾回收在C/C++语言中,没有自动垃圾回收机制,是通过new关键字申请内存资源,通过delete 关键字释放内存资源.如果,程序员在某些位置没有写delete进行释放,那么申请的对象将一直占用内存资源,

关于垃圾回收的一些基本原理及技术解析

关于垃圾回收的一些基本原理及技术解析什么是垃圾,为什么要垃圾回收? 垃圾回收是很大一块,在java虚拟机一些资料描述中,jvm大致干三件大事儿,1>加载class 2>分配存储空间 3>执行垃圾回收:可见垃圾回收在高级语言中所占的分量.(不好意思,扯远了~),简单点儿说就是:在程序运行时刻,产生的一直未能删除的或不能被引用的对象数据称之为垃圾,如果一直未能通过有效的方式回收会导致内存泄露(通俗点就是内存撑爆了). 关于人工回收的一些问题: 在C或C++语言中,程序员可显示地安排数据回收

你不得不知道的-垃圾回收机制及析构函数原理解析

前言当学习到Web API中摸索原理时,对于其中有关垃圾回收只是有点印象并未深入去了解其原理并且对索引器用的也很少,所以利用放假期间好好回顾下已经忘记或者遗漏的知识,温故而知新大概就是这道理吧,虽然园子中关于这两者的文章也是多不胜数,但笔者也有自己独特的见解. 垃圾回收机制引言我们知道.NET Framework中的对象是创建在托管堆中的,但是像C.C++等其他底层语言中的对象是创建在非托管堆中的,所以在这类语言中就会出现编程人员忘记去释放已经没有用的对象,同时编程人员也可能会去试图访问已