8382430: Extend output format of -XX:+PrintCompilation2 diagnostic flag

[vnkozlov]

During Leyden development we added additional information about times compilation task spends during its lifecycle. It was very useful to find bottlenecks during AOT production runs when we create compilation tasks to load AOT code.

Output before change (first line is from -XX:+PrintCompilation output):

$ java -Xbatch -XX:+PrintCompilation -XX:+UnlockDiagnosticVMOptions -XX:+PrintCompilation2 Test
...
85 12 % b 4 Test::test @ 2 (45 bytes)
     87 12 % size: 584(328) time: 1 inlined: 0 bytes

after change:

     48 W0.0 Q0.0 C1.7 12 % b 4 Test::test()V @ 2 (45 bytes) (inlined 0) (size 584/328)

Where times are in ms and output similar to PrintCompilation with additions:
48 - current time
W0.0 - is time it took to put compilation task on compilation queue (waiting MethodCompileQueue_lock)
Q0.0 - is time in compilation queue before compilation starts
C2.9 - compilation time
12 - compile ID
% - OSR compilation
4 - Tier4 (C2) compilation
@ 2 - OSR bytecode
45 bytes - Java method's bytecode size
(inlined 0) - inlined bytecodes
(size 584/328) - compiled nmethod total size in bytes / only instructions

In addition PrintCompilation2 always prints method name with signature.
And it does not depend on -XX:+PrintCompilation required before.

PrintCompilation2 is supported with CompileCommand too. You still need to specify -XX:+UnlockDiagnosticVMOptions because it is diagnostic flags:

$ java -XX:+UnlockDiagnosticVMOptions "-XX:CompileCommand=PrintCompilation2,Test::*" Test  
CompileCommand: PrintCompilation2 Test.* bool PrintCompilation2 = true
     27    W0.0    Q0.0    C0.1   10       3      Test::test()V (45 bytes) (inlined 0) (size 1056/776)
     28    W0.0    Q0.0    C0.8   11 %     4      Test::test()V @ 2 (45 bytes) (inlined 0) (size 352/240)
     29    W0.0    Q0.0    C0.7   12       4      Test::test()V (45 bytes) (inlined 0) (size 136/88)

Added _compiler field to CompileTask class to simplify some code.

And changed Method::name_and_sig_as_C_string() to use :: instead of . by request as separator in full method's name. We use :: in PrintCompilation output to clear separate method's name from class:

     37    W0.0    Q0.0    C0.4    3    b  3      java.lang.String::hashCode()I (60 bytes) (inlined 28) (size 1992/1104)

Testing: tier1-3,hs-comp-stress and 2 new tests are added to test PrintCompilation2.

---

• I confirm that I make this contribution in accordance with the OpenJDK Interim AI Policy.

---

Progress

• Change must not contain extraneous whitespace
• Commit message must refer to an issue
• Change must be properly reviewed (2 reviews required, with at least 1 Reviewer, 1 Author)

Issue

• JDK-8382430: Extend output format of -XX:+PrintCompilation2 diagnostic flag (Enhancement - P4)

Reviewers

• Vladimir Ivanov (@iwanowww - Reviewer)
• Anton Seoane Ampudia (@anton-seoane - Author)

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.org/jdk.git pull/30801/head:pull/30801
$ git checkout pull/30801

Update a local copy of the PR:
$ git checkout pull/30801
$ git pull https://git.openjdk.org/jdk.git pull/30801/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 30801

View PR using the GUI difftool:
$ git pr show -t 30801

Using diff file

Download this PR as a diff file:
https://git.openjdk.org/jdk/pull/30801.diff

Using Webrev

Link to Webrev Comment

[bridgekeeper]

👋 Welcome back kvn! A progress list of the required criteria for merging this PR into master will be added to the body of your pull request. There are additional pull request commands available for use with this pull request.

[openjdk]

@vnkozlov This change now passes all automated pre-integration checks.

ℹ️ This project also has non-automated pre-integration requirements. Please see the file CONTRIBUTING.md for details.

After integration, the commit message for the final commit will be:

8382430: Extend output format of -XX:+PrintCompilation2 diagnostic flag

Reviewed-by: vlivanov, aseoane

You can use pull request commands such as /summary, /contributor and /issue to adjust it as needed.

At the time when this comment was updated there had been 33 new commits pushed to the master branch:

• 952f9aa: 8382418: G1: Remove some stale comments about time accounting
• 62bd83a: 8382423: G1: Remove unused G1GCPhaseTimes::_external_accounted_time_ms
• 48b6da7: 8382422: G1: G1GCPhaseTimes::record_merge_heap_roots() uses += instead of direct assignment
• ... and 30 more: https://git.openjdk.org/jdk/compare/10e23dd5823258cfbf500175dde23be12cdd99bf...master

As there are no conflicts, your changes will automatically be rebased on top of these commits when integrating. If you prefer to avoid this automatic rebasing, please check the documentation for the /integrate command for further details.

➡️ To integrate this PR with the above commit message to the master branch, type /integrate in a new comment.

[openjdk]

@vnkozlov The following label will be automatically applied to this pull request:

• hotspot

When this pull request is ready to be reviewed, an "RFR" email will be sent to the corresponding mailing list. If you would like to change these labels, use the /label pull request command.

[openjdk]

The total number of required reviews for this PR has been set to 2 based on the presence of this label: hotspot. This can be overridden with the /reviewers command.

[mlbridge]

Webrevs

• 01: Full - Incremental (9ea15538)
• 00: Full (b0181bc1)

[chhagedorn]

That's a good improvement! Just a quick drive-by comment: We do not seem to have any test with PrintCompilation2. Could you add a hello world test with this flag as a sanity test?

[vnkozlov]

/cc hotspot-compiler

[openjdk]

@vnkozlov
The hotspot-compiler label was successfully added.

[vnkozlov]

New tests are added. They are based on existing tests for PrintCompilation.

And I updated Description with example for -XX:CompileCommand= PrintCompilation2,<method>.

[iwanowww]

Looks good.

[vnkozlov]

thank you, @iwanowww

[anton-seoane]

This looks good. Thanks!

[vnkozlov]

Thank you @anton-seoane for review.

[vnkozlov]

/integrate

[openjdk]

Going to push as commit ae5b765.
Since your change was applied there have been 41 commits pushed to the master branch:

• b854ba1: 8382441: Problemlist TestStressAllocationGCEventsWithShenandoah and TestStressBigAllocationGCEventsWithShenandoah
• d8e3813: 8382054: TestLoopPeelingDisabled.java fails with -DVerifyIR=false
• 9a3588b: 8379744: Add a way to update the key of a red-black tree node
• ... and 38 more: https://git.openjdk.org/jdk/compare/10e23dd5823258cfbf500175dde23be12cdd99bf...master

Your commit was automatically rebased without conflicts.

[openjdk]

@vnkozlov Pushed as commit ae5b765.

💡 You may see a message that your pull request was closed with unmerged commits. This can be safely ignored.