今天一个线上集群出现莫名奇妙不能写入数据的bug,log中不断打印如下信息:
我们知道每次put时会检查当前的memstore大小,当大于flush值的一个系数时(系数默认为2倍),就会block住这次写请求,并提交一个flush任务。但是很奇怪的是,用户此时再也不能往这个region写数据了,并在大约10多个小时以后又神奇地自然恢复了。
原因是什么呢?
经过一番检查,发现了hbase的一个bug,我们准备修改后提交到社区,不过因为实在太有趣了,体现了分布式事务的很有趣特征,所以先在此分享一下原因吧。
这个问题是由以下四个事件共同组成的,我把代码简单化后作如下整理:
1 put:
2 memstoreFlusher:
3 split:
4 rollback:
故障还原:当该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队列己然被清空了,于是陷入以下循环:
引用
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
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);
- }
- ...
- }
- ...
- }
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;
- }
- }
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;
- ...
...
closing = true;
closed = true;
...
4 rollback:
- ...
- closing=false;
- closed=false;
- ...
...
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
分析的很不错!
谢谢,follow了,以后多交流
忘记说一个前提了, split在close region之前会多次执行internFlush, 确保split之前memstore被清空, 所以这个问题出现以后, 严格意义上来说, 有一段时间的潜伏期, 知道region的memstore大于了blockSize才会爆发.
看了下代码, 这个问题的确是存在的, 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线程对资源解锁,不太靠谱..
要解除这种情况, 有三个办法:
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线程对资源解锁,不太靠谱..