HBase Full GC宕機

最近在給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)