[GitHub] [hbase] infraio commented on a change in pull request #1749: HBASE-24367 ScheduledChore log elapsed timespan in a human-friendly format

[GitBox <gi...@apache.org>]

infraio commented on a change in pull request #1749:
URL: https://github.com/apache/hbase/pull/1749#discussion_r428390337



##########
File path: hbase-common/src/main/java/org/apache/hadoop/hbase/ScheduledChore.java
##########
@@ -183,18 +176,21 @@ public void run() {
       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();
-          }
+        }
+        if (LOG.isDebugEnabled()) {
+          long end = System.nanoTime();
+          LOG.debug("{} execution time: {} ms.", getName(),

Review comment:
       log the start time, too? If the debug was enabled between execution, may get a wrong execution time?




----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org