HADOOP-16751: DurationInfo text parsing/formatting should be moved out of hotpath

hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/util/DurationInfo.java

@@ -23,6 +23,8 @@
 import org.apache.hadoop.classification.InterfaceAudience.Public;
 import org.apache.hadoop.classification.InterfaceStability.Unstable;
 
+import java.util.function.Supplier;
+
 /**
  * A duration with logging of final state at info or debug
  * in the {@code close()} call.
@@ -33,7 +35,10 @@
 @Unstable
 public class DurationInfo extends OperationDuration
     implements AutoCloseable {
-  private final String text;
+
+  private final Supplier<String> text;
+
+  private String textStr;
 
   private final Logger log;
 
@@ -65,19 +70,25 @@ public DurationInfo(Logger log,
       boolean logAtInfo,
       String format,
       Object... args) {
-    this.text = String.format(format, args);
+    this.text = () -> String.format(format, args);
     this.log = log;
     this.logAtInfo = logAtInfo;
     if (logAtInfo) {
-      log.info("Starting: {}", text);
+      log.info("Starting: {}", getFormattedText());
     } else {
-      log.debug("Starting: {}", text);
+      if (log.isDebugEnabled()) {
+        log.debug("Starting: {}", getFormattedText());
+      }
     }
   }
 
+  private String getFormattedText() {
+    return (textStr == null) ? (textStr = text.get()) : textStr;
+  }
+
   @Override
   public String toString() {
-    return text + ": duration " + super.toString();
+    return getFormattedText() + ": duration " + super.toString();
   }
 
   @Override
@@ -86,7 +97,9 @@ public void close() {
     if (logAtInfo) {
       log.info("{}", this);
     } else {
-      log.debug("{}", this);
+      if (log.isDebugEnabled()) {
+        log.debug("{}", this);
+      }
     }
   }
 }

hadoop-common-project/hadoop-common/src/test/java/org/apache/hadoop/util/TestDurationInfo.java

@@ -35,6 +35,14 @@ public void testDurationInfoCreation() throws Exception {
     Thread.sleep(1000);
     info.finished();
     Assert.assertTrue(info.value() > 0);
+
+    info = new DurationInfo(log, true, "test format %s", "value");
+    Assert.assertEquals("test format value: duration 0:00.000s",
+        info.toString());
+
+    info = new DurationInfo(log, false, "test format %s", "value");
+    Assert.assertEquals("test format value: duration 0:00.000s",
+        info.toString());
   }
 
   @Test