ramkrishna.s.vasudevan created HBASE-8282:
---------------------------------------------
Summary: User triggered flushes does not allow compaction to get
triggered even if compaction criteria is met
Key: HBASE-8282
URL: https://issues.apache.org/jira/browse/HBASE-8282
Project: HBase
Issue Type: Bug
Reporter: ramkrishna.s.vasudevan
Assignee: ramkrishna.s.vasudevan
Fix For: 0.95.0, 0.98.0, 0.94.7
Observe the below logs
{code}
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.
.............
{code}
The above logs continued and created around 38 files.
Later when the RS was restarted
{code}
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
{code}
The compaction happeneded for the 38 files.
The reason for the above is this, USer triggered flushes happen thro
HRS.flushRegion()
{code}
FlushRegionResponse.Builder builder = FlushRegionResponse.newBuilder();
if (shouldFlush) {
builder.setFlushed(region.flushcache());
}
builder.setLastFlushTime(region.getLastFlushTime());
return builder.build();
{code}
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.
{code}
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());
}
{code}
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.
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
