最近在给HBase集群进行扩容，然而事事不顺：
1.新添加的机器中有一台竟然无故重启，这个问题直接推给了系统部。
2.部署完HDFS和HBase后，启动都没有任何问题，然而过一夜后，HBase节点全部宕掉。
更奇怪的是，以前老集群中的节点没有问题，运行正常，只有新添加的几个节点宕掉，而且HDFS运行也正常（除了机器重启的那个节点）。
于是各种查看日志。
HBase日志显示如下：JVM暂停时间过长，导致无法与zookeeper通信，被zookeeper认为该节点已经宕掉，于是就关闭了该节点。
是不是真的发生了Full GC? 为什么会发生GC，暂停应用呢？老集群中的机器为什么没问题呢？由于对GC理解太浅，于是产生了各种问题，网上也没查到具体答案，只能一点一点查询、理解、梳理。
2015-10-13 23:47:12,295 WARN [JvmPauseMonitor] util.JvmPauseMonitor: Detected pause in JVM or host machine (eg GC): pause of approximately 83095ms GC pool ‘ParNew‘ had collection(s): count=2 time=216ms GC pool ‘ConcurrentMarkSweep‘ had collection(s): count=2 time=330ms 2015-10-13 23:47:12,295 WARN [regionserver60020] util.Sleeper: We slept 85995ms instead of 3000ms, this is likely due to a long garbage collecting pause and it‘s usually bad, see http://hbase.apache.org/book.html#trouble.rs.runtime.zkexpired 2015-10-13 23:47:12,295 INFO [regionserver60020-SendThread(zookeeper2:2181)] zookeeper.ClientCnxn: Client session timed out, have not heard from server in 95659ms for sessionid 0x25053f6801406ac, closing socket connection and attempting reconnect 2015-10-13 23:47:12,291 WARN [regionserver60020.compactionChecker] util.Sleeper: We slept 89894ms instead of 10000ms, this is likely due to a long garbage collecting pause and it‘s usually bad, see http://hbase.apache.org/book.html#trouble.rs.runtime.zkexpired 2015-10-13 23:47:12,291 WARN [regionserver60020.periodicFlusher] util.Sleeper: We slept 89894ms instead of 10000ms, this is likely due to a long garbage collecting pause and it‘s usually bad, see http://hbase.apache.org/book.html#trouble.rs.runtime.zkexpired 2015-10-13 23:47:12,291 INFO [regionserver60020-SendThread(zookeeper3:2181)] zookeeper.ClientCnxn: Client session timed out, have not heard from server in 89644ms for sessionid 0x1505ebc2da3010f, closing socket connection and attempting reconnect 2015-10-13 23:47:12,397 FATAL [regionserver60020] regionserver.HRegionServer: ABORTING region server hregion151,60020,1444732375821: org.apache.hadoop.hbase.YouAreDeadException: Server REPORT rejected; currently processing hregion151,60020,1444732375821 as dead server
在HBase的安装目录下有个gclog.0文件，记录了HBase运行时发生的垃圾回收信息。
但是各种查看后，也没发现什么问题。（或许是对GC不懂的缘故吧，不懂就查、学呗）。
2015-10-13T18:35:47.314+0800: 165.893: [GC [1 CMS-initial-mark: 32523K(63872K)] 35370K(83008K), 0.0185230 secs] [Times: user=0.01 sys=0.02, real=0.01 secs] 2015-10-13T18:35:47.333+0800: 165.912: [CMS-concurrent-mark-start] 2015-10-13T18:35:47.402+0800: 165.981: [CMS-concurrent-mark: 0.046/0.069 secs] [Times: user=0.32 sys=0.03, real=0.07 secs] 2015-10-13T18:35:47.402+0800: 165.982: [CMS-concurrent-preclean-start] 2015-10-13T18:35:47.411+0800: 165.990: [CMS-concurrent-preclean: 0.008/0.009 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2015-10-13T18:35:47.411+0800: 165.990: [CMS-concurrent-abortable-preclean-start] 2015-10-13T18:35:47.414+0800: 165.993: [GC 165.993: [ParNew: 18503K->2112K(19136K), 0.0681050 secs] 51027K->37708K(83008K), 0.0682600 secs] [Times: user=0.03 sys=0.07, real=0.06 secs] 2015-10-13T18:35:47.535+0800: 166.115: [CMS-concurrent-abortable-preclean: 0.028/0.124 secs] [Times: user=0.15 sys=0.09, real=0.13 secs] 2015-10-13T18:35:47.536+0800: 166.115: [GC[YG occupancy: 14168 K (19136 K)]166.115: [Rescan (parallel) , 0.0024340 secs]166.117: [weak refs processing, 0.0001320 secs] [1 CMS-remark: 35596K(63872K)] 49765K(83008K), 0.0026970 secs] [Times: user=0.03 sys=0.00, real=0.00 secs] 2015-10-13T18:35:47.539+0800: 166.118: [CMS-concurrent-sweep-start] 2015-10-13T18:35:47.554+0800: 166.133: [CMS-concurrent-sweep: 0.014/0.015 secs] [Times: user=0.05 sys=0.01, real=0.02 secs] 2015-10-13T18:35:47.554+0800: 166.133: [CMS-concurrent-reset-start] 2015-10-13T18:35:47.571+0800: 166.151: [GC 166.151: [ParNew: 19077K->2112K(19136K), 0.0028640 secs] 39044K->25755K(83008K), 0.0029990 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
在查询和学习JVM的垃圾回收时，看到了下面这句话：
对于采用CMS进行旧生代GC的程序而言，尤其要注意GC日志中是否有promotion failed和concurrent mode failure两种状况，当这两种状况出现时可能会触发Full GC。promotion failed是在进行Minor GC时，survivor space放不下、对象只能放入旧生代，而此时旧生代也放不下造成的；
然而在HBase的gclog.0的日志文件结尾发现了promotion failed，日志如下。
2015-10-14T00:55:40.417+0800: 22958.996: [GC 22958.996: [ParNew (promotion failed): 19133K->19116K(19136K), 0.0752040 secs]22959.071: [CMS: 24832559K->11737235K(28395128K), 54.6409350 secs] 24849259K->11737235K(28414264K), [CMS Perm : 48374K->48253K(80800K)], 54.7223900 secs] [Times: user=7.80 sys=1.13, real=54.72 secs] 2015-10-14T00:56:41.108+0800: 23019.687: [GC 23019.687: [ParNew: 221568K->9684K(249216K), 0.0259720 secs] 11958803K->11746920K(28644352K), 0.0261620 secs] [Times: user=0.29 sys=0.02, real=0.02 secs] Heap par new generation total 249216K, used 128841K [0x0000000124e00000, 0x0000000135c60000, 0x0000000135c60000) eden space 221568K, 53% used [0x0000000124e00000, 0x000000012c25d198, 0x0000000132660000) from space 27648K, 35% used [0x0000000134160000, 0x0000000134ad53b0, 0x0000000135c60000) to space 27648K, 0% used [0x0000000132660000, 0x0000000132660000, 0x0000000134160000) concurrent mark-sweep generation total 28395136K, used 11737235K [0x0000000135c60000, 0x00000007fae00000, 0x00000007fae00000) concurrent-mark-sweep perm gen total 80800K, used 48566K [0x00000007fae00000, 0x00000007ffce8000, 0x0000000800000000)
时间： 2024-11-05 02:02:32