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 <st...@duboce.net<mailto:st...@duboce.net>> 写道: On Wed, Jun 1, 2016 at 3:03 AM, 吴国泉wgq <wgq...@qunar.com<mailto:wgq...@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 <st...@duboce.net<mailto:st...@duboce.net>> 写道: On Mon, May 30, 2016 at 7:03 PM, 聪聪 <175998...@qq.com<mailto:175998...@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 <329853...@qq.com<mailto:329853...@qq.com>> 主题: memstore flush blocked 日期: 2016年5月30日 GMT+8 上午10:47:43 收件人: user@hbase.apache.org<mailto:user@hbase.apache.org> 抄送: 蒲聪 <cong...@qunar.com<mailto:cong...@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发送邮件