RFR: 8356027: Print enhanced compilation timings [v8]

Vladimir Ivanov vlivanov at openjdk.org
Thu May 8 21:51:52 UTC 2025


On Wed, 7 May 2025 11:51:04 GMT, Aleksey Shipilev <shade at openjdk.org> wrote:

>> In Leyden, we have the extended compilation timings printouts with -XX:+PrintCompilation / UL, that are very useful to study compiler dynamics. These timings include:
>>  1. Time spent before queuing: shows the compilation queue bottlenecks
>>  2. Time spent in the queue: shows delays caused by queue bottlenecks and compiler load
>>  3. Time spent actually compiling: shows the per-method compilation costs
>> 
>> We should consider the same kind of printout for mainline. This would also require us to print the compilation task _after_ the compilation, not only before it. This improvement would also obviate any need for `PrintCompilation2` flag, [JDK-8356028](https://bugs.openjdk.org/browse/JDK-8356028).
>> 
>> The difference from the output format we ship in Leyden:
>>  1. This output prints before/after the compilation to maintain old behavior partially. The "before" printout is now prepended with `started` to clearly mark it as such.
>>  2. The output is raw number in microseconds. In Leyden repo, we have these prepended with characters, like `C0.1`, but that prepending makes it a bit inconvenient with scripts. This PR also does microseconds, instead of fractional milliseconds. This should be enough to capture the wide range of durations.
>> 
>> See the sample `-XX:+PrintCompilation` output in the comments.
>> 
>> Additional testing:
>>  - [x] Linux x86_64 server fastdebug, `compiler`
>>  - [x]  Linux x86_64 server fastdebug, `all`
>
> Aleksey Shipilev has updated the pull request incrementally with one additional commit since the last revision:
> 
>   Do microseconds for timings

Frankly speaking, I'm on the fence about this particular change.

The information is very useful, but whether it has to be unconditionally printed as part of `-XX:+PrintCompilation` output or not is an open question for me. It more than doubles the amount of data printed and then if it is primarily intended to be consumed by tools, then `tty` is not the best way to stream the data out of the JVM (e.g., `ttyLocker` is not enough to completely eliminate VM output interleaving).

If you don't want to mess with `-XX:+LogCompilation`, unified logging provides a more convenient and configurable way to stream line-oriented textual data.

-------------

PR Review: https://git.openjdk.org/jdk/pull/24984#pullrequestreview-2826441190


More information about the hotspot-dev mailing list