Return-Path: X-Original-To: apmail-hbase-commits-archive@www.apache.org Delivered-To: apmail-hbase-commits-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id 34D9F17614 for ; Sat, 8 Nov 2014 05:54:05 +0000 (UTC) Received: (qmail 88558 invoked by uid 500); 8 Nov 2014 05:54:04 -0000 Delivered-To: apmail-hbase-commits-archive@hbase.apache.org Received: (qmail 88498 invoked by uid 500); 8 Nov 2014 05:54:04 -0000 Mailing-List: contact commits-help@hbase.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@hbase.apache.org Delivered-To: mailing list commits@hbase.apache.org Received: (qmail 88479 invoked by uid 99); 8 Nov 2014 05:54:04 -0000 Received: from tyr.zones.apache.org (HELO tyr.zones.apache.org) (140.211.11.114) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 08 Nov 2014 05:54:04 +0000 Received: by tyr.zones.apache.org (Postfix, from userid 65534) id 85A40814115; Sat, 8 Nov 2014 05:54:04 +0000 (UTC) Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit From: apurtell@apache.org To: commits@hbase.apache.org Date: Sat, 08 Nov 2014 05:54:04 -0000 Message-Id: X-Mailer: ASF-Git Admin Mailer Subject: [1/3] hbase git commit: HBASE-12448 Fix rate reporting in compaction progress DEBUG logging Repository: hbase Updated Branches: refs/heads/0.98 2a12bac89 -> ab3b26c03 refs/heads/branch-1 0145650cb -> b1f7d7cd3 refs/heads/master 3b8c0769c -> 7657090ad HBASE-12448 Fix rate reporting in compaction progress DEBUG logging Project: http://git-wip-us.apache.org/repos/asf/hbase/repo Commit: http://git-wip-us.apache.org/repos/asf/hbase/commit/7657090a Tree: http://git-wip-us.apache.org/repos/asf/hbase/tree/7657090a Diff: http://git-wip-us.apache.org/repos/asf/hbase/diff/7657090a Branch: refs/heads/master Commit: 7657090ad9ab1243041b9bc344a6a44a252f4239 Parents: 3b8c076 Author: Andrew Purtell Authored: Fri Nov 7 18:36:43 2014 -0800 Committer: Andrew Purtell Committed: Fri Nov 7 18:36:43 2014 -0800 ---------------------------------------------------------------------- .../regionserver/compactions/Compactor.java | 45 +++++++++++--------- 1 file changed, 26 insertions(+), 19 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/hbase/blob/7657090a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/compactions/Compactor.java ---------------------------------------------------------------------- diff --git a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/compactions/Compactor.java b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/compactions/Compactor.java index 6b07d73..2ddc06a 100644 --- a/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/compactions/Compactor.java +++ b/hbase-server/src/main/java/org/apache/hadoop/hbase/regionserver/compactions/Compactor.java @@ -43,6 +43,7 @@ import org.apache.hadoop.hbase.regionserver.StoreFile; import org.apache.hadoop.hbase.regionserver.StoreFileScanner; import org.apache.hadoop.hbase.regionserver.StoreScanner; import org.apache.hadoop.hbase.util.Bytes; +import org.apache.hadoop.hbase.util.EnvironmentEdgeManager; import org.apache.hadoop.util.StringUtils; /** @@ -228,43 +229,39 @@ public abstract class Compactor { */ protected boolean performCompaction(InternalScanner scanner, CellSink writer, long smallestReadPoint, boolean cleanSeqId) throws IOException { - int bytesWritten = 0; + long bytesWritten = 0; + long bytesWrittenProgress = 0; // Since scanner.next() can return 'false' but still be delivering data, // we have to use a do/while loop. List cells = new ArrayList(); - int closeCheckInterval = HStore.getCloseCheckInterval(); - long lastMillis; + long closeCheckInterval = HStore.getCloseCheckInterval(); + long lastMillis = 0; if (LOG.isDebugEnabled()) { - lastMillis = System.currentTimeMillis(); - } else { - lastMillis = 0; + lastMillis = EnvironmentEdgeManager.currentTime(); } + long now = 0; boolean hasMore; do { hasMore = scanner.next(cells, compactionKVMax); + if (LOG.isDebugEnabled()) { + now = EnvironmentEdgeManager.currentTime(); + } // output to writer: for (Cell c : cells) { if (cleanSeqId && c.getSequenceId() <= smallestReadPoint) { CellUtil.setSequenceId(c, 0); } writer.append(c); + int len = KeyValueUtil.length(c); ++progress.currentCompactedKVs; - progress.totalCompactedSize += KeyValueUtil.length(c); - + progress.totalCompactedSize += len; + if (LOG.isDebugEnabled()) { + bytesWrittenProgress += len; + } // check periodically to see if a system stop is requested if (closeCheckInterval > 0) { - bytesWritten += KeyValueUtil.length(c); + bytesWritten += len; if (bytesWritten > closeCheckInterval) { - // Log the progress of long running compactions every minute if - // logging at DEBUG level - if (LOG.isDebugEnabled()) { - long now = System.currentTimeMillis(); - if ((now - lastMillis) >= 60 * 1000) { - LOG.debug("Compaction progress: " + progress + String.format(", rate=%.2f kB/sec", - (bytesWritten / 1024.0) / ((now - lastMillis) / 1000.0))); - lastMillis = now; - } - } bytesWritten = 0; if (!store.areWritesEnabled()) { progress.cancel(); @@ -273,6 +270,16 @@ public abstract class Compactor { } } } + // Log the progress of long running compactions every minute if + // logging at DEBUG level + if (LOG.isDebugEnabled()) { + if ((now - lastMillis) >= 60 * 1000) { + LOG.debug("Compaction progress: " + progress + String.format(", rate=%.2f kB/sec", + (bytesWrittenProgress / 1024.0) / ((now - lastMillis) / 1000.0))); + lastMillis = now; + bytesWrittenProgress = 0; + } + } cells.clear(); } while (hasMore); progress.complete();