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

Contributed by Rajesh Balamohan

Change-Id: Icc3dcfa81aa69164f2c088f9b533d231138cbb8b
This commit is contained in:
Rajesh Balamohan 2020-01-02 17:01:41 +00:00 committed by Steve Loughran
parent 1b04bcc0d9
commit b19d87c2b7
No known key found for this signature in database
GPG Key ID: D22CF846DBB162A0
2 changed files with 27 additions and 6 deletions

View File

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

View File

@ -35,6 +35,14 @@ public void testDurationInfoCreation() throws Exception {
Thread.sleep(1000); Thread.sleep(1000);
info.finished(); info.finished();
Assert.assertTrue(info.value() > 0); 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 @Test