You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hbase.apache.org by "ramkrishna.s.vasudevan (JIRA)" <ji...@apache.org> on 2013/05/21 05:39:17 UTC
[jira] [Updated] (HBASE-8282) User triggered flushes does not allow
compaction to get triggered even if compaction criteria is met
[ https://issues.apache.org/jira/browse/HBASE-8282?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
ramkrishna.s.vasudevan updated HBASE-8282:
------------------------------------------
Attachment: HBASE-8282_0.94.patch
Patch for 0.94. The changes are to be done in all the 3 flavours of flushCache.
> 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.98.0, 0.94.8, 0.95.1
>
> Attachments: HBASE-8282_0.94.patch, HBASE-8282_trunk_1.patch, HBASE-8282_trunk.patch
>
>
> 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