Grokbase Groups HBase user May 2016
FAQ
HI ALL: Recently,I met a strange problem, the first Region’s Memstore of one table (the only one) often blocked when flushing.(Both Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to 1.0.1.1,hope to solve the problem,But failed)
        On the web UI, I can see the status shows: ABORTED(since XXsec ago), Not flushing since already flushing.
        But it will never flush success, and the usage of the disk will increase very high.Now other regionservers just use 30% of the disk capacity, the problematic region server will increase to 100%,unless killing the process.
        What’s more, the region server process cannot be shutdown normally,every time I have to use the KILL -9 command.
        I check the log,the reason why cannot flush is one of the MemstoreFlusher cannot exiting.
        The log is like blow:
        2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13] regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
  2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6] regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
  2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16] regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
  2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33] regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
  2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25] regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31] regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29] regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23] regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32] regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1] regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38] regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10] regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7] regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12] regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21] regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
  2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37] regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
  2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24] regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
  2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39] regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
  2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17] regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3] regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27] regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18] regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4] regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19] regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22] regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9] regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
  2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36] regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
  2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11] regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14] regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2] regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26] regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0] regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30] regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28] regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


  here is the jstack log when I try to shutdown the region server process normally:
  we can see the MemstoreFlusher.34 meet some problems, it can not exiting normally
  (By the way, we can see “locked at snappy”, but it not always locked at snappy,sometime it will locked at other place,so I think snappy is ok, Here I just want to show the MemStoreFlusher meet some problem).


   "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable [0x00007f08941c3000]
     java.lang.Thread.State: RUNNABLE
  at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native Method)
  at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
  - locked <0x00007f0a5f85c430> (a org.apache.hadoop.io.compress.snappy.SnappyCompressor)
  at org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
  at org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
  at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
  at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
  at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
  at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
  at org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
  at org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
  - locked <0x00007f09fdcccda0> (a java.lang.Object)
  at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
  at org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
  at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
  at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
  at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
  at java.lang.Thread.run(Thread.java:744)


  "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on condition [0x00007f08942c5000]
     java.lang.Thread.State: TIMED_WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)
  - parking to wait for <0x00007f09b8e20f80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
  at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
  at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
  at java.lang.Thread.run(Thread.java:744)





     I do not know why the memstore cannot flush.
     Is this a bug?



    下面是被转发的邮件:

   发件人: quan <329853099@qq.com>

   主题: memstore flush blocked

   日期: 2016年5月30日 GMT+8 上午10:47:43

   收件人: user@hbase.apache.org

   抄送: 蒲聪 <cong.pu@qunar.com>


    HI ALL: Recently,I met a strange problem, the first Region’s Memstore of one table (the only one) often blocked when flushing.(Both Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to 1.0.1.1,hope to solve the problem,But failed)
        On the web UI, I can see the status shows: ABORTED(since XXsec ago), Not flushing since already flushing.
        But it will never flush success, and the usage of the disk will increase very high.Now other regionservers just use 30% of the disk capacity, the problematic region server will increase to 100%,unless killing the process.
        What’s more, the region server process cannot be shutdown normally,every time I have to use the KILL -9 command.
        I check the log,the reason why cannot flush is one of the MemstoreFlusher cannot exiting.
        The log is like blow:
        2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13] regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
  2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6] regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
  2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16] regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
  2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33] regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
  2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25] regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31] regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29] regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23] regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32] regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1] regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38] regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
  2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10] regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7] regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12] regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
  2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21] regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
  2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37] regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
  2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24] regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
  2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39] regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
  2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17] regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3] regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27] regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18] regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4] regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19] regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22] regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
  2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9] regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
  2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36] regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
  2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11] regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14] regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2] regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26] regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0] regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30] regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
  2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28] regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


  here is the jstack log when I try to shutdown the region server process normally:
  we can see the MemstoreFlusher.34 meet some problems, it can not exiting normally
  (By the way, we can see “locked at snappy”, but it not always locked at snappy,sometime it will locked at other place,so I think snappy is ok, Here I just want to show the MemStoreFlusher meet some problem).


   "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable [0x00007f08941c3000]
     java.lang.Thread.State: RUNNABLE
  at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native Method)
  at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
  - locked <0x00007f0a5f85c430> (a org.apache.hadoop.io.compress.snappy.SnappyCompressor)
  at org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
  at org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
  at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
  at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
  at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
  at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
  at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
  at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
  at org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
  at org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
  - locked <0x00007f09fdcccda0> (a java.lang.Object)
  at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
  at org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
  at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
  at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
  at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
  at java.lang.Thread.run(Thread.java:744)


  "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on condition [0x00007f08942c5000]
     java.lang.Thread.State: TIMED_WAITING (parking)
  at sun.misc.Unsafe.park(Native Method)
  - parking to wait for <0x00007f09b8e20f80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
  at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
  at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
  at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
  at java.lang.Thread.run(Thread.java:744)





     I do not know why the memstore cannot flush.
     Is this a bug?

Search Discussions

  • Michael Stack at May 31, 2016 at 7:11 pm

    On Mon, May 30, 2016 at 7:03 PM, 聪聪 wrote:

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)

    Is region always on same machine or do you see this phenomenon on more than
    one machine?


    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.

    The RS is ABORTED? Because it can't flush? Is that what it says in the log?
    Can we see the log message around the ABORT?


    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.

    100% disk only? The CPU does not go up too?

    Can we see a thread dump? Do jstack -l PID if you can.


    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    Any other special configurations going on on this install? Phoenix or use
    of Coprocessors?


    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at
    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at
    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at
    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at
    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at
    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)
    If you thread dump a few times, it is always stuck here?

    Thanks,
    St.Ack


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?



    下面是被转发的邮件:

    发件人: quan <329853099@qq.com>

    主题: memstore flush blocked

    日期: 2016年5月30日 GMT+8 上午10:47:43

    收件人: user@hbase.apache.org

    抄送: 蒲聪 <cong.pu@qunar.com>


    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)
    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.
    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.
    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at
    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at
    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at
    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at
    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at
    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?
  • 吴国泉wgq at Jun 1, 2016 at 10:05 am
    hi all:

    1.Is region always on same machine or do you see this phenomenon on more than one machine?
            Not always on the same machine, but always on the machine which hold the first region of a table(the only table that its first region cannot flush,when restart the regionserver, the first region would move to another machine)

      2.The RS is ABORTED? Because it can't flush? Is that what it says in the log? Can we see the log message around the ABORT?
            sorry,I did not express clear here. It is the MemStore of the first region can’t flush, not the RS.
            The RS Log is like this:
            INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 9452
            DEBUG [MemStoreFlusher.39] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true

            And the web UI shows:
            Aborted flushing .(Not flushing since already flushing.) But the Flusher thread never finish.

      3.100% disk only? The CPU does not go up too? Can we see a thread dump? Do jstack -l PID if you can
            Only the disk usage(command : df -h) increases faster than other machine, not the IO usage. The usage of CPU is very low.


      4.Any other special configurations going on on this install? Phoenix or use of Coprocessors?
            NO, no phoenix. Only AccessController coprocessor.

      5.If you thread dump a few times, it is always stuck here?
            Yes, always stuck here. here is the jstack log.(in this log, it is the MemStoreFlusher.13 can ’t flush)


            PS: As I see. I think this is because the first region cannot flush cause the problem. But I do not know why it can’t flush and why just the first region of the only table has this problem.


    在 2016年6月1日,上午3:10,Stack <stack@duboce.net 写道:

    On Mon, May 30, 2016 at 7:03 PM, 聪聪 wrote:

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)



    Is region always on same machine or do you see this phenomenon on more than
    one machine?



           On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.



    The RS is ABORTED? Because it can't flush? Is that what it says in the log?
    Can we see the log message around the ABORT?



           But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.



    100% disk only? The CPU does not go up too?

    Can we see a thread dump? Do jstack -l PID if you can.



           What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
           I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
           The log is like blow:
           2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    Any other special configurations going on on this install? Phoenix or use
    of Coprocessors?



      "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
        java.lang.Thread.State: RUNNABLE
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at
    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at
    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at
    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at
    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at
    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)



    If you thread dump a few times, it is always stuck here?

    Thanks,
    St.Ack




    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
        java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





        I do not know why the memstore cannot flush.
        Is this a bug?



       下面是被转发的邮件:

      发件人: quan <329853099@qq.com

      主题: memstore flush blocked

      日期: 2016年5月30日 GMT+8 上午10:47:43

      收件人: user@hbase.apache.org

      抄送: 蒲聪 <cong.pu@qunar.com


       HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)
           On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.
           But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.
           What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
           I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
           The log is like blow:
           2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


      "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
        java.lang.Thread.State: RUNNABLE
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at
    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at
    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at
    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at
    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at
    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
        java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





        I do not know why the memstore cannot flush.
        Is this a bug?


    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件
  • Michael Stack at Jun 2, 2016 at 4:08 pm

    On Wed, Jun 1, 2016 at 3:03 AM, 吴国泉wgq wrote:

    hi all:

    1.Is region always on same machine or do you see this phenomenon on more
    than one machine?
    Not always on the same machine, but always on the machine which
    hold the first region of a table(the only table that its first region
    cannot flush,when restart the regionserver, the first region would move to
    another machine)

    2.The RS is ABORTED? Because it can't flush? Is that what it says in the
    log? Can we see the log message around the ABORT?
    sorry,I did not express clear here. It is the MemStore of the first
    region can’t flush, not the RS.
    The RS Log is like this:
    INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 9452
    DEBUG [MemStoreFlusher.39] regionserver.HRegion: NOT flushing
    memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true

    And the web UI shows:
    Aborted flushing .(Not flushing since already flushing.) But the
    Flusher thread never finish.

    Can you back up in the log for this region? It looks like the first flush
    attempt failed or never completed. Perhaps there is a clue in the log
    message from the first attempt as to why the failure. The above log seems
    to be from a later stage, when we have gotten into the unhealthy state
    where we can't flush the first region memstore.


    3.100% disk only? The CPU does not go up too? Can we see a thread dump?
    Do jstack -l PID if you can
    Only the disk usage(command : df -h) increases faster than other
    machine, not the IO usage. The usage of CPU is very low.

    Sorry. Your disk is filling faster than on other machines? Or the iostat
    shows the disk is doing more seeks than on other machines?


    4.Any other special configurations going on on this install? Phoenix or
    use of Coprocessors?
    NO, no phoenix. Only AccessController coprocessor.

    5.If you thread dump a few times, it is always stuck here?
    Yes, always stuck here. here is the jstack log.(in this log, it is
    the MemStoreFlusher.13 can ’t flush)


    PS: As I see. I think this is because the first region cannot
    flush cause the problem. But I do not know why it can’t flush and why just
    the first region of the only table has this problem.

    Please include pointer to the stack trace. You can't have attachments on
      mail to this list.

    Thank you,
    St.Ack



    在 2016年6月1日,上午3:10,Stack <stack@duboce.net> 写道:

    On Mon, May 30, 2016 at 7:03 PM, 聪聪 wrote:

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)



    Is region always on same machine or do you see this phenomenon on more than
    one machine?



    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.



    The RS is ABORTED? Because it can't flush? Is that what it says in the log?
    Can we see the log message around the ABORT?



    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.



    100% disk only? The CPU does not go up too?

    Can we see a thread dump? Do jstack -l PID if you can.



    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    Any other special configurations going on on this install? Phoenix or use

    of Coprocessors?



    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at

    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at

    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at

    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at

    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at

    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)



    If you thread dump a few times, it is always stuck here?

    Thanks,
    St.Ack




    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at

    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?



    下面是被转发的邮件:

    发件人: quan <329853099@qq.com>

    主题: memstore flush blocked

    日期: 2016年5月30日 GMT+8 上午10:47:43

    收件人: user@hbase.apache.org

    抄送: 蒲聪 <cong.pu@qunar.com>


    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)
    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.
    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.
    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at

    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at

    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at

    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at

    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at

    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at

    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?



    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件

  • 吴国泉wgq at Jun 3, 2016 at 3:14 am
    HI STACK:

        1. The log is very large,so I pick some of it. But it seems not provide valuable info.Here is the region named qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be can’t flush.

           When the flush Thread works well, The log is like this:
           2016-05-24 12:38:27,071 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 16681
    2016-05-24 12:38:37,071 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 8684
    2016-05-24 12:38:43,753 INFO [MemStoreFlusher.2] regionserver.HRegion: Started memstore flush for qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., current region memstore size 305.3 K
    2016-05-24 12:38:43,753 WARN [MemStoreFlusher.2] wal.FSHLog: Couldn't find oldest seqNum for the region we are about to flush: [dd8f92e3c161a8534b30ab17c28ae8be]
    2016-05-24 12:38:43,816 INFO [MemStoreFlusher.2] regionserver.DefaultStoreFlusher: Flushed, sequenceid=54259, memsize=305.3 K, hasBloomFilter=true, into tmp file hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/.tmp/fddbb05945354d5cbdae4afd24e5bb9d
    2016-05-24 12:38:43,822 DEBUG [MemStoreFlusher.2] regionserver.HRegionFileSystem: Committing store file hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/.tmp/fddbb05945354d5cbdae4afd24e5bb9d as hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/t/fddbb05945354d5cbdae4afd24e5bb9d
    2016-05-24 12:38:43,837 INFO [MemStoreFlusher.2] regionserver.HStore: Added hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/t/fddbb05945354d5cbdae4afd24e5bb9d, entries=108, sequenceid=54259, filesize=68.3 K
    2016-05-24 12:38:43,837 INFO [MemStoreFlusher.2] regionserver.HRegion: Finished memstore flush of ~305.3 K/312664, currentsize=0/0 for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. in 84ms, sequenceid=54259, compaction requested=true

           And when the flush Thread does not work well,The log just always shows :
    2016-05-25 14:57:02,588 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 18068
    2016-05-25 14:57:12,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 13165
    2016-05-25 14:57:20,656 DEBUG [MemStoreFlusher.36] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true
    2016-05-25 14:57:22,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 5526
    2016-05-25 14:57:28,113 DEBUG [MemStoreFlusher.34] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true
    2016-05-25 14:57:32,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 8178
    2016-05-25 14:57:40,767 DEBUG [MemStoreFlusher.9] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true
    2016-05-25 14:57:42,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 22068
    2016-05-25 14:57:52,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 5492
    2016-05-25 14:58:02,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 10472
    2016-05-25 14:58:04,655 DEBUG [MemStoreFlusher.23] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true
    2016-05-25 14:58:12,587 INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 8435

          I check the log before the region can’t flush, but find nothing special from usual.
          by the way, this table has a heavy load on writing, so I turn off the WAL.


    2. It is the disk is filling faster than on other machines. Not the instat show.

    3.this is the jstack log of the memstoreflusher:
    "MemStoreFlusher.14" prio=10 tid=0x00007fe69487d800 nid=0x387d waiting on condition [0x00007fce7118c000]
        java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007fd09e031470> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)

    "MemStoreFlusher.13" prio=10 tid=0x00007fe69487b800 nid=0x387c runnable [0x00007fce7128c000]
        java.lang.Thread.State: RUNNABLE
    at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native Method)
    at org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007fcfe3ba1190> (a org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007fd8d1778be8> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)

    "MemStoreFlusher.12" prio=10 tid=0x00007fe694879800 nid=0x387b waiting on condition [0x00007fce7138e000]
        java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007fd09e031470> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)

    在 2016年6月3日,上午12:08,Stack <stack@duboce.net 写道:

    On Wed, Jun 1, 2016 at 3:03 AM, 吴国泉wgq wrote:

    hi all:

    1.Is region always on same machine or do you see this phenomenon on more
    than one machine?
           Not always on the same machine, but always on the machine which
    hold the first region of a table(the only table that its first region
    cannot flush,when restart the regionserver, the first region would move to
    another machine)

    2.The RS is ABORTED? Because it can't flush? Is that what it says in the
    log? Can we see the log message around the ABORT?
           sorry,I did not express clear here. It is the MemStore of the first
    region can’t flush, not the RS.
           The RS Log is like this:
           INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 9452
           DEBUG [MemStoreFlusher.39] regionserver.HRegion
    memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true

           And the web UI shows:
           Aborted flushing .(Not flushing since already flushing.) But the
    Flusher thread never finish.




    Can you back up in the log for this region? It looks like the first flush
    attempt failed or never completed. Perhaps there is a clue in the log
    message from the first attempt as to why the failure. The above log seems
    to be from a later stage, when we have gotten into the unhealthy state
    where we can't flush the first region memstore.



    3.100% disk only? The CPU does not go up too? Can we see a thread dump?
    Do jstack -l PID if you can
           Only the disk usage(command : df -h) increases faster than other
    machine, not the IO usage. The usage of CPU is very low.



    Sorry. Your disk is filling faster than on other machines? Or the iostat
    shows the disk is doing more seeks than on other machines?



    4.Any other special configurations going on on this install? Phoenix or
    use of Coprocessors?
           NO, no phoenix. Only AccessController coprocessor.

    5.If you thread dump a few times, it is always stuck here?
           Yes, always stuck here. here is the jstack log.(in this log, it is
    the MemStoreFlusher.13 can ’t flush)


           PS: As I see. I think this is because the first region cannot
    flush cause the problem. But I do not know why it can’t flush and why just
    the first region of the only table has this problem.



    Please include pointer to the stack trace. You can't have attachments on
    mail to this list.

    Thank you,
    St.Ack





    在 2016年6月1日,上午3:10,Stack <stack@duboce.net 写道:

    On Mon, May 30, 2016 at 7:03 PM, 聪聪 wrote:

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)



    Is region always on same machine or do you see this phenomenon on more than
    one machine?



          On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.



    The RS is ABORTED? Because it can't flush? Is that what it says in the log?
    Can we see the log message around the ABORT?



          But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.



    100% disk only? The CPU does not go up too?

    Can we see a thread dump? Do jstack -l PID if you can.



          What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
          I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
          The log is like blow:
          2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    Any other special configurations going on on this install? Phoenix or use

    of Coprocessors?



    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
       java.lang.Thread.State: RUNNABLE
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at

    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at

    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at

    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at

    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at

    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)



    If you thread dump a few times, it is always stuck here?

    Thanks,
    St.Ack




    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
       java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at

    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





       I do not know why the memstore cannot flush.
       Is this a bug?



      下面是被转发的邮件:

    发件人: quan <329853099@qq.com

    主题: memstore flush blocked

    日期: 2016年5月30日 GMT+8 上午10:47:43

    收件人: user@hbase.apache.org

    抄送: 蒲聪 <cong.pu@qunar.com


      HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)
          On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.
          But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.
          What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
          I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
          The log is like blow:
          2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
       java.lang.Thread.State: RUNNABLE
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at

    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at

    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at

    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at

    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at

    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at

    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at

    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at

    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at

    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at

    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
       java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at

    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at

    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





       I do not know why the memstore cannot flush.
       Is this a bug?



    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件





    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件
  • Heng Chen at Jun 3, 2016 at 3:43 am
    Something wrong in snappy Library?

    Have you try to not use compression?

    2016-06-03 11:13 GMT+08:00 吴国泉wgq <wgq.wu@qunar.com>:
    HI STACK:

    1. The log is very large,so I pick some of it. But it seems not
    provide valuable info.Here is the region named
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be can’t flush.

    When the flush Thread works well, The log is like this:
    2016-05-24 12:38:27,071 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 16681
    2016-05-24 12:38:37,071 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 8684
    2016-05-24 12:38:43,753 INFO [MemStoreFlusher.2] regionserver.HRegion:
    Started memstore flush for
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., current region
    memstore size 305.3 K
    2016-05-24 12:38:43,753 WARN [MemStoreFlusher.2] wal.FSHLog: Couldn't
    find oldest seqNum for the region we are about to flush:
    [dd8f92e3c161a8534b30ab17c28ae8be]
    2016-05-24 12:38:43,816 INFO [MemStoreFlusher.2]
    regionserver.DefaultStoreFlusher: Flushed, sequenceid=54259, memsize=305.3
    K, hasBloomFilter=true, into tmp file
    hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/.tmp/fddbb05945354d5cbdae4afd24e5bb9d
    2016-05-24 12:38:43,822 DEBUG [MemStoreFlusher.2]
    regionserver.HRegionFileSystem: Committing store file
    hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/.tmp/fddbb05945354d5cbdae4afd24e5bb9d
    as
    hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/t/fddbb05945354d5cbdae4afd24e5bb9d
    2016-05-24 12:38:43,837 INFO [MemStoreFlusher.2] regionserver.HStore:
    Added
    hdfs://cluster-tc-qtrace:8020/hbase/tc_qtrace/data/default/qtrace/dd8f92e3c161a8534b30ab17c28ae8be/t/fddbb05945354d5cbdae4afd24e5bb9d,
    entries=108, sequenceid=54259, filesize=68.3 K
    2016-05-24 12:38:43,837 INFO [MemStoreFlusher.2] regionserver.HRegion:
    Finished memstore flush of ~305.3 K/312664, currentsize=0/0 for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. in 84ms,
    sequenceid=54259, compaction requested=true

    And when the flush Thread does not work well,The log just always
    shows :
    2016-05-25 14:57:02,588 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 18068
    2016-05-25 14:57:12,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 13165
    2016-05-25 14:57:20,656 DEBUG [MemStoreFlusher.36] regionserver.HRegion:
    NOT flushing memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true
    2016-05-25 14:57:22,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 5526
    2016-05-25 14:57:28,113 DEBUG [MemStoreFlusher.34] regionserver.HRegion:
    NOT flushing memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true
    2016-05-25 14:57:32,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 8178
    2016-05-25 14:57:40,767 DEBUG [MemStoreFlusher.9] regionserver.HRegion:
    NOT flushing memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true
    2016-05-25 14:57:42,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 22068
    2016-05-25 14:57:52,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 5492
    2016-05-25 14:58:02,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 10472
    2016-05-25 14:58:04,655 DEBUG [MemStoreFlusher.23] regionserver.HRegion:
    NOT flushing memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true
    2016-05-25 14:58:12,587 INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 8435

    I check the log before the region can’t flush, but find nothing
    special from usual.
    by the way, this table has a heavy load on writing, so I turn off
    the WAL.


    2. It is the disk is filling faster than on other machines. Not the
    instat show.

    3.this is the jstack log of the memstoreflusher:
    "MemStoreFlusher.14" prio=10 tid=0x00007fe69487d800 nid=0x387d waiting on
    condition [0x00007fce7118c000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007fd09e031470> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)

    "MemStoreFlusher.13" prio=10 tid=0x00007fe69487b800 nid=0x387c runnable
    [0x00007fce7128c000]
    java.lang.Thread.State: RUNNABLE
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at
    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007fcfe3ba1190> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at
    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at
    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at
    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at
    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at
    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at
    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at
    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007fd8d1778be8> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at
    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)

    "MemStoreFlusher.12" prio=10 tid=0x00007fe694879800 nid=0x387b waiting on
    condition [0x00007fce7138e000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007fd09e031470> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at
    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)

    在 2016年6月3日,上午12:08,Stack <stack@duboce.net 写道:

    On Wed, Jun 1, 2016 at 3:03 AM, 吴国泉wgq <wgq.wu@qunar.com<mailto:
    wgq.wu@qunar.com>> wrote:

    hi all:

    1.Is region always on same machine or do you see this phenomenon on more
    than one machine?
    Not always on the same machine, but always on the machine which
    hold the first region of a table(the only table that its first region
    cannot flush,when restart the regionserver, the first region would move to
    another machine)

    2.The RS is ABORTED? Because it can't flush? Is that what it says in the
    log? Can we see the log message around the ABORT?
    sorry,I did not express clear here. It is the MemStore of the first
    region can’t flush, not the RS.
    The RS Log is like this:
    INFO [regionserver60020.periodicFlusher]
    regionserver.HRegionServer: regionserver60020.periodicFlusher requesting
    flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be.
    after a delay of 9452
    DEBUG [MemStoreFlusher.39] regionserver.HRegion
    memstore for region
    qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true,
    writesEnabled=true

    And the web UI shows:
    Aborted flushing .(Not flushing since already flushing.) But the
    Flusher thread never finish.




    Can you back up in the log for this region? It looks like the first flush
    attempt failed or never completed. Perhaps there is a clue in the log
    message from the first attempt as to why the failure. The above log seems
    to be from a later stage, when we have gotten into the unhealthy state
    where we can't flush the first region memstore.



    3.100% disk only? The CPU does not go up too? Can we see a thread dump?
    Do jstack -l PID if you can
    Only the disk usage(command : df -h) increases faster than other
    machine, not the IO usage. The usage of CPU is very low.



    Sorry. Your disk is filling faster than on other machines? Or the iostat
    shows the disk is doing more seeks than on other machines?



    4.Any other special configurations going on on this install? Phoenix or
    use of Coprocessors?
    NO, no phoenix. Only AccessController coprocessor.

    5.If you thread dump a few times, it is always stuck here?
    Yes, always stuck here. here is the jstack log.(in this log, it is
    the MemStoreFlusher.13 can ’t flush)


    PS: As I see. I think this is because the first region cannot
    flush cause the problem. But I do not know why it can’t flush and why just
    the first region of the only table has this problem.



    Please include pointer to the stack trace. You can't have attachments on
    mail to this list.

    Thank you,
    St.Ack





    在 2016年6月1日,上午3:10,Stack <stack@duboce.net 写道:

    On Mon, May 30, 2016 at 7:03 PM, 聪聪 <175998806@qq.com<mailto:
    175998806@qq.com>> wrote:

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)



    Is region always on same machine or do you see this phenomenon on more than
    one machine?



    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.



    The RS is ABORTED? Because it can't flush? Is that what it says in the log?
    Can we see the log message around the ABORT?



    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.



    100% disk only? The CPU does not go up too?

    Can we see a thread dump? Do jstack -l PID if you can.



    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    Any other special configurations going on on this install? Phoenix or use

    of Coprocessors?



    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at


    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at


    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at


    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at


    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at


    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at


    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at


    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at


    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at


    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at


    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at


    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at


    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at


    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)



    If you thread dump a few times, it is always stuck here?

    Thanks,
    St.Ack




    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at


    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?



    下面是被转发的邮件:

    发件人: quan <329853099@qq.com
    主题: memstore flush blocked

    日期: 2016年5月30日 GMT+8 上午10:47:43

    收件人: user@hbase.apache.org
    抄送: 蒲聪 <cong.pu@qunar.com

    HI ALL: Recently,I met a strange problem, the first Region’s
    Memstore of one table (the only one) often blocked when flushing.(Both
    Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
    1.0.1.1,hope to solve the problem,But failed)
    On the web UI, I can see the status shows: ABORTED(since XXsec
    ago), Not flushing since already flushing.
    But it will never flush success, and the usage of the disk will
    increase very high.Now other regionservers just use 30% of the disk
    capacity, the problematic region server will increase to 100%,unless
    killing the process.
    What’s more, the region server process cannot be shutdown
    normally,every time I have to use the KILL -9 command.
    I check the log,the reason why cannot flush is one of the
    MemstoreFlusher cannot exiting.
    The log is like blow:
    2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
    regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
    2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
    regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
    2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
    regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
    2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
    regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
    2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
    regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
    regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
    regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
    regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
    regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
    regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
    regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
    2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
    regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
    regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
    regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
    2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
    regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
    regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
    2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
    regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
    2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
    regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
    2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
    regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
    regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
    regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
    regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
    regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
    regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
    regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
    2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
    regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
    2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
    regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
    2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
    regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
    regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
    regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
    regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
    regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
    regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
    2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
    regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


    here is the jstack log when I try to shutdown the region server process
    normally:
    we can see the MemstoreFlusher.34 meet some problems, it can not exiting
    normally
    (By the way, we can see “locked at snappy”, but it not always locked at
    snappy,sometime it will locked at other place,so I think snappy is ok, Here
    I just want to show the MemStoreFlusher meet some problem).


    "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
    [0x00007f08941c3000]
    java.lang.Thread.State: RUNNABLE
    at


    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
    Method)
    at


    org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
    - locked <0x00007f0a5f85c430> (a
    org.apache.hadoop.io.compress.snappy.SnappyCompressor)
    at


    org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
    at


    org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
    at


    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
    at


    org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
    at


    org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
    at


    org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
    at


    org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
    at


    org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
    at


    org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
    - locked <0x00007f09fdcccda0> (a java.lang.Object)
    at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
    at


    org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
    at


    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
    at


    org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
    at
    org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
    at java.lang.Thread.run(Thread.java:744)


    "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
    condition [0x00007f08942c5000]
    java.lang.Thread.State: TIMED_WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for <0x00007f09b8e20f80> (a
    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
    at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
    at


    java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
    at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
    at


    org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
    at java.lang.Thread.run(Thread.java:744)





    I do not know why the memstore cannot flush.
    Is this a bug?



    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件





    安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件
  • 聪聪 at Jun 1, 2016 at 10:12 am
    hi Stack:


      1.Is region always on same machine or do you see this phenomenon on more than one machine?
             Not always on the same machine, but always on the machine which hold the first region of a table(the only table that its first region cannot flush,when restart the regionserver, the first region would move to another machine)

       2.The RS is ABORTED? Because it can't flush? Is that what it says in the log? Can we see the log message around the ABORT?
             sorry,I did not express clear here. It is the MemStore of the first region can’t flush, not the RS.
             The RS Log is like this:
             INFO [regionserver60020.periodicFlusher] regionserver.HRegionServer: regionserver60020.periodicFlusher requesting flush for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be. after a delay of 9452
             DEBUG [MemStoreFlusher.39] regionserver.HRegion: NOT flushing memstore for region qtrace,,1458012479440.dd8f92e3c161a8534b30ab17c28ae8be., flushing=true, writesEnabled=true

             And the web UI shows:
             Aborted flushing .(Not flushing since already flushing.) But the Flusher thread never finish.

       3.100% disk only? The CPU does not go up too? Can we see a thread dump? Do jstack -l PID if you can
             Only the disk usage(command : df -h) increases faster than other machine, not the IO usage. The usage of CPU is very low.



       4.Any other special configurations going on on this install? Phoenix or use of Coprocessors?
             NO, no phoenix. Only AccessController coprocessor.


       5.If you thread dump a few times, it is always stuck here?
             Yes, always stuck here. here is the jstack log.(in this log, it is the MemStoreFlusher.13 can ’t flush)




             PS: As I see. I think this is because the first region cannot flush cause the problem. But I do not know why it can’t flush and why just the first region of the only table has this problem.



        在 2016年6月1日,上午3:10,Stack <stack@duboce.net> 写道:

       On Mon, May 30, 2016 at 7:03 PM, 聪聪 wrote:

      HI ALL: Recently,I met a strange problem, the first Region’s
      Memstore of one table (the only one) often blocked when flushing.(Both
      Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
      1.0.1.1,hope to solve the problem,But failed)



      Is region always on same machine or do you see this phenomenon on more than
      one machine?



            On the web UI, I can see the status shows: ABORTED(since XXsec
      ago), Not flushing since already flushing.



      The RS is ABORTED? Because it can't flush? Is that what it says in the log?
      Can we see the log message around the ABORT?



            But it will never flush success, and the usage of the disk will
      increase very high.Now other regionservers just use 30% of the disk
      capacity, the problematic region server will increase to 100%,unless
      killing the process.



      100% disk only? The CPU does not go up too?

      Can we see a thread dump? Do jstack -l PID if you can.



            What’s more, the region server process cannot be shutdown
      normally,every time I have to use the KILL -9 command.
            I check the log,the reason why cannot flush is one of the
      MemstoreFlusher cannot exiting.
            The log is like blow:
            2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
      regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
      2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
      regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
      2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
      regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
      2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
      regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
      2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
      regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
      regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
      regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
      regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
      regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
      regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
      regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
      regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
      regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
      regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
      regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
      2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
      regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
      2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
      regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
      2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
      regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
      2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
      regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
      regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
      regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
      regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
      regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
      regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
      regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
      regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
      2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
      regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
      2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
      regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
      regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
      regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
      regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
      regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
      regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
      regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


      here is the jstack log when I try to shutdown the region server process
      normally:
      we can see the MemstoreFlusher.34 meet some problems, it can not exiting
      normally
      (By the way, we can see “locked at snappy”, but it not always locked at
      snappy,sometime it will locked at other place,so I think snappy is ok, Here
      I just want to show the MemStoreFlusher meet some problem).


      Any other special configurations going on on this install? Phoenix or use
       of Coprocessors?



       "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
      [0x00007f08941c3000]
         java.lang.Thread.State: RUNNABLE
      at
      org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
      Method)
      at
      org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
      - locked <0x00007f0a5f85c430> (a
      org.apache.hadoop.io.compress.snappy.SnappyCompressor)
      at
      org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
      at
      org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
      at
      org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
      at
      org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
      at
      org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
      at
      org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
      at
      org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
      at
      org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
      - locked <0x00007f09fdcccda0> (a java.lang.Object)
      at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
      at
      org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
      at java.lang.Thread.run(Thread.java:744)



      If you thread dump a few times, it is always stuck here?

      Thanks,
      St.Ack




      "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
      condition [0x00007f08942c5000]
         java.lang.Thread.State: TIMED_WAITING (parking)
      at sun.misc.Unsafe.park(Native Method)
      - parking to wait for <0x00007f09b8e20f80> (a
      java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
      at
      java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
      at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
      at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
      at java.lang.Thread.run(Thread.java:744)





         I do not know why the memstore cannot flush.
         Is this a bug?



        下面是被转发的邮件:

       发件人: quan <329853099@qq.com>

       主题: memstore flush blocked

       日期: 2016年5月30日 GMT+8 上午10:47:43

       收件人: user@hbase.apache.org

       抄送: 蒲聪 <cong.pu@qunar.com>


        HI ALL: Recently,I met a strange problem, the first Region’s
      Memstore of one table (the only one) often blocked when flushing.(Both
      Version: hbase-0.98.6-cdh5.2.0 and 1.0.1.1, I updated 0.98 to
      1.0.1.1,hope to solve the problem,But failed)
            On the web UI, I can see the status shows: ABORTED(since XXsec
      ago), Not flushing since already flushing.
            But it will never flush success, and the usage of the disk will
      increase very high.Now other regionservers just use 30% of the disk
      capacity, the problematic region server will increase to 100%,unless
      killing the process.
            What’s more, the region server process cannot be shutdown
      normally,every time I have to use the KILL -9 command.
            I check the log,the reason why cannot flush is one of the
      MemstoreFlusher cannot exiting.
            The log is like blow:
            2016-05-29 19:54:11,982 INFO [MemStoreFlusher.13]
      regionserver.MemStoreFlusher: MemStoreFlusher.13 exiting
      2016-05-29 19:54:13,016 INFO [MemStoreFlusher.6]
      regionserver.MemStoreFlusher: MemStoreFlusher.6 exiting
      2016-05-29 19:54:13,260 INFO [MemStoreFlusher.16]
      regionserver.MemStoreFlusher: MemStoreFlusher.16 exiting
      2016-05-29 19:54:16,032 INFO [MemStoreFlusher.33]
      regionserver.MemStoreFlusher: MemStoreFlusher.33 exiting
      2016-05-29 19:54:16,341 INFO [MemStoreFlusher.25]
      regionserver.MemStoreFlusher: MemStoreFlusher.25 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.31]
      regionserver.MemStoreFlusher: MemStoreFlusher.31 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.29]
      regionserver.MemStoreFlusher: MemStoreFlusher.29 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.23]
      regionserver.MemStoreFlusher: MemStoreFlusher.23 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.32]
      regionserver.MemStoreFlusher: MemStoreFlusher.32 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.1]
      regionserver.MemStoreFlusher: MemStoreFlusher.1 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.38]
      regionserver.MemStoreFlusher: MemStoreFlusher.38 exiting
      2016-05-29 19:54:16,621 INFO [MemStoreFlusher.10]
      regionserver.MemStoreFlusher: MemStoreFlusher.10 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.7]
      regionserver.MemStoreFlusher: MemStoreFlusher.7 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.12]
      regionserver.MemStoreFlusher: MemStoreFlusher.12 exiting
      2016-05-29 19:54:16,620 INFO [MemStoreFlusher.21]
      regionserver.MemStoreFlusher: MemStoreFlusher.21 exiting
      2016-05-29 19:54:16,622 INFO [MemStoreFlusher.37]
      regionserver.MemStoreFlusher: MemStoreFlusher.37 exiting
      2016-05-29 19:54:16,622 INFO [MemStoreFlusher.24]
      regionserver.MemStoreFlusher: MemStoreFlusher.24 exiting
      2016-05-29 19:54:16,806 INFO [MemStoreFlusher.39]
      regionserver.MemStoreFlusher: MemStoreFlusher.39 exiting
      2016-05-29 19:54:16,908 INFO [MemStoreFlusher.17]
      regionserver.MemStoreFlusher: MemStoreFlusher.17 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.3]
      regionserver.MemStoreFlusher: MemStoreFlusher.3 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.27]
      regionserver.MemStoreFlusher: MemStoreFlusher.27 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.18]
      regionserver.MemStoreFlusher: MemStoreFlusher.18 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.4]
      regionserver.MemStoreFlusher: MemStoreFlusher.4 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.19]
      regionserver.MemStoreFlusher: MemStoreFlusher.19 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.22]
      regionserver.MemStoreFlusher: MemStoreFlusher.22 exiting
      2016-05-29 19:54:16,952 INFO [MemStoreFlusher.9]
      regionserver.MemStoreFlusher: MemStoreFlusher.9 exiting
      2016-05-29 19:54:17,137 INFO [MemStoreFlusher.36]
      regionserver.MemStoreFlusher: MemStoreFlusher.36 exiting
      2016-05-29 19:54:17,263 INFO [MemStoreFlusher.11]
      regionserver.MemStoreFlusher: MemStoreFlusher.11 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.14]
      regionserver.MemStoreFlusher: MemStoreFlusher.14 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.2]
      regionserver.MemStoreFlusher: MemStoreFlusher.2 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.26]
      regionserver.MemStoreFlusher: MemStoreFlusher.26 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.0]
      regionserver.MemStoreFlusher: MemStoreFlusher.0 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.30]
      regionserver.MemStoreFlusher: MemStoreFlusher.30 exiting
      2016-05-29 19:54:17,499 INFO [MemStoreFlusher.28]
      regionserver.MemStoreFlusher: MemStoreFlusher.28 exiting


      here is the jstack log when I try to shutdown the region server process
      normally:
      we can see the MemstoreFlusher.34 meet some problems, it can not exiting
      normally
      (By the way, we can see “locked at snappy”, but it not always locked at
      snappy,sometime it will locked at other place,so I think snappy is ok, Here
      I just want to show the MemStoreFlusher meet some problem).


       "MemStoreFlusher.34" prio=10 tid=0x00007f20b8939000 nid=0x511b runnable
      [0x00007f08941c3000]
         java.lang.Thread.State: RUNNABLE
      at
      org.apache.hadoop.io.compress.snappy.SnappyCompressor.compressBytesDirect(Native
      Method)
      at
      org.apache.hadoop.io.compress.snappy.SnappyCompressor.compress(SnappyCompressor.java:232)
      - locked <0x00007f0a5f85c430> (a
      org.apache.hadoop.io.compress.snappy.SnappyCompressor)
      at
      org.apache.hadoop.io.compress.BlockCompressorStream.compress(BlockCompressorStream.java:149)
      at
      org.apache.hadoop.io.compress.BlockCompressorStream.finish(BlockCompressorStream.java:142)
      at
      org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncoding(HFileBlockDefaultEncodingContext.java:238)
      at
      org.apache.hadoop.hbase.io.encoding.HFileBlockDefaultEncodingContext.compressAfterEncodingWithBlockType(HFileBlockDefaultEncodingContext.java:149)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlock(HFileBlock.java:783)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.ensureBlockReady(HFileBlock.java:761)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.finishBlockAndWriteHeaderAndData(HFileBlock.java:878)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlock$Writer.writeHeaderAndData(HFileBlock.java:864)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateBlock(HFileBlockIndex.java:948)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIntermediateLevel(HFileBlockIndex.java:931)
      at
      org.apache.hadoop.hbase.io.hfile.HFileBlockIndex$BlockIndexWriter.writeIndexBlocks(HFileBlockIndex.java:840)
      at
      org.apache.hadoop.hbase.io.hfile.HFileWriterV2.close(HFileWriterV2.java:367)
      at
      org.apache.hadoop.hbase.regionserver.StoreFile$Writer.close(StoreFile.java:974)
      at
      org.apache.hadoop.hbase.regionserver.StoreFlusher.finalizeWriter(StoreFlusher.java:69)
      at
      org.apache.hadoop.hbase.regionserver.DefaultStoreFlusher.flushSnapshot(DefaultStoreFlusher.java:70)
      - locked <0x00007f09fdcccda0> (a java.lang.Object)
      at org.apache.hadoop.hbase.regionserver.HStore.flushCache(HStore.java:829)
      at
      org.apache.hadoop.hbase.regionserver.HStore$StoreFlusherImpl.flushCache(HStore.java:1989)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1779)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.internalFlushcache(HRegion.java:1662)
      at
      org.apache.hadoop.hbase.regionserver.HRegion.flushcache(HRegion.java:1575)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:461)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.flushRegion(MemStoreFlusher.java:435)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher.access$800(MemStoreFlusher.java:66)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:253)
      at java.lang.Thread.run(Thread.java:744)


      "MemStoreFlusher.33" prio=10 tid=0x00007f20b8937000 nid=0x511a waiting on
      condition [0x00007f08942c5000]
         java.lang.Thread.State: TIMED_WAITING (parking)
      at sun.misc.Unsafe.park(Native Method)
      - parking to wait for <0x00007f09b8e20f80> (a
      java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
      at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
      at
      java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
      at java.util.concurrent.DelayQueue.poll(DelayQueue.java:264)
      at java.util.concurrent.DelayQueue.poll(DelayQueue.java:68)
      at
      org.apache.hadoop.hbase.regionserver.MemStoreFlusher$FlushHandler.run(MemStoreFlusher.java:233)
      at java.lang.Thread.run(Thread.java:744)





         I do not know why the memstore cannot flush.
         Is this a bug?


      安全提示:本邮件非QUNAR内部邮件,请注意保护个人及公司信息安全,如有索取帐号密码等可疑情况请向 secteam发送邮件

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupuser @
categorieshbase, hadoop
postedMay 31, '16 at 2:03a
activeJun 3, '16 at 3:43a
posts7
users4
websitehbase.apache.org

People

Translate

site design / logo © 2018 Grokbase