You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hbase.apache.org by ap...@apache.org on 2020/06/09 17:00:32 UTC
[hbase] branch branch-2.3 updated: HBASE-24367 ScheduledChore log
elapsed timespan in a human-friendly format (#1749)
This is an automated email from the ASF dual-hosted git repository.
apurtell pushed a commit to branch branch-2.3
in repository https://gitbox.apache.org/repos/asf/hbase.git
The following commit(s) were added to refs/heads/branch-2.3 by this push:
new da7102e HBASE-24367 ScheduledChore log elapsed timespan in a human-friendly format (#1749)
da7102e is described below
commit da7102e6ce15f479c62bfd7b91a8082908f53324
Author: Andrew Purtell <ap...@apache.org>
AuthorDate: Tue Jun 9 09:55:20 2020 -0700
HBASE-24367 ScheduledChore log elapsed timespan in a human-friendly format (#1749)
Signed-off-by: Nick Dimiduk <nd...@apache.org>
Signed-off-by: Guanghao Zhang <zg...@apache.org>
Signed-off-by: Viraj Jasani <vj...@apache.org>
---
.../org/apache/hadoop/hbase/ScheduledChore.java | 28 ++++++++++------------
1 file changed, 12 insertions(+), 16 deletions(-)
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/ScheduledChore.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/ScheduledChore.java
index 86dcb2c..28af186 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/ScheduledChore.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/ScheduledChore.java
@@ -21,8 +21,6 @@ package org.apache.hadoop.hbase;
import java.util.concurrent.ScheduledThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
-import org.apache.hadoop.hbase.util.MovingAverage;
-import org.apache.hadoop.hbase.util.WindowMovingAverage;
import org.apache.yetus.audience.InterfaceAudience;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@@ -81,10 +79,6 @@ public abstract class ScheduledChore implements Runnable {
*/
private final Stoppable stopper;
- private final MovingAverage<Void> timeMeasurement;
- private static final long FIVE_MINUTES_IN_NANOS = TimeUnit.MINUTES.toNanos(5L);
- private long lastLog = System.nanoTime();
-
interface ChoreServicer {
/**
* Cancel any ongoing schedules that this chore has with the implementer of this interface.
@@ -165,7 +159,6 @@ public abstract class ScheduledChore implements Runnable {
this.period = period;
this.initialDelay = initialDelay < 0 ? 0 : initialDelay;
this.timeUnit = unit;
- this.timeMeasurement = new WindowMovingAverage(name);
}
/**
@@ -183,18 +176,21 @@ public abstract class ScheduledChore implements Runnable {
if (LOG.isInfoEnabled()) LOG.info("Chore: " + getName() + " was stopped");
} else {
try {
+ // TODO: Histogram metrics per chore name.
+ // For now, just measure and log if DEBUG level logging is enabled.
+ long start = 0;
+ if (LOG.isDebugEnabled()) {
+ start = System.nanoTime();
+ }
if (!initialChoreComplete) {
initialChoreComplete = initialChore();
} else {
- timeMeasurement.measure(() -> {
- chore();
- return null;
- });
- if (LOG.isInfoEnabled() && (System.nanoTime() - lastLog > FIVE_MINUTES_IN_NANOS)) {
- LOG.info("{} average execution time: {} ns.", getName(),
- (long)(timeMeasurement.getAverageTime()));
- lastLog = System.nanoTime();
- }
+ chore();
+ }
+ if (LOG.isDebugEnabled() && start > 0) {
+ long end = System.nanoTime();
+ LOG.debug("{} execution time: {} ms.", getName(),
+ TimeUnit.NANOSECONDS.toMillis(end - start));
}
} catch (Throwable t) {
if (LOG.isErrorEnabled()) LOG.error("Caught error", t);