Record check timings only when -XepPrintTimings asks for them

check_api/src/main/java/com/google/errorprone/ErrorProneAnalyzer.java

@@ -19,9 +19,11 @@
 import static com.google.common.base.Preconditions.checkNotNull;
 import static com.google.common.base.Throwables.getStackTraceAsString;
 import static com.google.common.base.Verify.verify;
+import static java.util.Comparator.comparing;
 
 import com.google.common.base.Supplier;
 import com.google.common.base.Suppliers;
+import com.google.common.collect.ImmutableMap;
 import com.google.common.collect.ImmutableSet;
 import com.google.errorprone.BugPattern.SeverityLevel;
 import com.google.errorprone.ErrorProneOptions.Severity;
@@ -45,7 +47,10 @@
 import com.sun.tools.javac.util.Log.WriterKind;
 import com.sun.tools.javac.util.PropagatedException;
 import java.io.PrintWriter;
+import java.time.Duration;
 import java.util.HashSet;
+import java.util.Locale;
+import java.util.Map;
 import java.util.Set;
 import javax.tools.JavaFileObject;
 import org.safere.Pattern;
@@ -190,8 +195,39 @@ private ErrorProneAnalyzer(
 
   private int errorProneErrors = 0;
 
+  /** Prints how long each check ran, slowest first. */
+  private void printTimings() {
+    ErrorProneTimings timings = ErrorProneTimings.instance(context);
+    ImmutableMap<String, Duration> checks = timings.timings();
+    Duration total = checks.values().stream().reduce(Duration.ZERO, Duration::plus);
+    PrintWriter out = Log.instance(context).getWriter(WriterKind.NOTICE);
+    out.printf(
+        Locale.ROOT,
+        "Error Prone ran %d checks in %d ms, and spent %d ms initializing%n",
+        checks.size(),
+        total.toMillis(),
+        timings.initializationTime().toMillis());
+    checks.entrySet().stream()
+        .sorted(comparing((Map.Entry<String, Duration> e) -> e.getValue()).reversed())
+        .forEach(
+            e ->
+                out.printf(
+                    Locale.ROOT,
+                    "  %8d ms  %5.1f%%  %s%n",
+                    e.getValue().toMillis(),
+                    total.isZero() ? 0.0 : 100.0 * e.getValue().toNanos() / total.toNanos(),
+                    e.getKey()));
+    out.flush();
+  }
+
   @Override
   public void finished(TaskEvent taskEvent) {
+    if (taskEvent.getKind() == Kind.COMPILATION) {
+      if (errorProneOptions.printTimings()) {
+        printTimings();
+      }
+      return;
+    }
     if (taskEvent.getKind() != Kind.ANALYZE) {
       return;
     }

check_api/src/main/java/com/google/errorprone/ErrorProneOptions.java

@@ -69,6 +69,7 @@ public final class ErrorProneOptions {
       "-XepDisableWarningsInGeneratedCode";
   private static final String COMPILING_TEST_ONLY_CODE = "-XepCompilingTestOnlyCode";
   private static final String COMPILING_PUBLICLY_VISIBLE_CODE = "-XepCompilingPubliclyVisibleCode";
+  private static final String PRINT_TIMINGS = "-XepPrintTimings";
   private static final String ARGUMENT_FILE_PREFIX = "@";
 
   /** see {@link javax.tools.OptionChecker#isSupportedOption(String)} */
@@ -88,6 +89,7 @@ public static int isSupportedOption(String option) {
             || option.equals(IGNORE_SUPPRESSION_ANNOTATIONS)
             || option.equals(COMPILING_TEST_ONLY_CODE)
             || option.equals(COMPILING_PUBLICLY_VISIBLE_CODE)
+            || option.equals(PRINT_TIMINGS)
             || option.equals(DISABLE_ALL_WARNINGS);
     return isSupported ? 0 : -1;
   }
@@ -161,6 +163,7 @@ abstract static class Builder {
   private final Pattern excludedPattern;
   private final boolean ignoreSuppressionAnnotations;
   private final boolean ignoreLargeCodeGenerators;
+  private final boolean printTimings;
 
   private ErrorProneOptions(
       ImmutableMap<String, Severity> severityMap,
@@ -178,7 +181,8 @@ private ErrorProneOptions(
       PatchingOptions patchingOptions,
       Pattern excludedPattern,
       boolean ignoreSuppressionAnnotations,
-      boolean ignoreLargeCodeGenerators) {
+      boolean ignoreLargeCodeGenerators,
+      boolean printTimings) {
     this.severityMap = severityMap;
     this.remainingArgs = remainingArgs;
     this.ignoreUnknownChecks = ignoreUnknownChecks;
@@ -195,6 +199,7 @@ private ErrorProneOptions(
     this.excludedPattern = excludedPattern;
     this.ignoreSuppressionAnnotations = ignoreSuppressionAnnotations;
     this.ignoreLargeCodeGenerators = ignoreLargeCodeGenerators;
+    this.printTimings = printTimings;
   }
 
   public ImmutableList<String> getRemainingArgs() {
@@ -241,6 +246,14 @@ public boolean ignoreLargeCodeGenerators() {
     return ignoreLargeCodeGenerators;
   }
 
+  /**
+   * Returns true if Error Prone records how long each check runs, and prints the totals once the
+   * compilation finishes.
+   */
+  public boolean printTimings() {
+    return printTimings;
+  }
+
   public ErrorProneFlags getFlags() {
     return flags;
   }
@@ -265,6 +278,7 @@ private static class Builder {
     private boolean isPubliclyVisibleTarget = false;
     private boolean ignoreSuppressionAnnotations = false;
     private boolean ignoreLargeCodeGenerators = true;
+    private boolean printTimings = false;
     private final Map<String, Severity> severityMap = new LinkedHashMap<>();
     private final ErrorProneFlags.Builder flagsBuilder = ErrorProneFlags.builder();
     private final PatchingOptions.Builder patchingOptionsBuilder = PatchingOptions.builder();
@@ -339,6 +353,10 @@ void setIgnoreLargeCodeGenerators(boolean ignoreLargeCodeGenerators) {
       this.ignoreLargeCodeGenerators = ignoreLargeCodeGenerators;
     }
 
+    void setPrintTimings(boolean printTimings) {
+      this.printTimings = printTimings;
+    }
+
     void setDisableAllChecks(boolean disableAllChecks) {
       // Discard previously set severities so that the DisableAllChecks flag is position sensitive.
       severityMap.clear();
@@ -374,7 +392,8 @@ ErrorProneOptions build(ImmutableList<String> remainingArgs) {
           patchingOptionsBuilder.build(),
           excludedPattern,
           ignoreSuppressionAnnotations,
-          ignoreLargeCodeGenerators);
+          ignoreLargeCodeGenerators,
+          printTimings);
     }
 
     void setExcludedPattern(Pattern excludedPattern) {
@@ -478,6 +497,7 @@ public static ErrorProneOptions processArgs(Iterable<String> args) {
         case COMPILING_TEST_ONLY_CODE -> builder.setTestOnlyTarget(true);
         case COMPILING_PUBLICLY_VISIBLE_CODE -> builder.setPubliclyVisibleTarget(true);
         case DISABLE_ALL_WARNINGS -> builder.setDisableAllWarnings(true);
+        case PRINT_TIMINGS -> builder.setPrintTimings(true);
         default -> {
           if (arg.startsWith(SEVERITY_PREFIX)) {
             builder.parseSeverity(arg);

check_api/src/main/java/com/google/errorprone/VisitorState.java

@@ -601,8 +601,16 @@ public boolean isAndroidCompatible() {
     return Options.instance(context).getBoolean("androidCompatible");
   }
 
-  /** Returns a timing span for the given {@link Suppressible}. */
+  private static final AutoCloseable NO_TIMING_SPAN = () -> {};
+
+  /**
+   * Returns a timing span for the given {@link Suppressible}, or a span that records nothing unless
+   * {@link ErrorProneOptions#printTimings} asked for the timings.
+   */
   public AutoCloseable timingSpan(Suppressible suppressible) {
+    if (!sharedState.recordTimings) {
+      return NO_TIMING_SPAN;
+    }
     return sharedState.timings.span(suppressible);
   }
 
@@ -675,6 +683,7 @@ private static final class SharedState {
     private final Names names;
     private final Symtab symtab;
     private final ErrorProneTimings timings;
+    private final boolean recordTimings;
     private final Types types;
     private final TreeMaker treeMaker;
     private final JavacInvocationInstance javacInvocationInstance;
@@ -699,6 +708,7 @@ private static final class SharedState {
       this.names = Names.instance(context);
       this.symtab = Symtab.instance(context);
       this.timings = ErrorProneTimings.instance(context);
+      this.recordTimings = errorProneOptions.printTimings();
       this.types = Types.instance(context);
       this.treeMaker = TreeMaker.instance(context);
       this.javacInvocationInstance = JavacInvocationInstance.instance(context);

check_api/src/test/java/com/google/errorprone/ErrorProneOptionsTest.java

@@ -170,6 +170,18 @@ public void recognizesDisableAllChecks() {
     assertThat(options.isDisableAllChecks()).isTrue();
   }
 
+  @Test
+  public void recognizesPrintTimings() {
+    ErrorProneOptions options = ErrorProneOptions.processArgs(new String[] {"-XepPrintTimings"});
+    assertThat(options.printTimings()).isTrue();
+    assertThat(ErrorProneOptions.isSupportedOption("-XepPrintTimings")).isEqualTo(0);
+  }
+
+  @Test
+  public void printTimingsIsOffByDefault() {
+    assertThat(ErrorProneOptions.processArgs(new String[] {}).printTimings()).isFalse();
+  }
+
   @Test
   public void recognizesCompilingTestOnlyCode() {
     ErrorProneOptions options =

core/src/test/java/com/google/errorprone/ErrorProneJavaCompilerTest.java

@@ -130,6 +130,28 @@ public void sourceVersion() {
     assertThat(compiler.getSourceVersions()).doesNotContain(SourceVersion.RELEASE_5);
   }
 
+  @Test
+  public void printTimingsReportsEveryCheckThatRan() {
+    CompilationResult result =
+        doCompile(
+            Arrays.asList("bugpatterns/testdata/SelfAssignmentPositiveCases1.java"),
+            Arrays.asList("-XepPrintTimings"),
+            Collections.<Class<? extends BugChecker>>emptyList());
+    // A header alone would pass with nothing recorded, because it is printed before the rows.
+    assertThat(result.output).containsMatch("Error Prone ran [1-9]\\d* checks");
+    assertThat(result.output).containsMatch("\\d+ ms\\s+[\\d.]+%");
+  }
+
+  @Test
+  public void withoutPrintTimingsNoReportIsPrinted() {
+    CompilationResult result =
+        doCompile(
+            Arrays.asList("bugpatterns/testdata/SelfAssignmentPositiveCases1.java"),
+            Collections.<String>emptyList(),
+            Collections.<Class<? extends BugChecker>>emptyList());
+    assertThat(result.output).doesNotContain("Error Prone ran");
+  }
+
   @Test
   public void fileWithErrorIntegrationTest() {
     CompilationResult result =