You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@hbase.apache.org by bu...@apache.org on 2019/11/16 15:43:54 UTC
[hbase] branch branch-2 updated: HBASE-19450 Addendum Limit logging
of chore execution time at INFO to once per 5 minutes.
This is an automated email from the ASF dual-hosted git repository.
busbey pushed a commit to branch branch-2
in repository https://gitbox.apache.org/repos/asf/hbase.git
The following commit(s) were added to refs/heads/branch-2 by this push:
new baf8849 HBASE-19450 Addendum Limit logging of chore execution time at INFO to once per 5 minutes.
baf8849 is described below
commit baf8849050d62f565f988a271035f67861e680df
Author: Sean Busbey <bu...@apache.org>
AuthorDate: Fri Nov 15 20:34:54 2019 -0600
HBASE-19450 Addendum Limit logging of chore execution time at INFO to once per 5 minutes.
* Ensure MovingAverage related classes are IA.Private
* Move trace logging into MovingAverage class
Signed-off-by: Duo Zhang <zh...@apache.org>
---
.../java/org/apache/hadoop/hbase/ScheduledChore.java | 18 ++++++++++--------
.../hadoop/hbase/util/ExponentialMovingAverage.java | 18 +++++++++---------
.../org/apache/hadoop/hbase/util/MovingAverage.java | 12 +++++++++---
.../apache/hadoop/hbase/util/SimpleMovingAverage.java | 5 +++--
.../org/apache/hadoop/hbase/util/TimeMeasurable.java | 2 +-
.../hadoop/hbase/util/WeightedMovingAverage.java | 10 +++++-----
.../apache/hadoop/hbase/util/WindowMovingAverage.java | 9 +++++----
.../apache/hadoop/hbase/util/TestMovingAverage.java | 13 +++++++++----
8 files changed, 51 insertions(+), 36 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 78458d4..b5197a0 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
@@ -81,7 +81,9 @@ public abstract class ScheduledChore implements Runnable {
*/
private final Stoppable stopper;
- private final MovingAverage<Void> timeMeasurement = new WindowMovingAverage();
+ private final MovingAverage<Void> timeMeasurement;
+ private static final long FIVE_MINUTES_IN_NANOS = TimeUnit.MINUTES.toNanos(5L);
+ private long lastLog = System.nanoTime();
interface ChoreServicer {
/**
@@ -122,11 +124,7 @@ public abstract class ScheduledChore implements Runnable {
@InterfaceAudience.Private
@VisibleForTesting
protected ScheduledChore() {
- this.name = null;
- this.stopper = null;
- this.period = 0;
- this.initialDelay = DEFAULT_INITIAL_DELAY;
- this.timeUnit = DEFAULT_TIME_UNIT;
+ this("TestChore", null, 0, DEFAULT_INITIAL_DELAY, DEFAULT_TIME_UNIT);
}
/**
@@ -167,6 +165,7 @@ public abstract class ScheduledChore implements Runnable {
this.period = period;
this.initialDelay = initialDelay < 0 ? 0 : initialDelay;
this.timeUnit = unit;
+ this.timeMeasurement = new WindowMovingAverage(name);
}
/**
@@ -191,8 +190,11 @@ public abstract class ScheduledChore implements Runnable {
chore();
return null;
});
- LOG.info(String.format("%s average execution time: %.2f ns.", getName(),
- timeMeasurement.getAverageTime()));
+ if (LOG.isInfoEnabled() && (System.nanoTime() - lastLog > FIVE_MINUTES_IN_NANOS)) {
+ LOG.info("{} average execution time: {} ns.", getName(),
+ (long)(timeMeasurement.getAverageTime()));
+ lastLog = System.nanoTime();
+ }
}
} catch (Throwable t) {
if (LOG.isErrorEnabled()) LOG.error("Caught error", t);
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/ExponentialMovingAverage.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/ExponentialMovingAverage.java
index ce0c1a3..d36ca7a 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/ExponentialMovingAverage.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/ExponentialMovingAverage.java
@@ -24,26 +24,26 @@ import org.apache.yetus.audience.InterfaceAudience;
* EMA is similar to {@link WeightedMovingAverage} in weighted, but the weighting factor decrease
* exponentially. It brings benefits that it is more sensitive, and can see the trends easily.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public class ExponentialMovingAverage extends WindowMovingAverage {
private double alpha;
private double previousAverage;
private double currentAverage;
- public ExponentialMovingAverage() {
- this(DEFAULT_SIZE);
+ public ExponentialMovingAverage(String label) {
+ this(label, DEFAULT_SIZE);
}
- public ExponentialMovingAverage(double alpha) {
- this(DEFAULT_SIZE, alpha);
+ public ExponentialMovingAverage(String label, double alpha) {
+ this(label, DEFAULT_SIZE, alpha);
}
- public ExponentialMovingAverage(int size) {
- this(size, (double) 2 / (1 + size));
+ public ExponentialMovingAverage(String label, int size) {
+ this(label, size, (double) 2 / (1 + size));
}
- public ExponentialMovingAverage(int size, double alpha) {
- super(size);
+ public ExponentialMovingAverage(String label, int size, double alpha) {
+ super(label, size);
this.previousAverage = -1.0;
this.currentAverage = 0.0;
this.alpha = alpha;
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/MovingAverage.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/MovingAverage.java
index 7687915..55a9766 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/MovingAverage.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/MovingAverage.java
@@ -29,10 +29,16 @@ import org.slf4j.LoggerFactory;
* <br>
* In different situation, different {@link MovingAverage} algorithm can be used based on needs.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public abstract class MovingAverage<T> {
private final static Logger LOG = LoggerFactory.getLogger(MovingAverage.class);
+ protected final String label;
+
+ protected MovingAverage(String label) {
+ this.label = label;
+ }
+
/**
* Mark start time of an execution.
* @return time in ns.
@@ -57,12 +63,12 @@ public abstract class MovingAverage<T> {
*/
public T measure(TimeMeasurable<T> measurable) {
long startTime = start();
- LOG.debug("Start to measure at: {} ns.", startTime);
+ LOG.trace("{} - start to measure at: {} ns.", label, startTime);
// Here may throw exceptions which should be taken care by caller, not here.
// If exception occurs, this time wouldn't count.
T result = measurable.measure();
long elapsed = stop(startTime);
- LOG.debug("Elapse: {} ns.", elapsed);
+ LOG.trace("{} - elapse: {} ns.", label, elapsed);
updateMostRecentTime(elapsed);
return result;
}
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/SimpleMovingAverage.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/SimpleMovingAverage.java
index 058c9f6..4e03a31 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/SimpleMovingAverage.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/SimpleMovingAverage.java
@@ -23,12 +23,13 @@ import org.apache.yetus.audience.InterfaceAudience;
/**
* SMA measure the overall average execution time of a specific method.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public class SimpleMovingAverage extends MovingAverage {
private double averageTime = 0.0;
protected long count = 0;
- public SimpleMovingAverage() {
+ public SimpleMovingAverage(String label) {
+ super(label);
this.averageTime = 0.0;
this.count = 0;
}
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/TimeMeasurable.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/TimeMeasurable.java
index 111093d..5dac959 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/TimeMeasurable.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/TimeMeasurable.java
@@ -24,7 +24,7 @@ import org.apache.yetus.audience.InterfaceAudience;
* Methods that implement this interface can be measured elapsed time.
* It works together with {@link MovingAverage} to take effect.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public interface TimeMeasurable<T> {
/**
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WeightedMovingAverage.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WeightedMovingAverage.java
index 33aa5698..1f43273 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WeightedMovingAverage.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WeightedMovingAverage.java
@@ -24,17 +24,17 @@ import org.apache.yetus.audience.InterfaceAudience;
* Different from SMA {@link SimpleMovingAverage}, WeightedMovingAverage gives each data different
* weight. And it is based on {@link WindowMovingAverage}, such that it only focus on the last N.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public class WeightedMovingAverage extends WindowMovingAverage {
private int[] coefficient;
private int denominator;
- public WeightedMovingAverage() {
- this(DEFAULT_SIZE);
+ public WeightedMovingAverage(String label) {
+ this(label, DEFAULT_SIZE);
}
- public WeightedMovingAverage(int size) {
- super(size);
+ public WeightedMovingAverage(String label, int size) {
+ super(label, size);
int length = getNumberOfStatistics();
denominator = length * (length + 1) / 2;
coefficient = new int[length];
diff --git a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WindowMovingAverage.java b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WindowMovingAverage.java
index fbfc73b..1ed950d 100644
--- a/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WindowMovingAverage.java
+++ b/hbase-common/src/main/java/org/apache/hadoop/hbase/util/WindowMovingAverage.java
@@ -24,7 +24,7 @@ import org.apache.yetus.audience.InterfaceAudience;
* Instead of calculate a whole time average, this class focus on the last N.
* The last N is stored in a circle array.
*/
-@InterfaceAudience.Public
+@InterfaceAudience.Private
public class WindowMovingAverage extends MovingAverage {
protected final static int DEFAULT_SIZE = 5;
@@ -35,11 +35,12 @@ public class WindowMovingAverage extends MovingAverage {
// If it travels a round.
protected boolean oneRound;
- public WindowMovingAverage() {
- this(DEFAULT_SIZE);
+ public WindowMovingAverage(String label) {
+ this(label, DEFAULT_SIZE);
}
- public WindowMovingAverage(int size) {
+ public WindowMovingAverage(String label, int size) {
+ super(label);
this.lastN = new long[size <= 0 ? DEFAULT_SIZE : size];
this.mostRecent = -1;
this.oneRound = false;
diff --git a/hbase-common/src/test/java/org/apache/hadoop/hbase/util/TestMovingAverage.java b/hbase-common/src/test/java/org/apache/hadoop/hbase/util/TestMovingAverage.java
index 990cacd..8852d5c7 100644
--- a/hbase-common/src/test/java/org/apache/hadoop/hbase/util/TestMovingAverage.java
+++ b/hbase-common/src/test/java/org/apache/hadoop/hbase/util/TestMovingAverage.java
@@ -22,8 +22,10 @@ import org.apache.hadoop.hbase.HBaseClassTestRule;
import org.apache.hadoop.hbase.testclassification.SmallTests;
import org.junit.Assert;
import org.junit.ClassRule;
+import org.junit.Rule;
import org.junit.Test;
import org.junit.experimental.categories.Category;
+import org.junit.rules.TestName;
@Category(SmallTests.class)
public class TestMovingAverage {
@@ -32,12 +34,15 @@ public class TestMovingAverage {
public static final HBaseClassTestRule CLASS_RULE =
HBaseClassTestRule.forClass(TestMovingAverage.class);
+ @Rule
+ public TestName name = new TestName();
+
private long[] data = {1, 12, 13, 24, 25, 26, 37, 38, 39, 40};
private double delta = 0.1;
@Test
public void testSimpleMovingAverage() throws Exception {
- MovingAverage<?> algorithm = new SimpleMovingAverage();
+ MovingAverage<?> algorithm = new SimpleMovingAverage(name.getMethodName());
int index = 0;
// [1, 12, 13, 24]
int bound = 4;
@@ -67,7 +72,7 @@ public class TestMovingAverage {
@Test
public void testWindowMovingAverage() throws Exception {
// Default size is 5.
- MovingAverage<?> algorithm = new WindowMovingAverage();
+ MovingAverage<?> algorithm = new WindowMovingAverage(name.getMethodName());
int index = 0;
// [1, 12, 13, 24]
int bound = 4;
@@ -97,7 +102,7 @@ public class TestMovingAverage {
@Test
public void testWeightedMovingAverage() throws Exception {
// Default size is 5.
- MovingAverage<?> algorithm = new WeightedMovingAverage();
+ MovingAverage<?> algorithm = new WeightedMovingAverage(name.getMethodName());
int index = 0;
// [1, 12, 13, 24]
int bound = 4;
@@ -127,7 +132,7 @@ public class TestMovingAverage {
@Test
public void testExponentialMovingAverage() throws Exception {
// [1, 12, 13, 24, 25, 26, 37, 38, 39, 40]
- MovingAverage<?> algorithm = new ExponentialMovingAverage();
+ MovingAverage<?> algorithm = new ExponentialMovingAverage(name.getMethodName());
int index = 0;
int bound = 5;
for (; index < bound; index++) {