hbase写被block住的典型案例分析

    今天一个线上集群出现莫名奇妙不能写入数据的bug，log中不断打印如下信息：

引用

2011-11-09 07:35:45,911 INFO org.apache.hadoop.hbase.regionserver.HRegion: Blocking updates for 'IPC Server handler 32 on 60020' on
region xxx,333-2395000000032117,1320773734010.9a7ae39b5a42ccfa1fa6118aa8f79195.: memstore size 128.0m is >= than blocking 128.0m size

    我们知道每次put时会检查当前的memstore大小，当大于flush值的一个系数时（系数默认为2倍），就会block住这次写请求，并提交一个flush任务。但是很奇怪的是，用户此时再也不能往这个region写数据了，并在大约10多个小时以后又神奇地自然恢复了。
    原因是什么呢？
    经过一番检查，发现了hbase的一个bug，我们准备修改后提交到社区，不过因为实在太有趣了，体现了分布式事务的很有趣特征，所以先在此分享一下原因吧。
    这个问题是由以下四个事件共同组成的，我把代码简单化后作如下整理：
1 put:

put{
  checkResources{
    while (this.memstoreSize.get() > this.blockingMemStoreSize) {
      if(flushRequested==true)
        continue;
      flushRequested = true;
      flushQueue.add(this);
    }
...
  }
...
}

2 memstoreFlusher:

while(!serverstop){
  task = flushQueue.poll();
  if(task == null)
    continue;
  if(closing)
    continue;
  try{
    if(closed)
      continue;
    if(flush(task))
      continue;
    else
      break;
  }finally{
    flushRequested = false;
  }
}

3 split:

...
closing = true;
closed = true;
...

4 rollback:

...
closing = false;
closed = false;
...

    故障还原：当该region执行一次flush时，flushRequested被put线程置为了true，并push一个flush任务。然后memstoreFlusher检查到该任务时，刚好split开始进行，进行到了CLOSED_PARENT_REGION那一步，处于closing状态，于是memstoreflusher跳过任务，但在这里，memstoreflusher仍然报告该任务完成了，于是flush队列被清空。
    但split在执行splitStoreFiles时，因为hdfs的问题失败了(具体原因是namenode在close一个文件的时候失败，不停地retry并超时)，此时split开始执行回滚，即该region恢复到split之前的状态，于是我们发现该region又重新onlined。

    虽然split在rollback的时候会将closing和closed状态置回来，但因为flush队列己然被清空了，于是陷入以下循环：

• put数据的线程，发现需要flush，但flushRequested为true，说明还有flush任务没完成，于是继续等待，并不会提交flush任务
• memstoreFlush的线程，每次取flushQueue都为空，于是循环等待put线程提交flush任务，因此写数据就被block住了

    以上悲催的情况将一直持续，直到迎来cleanOldLogs任务。因为cleanOldLogs会每小时执行一次，它会将最早的.logs目录下的文件移到.oldlogs目录下，但移之前先检查该文件中所有的数据是否己经flush到磁盘了，如果还没有就将该region执行一次flush。所以在经过n小时以后，.logs终于滚动到了用户之前卡住的那一段，这时就强制执行flush任务，因此flushQueue队列就不为空了，死循环被打破。系统也就自愈了。

评论

4 楼 AntyRao 2011-11-15  

分析的很不错！

3 楼 lc_koven 2011-11-13  

谢谢，follow了，以后多交流

2 楼 wangjinpeng 2011-11-11  

忘记说一个前提了, split在close region之前会多次执行internFlush, 确保split之前memstore被清空, 所以这个问题出现以后, 严格意义上来说, 有一段时间的潜伏期, 知道region的memstore大于了blockSize才会爆发.

1 楼 wangjinpeng 2011-11-11  

看了下代码, 这个问题的确是存在的, split失败以后rollback没有把flushRequested重新设置为false,导致接下来put/delete的checkResource和已经put结束以后的检查到需要flush,两种情况的requestFlush都直接返回, 直接后果就是这个region的memstore越来越大,可是始终都不能flush, 直到memstore size大于了blockSize, 接下来在进来的所有put/delete都会block在checkResource这个地方.

要解除这种情况, 有三个办法:
1. reclaimMemStoreMemory的isAboveHighWaterMark或者isAboveLowWaterMark触发,然后会MemstoreFlush会调用flushOneForGlobalPressure去选择一个region进行Flush, 选择的标准是StoreFile最多或者memstore最大, 如果后者的memstore size已经比前者的2倍还大, 那就选它了. 从前面的分析来看, 出现问题的region的memstore size已经达到了block size, 起码是正常flush size的2倍, 所以不出意外就会选它,接下来调用region.flushcache, flush和设置flushRequested为false, 状况解除
2. 有LogRoller来触发Flush, 就是楼主说的这种
3. 如果发现了这种情况, 可以通过Client主动发起flush请求, 也可以解除这种状况.

1,2 是系统自愈型, 3是运维处理.

感觉上这个patch只需要在split的rollback地方加上修改flushRequested为false就可以了. 不过总觉得这种做法就类似在A线程对资源加锁,在B线程对资源解锁,不太靠谱..

楼主的HBase文章都相当精彩, 我最近也在阅读HBase的源代码, 希望跟楼主一起多交流, 我的心得都写在: http://qing.weibo.com/jinpengw