diff --git a/check_api/src/main/java/com/google/errorprone/ErrorProneAnalyzer.java b/check_api/src/main/java/com/google/errorprone/ErrorProneAnalyzer.java index 45d073e88dc..5f04125efe0 100644 --- a/check_api/src/main/java/com/google/errorprone/ErrorProneAnalyzer.java +++ b/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 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 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; } diff --git a/check_api/src/main/java/com/google/errorprone/ErrorProneOptions.java b/check_api/src/main/java/com/google/errorprone/ErrorProneOptions.java index 4acb43b6084..6812439da6a 100644 --- a/check_api/src/main/java/com/google/errorprone/ErrorProneOptions.java +++ b/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 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 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 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 remainingArgs) { patchingOptionsBuilder.build(), excludedPattern, ignoreSuppressionAnnotations, - ignoreLargeCodeGenerators); + ignoreLargeCodeGenerators, + printTimings); } void setExcludedPattern(Pattern excludedPattern) { @@ -478,6 +497,7 @@ public static ErrorProneOptions processArgs(Iterable 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); diff --git a/check_api/src/main/java/com/google/errorprone/VisitorState.java b/check_api/src/main/java/com/google/errorprone/VisitorState.java index 76f799e0c2d..924755e7cf8 100644 --- a/check_api/src/main/java/com/google/errorprone/VisitorState.java +++ b/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); diff --git a/check_api/src/test/java/com/google/errorprone/ErrorProneOptionsTest.java b/check_api/src/test/java/com/google/errorprone/ErrorProneOptionsTest.java index bc0e917b2b6..2b562b640de 100644 --- a/check_api/src/test/java/com/google/errorprone/ErrorProneOptionsTest.java +++ b/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 = diff --git a/core/src/test/java/com/google/errorprone/ErrorProneJavaCompilerTest.java b/core/src/test/java/com/google/errorprone/ErrorProneJavaCompilerTest.java index d27a8ab7ba4..c64d93939ba 100644 --- a/core/src/test/java/com/google/errorprone/ErrorProneJavaCompilerTest.java +++ b/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.>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.emptyList(), + Collections.>emptyList()); + assertThat(result.output).doesNotContain("Error Prone ran"); + } + @Test public void fileWithErrorIntegrationTest() { CompilationResult result =