diff options
Diffstat (limited to 'src/main/java/com/google/devtools/build/lib/profiler')
-rw-r--r-- | src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java | 79 |
1 files changed, 62 insertions, 17 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java b/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java index 33977ea58e..bec813a5ce 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/AutoProfiler.java @@ -22,6 +22,8 @@ import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicReference; import java.util.logging.Logger; +import javax.annotation.Nullable; + /** * A convenient way to actively get access to timing information (e.g. for logging and/or * profiling purposes) with minimal boilerplate. The lack of boilerplate comes at a performance @@ -104,7 +106,8 @@ public class AutoProfiler implements AutoCloseable { * {@link #logged} et al. */ public interface LoggingElapsedTimeReceiverFactory { - ElapsedTimeReceiver create(String taskDescription, Logger logger, TimeUnit timeUnit); + ElapsedTimeReceiver create( + String taskDescription, Logger logger, long minTimeForLogging, TimeUnit timeUnit); } /** @@ -128,14 +131,31 @@ public class AutoProfiler implements AutoCloseable { } /** - * Returns an {@link AutoProfiler} that, when closed, logs the elapsed time the given + * Returns an {@link AutoProfiler} that, when closed, logs the elapsed time in the given * {@link TimeUnit} to the given {@link Logger}. * * <p>The returned {@link AutoProfiler} is thread-safe. */ public static AutoProfiler logged(String taskDescription, Logger logger, TimeUnit timeUnit) { - return create(LOGGING_ELAPSED_TIME_RECEIVER_FACTORY_REF.get().create( - taskDescription, logger, timeUnit)); + return create( + LOGGING_ELAPSED_TIME_RECEIVER_FACTORY_REF + .get() + .create(taskDescription, logger, 0L, timeUnit)); + } + + /** + * Returns an {@link AutoProfiler} that, when closed, logs the elapsed time in milliseconds to the + * given {@link Logger} if it is greater than {@code minTimeForLoggingInMilliseconds}. + * + * <p>The returned {@link AutoProfiler} is thread-safe. + */ + public static AutoProfiler logged( + String taskDescription, Logger logger, long minTimeForLoggingInMilliseconds) { + return create( + LOGGING_ELAPSED_TIME_RECEIVER_FACTORY_REF + .get() + .create( + taskDescription, logger, minTimeForLoggingInMilliseconds, TimeUnit.MILLISECONDS)); } /** @@ -158,8 +178,10 @@ public class AutoProfiler implements AutoCloseable { ProfilerTask profilerTaskType, Logger logger) { ElapsedTimeReceiver profilingReceiver = new ProfilingElapsedTimeReceiver(taskDescription, profilerTaskType); - ElapsedTimeReceiver loggingReceiver = LOGGING_ELAPSED_TIME_RECEIVER_FACTORY_REF.get().create( - taskDescription, logger, TimeUnit.MILLISECONDS); + ElapsedTimeReceiver loggingReceiver = + LOGGING_ELAPSED_TIME_RECEIVER_FACTORY_REF + .get() + .create(taskDescription, logger, 0L, TimeUnit.MILLISECONDS); return create(new SequencedElapsedTimeReceiver(profilingReceiver, loggingReceiver)); } @@ -241,33 +263,56 @@ public class AutoProfiler implements AutoCloseable { } } - private static class LoggingElapsedTimeReceiver implements ElapsedTimeReceiver { + /** + * {@link ElapsedTimeReceiver} that logs a message in {@link #accept} if the elapsed time is at + * least a given threshold. + */ + public static class LoggingElapsedTimeReceiver implements ElapsedTimeReceiver { private static final LoggingElapsedTimeReceiverFactory FACTORY = new LoggingElapsedTimeReceiverFactory() { @Override - public ElapsedTimeReceiver create(String taskDescription, Logger logger, - TimeUnit timeUnit) { - return new LoggingElapsedTimeReceiver(taskDescription, logger, timeUnit); + public ElapsedTimeReceiver create( + String taskDescription, Logger logger, long minTimeForLogging, TimeUnit timeUnit) { + return new LoggingElapsedTimeReceiver( + taskDescription, logger, minTimeForLogging, timeUnit); } }; private final String taskDescription; - private final Logger logger; + protected final Logger logger; private final TimeUnit timeUnit; + private final long minNanosForLogging; - private LoggingElapsedTimeReceiver(String taskDescription, Logger logger, TimeUnit timeUnit) { + protected LoggingElapsedTimeReceiver( + String taskDescription, Logger logger, long minTimeForLogging, TimeUnit timeUnit) { this.taskDescription = taskDescription; this.logger = logger; this.timeUnit = timeUnit; + this.minNanosForLogging = timeUnit.toNanos(minTimeForLogging); } - @Override - public void accept(long elapsedTimeNanos) { - if (elapsedTimeNanos > 0) { - logger.info(String.format("Spent %d %s doing %s", + /** + * Returns a message about the amount of time spent doing a task if {@code elapsedTimeNanos} is + * at least {@link #minNanosForLogging} and null otherwise. + */ + @Nullable + protected String loggingMessage(long elapsedTimeNanos) { + if (elapsedTimeNanos >= minNanosForLogging) { + return String.format( + "Spent %d %s doing %s", timeUnit.convert(elapsedTimeNanos, TimeUnit.NANOSECONDS), timeUnit.toString().toLowerCase(), - taskDescription)); + taskDescription); + } else { + return null; + } + } + + @Override + public void accept(long elapsedTimeNanos) { + String logMessage = loggingMessage(elapsedTimeNanos); + if (logMessage != null) { + logger.info(logMessage); } } } |