解决HBase Replication在数据大量写入时致使RegionServer崩溃问题

HBase在0.90以后的版本提供Replication功能，这些天本人在测试这个功能时发如今大量数据(>100W)写入时会出现RegionServer崩溃的状况。异常日志以下：

2014-10-29 10:40:44,225 WARN org.apache.hadoop.hdfs.DFSClient: DFSOutputStream ResponseProcessor exception  for block blk_-2223802775658985697_1410java.io.EOFException
	at java.io.DataInputStream.readFully(DataInputStream.java:180)
	at java.io.DataInputStream.readLong(DataInputStream.java:399)
	at org.apache.hadoop.hdfs.protocol.DataTransferProtocol$PipelineAck.readFields(DataTransferProtocol.java:124)
	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$ResponseProcessor.run(DFSClient.java:2967)

2014-10-29 10:40:44,225 INFO org.apache.hadoop.hdfs.DFSClient: Could not obtain block blk_-2223802775658985697_1410 from any node: java.io.IOException: No live nodes contain current block. Will get new block locations from namenode and retry...
2014-10-29 10:40:44,228 WARN org.apache.hadoop.hdfs.DFSClient: Error Recovery for block blk_-2223802775658985697_1410 bad datanode[0] 192.168.11.55:40010
2014-10-29 10:40:44,232 WARN org.apache.hadoop.hdfs.DFSClient: Error while syncing
java.io.IOException: All datanodes 192.168.11.55:40010 are bad. Aborting...
	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.processDatanodeError(DFSClient.java:3096)
	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.access$2100(DFSClient.java:2589)
	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream$DataStreamer.run(DFSClient.java:2793)
2014-10-29 10:40:44,235 FATAL org.apache.hadoop.hbase.regionserver.wal.HLog: Could not sync. Requesting close of hlog
java.io.IOException: Reflection
	at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter.sync(SequenceFileLogWriter.java:310)
	at org.apache.hadoop.hbase.regionserver.wal.HLog.syncer(HLog.java:1366)
	at org.apache.hadoop.hbase.regionserver.wal.HLog.sync(HLog.java:1476)
	at org.apache.hadoop.hbase.regionserver.HRegion.syncOrDefer(HRegion.java:5970)
	at org.apache.hadoop.hbase.regionserver.HRegion.doMiniBatchMutation(HRegion.java:2490)
	at org.apache.hadoop.hbase.regionserver.HRegion.batchMutate(HRegion.java:2190)
	at org.apache.hadoop.hbase.regionserver.HRegionServer.multi(HRegionServer.java:3888)
	at sun.reflect.GeneratedMethodAccessor33.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.hadoop.hbase.ipc.WritableRpcEngine$Server.call(WritableRpcEngine.java:323)
	at org.apache.hadoop.hbase.ipc.HBaseServer$Handler.run(HBaseServer.java:1434)
Caused by: java.lang.reflect.InvocationTargetException
	at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:597)
	at org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter.sync(SequenceFileLogWriter.java:308)
	... 11 more
Caused by: java.io.IOException: DFSOutputStream is closed
	at org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.sync(DFSClient.java:3669)
	at org.apache.hadoop.fs.FSDataOutputStream.sync(FSDataOutputStream.java:97)
	at org.apache.hadoop.io.SequenceFile$Writer.syncFs(SequenceFile.java:995)
	... 15 more

实际上，这个问题并非由Replication功能引发的，而由客户端在数据密集写入时超时引发的

============================如下内容来源于网络===================================

正常状况下DFSClient写block数据的过程是：

1. DFSClient端
   a）DFSOutputStream负责数据的接收和写入，即经过DFSOutputSummer中的write方法（synchronized）得到数据，而sync（主要代码 synchronized(this)）经过FlushBuffer创建packet后，经过enqueuePacket向dataQueue中写入数据。
   b）DFSOutputStream中的DataStreamer（Daemon线程），负责向DataNode发送数据，每次发送前会检查dataQueue中是否有数据，没有就等待。
   c）DataStreamer创建pipeline传输数据时，对这个pipeline会起一个ResponseProcessor（Thread）去得到DataNode的反馈ack，并判断是否有错误、进行recoverBlock等
2. DataNode端
   a）在每一个packet传输过程当中，根据创建数据传输的pipleLine，上游依次向下游发送数据，下游依次向上游发送ack。
   b）pipeline的最后一个节点（numTarget=0），PacketResponder 会一直运行lastDatanodeRun?方法，这个方法会在ack发送完毕(ackQueue.size()=0)后约1/2个dfs.socket.timeout?时刻发送心跳包，沿着pipeline发送给client。
3. HBase端
  HBase端经过hlog中的writer向hdfs写数据，每次有数据写入，都会sync。同时，HLog中有个logSyncer，默认配置是每秒钟调用一次sync，无论有没有数据写入。


这个问题首先是因为超时引发的，咱们先分析一下超时先后DFSClient和DataNode上发生了什么。
1. 问题重现
    a）客户端ResponseProcessor报69秒socket超时，出错点在PipelineAck.readFields()。出错后直接catch，标记hasError=true，closed=true。这个线程不会中止。
    b）DataStreamer在轮询中调用processDatanodeError对hasError=true进行处理。此时errorIndex=0（默认值），首先会抛出Recovery for Block的异常. 而后关闭blockstream，从新基于两个节点的pipeline进行recoverBlock。
    c）在DataNode上，processDatanodeError()关闭blockstream。这将致使pipeline中的packetResponder被interrupted和terminated。
    d）在DataNode上，processDatanodeError()关闭blockstream，致使BlockReceiver的readNextPacket()中的readToBuf读取不到数据，throw EOFException的异常。这个异常一直向上抛，直到DataXceiver的run中，它将致使DataXceiver停止运行，提示DataNode.dnRegistration Error。
   e）recoverBlock会正常进行，并先在两个节点上完成（第二个和第三个）。随后Namenode会发现replicas数量不足，向DataNode发起transfer block的命令，这是一个异步的过程。可是在hlog检查时，transfer颇有可能未完成，这时会报 pipeline error detected. Found 2 replicas but expecting 3 replicas。并关闭hlog。


以上就是根据日志能够看到的错误过程。
2. 问题分析
a)为何会超时，为何心跳包没有发？
根据以上的分析，ResponseProcessor socket 69秒超时是致使后续一系列异常和hlog关闭的缘由。那么为什么会发生socket超时？ResponseProcessor应该会在dfs.socket.timeout的1/2时间内收到HeartBeat包。
通过打印日志，咱们发现，DataNode上配置的dfs.socket.timeout为180秒，而HBase调用DFSClient时采用默认配置，即60秒。所以，DFSClient认为超时时间为3×nodes.length+60=69秒，而DataNode端发送心跳包的timeout=1/2×180=90秒！所以，若是在没有数据写入的状况下，DataNode将在90秒后发送心跳包，此时DFSClient已经socketTimeout了，并致使后续的一系列现象。
b）为何会在69秒内没有新的packet发送过去呢？
咱们先分析一下DFSOutputStream写数据和sync的同步关系。DFSOutputStream继承自FSOutputSummer，DFSOutputStream接收数据是经过FSOutputSummer的write方法，这个方法是synchronized。而sync方法的flushBuffer()和enqueuePacket()，也在synchronized(this)代码块中。也就是说，对一个DFSOutputStream线程，若是sync和write同时调用，将发生同步等待。在HBase的场景下，sync发生的频率很是高，sync抢到锁的可能性很大。这样，就颇有可能在不断的sync，不断的flushBuffer，可是却没能经过write写入数据（被blocked了）。这就是致使超时时间内一直没有packet发送的缘由。

综上，HBase业务调用的特色和DFSOutputStream的synchronized代码块，颇有可能69秒中没有packet写入。但这个时候，不该该socket超时，socket超时是这个问题的根本缘由，而socket超时的缘由是配置不一致。


3. 问题解决

在hdfs端和HBase端，给dfs.socket.timeout设置一个较大的值，好比300000（300秒）【注意两处设置的值要相等】