[HBASE-8282] User triggered flushes does not allow compaction to get triggered even if compaction criteria is met - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Closed
Priority: Major
Resolution: Fixed
Affects Version/s: None
Fix Version/s: 0.98.0, 0.94.8, 0.95.1
Component/s: None
Labels:
None

Hadoop Flags:

Reviewed

Description

Observe the below logs

2013-04-04 17:43:45,825 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Flushing MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9.
2013-04-04 17:43:45,826 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., current region memstore size 42.3 M
2013-04-04 17:43:45,826 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., commencing wait for mvcc, flushsize=44388936
2013-04-04 17:43:45,826 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, commencing flushing stores
2013-04-04 17:43:45,831 DEBUG org.apache.hadoop.hbase.util.FSUtils: Creating file=hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/7020db24b38246a5818e7eb4e130ad9e with permission=rwxrwxrwx
2013-04-04 17:43:45,834 DEBUG org.apache.hadoop.hbase.io.hfile.HFileWriterV2: Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2013-04-04 17:43:45,835 INFO org.apache.hadoop.hbase.regionserver.StoreFile: Delete Family Bloom filter type for hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/7020db24b38246a5818e7eb4e130ad9e: CompoundBloomFilterWriter
2013-04-04 17:43:46,074 INFO org.apache.hadoop.hbase.regionserver.StoreFile: NO General Bloom and NO DeleteFamily was added to HFile (hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/7020db24b38246a5818e7eb4e130ad9e) 
2013-04-04 17:43:46,074 INFO org.apache.hadoop.hbase.regionserver.HStore: Flushed , sequenceid=1051817, memsize=42.3 M, into tmp file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/7020db24b38246a5818e7eb4e130ad9e
2013-04-04 17:43:46,093 DEBUG org.apache.hadoop.hbase.regionserver.HRegionFileSystem: Committing store file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/7020db24b38246a5818e7eb4e130ad9e as hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/7020db24b38246a5818e7eb4e130ad9e
2013-04-04 17:43:46,103 INFO org.apache.hadoop.hbase.regionserver.HStore: Added hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/7020db24b38246a5818e7eb4e130ad9e, entries=54911, sequenceid=1051817, filesize=35.1 M
2013-04-04 17:43:46,103 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~42.3 M/44388936, currentsize=0/0 for region MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9. in 278ms, sequenceid=-1, compaction requested=true
2013-04-04 17:43:56,335 DEBUG org.apache.hadoop.hbase.io.hfile.LruBlockCache: Stats: total=394.09 MB, free=3.61 GB, max=4.00 GB, blocks=5263, accesses=244882, hits=42988, hitRatio=17.55%, , cachingAccesses=49869, cachingHits=24251, cachingHitsRatio=48.63%, , evictions=0, evicted=20349, evictedPerRun=Infinity
2013-04-04 17:44:31,119 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Flushing MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9.
2013-04-04 17:44:31,120 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., current region memstore size 42.7 M
2013-04-04 17:44:31,120 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., commencing wait for mvcc, flushsize=44764248
2013-04-04 17:44:31,120 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, commencing flushing stores
2013-04-04 17:44:31,136 DEBUG org.apache.hadoop.hbase.util.FSUtils: Creating file=hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/c5c2cd6aaf1644daa9c858149da39081 with permission=rwxrwxrwx
2013-04-04 17:44:31,139 DEBUG org.apache.hadoop.hbase.io.hfile.HFileWriterV2: Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2013-04-04 17:44:31,140 INFO org.apache.hadoop.hbase.regionserver.StoreFile: Delete Family Bloom filter type for hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/c5c2cd6aaf1644daa9c858149da39081: CompoundBloomFilterWriter
2013-04-04 17:44:31,341 INFO org.apache.hadoop.hbase.regionserver.StoreFile: NO General Bloom and NO DeleteFamily was added to HFile (hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/c5c2cd6aaf1644daa9c858149da39081) 
2013-04-04 17:44:31,341 INFO org.apache.hadoop.hbase.regionserver.HStore: Flushed , sequenceid=1051858, memsize=42.7 M, into tmp file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/c5c2cd6aaf1644daa9c858149da39081
2013-04-04 17:44:31,356 DEBUG org.apache.hadoop.hbase.regionserver.HRegionFileSystem: Committing store file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/c5c2cd6aaf1644daa9c858149da39081 as hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/c5c2cd6aaf1644daa9c858149da39081
2013-04-04 17:44:31,365 INFO org.apache.hadoop.hbase.regionserver.HStore: Added hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/c5c2cd6aaf1644daa9c858149da39081, entries=55156, sequenceid=1051858, filesize=35.5 M
2013-04-04 17:44:31,365 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~42.7 M/44764248, currentsize=0/0 for region MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9. in 245ms, sequenceid=-1, compaction requested=true
2013-04-04 17:45:09,450 DEBUG org.apache.hadoop.hbase.regionserver.LogRoller: HLog roll requested
2013-04-04 17:45:09,458 DEBUG org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using new createWriter -- HADOOP-6840
2013-04-04 17:45:09,458 DEBUG org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: Path=hdfs://localhost:9010/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365111909450, compression=false
2013-04-04 17:45:09,462 INFO org.apache.hadoop.hbase.regionserver.wal.FSHLog: Rolled log for file=/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365111822437, entries=70, filesize=65061576; new path=/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365111909450
2013-04-04 17:45:51,419 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Flushing MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9.
2013-04-04 17:45:51,419 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., current region memstore size 42.4 M
2013-04-04 17:45:51,420 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., commencing wait for mvcc, flushsize=44419376
2013-04-04 17:45:51,420 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, commencing flushing stores
2013-04-04 17:45:51,428 DEBUG org.apache.hadoop.hbase.util.FSUtils: Creating file=hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/6c502092c27a4eae847a51109e764be3 with permission=rwxrwxrwx
2013-04-04 17:45:51,432 DEBUG org.apache.hadoop.hbase.io.hfile.HFileWriterV2: Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2013-04-04 17:45:51,433 INFO org.apache.hadoop.hbase.regionserver.StoreFile: Delete Family Bloom filter type for hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/6c502092c27a4eae847a51109e764be3: CompoundBloomFilterWriter
2013-04-04 17:45:51,627 INFO org.apache.hadoop.hbase.regionserver.StoreFile: NO General Bloom and NO DeleteFamily was added to HFile (hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/6c502092c27a4eae847a51109e764be3) 
2013-04-04 17:45:51,627 INFO org.apache.hadoop.hbase.regionserver.HStore: Flushed , sequenceid=1051899, memsize=42.4 M, into tmp file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/6c502092c27a4eae847a51109e764be3
2013-04-04 17:45:51,645 DEBUG org.apache.hadoop.hbase.regionserver.HRegionFileSystem: Committing store file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/6c502092c27a4eae847a51109e764be3 as hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/6c502092c27a4eae847a51109e764be3
2013-04-04 17:45:51,654 INFO org.apache.hadoop.hbase.regionserver.HStore: Added hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/6c502092c27a4eae847a51109e764be3, entries=54781, sequenceid=1051899, filesize=35.2 M
2013-04-04 17:45:51,654 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~42.4 M/44419376, currentsize=0/0 for region MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9. in 235ms, sequenceid=-1, compaction requested=true
2013-04-04 17:47:36,168 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Flushing MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9.
2013-04-04 17:47:36,168 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Started memstore flush for MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., current region memstore size 42.5 M
2013-04-04 17:47:36,169 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9., commencing wait for mvcc, flushsize=44568408
2013-04-04 17:47:36,169 DEBUG org.apache.hadoop.hbase.regionserver.HRegion: Finished snapshotting, commencing flushing stores
2013-04-04 17:47:36,177 DEBUG org.apache.hadoop.hbase.util.FSUtils: Creating file=hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/b1f04e64c8be4ea1bd1d95f8a4ee8936 with permission=rwxrwxrwx
2013-04-04 17:47:36,194 DEBUG org.apache.hadoop.hbase.io.hfile.HFileWriterV2: Initialized with CacheConfig:enabled [cacheDataOnRead=true] [cacheDataOnWrite=false] [cacheIndexesOnWrite=false] [cacheBloomsOnWrite=false] [cacheEvictOnClose=false] [cacheCompressed=false]
2013-04-04 17:47:36,194 INFO org.apache.hadoop.hbase.regionserver.StoreFile: Delete Family Bloom filter type for hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/b1f04e64c8be4ea1bd1d95f8a4ee8936: CompoundBloomFilterWriter
2013-04-04 17:47:36,426 INFO org.apache.hadoop.hbase.regionserver.StoreFile: NO General Bloom and NO DeleteFamily was added to HFile (hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/b1f04e64c8be4ea1bd1d95f8a4ee8936) 
2013-04-04 17:47:36,426 INFO org.apache.hadoop.hbase.regionserver.HStore: Flushed , sequenceid=1051940, memsize=42.5 M, into tmp file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/b1f04e64c8be4ea1bd1d95f8a4ee8936
2013-04-04 17:47:36,443 DEBUG org.apache.hadoop.hbase.regionserver.HRegionFileSystem: Committing store file hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/.tmp/b1f04e64c8be4ea1bd1d95f8a4ee8936 as hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/b1f04e64c8be4ea1bd1d95f8a4ee8936
2013-04-04 17:47:36,452 INFO org.apache.hadoop.hbase.regionserver.HStore: Added hdfs://localhost:9010/hbase/MyTable/f6792086ad3518dee244e7bf2761a1f9/f1/b1f04e64c8be4ea1bd1d95f8a4ee8936, entries=55107, sequenceid=1051940, filesize=35.3 M
2013-04-04 17:47:36,452 INFO org.apache.hadoop.hbase.regionserver.HRegion: Finished memstore flush of ~42.5 M/44568408, currentsize=0/0 for region MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9. in 284ms, sequenceid=-1, compaction requested=true
2013-04-04 17:47:57,196 DEBUG org.apache.hadoop.hbase.regionserver.LogRoller: HLog roll requested
2013-04-04 17:47:57,203 DEBUG org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: using new createWriter -- HADOOP-6840
2013-04-04 17:47:57,203 DEBUG org.apache.hadoop.hbase.regionserver.wal.SequenceFileLogWriter: Path=hdfs://localhost:9010/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365112077196, compression=false
2013-04-04 17:47:57,208 INFO org.apache.hadoop.hbase.regionserver.wal.FSHLog: Rolled log for file=/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365111909450, entries=70, filesize=64871151; new path=/hbase/.logs/ram.sh.intel.com,60020,1365040136175/ram.sh.intel.com%2C60020%2C1365040136175.1365112077196
2013-04-04 17:48:16,796 INFO org.apache.hadoop.hbase.regionserver.HRegionServer: Flushing MyTable,,1365111467842.f6792086ad3518dee244e7bf2761a1f9.
.............

The above logs continued and created around 38 files.

Later when the RS was restarted

2013-04-04 18:36:18,007 INFO org.apache.hadoop.hbase.regionserver.compactions.DefaultCompactionPolicy: Default compaction algorithm has selected 38 files from 38 candidates

The compaction happeneded for the 38 files.
The reason for the above is this, USer triggered flushes happen thro
HRS.flushRegion()

FlushRegionResponse.Builder builder = FlushRegionResponse.newBuilder();
      if (shouldFlush) {
        builder.setFlushed(region.flushcache());
      }
      builder.setLastFlushTime(region.getLastFlushTime());
      return builder.build();

Here we call region.flushCache but the return value is never used. The return value is nothing but the variable which says a compaction is needed after this flush or not (that is returned by internalFlushCache). In the HRS.flushRegion method the return value is ignored.
But the same when it happens thro MemstoreFlusher the return value is used and we call requestCompaction.

try {
      boolean shouldCompact = region.flushcache();
      // We just want to check the size
      boolean shouldSplit = region.checkSplit() != null;
      if (shouldSplit) {
        this.server.compactSplitThread.requestSplit(region);
      } else if (shouldCompact) {
        server.compactSplitThread.requestCompaction(region, Thread.currentThread().getName());
      }

Doing the above step in HRS.flushRegion() should be enough i feel.
I had a doubt here if user triggered flush had to behave differently. The same can be observed in the 0.94 code also.

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending

HBASE-8282_trunk.patch
08/Apr/13 11:29
2 kB
ramkrishna.s.vasudevan
HBASE-8282_trunk_1.patch
25/Apr/13 16:36
2 kB
ramkrishna.s.vasudevan
HBASE-8282_0.94.patch
21/May/13 03:38
2 kB
ramkrishna.s.vasudevan

Activity

People

Assignee:: ramkrishna.s.vasudevan

Reporter:: ramkrishna.s.vasudevan

Votes:: 0 Vote for this issue

Watchers:: 9 Start watching this issue

Dates

Created:: 05/Apr/13 17:56

Updated:: 04/Jun/13 00:07

Resolved:: 21/May/13 05:38