lease引发的血案

今天线上出现了一个故障惊出一身冷汗，经过查明原来是lease引发的问题。不过查问题的过程让我们耽误了很多修复故障的时间，很是不爽。

起因：datanode和regionserver以及master同时挂掉
现象：datanode重启后，regionserver重启不久，多台regionserver相继即挂掉，log显示：

org.apache.hadoop.hbase.regionserver.wal.HLog: Could not append. Requesting close of hlog java.io.IOException: Reflection at 
org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter.sync(SequenceFileLogWriter.java:147) at 
org.apache.hadoop.hbase.regionserver.wal.HLog.sync(HLog.java:994) at 
org.apache.hadoop.hbase.regionserver.wal.HLog.completeCacheFlush(HLog.java:1176) at 
org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1038) at 
org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:929) at 
org.apache.hadoop.hbase.regionserver.HRegion.doClose(HRegion.java:571) at 
org.apache.hadoop.hbase.regionserver.HRegion.close(HRegion.java:524) at 
org.apache.hadoop.hbase.regionserver.handler.CloseRegionHandler.process(CloseRegionHandler.java:120) at 
org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:151) at 
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at 
java.lang.Thread.run(Thread.java:662) Caused by: java.lang.reflect.InvocationTargetException at 
sun.reflect.GeneratedMethodAccessor2.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:145) ... 11 more 
Caused by: java.io.IOException: Error Recovery for block blk_-5430512709521689588_45878056 failed because recovery from primary datanode xx.xx.xx.xx:50010 failed 6 times. Pipeline was xx.xx.xx.xx:50010. Aborting... at 
org.apache.hadoop.hdfs.DFSClient$DFSOutputStream.processDatanodeError(DFSClient.java:2841) at 

    看起来是datanode的问题，但是登陆datanode发现木有问题。于是再重启regionserver，过一会又报同样的错误退出...
    于是开始查系统的问题。半个小时过去鸟。。。
    实在查不到原因，再重启，发现系统好了。。。

    原因：datanode挂掉的时候，regionserver正在写hlog，这是一个append的过程。当regionserver也挂掉后，则相应的块的client也断开了，很自然这个block连同它的备份都处于需要修复的状态。由于master也挂掉了，所以master被备机接管。接管时候有一步是检查哪些region server处于online状态(waitForRegionServers)。不处于online状态的rs(默认的配置下有一定概率在线的rs也会被判断为不在线，如果hbase.master.wait.on.regionservers.timeout设置为大于6秒则不会出现这种情况)会被master强制执行recoverFileLease。于是引发了namenode对这个block发起recovery block过程，这个过程抢占了lease。当其它region server需要读这个文件或者其它这个datanode原先持有的block的时候都会发现需要recovery block，这个过程由于抢占不到lease导致失败。而写hlog阶段的失败regionserver的处理逻辑是让自己挂掉（这样最安全）。于是会发现凡是需要写这个hlog的region server会连续挂掉。
    虽然regionserver挂掉了，但是它对这个坏块仍然发起过一次写操作，于是这个block上的lease由1小时的硬lease降级为了1分钟的软lease，即1分钟后租约消失。所以1分钟后再次发起请求就恢复正常了。
    但是为什么再次重启regionserver也挂掉了呢？原因是当时datanode上面还有其它正在被写的hlog的block，所以多重启几次就好了。事实上当时如果我们不等待这半小时而是直接手忙脚乱重启的话，故障就会更快恢复了。。。

    结论：master和regionserver不能同时挂掉。只要不是同时挂掉，就不会导致recovery block的发生，也就不会发生lease的杯具了。不过这种情况很难发生，所以我们决定将hbase.master.wait.on.regionservers.timeout参数改为10秒。

评论

7 楼 alexanderdai 2012-04-03  

lease非客户端正常回收有两种，一种是其他dfsclient主动force回收，一种是NN对lease的心跳判断，判定lease很久没有心跳了，心跳超时于是租约超时，然后主动走入force调用的相同逻辑代码。

执行逻辑如下：NN找到最后一个block所在的dn，并向dn发recoverblock命令，dn flush到磁盘后会向NN发送一个comit操作（全局互斥），NN在comit操作中会将pending的数据结构挂到正常数据结构中。

6 楼 piaoya 2012-01-14  

上周也遇到一个lease引发的线上血案~~~baggioss也清楚啊。哈哈。lease这东西，总是这么巧的被触发做recovery...

5 楼 lc_koven 2011-12-21  

nopower 写道

发起lease recovery的不是datanode吧，貌似是NN？lease是针对文件而言的，DN只管block，所以不大可能是他发起的，回头我再看看代码。庄哥威武。

大师威武，感激艳堂

4 楼 lc_koven 2011-12-21  

baggioss 写道

为什么会有多个人同时出发lease recovery？  我印象里split hlog不是有hmaster干的吗？ lease的 owner 应该只有一个才对呀。

master发起lease recovery在先，rs写满hlog滚动log时需要recovery在后，这两者间隔在1分钟以内的话就挂了。P.S:修改了下原文，再看下吧。还有，这里挂的rs并不是原先被重启的那一台，而是其它好几台的rs

3 楼 lc_koven 2011-12-21  

nopower 写道

发起lease recovery的不是datanode吧，貌似是NN？lease是针对文件而言的，DN只管block，所以不大可能是他发起的，回头我再看看代码。庄哥威武。

今天再review了一下，稍改了下原文

2 楼 baggioss 2011-12-21  

为什么会有多个人同时出发lease recovery？  我印象里split hlog不是有hmaster干的吗？ lease的 owner 应该只有一个才对呀。

1 楼 nopower 2011-12-20  

发起lease recovery的不是datanode吧，貌似是NN？lease是针对文件而言的，DN只管block，所以不大可能是他发起的，回头我再看看代码。庄哥威武。