Per-check timing spans cost a few percent of the compile, and nothing reads the timings

`ErrorProneScanner.processMatchers` opens a timing span for every matcher it runs on every AST node:

```java
try (AutoCloseable unused = oldState.timingSpan(matcher)) {
```

`VisitorState.timingSpan` forwards to `ErrorProneTimings.span`, which looks the check up by canonical name, starts a `Stopwatch`, and returns a closure that stops it. Every span is therefore a `HashMap` lookup, two `System.nanoTime` calls, and a closure.

Nothing in this repository reads what the timers record: `ErrorProneTimings.timings()` and `initializationTime()` have no callers in `error_prone_check_api` or `error_prone_core`, and no test asserts on either. I assume there is an internal consumer, since the class arrived in cl/245821511 for that purpose, but every build that uses the released artifact pays for data it has no way to read.

`span` has one caller, so it is not that some spans are coarse and useful while others are fine-grained: all of them wrap one matcher on one node.

## Cost

Two workloads, both compiled in process so that the numbers are the compiling thread's own, on macOS on Apple silicon.

**`error_prone_core` itself**, 948 sources, JDK 24, default check set. One compilation opens 14771508 spans, so it makes 29543016 `System.nanoTime` calls. Comparing that build against one whose `span` returns a shared no-op, alternating the two inside a single JVM so each pair meets the same machine state, the spans cost a median of **656 ms against a floor of 13.0 s**, positive in 8 pairs out of 8.

**Calcite's `:core`**, 1655 sources, JDK 21, with NullAway and the project's own check selection. One compilation opens 28493608 spans. The spans cost a median of **1216 ms against a floor of 37 s**, positive in 4 pairs out of 4, and — unlike the first workload — **0.42 GiB of allocation**:

| | allocated by the compiling thread |
| --- | --- |
| spans on | 21.03 GiB |
| spans off | 20.61 GiB |

The closure is what accounts for that. It does not show up on `error_prone_core`, where C2 inlines `span` into `processMatchers` and scalar-replaces the closure; it does show up on Calcite, whose larger check set defeats that inlining. So whether the allocation is real depends on the JIT, and a project cannot tell which case it is in.

## What the spans measure

Recording each span's duration alongside the per-check totals, on `error_prone_core`:

| span duration | share of spans | share of measured time |
| --- | --- | --- |
| under 128 ns | 45.1% | 2.9% |
| under 512 ns | 78.2% | 11.4% |
| under 2 us | 95.2% | 27.3% |

4.6% of spans come back as 0 ns, which the clock cannot resolve. Grouping the same run by each check's mean cost per call, over the 499 checks that ran:

| mean cost per call | checks | share of spans | share of measured time |
| --- | --- | --- | --- |
| under 100 ns | 53 | 22.8% | 2.5% |
| 100 ns to 300 ns | 141 | 41.9% | 10.2% |
| 300 ns to 1 us | 137 | 21.8% | 16.7% |
| 1 us to 10 us | 121 | 13.1% | 35.3% |
| 10 us to 100 us | 38 | 0.40% | 20.0% |
| over 100 us | 9 | 0.04% | 15.4% |

The two cheapest rows are 64.7% of the spans and 12.7% of the time. A pair of `nanoTime` calls measures 24 ns to 27 ns on this machine, and the checks in the first row average 38 ns to 73 ns per call, so measuring them costs about as much as they do: `MislabeledAndroidString` runs 141571 times for 8 ms of work, and the clock reads that measure it come to about 5 ms.

The checks a report is read for sit at the other end, and they are rare. On `error_prone_core` every one of the top entries by total time runs 948 times, once per compilation unit: `AlreadyChecked` at 408 ms, `NotJavadoc` at 339 ms, `AlmostJavadoc` at 244 ms — each 0.01% of the spans.

## What I would propose

**Gate the spans on a flag, and make that flag print the report.** A build that does not ask for timings then opens no span, and a build that does gets the numbers rather than collecting them for a consumer it does not have. I have this working as `-XepPrintTimings`, printing from `finished(TaskEvent.Kind.COMPILATION)`:

```text
Error Prone ran 457 checks in 34585 ms, and spent 326 ms initializing
8567 ms 24.8% 859655 calls max 175288458 ns NullAway
1222 ms 3.5% 101964 calls max 67279500 ns ParameterName
1179 ms 3.4% 21416 calls max 15422250 ns MissingFail
```

That is Calcite's `:core`. The call count and the longest single invocation are there because a total alone misleads: a one-off cost — the first lookup of a type the classpath does not have, say — lands on whichever check triggered it. `InjectOnBugCheckers` reads 7 ms over 21416 calls with a maximum in the tens of microseconds, and one run charged it 307 ms; the maximum is what tells those two cases apart.

**Then make the collection cheap enough that asking for it is not a decision.** How many spans a check opens is already known statically — it is the number of nodes of the kind its `*TreeMatcher` interfaces select — while what a span costs is not. That split suggests keeping the count and sampling the clock: a per-check counter, a clock read on one invocation in N, and a total scaled by the counter. Timing a check on every invocation while its mean stays above roughly a microsecond keeps the checks the report is about measured exactly, and drops the cheap, numerous ones to a rounding error.

I have that working too. On `error_prone_core` it costs a median of 209 ms where the current implementation costs 656 ms, and on Calcite it is not distinguishable from having no spans at all, allocation included. Its accuracy against an exactly-timed run is no worse than two exactly-timed runs differ from each other:

| comparison | within 10% | within 20% |
| --- | --- | --- |
| exact against exact, the noise floor | 78% | 91% |
| exact against sampled | 65% | 86% |

The threshold is not a knob I would want to document. A clock read can be measured at startup in well under a millisecond, and the bound follows from it: time a check exactly while one measurement perturbs it by less than a few percent.

One caveat I have not solved: under Gradle the report does not reach the build log. It goes to javac's `NOTICE` writer, and Gradle passes no writer to `getTask`, so the text goes to the compiler daemon's stderr and is dropped. It arrives fine through `JavaCompiler.getTask` with a writer, which is how `ErrorProneJavaCompilerTest` sees it. Emitting the report as a diagnostic, or behind a flag that names a file, would fix that; the same applies to what `RefactoringCollection` already prints.

I am happy to send a pull request. The gate and the report are the small half and stand alone; the sampled collection is the larger half and I would rather hear which shape suits the internal consumer before proposing it.

Start at ErrorProneScanner.processMatchers and follow VisitorState.timingSpan into ErrorProneTimings.span, then inspect the finished(TaskEvent.Kind.COMPILATION) path and ErrorProneJavaCompilerTest. Determine how the timing flag should gate collection and printing, including the writer behavior under Gradle. Done means the requested report is produced without paying for spans when timings are disabled, with tests covering the enabled path.

Written by the indexing model from the issue text.