8309210: Extend VM Operations hs_err logging

[stefank]

We have a section in the hs_err file, which prints the most recently run VM operations. Sometimes a VM operation type is used from multiple places in our code and it's not obvious why the VM operation was run. For example, HandshakeAllThreads doesn't tell us why we are running the handshake. I propose that we add an option for the VM operations to tell more about why they are used.

The proposed patch enhances the Handshake VM operation and the ZGC pause VM Operations.

---

Progress

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

Issue

• JDK-8309210: Extend VM Operations hs_err logging

Reviewers

• David Holmes (@dholmes-ora - Reviewer)
• Thomas Stuefe (@tstuefe - Reviewer)
• Erik Österlund (@fisk - Reviewer)
• Stefan Johansson (@kstefanj - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 14248

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

Using diff file

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

Webrev

Link to Webrev Comment

[stefank]

/label add hotspot

[stefank]

This proposal would change the output from:

Event: 1.502 Executing VM operation: ZRelocateStartYoung
Event: 1.502 Executing VM operation: ZRelocateStartYoung done
Event: 1.502 Executing VM operation: ZMarkStartYoung
Event: 1.503 Executing VM operation: ZMarkStartYoung done
Event: 1.504 Executing VM operation: HandshakeAllThreads
Event: 1.504 Executing VM operation: HandshakeAllThreads done
Event: 1.504 Executing VM operation: ZMarkFlushOperation
Event: 1.504 Executing VM operation: ZMarkFlushOperation done
Event: 1.504 Executing VM operation: HandshakeAllThreads
Event: 1.504 Executing VM operation: HandshakeAllThreads done
Event: 1.504 Executing VM operation: ZMarkFlushOperation
Event: 1.504 Executing VM operation: ZMarkFlushOperation done
Event: 1.504 Executing VM operation: ZMarkEndYoung
Event: 1.504 Executing VM operation: ZMarkEndYoung done
Event: 1.508 Executing VM operation: HandshakeAllThreads
Event: 1.508 Executing VM operation: HandshakeAllThreads done
Event: 1.508 Executing VM operation: ZMarkFlushOperation
Event: 1.508 Executing VM operation: ZMarkFlushOperation done
Event: 1.508 Executing VM operation: HandshakeAllThreads
Event: 1.508 Executing VM operation: HandshakeAllThreads done
Event: 1.508 Executing VM operation: ZMarkFlushOperation
Event: 1.508 Executing VM operation: ZMarkFlushOperation done
Event: 1.508 Executing VM operation: ZMarkEndOld
Event: 1.519 Executing VM operation: ZMarkEndOld done
Event: 1.519 Executing VM operation: ZRelocateStartYoung
Event: 1.519 Executing VM operation: ZRelocateStartYoung done
Event: 1.521 Executing VM operation: HandshakeAllThreads
Event: 1.521 Executing VM operation: HandshakeAllThreads done
Event: 1.521 Executing VM operation: ZRendezvousGCThreads
Event: 1.521 Executing VM operation: ZRendezvousGCThreads done

To something like this:

Event: 1.502 Executing VM operation: ZRelocateStartYoung (Allocation Stall)
Event: 1.502 Executing VM operation: ZRelocateStartYoung (Allocation Stall) done
Event: 1.502 Executing VM operation: ZMarkStartYoung (Allocation Stall)
Event: 1.503 Executing VM operation: ZMarkStartYoung (Allocation Stall) done
Event: 1.504 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks)
Event: 1.504 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks) done
Event: 1.504 Executing VM operation: ZMarkFlushOperation
Event: 1.504 Executing VM operation: ZMarkFlushOperation done
Event: 1.504 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks)
Event: 1.504 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks) done
Event: 1.504 Executing VM operation: ZMarkFlushOperation
Event: 1.504 Executing VM operation: ZMarkFlushOperation done
Event: 1.504 Executing VM operation: ZMarkEndYoung (Allocation Stall)
Event: 1.504 Executing VM operation: ZMarkEndYoung (Allocation Stall) done
Event: 1.508 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks)
Event: 1.508 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks) done
Event: 1.508 Executing VM operation: ZMarkFlushOperation
Event: 1.508 Executing VM operation: ZMarkFlushOperation done
Event: 1.508 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks)
Event: 1.508 Executing VM operation: HandshakeAllThreads (ZMarkFlushAndFreeStacks) done
Event: 1.508 Executing VM operation: ZMarkFlushOperation
Event: 1.508 Executing VM operation: ZMarkFlushOperation done
Event: 1.508 Executing VM operation: ZMarkEndOld (Allocation Stall)
Event: 1.519 Executing VM operation: ZMarkEndOld (Allocation Stall) done
Event: 1.519 Executing VM operation: ZRelocateStartYoung (Allocation Stall)
Event: 1.519 Executing VM operation: ZRelocateStartYoung (Allocation Stall) done
Event: 1.521 Executing VM operation: HandshakeAllThreads (ZRendezvous)
Event: 1.521 Executing VM operation: HandshakeAllThreads (ZRendezvous) done
Event: 1.521 Executing VM operation: ZRendezvousGCThreads
Event: 1.521 Executing VM operation: ZRendezvousGCThreads done

[bridgekeeper]

👋 Welcome back stefank! 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]

@stefank
The hotspot label was successfully added.

[mlbridge]

Webrevs

• 00: Full (8bab1a50)

[dholmes-ora]

Seems quite reasonable.

Thanks.

[openjdk]

@stefank 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:

8309210: Extend VM Operations hs_err logging

Reviewed-by: dholmes, stuefe, eosterlund, sjohanss

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 42 new commits pushed to the master branch:

• dc8bc6c: 8308090: Add container tests for on-the-fly resource quota updates
• 73e7af9: 8309287: Add fontconfig requirement to building.md for Debian
• aeb53e6: 8308711: Develop additional Tests for KEM implementation
• dcd9590: 8309224: Fix xlc17 clang 15 warnings in java.desktop
• 8f1ce78: 8308752: Generational ZGC: Avoid final marking through stack chunks
• 7b0a336: 8308387: CLD created and unloading list sharing _next node pointer leads to concurrent YC missing CLD roots
• 60f3b87: 8309295: C2: MaxNode::signed_min() returns nullptr for int operands
• 8007599: 8309093: Underscore with brackets
• 5bd2af2: 8307478: Implementation of Prepare to Restrict The Dynamic Loading of Agents
• 325940b: 8307105: JFileChooser InvalidPathException when selecting some system folders on Windows
• ... and 32 more: https://git.openjdk.org/jdk/compare/024d9b131d6c2d5ee6c8cafdb05b9e9e299d588e...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.

[tstuefe]

Looks good.

[fisk]

This will make debugging much easier. Thank you. Looks good.

[kstefanj]

Looks good! File file an enhancement to add this for all VM_GC_Operations

[stefank]

Thanks for the reviews!
/integrate

[openjdk]

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

• 7dbdad5: 8308892: Bad graph detected in build_loop_late after JDK-8305635
• dc8bc6c: 8308090: Add container tests for on-the-fly resource quota updates
• 73e7af9: 8309287: Add fontconfig requirement to building.md for Debian
• aeb53e6: 8308711: Develop additional Tests for KEM implementation
• dcd9590: 8309224: Fix xlc17 clang 15 warnings in java.desktop
• 8f1ce78: 8308752: Generational ZGC: Avoid final marking through stack chunks
• 7b0a336: 8308387: CLD created and unloading list sharing _next node pointer leads to concurrent YC missing CLD roots
• 60f3b87: 8309295: C2: MaxNode::signed_min() returns nullptr for int operands
• 8007599: 8309093: Underscore with brackets
• 5bd2af2: 8307478: Implementation of Prepare to Restrict The Dynamic Loading of Agents
• ... and 33 more: https://git.openjdk.org/jdk/compare/024d9b131d6c2d5ee6c8cafdb05b9e9e299d588e...master

Your commit was automatically rebased without conflicts.

[openjdk]

@stefank Pushed as commit e8268d9.

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