Return-Path: X-Original-To: apmail-hbase-issues-archive@www.apache.org Delivered-To: apmail-hbase-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 90D0FF0FF for ; Fri, 26 Apr 2013 03:56:20 +0000 (UTC) Received: (qmail 6744 invoked by uid 500); 26 Apr 2013 03:56:19 -0000 Delivered-To: apmail-hbase-issues-archive@hbase.apache.org Received: (qmail 6432 invoked by uid 500); 26 Apr 2013 03:56:19 -0000 Mailing-List: contact issues-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Delivered-To: mailing list issues@hbase.apache.org Received: (qmail 6161 invoked by uid 99); 26 Apr 2013 03:56:17 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 26 Apr 2013 03:56:17 +0000 Date: Fri, 26 Apr 2013 03:56:17 +0000 (UTC) From: "Anoop Sam John (JIRA)" To: issues@hbase.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Commented] (HBASE-8282) User triggered flushes does not allow compaction to get triggered even if compaction criteria is met MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 [ https://issues.apache.org/jira/browse/HBASE-8282?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13642565#comment-13642565 ] Anoop Sam John commented on HBASE-8282: --------------------------------------- bq.HRegion.flushCache() sometimes returns false if really the flush did not proceed and sometimes returns false if there was no need for compaction That looks bad.. We can try fixing it (In another jira?) I agree with Lars that we should return whether flush is happened or not.. Internally the flush might triggered a compaction but might not be worth telling that back to the user. > 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_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