HBase GC日志

HBase依靠ZooKeeper来感知集群成员及其存活性。如果一个服务器暂停了很长时间,它将无法给ZooKeeper quorum发送心跳信息,其它服务器会认为这台服务器已死亡。这将导致master为其启动恢复进程。当该服务器脱离停顿时,它会发现它的所有租约都已失效(hbase
client端每次和regionserver交互的时候,都会在服务器端生成一个租约(Lease),租约的有效期由参数hbase.regionserver.lease.period确定),然后自杀。HBase开发团队亲切地称这个场景为Juliet Pause。

在HBase中使用默认GC,可以看到所有线程中的长时间停顿,包括Juliet Pause, 又名"GC of
Death"。可以在JAVA虚拟机中开启GC日志,来帮助调试这种问题。

hbase-env.sh中,取消以下任一注释即可开启GC日志:

# This enables basic gc logging to the .out file.
# export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps"

# This enables basic gc logging to its own file.
# export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH>"

# This enables basic GC logging to its own file with automatic log rolling. Only applies to jdk 1.6.0_34+ and 1.7.0_2+.
# export SERVER_GC_OPTS="-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:<FILE-PATH> -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=1 -XX:GCLogFileSize=512M"

# If <FILE-PATH> is not replaced, the log file(.gc) would be generated in the HBASE_LOG_DIR.       

点击"Local logs",查看gc-xxx.log日志,格式如下:

<span style="font-size:14px;"><span style="font-family:Microsoft YaHei;font-size:12px;">15578637.583: [GC [1 CMS-initial-mark: 12076002K(12582912K)] 18788432K(29360128K), 1.0113310 secs] [Times: user=1.01 sys=0.00, real=1.01 secs]
15578638.595: [CMS-concurrent-mark-start]
15578639.125: [CMS-concurrent-mark: 0.530/0.530 secs] [Times: user=1.61 sys=0.01, real=0.53 secs]
15578639.125: [CMS-concurrent-preclean-start]
15578639.160: [CMS-concurrent-preclean: 0.035/0.035 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
15578639.160: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 15578644.606: [CMS-concurrent-abortable-preclean: 5.446/5.446 secs] [Times: user=5.82 sys=0.07, real=5.45 secs]
15578644.607: [GC[YG occupancy: 6769031 K (16777216 K)]15578644.607: [Rescan (parallel) , 0.9756010 secs]15578645.583: [weak refs processing, 0.0000280 secs]15578645.583: [scrub string table, 0.0006370 secs] [1 CMS-remark: 12076002K(12582912K)] 18845034K(29360128K), 0.9764070 secs] [Times: user=9.52 sys=0.03, real=0.97 secs]
15578645.584: [CMS-concurrent-sweep-start]
15578645.829: [CMS-concurrent-sweep: 0.245/0.245 secs] [Times: user=0.30 sys=0.00, real=0.24 secs]
15578645.829: [CMS-concurrent-reset-start]
15578645.855: [CMS-concurrent-reset: 0.026/0.026 secs] [Times: user=0.05 sys=0.01, real=0.03 secs] 

15578647.856: [GC [1 CMS-initial-mark: 12075999K(12582912K)] 20737398K(29360128K), 1.0872730 secs] [Times: user=1.09 sys=0.00, real=1.08 secs]
15578648.943: [CMS-concurrent-mark-start]
15578649.472: [CMS-concurrent-mark: 0.528/0.528 secs] [Times: user=2.06 sys=0.02, real=0.53 secs]
15578649.472: [CMS-concurrent-preclean-start]
15578649.507: [CMS-concurrent-preclean: 0.035/0.035 secs] [Times: user=0.04 sys=0.00, real=0.04 secs]
15578649.507: [CMS-concurrent-abortable-preclean-start]
 CMS: abort preclean due to time 15578654.961: [CMS-concurrent-abortable-preclean: 5.454/5.454 secs] [Times: user=8.15 sys=0.17, real=5.45 secs]
15578654.962: [GC[YG occupancy: 11315403 K (16777216 K)]15578654.963: [Rescan (parallel) , 1.1274320 secs]15578656.090: [weak refs processing, 0.0000240 secs]15578656.090: [scrub string table, 0.0005890 secs] [1 CMS-remark: 12075999K(12582912K)] 23391403K(29360128K), 1.1281890 secs] [Times: user=11.00 sys=0.03, real=1.13 secs]
15578656.091: [CMS-concurrent-sweep-start]
15578656.327: [CMS-concurrent-sweep: 0.236/0.236 secs] [Times: user=0.52 sys=0.01, real=0.24 secs]
15578656.327: [CMS-concurrent-reset-start]
15578656.353: [CMS-concurrent-reset: 0.026/0.026 secs] [Times: user=0.05 sys=0.00, real=0.02 secs] </span></span>

CMS垃圾回收的执行过程:

1、CMS-initial-mark :初始标记,从root对象开始标记存活的对象。它花费的时间是real=1.01 secs,由于这一步骤是STW的,所以整个application被暂停了1.01秒。并且,user time和real time相差不大,所以确实是只有一个thread执行这一步;

2、CMS-concurrent-mark-start:并发标记。它执行时间是real=0.53 secs,但因为这一步是可以并发执行的,所以系统在这段时间内并没有暂停;

3、CMS-concurrent-preclean-start :concurrent precleaning。同样的,这一步也是并发执行;

4、CMS-remark:重新标记。暂停应用程序,同时启动一定数目的垃圾回收线程,并行地标记第2阶段遗漏的对象(在并发标记阶段结束后对象状态的更新导致)。它的执行时间是real=0.97
secs。因为这是STW的步骤,并且它的pause time一般是最长的,所以这一步的执行时间会直接决定这次Full GC对系统的影响。

5、CMS-concurrent-sweep-start:并发清除。

6、CMS-concurrent-reset-start:并发重设状态等待下一次CMS的触发。

只有在第1、4阶段需要暂停所有的应用程序,其它阶段的垃圾回收线程与应用程序线程并发执行。

时间: 2024-10-12 23:36:14

HBase GC日志的相关文章

HBase GC的前生今世 - 身世篇

网易视频云是网易倾力打造的一款基于云计算的分布式多媒体处理集群和专业音视频技术,提供稳定流畅.低时延.高并发的视频直播.录制.存储.转码及点播等音视频的PAAS服务,在线教育.远程医疗.娱乐秀场.在线金融等各行业及企业用户只需经过简单的开发即可打造在线音视频平台.现在,网易视频云的技术专家给大家分享一则技术文:HBase GC的前生今世 - 身世篇. 在之前的HBase BlockCache系列文章中已经简单提到:使用LRUBlockCache缓存机制会因为CMS GC策略导致内存碎片过多,从而

理解GC日志

每一种收集器的日志形式都是由它们自身的实现所决定的,换而言之,每个收集器的日志格式都可以不一样.但虚拟机设计者为了方便用户阅读,将各个收集器的日志都维持一定的共性,例如以下两段典型的GC日志: 33.125: [GC [DefNew: 3324K->152K(3712K), 0.0025925 secs] 3324K->152K(11904K), 0.0031680 secs] 100.667: [Full GC [Tenured: 0K->210K(10240K), 0.0149142

快速解读GC日志(转)

本文是 Plumbr 发行的 Java垃圾收集手册 的部分内容.文中将介绍GC日志的输出格式, 以及如何解读GC日志, 从中提取有用的信息.我们通过 -XX:+UseSerialGC 选项,指定JVM使用串行垃圾收集器, 并使用下面的启动参数让 JVM 打印出详细的GC日志: -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps 这样配置以后,发生GC时输出的日志就类似于下面这种格式(为了显示方便,已手工折行): 20

GC日志格式及分析、heapdump文件获取

==仅方便后续参考== GC日志配置 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:servers/%SERVER_NAME%_gc.log -XX:+HeapDumpOnOutOfMemoryError注意,%SERVER_NAME%是win格式,linux下为${SERVER_NAME}. JVM的GC日志的主要参数包括如下几个:-XX:+PrintGC 输出简单GC日志-XX:+PrintGCDetails 输出GC的详细日志-XX:

GC日志分析

结合上篇博文(其中的Eclipse Memory Analyzer分析内存溢出)进行分析GC日志 (1)首先,给出一个日志输出的例子: 参数设置为: -XX:+PrintGCDetails -XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8 -XX:NewSize=10M -XX:MaxNewSize=10M 参数解释: -XX:+PrintGCDetails 启用日志 -XX:-UseAdaptiveSizePolicy 禁用动态调整,使Survivo

看懂gc日志

使用的是:+PrintGCDetails -XX:+PrintGCTimeStamps 输出的日志格式: [Times: user=0.03 sys=0.00, real=0.01 secs] 363.375: [GC 363.375: [ParNew: 39424K->3249K(39424K), 0.0054790 secs] 69520K->37044K(126848K), 0.0055800 secs] 8.672: [Full GC 8.673: [Tenured: 26086K-&

浅析JVM中的GC日志

目录 一.GC日志的格式分析 二.运行时开启GC日志 一.GC日志的格式分析 在讲述GC日志之前,我们先来运行下面这段代码 1 package com.example; 2 3 public class TestMinorGC { 4 private static final int _1MB = 1024*1024; 5 6 public static void testAllocation() { 7 byte[] allocation1, allocation2, allocation3,

tomcat开启gc日志

编辑修改catlian.sh文件添加如下信息: -XX:+PrintGC  // 开启gc日志监控 -XX:+PrintGCDetails // 可以详细了解GC中的变化 -XX:+PrintGCTimeStamps  // 可以了解这些垃圾收集发生的时间,自JVM启动以后以秒计量 -XX:+PrintGCDateStamps  // GC发生的时间信息 -XX:+PrintHeapAtGC  // 了解堆的更详细的信息 -Xloggc:/opt/tomcat_8080/logs/gc.log

Java GC 日志详解

详见:http://blog.yemou.net/article/query/info/tytfjhfascvhzxcyt105 java GC日志可以通过 +PrintGCDetails开启 以ParallelGC为例 YoungGC日志解释如下(图片源地址:这里) : FullGC(图片源地址:这里):