8291418: adjust monitor deflation logging and deflate_idle_monitors use #11293

dcubed-ojdk · 2022-11-22T17:10:56Z

Trivial fixes to monitor deflation logging and deflate_idle_monitors use.

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-8291418: adjust monitor deflation logging and deflate_idle_monitors use

Reviewers

David Holmes (@dholmes-ora - Reviewer) ⚠️ Review applies to f558d870
Thomas Stuefe (@tstuefe - Reviewer) ⚠️ Review applies to f558d870
Patricio Chilano Mateo (@pchilano - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 11293

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

Using diff file

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

dcubed-ojdk · 2022-11-22T17:11:24Z

/label add hotspot-runtime

bridgekeeper · 2022-11-22T17:12:50Z

👋 Welcome back dcubed! 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 · 2022-11-22T17:15:20Z

@dcubed-ojdk
The hotspot-runtime label was successfully added.

mlbridge · 2022-11-22T17:19:10Z

Webrevs

01: Full - Incremental (4b486d62)
00: Full (f558d870)

dholmes-ora

This seems reasonable.

Just an observation on the pre-existing logic ... it is interesting that logging has a side-effect of deflating idle monitors. If someone was encountering a problem due to too many inflated monitors and turned on logging to try and show them why, the problem might disappear and the logging would be ineffective in aiding in tracking down the problem.

openjdk · 2022-11-23T00:00:36Z

@dcubed-ojdk 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:

8291418: adjust monitor deflation logging and deflate_idle_monitors use

Reviewed-by: dholmes, stuefe, pchilanomate

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

6065696: 8297982: Exclude vmTestbase/nsk/monitoring/stress/lowmem/ with ZGC until 8297979 is fixed
415cfd2: 8297285: Shenandoah pacing causes assertion failure during VM initialization
df07255: 8297984: Turn on warnings as errors for javadoc
227364d: 8297953: Fix several C2 IR matching tests for RISC-V
1370228: 8297941: Add override modifier in space.hpp
319faa5: 8296084: javax/swing/JSpinner/4788637/bug4788637.java fails intermittently on a VM
b73363f: 8297686: JFR: Improve documentation of EventStream::onMetadata(Consumer)
1376f33: 8297911: Memory leak in JfrUpcalls::on_retransform
5c0ff26: 8291444: GHA builds/tests won't run manually if disabled from automatic running
6d0fbb2: 8297645: Drop the test/jdk/java/net/httpclient/reactivestreams-tck-tests/TckDriver.java test
... and 43 more: https://git.openjdk.org/jdk/compare/c68556916ae7cc0301f3c89c05148547dcb44278...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.

But this felt not trivial to me :) I tried to understand the preexisting code:

while (ObjectSynchronizer::deflate_idle_monitors(tablep) >= (size_t)MonitorDeflationMax) {

So, was the intent behind this "as long as deflate_idle_monitors() uses its full allotment of deflations, continue, but if you notice it slacking off, stop?" And the assumption is we always deflate n*MonitorDeflationMax + a smaller rest? And this assumption was wrong?

pchilano

Looks good to me.

pchilano · 2022-11-23T16:25:55Z

src/hotspot/share/runtime/synchronizer.cpp

-    if (deflated_count != 0 || log_is_enabled(Debug, monitorinflation)) {
-      ls->print_cr("deflated " SIZE_FORMAT " monitors in %3.7f secs",
-                   deflated_count, timer.seconds());
+    if (deflated_count != 0 || unlinked_count != 0 || deleted_count != 0 || log_is_enabled(Debug, monitorinflation)) {


Why check both unlinked_count and deleted_count? Shouldn't they be equal if we got here?

If memory serves, it's possible for the final safepoint to catch
the MonitorDeflation thread while it's working in here at different
phases of the deflate_idle_monitors() work. When the VM Thread
comes in here for the "final audit" it can find different amounts of
work to do in the different phases because the MonitorDeflation
thread might have deflated N monitors, but it wasn't able to unlink
them all. When the VM Thread does its pass, it may deflate fewer
monitors (M), but may find N+M monitors need to be unlinked and
deleted.

Similarly, I think it's possible for the MonitorDeflation thread to
deflate N monitors and unlink N monitors, but then block for the
final safepoint. When the VMThread comes along, it may delete
fewer monitors(M) and unlink fewer monitors(M), but may find
N+M monitors need to be deleted. If the VM Thread's M value is
zero, then it will have deflated_count == 0, unlinked_count == 0
and deleted_count != 0.

But isn't the delete_list local to the MonitorDeflation thread? How can the VMThread access those unlinked but not deleted monitors?

You are right about delete_list being local so once the
MonitorDeflation thread has successfully unlinked a deflated
ObjectMonitor and put it on the local delete_list, if the
MonitorDeflation thread goes to a final safepoint, then any
ObjectMonitors on the delete_list won't be freed.

It also means that unlinked_count == deleted_count in any
thread that reaches L1551. If I change that if-statement, I think
I'd want to add an assert() there also.

dcubed-ojdk · 2022-11-29T21:32:22Z

@dholmes-ora, @tstuefe and @pchilano - Thanks for the reviews!

Sorry for the delay in getting back to this review. I had an over abundance of
CI/GK work to do before the holiday break and I just finished getting caught
up after the holiday break.

dcubed-ojdk · 2022-11-29T21:58:31Z

@dholmes-ora:

This seems reasonable.

Thanks!

Just an observation on the pre-existing logic ... it is interesting that logging has a side-effect of deflating idle monitors. If someone was encountering a problem due to too many inflated monitors and turned on logging to try and show them why, the problem might disappear and the logging would be ineffective in aiding in tracking down the problem.

I suppose that is a possibility if, for some reason, the MonitorDeflation thread was not
running in a timely fashion (too long of a delay, missed notification, stuck thread).
However, most cases of too many inflated monitors end up being because the monitors
didn't meet the requirements for being deflated (non-zero waiter count being the most
likely).

dcubed-ojdk · 2022-11-29T22:07:28Z

@tstuefe:

Looks good.

Thanks!

But this felt not trivial to me :)

Sorry about that. I suspect that I have lived with this code for too long...
I tried to figure out how to update the PR description to put a line thru
the word "Trivial", but I don't see that option.

I tried to understand the preexisting code:

while (ObjectSynchronizer::deflate_idle_monitors(tablep) >= (size_t)MonitorDeflationMax) {

So, was the intent behind this "as long as deflate_idle_monitors() uses its full allotment of deflations, continue, but if you notice it slacking off, stop?" And the assumption is we always deflate n*MonitorDeflationMax + a smaller rest? And this assumption was wrong?

My original intent was "loop here until we have nothing left to deflate".
I implemented it wrong and we stopped if there was a partial
deflation, i.e., less than MonitorDeflationMax deflated.
However, in some cases, we would see multiple partial deflations
in a row before there is nothing left to deflate so I changed the loop
to stop when we did a complete pass and deflated nothing.

dcubed-ojdk · 2022-11-29T22:08:40Z

@pchilano:

Looks good to me.

Thanks.

dcubed-ojdk · 2022-11-29T22:11:09Z

@dholmes-ora, @tstuefe and @pchilano -

I think I've replied to all the review comments. Please let me know if
you are okay with the replies.

tstuefe · 2022-11-30T09:17:51Z

All good. Thanks for answering my question.

Added tag jdk-20+26 for changeset c685569

dcubed-ojdk · 2022-12-01T22:28:45Z

Logging output with the latest commit looks like this:

[0.040s][info][monitorinflation] Starting the final audit.
[0.040s][info][monitorinflation] begin deflating: in_use_list stats: ceiling=10240, count=2, max=2
[0.040s][info][monitorinflation] deflated_count=1, {unlinked,deleted}_count=1 monitors in 0.0000017 secs
[0.040s][info][monitorinflation] end deflating: in_use_list stats: ceiling=10240, count=1, max=2

pchilano

Thanks Dan, latest changes look good.

dcubed-ojdk · 2022-12-02T21:19:42Z

@pchilano - Thanks for the re-review.

dcubed-ojdk · 2022-12-02T22:28:40Z

Local testing of this patch after rebasing to the jdk-20+26 snapshot looks good.

/integrate

openjdk · 2022-12-02T22:31:19Z

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

6e54705: 8295424: adjust timeout for another JLI GetObjectSizeIntrinsicsTest.java subtest
562bc17: 8291359: Specification of method j.l.foreign.VaList::skip still deserves clarification
2821fa9: 8280798: com.sun.jdi.ObjectReference::setValue spec should prohibit any final field modification
fb6fd03: 8291830: jvmti/RedefineClasses/StressRedefine failed: assert(!is_null(v)) failed: narrow klass value can never be zero
1b92465: 8297608: JFR: Incorrect duration after chunk rotation
6065696: 8297982: Exclude vmTestbase/nsk/monitoring/stress/lowmem/ with ZGC until 8297979 is fixed
415cfd2: 8297285: Shenandoah pacing causes assertion failure during VM initialization
df07255: 8297984: Turn on warnings as errors for javadoc
227364d: 8297953: Fix several C2 IR matching tests for RISC-V
1370228: 8297941: Add override modifier in space.hpp
... and 48 more: https://git.openjdk.org/jdk/compare/c68556916ae7cc0301f3c89c05148547dcb44278...master

Your commit was automatically rebased without conflicts.

openjdk · 2022-12-02T22:31:38Z

@dcubed-ojdk Pushed as commit 6065516.

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

8291418: adjust monitor deflation logging and deflate_idle_monitors use

f558d87

dcubed-ojdk marked this pull request as ready for review November 22, 2022 17:11

openjdk bot added rfr Pull request is ready for review hotspot-runtime hotspot-runtime-dev@openjdk.org labels Nov 22, 2022

This was referenced Nov 22, 2022

8256302: releasing oopStorage when deflating allows for faster deleting #11295

Closed

8256302: releasing oopStorage when deflating allows for faster deleting #11296

Closed

dholmes-ora approved these changes Nov 22, 2022

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Nov 23, 2022

tstuefe approved these changes Nov 23, 2022

View reviewed changes

pchilano approved these changes Nov 23, 2022

View reviewed changes

dcubed-ojdk added 2 commits December 1, 2022 15:27

Merge tag 'jdk-20+26' into JDK-8291418

392ecf4

Added tag jdk-20+26 for changeset c685569

address pchilano CR comments.

4b486d6

pchilano approved these changes Dec 2, 2022

View reviewed changes

openjdk bot added the integrated Pull request has been integrated label Dec 2, 2022

openjdk bot closed this Dec 2, 2022

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Dec 2, 2022

dcubed-ojdk deleted the JDK-8291418 branch December 8, 2022 17:24

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8291418: adjust monitor deflation logging and deflate_idle_monitors use #11293

8291418: adjust monitor deflation logging and deflate_idle_monitors use #11293

dcubed-ojdk commented Nov 22, 2022 •

edited by openjdk bot

Loading

dcubed-ojdk commented Nov 22, 2022

bridgekeeper bot commented Nov 22, 2022

openjdk bot commented Nov 22, 2022

mlbridge bot commented Nov 22, 2022 •

edited

Loading

dholmes-ora left a comment

openjdk bot commented Nov 23, 2022 •

edited

Loading

tstuefe left a comment

pchilano left a comment

pchilano Nov 23, 2022

dcubed-ojdk Nov 29, 2022

pchilano Nov 30, 2022

dcubed-ojdk Nov 30, 2022

dcubed-ojdk commented Nov 29, 2022

dcubed-ojdk commented Nov 29, 2022 •

edited

Loading

dcubed-ojdk commented Nov 29, 2022 •

edited

Loading

dcubed-ojdk commented Nov 29, 2022

dcubed-ojdk commented Nov 29, 2022

tstuefe commented Nov 30, 2022

dcubed-ojdk commented Dec 1, 2022

pchilano left a comment

dcubed-ojdk commented Dec 2, 2022

dcubed-ojdk commented Dec 2, 2022

openjdk bot commented Dec 2, 2022

openjdk bot commented Dec 2, 2022

8291418: adjust monitor deflation logging and deflate_idle_monitors use #11293

8291418: adjust monitor deflation logging and deflate_idle_monitors use #11293

Conversation

dcubed-ojdk commented Nov 22, 2022 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

dcubed-ojdk commented Nov 22, 2022

bridgekeeper bot commented Nov 22, 2022

openjdk bot commented Nov 22, 2022

mlbridge bot commented Nov 22, 2022 • edited Loading

Webrevs

dholmes-ora left a comment

Choose a reason for hiding this comment

openjdk bot commented Nov 23, 2022 • edited Loading

tstuefe left a comment

Choose a reason for hiding this comment

pchilano left a comment

Choose a reason for hiding this comment

pchilano Nov 23, 2022

Choose a reason for hiding this comment

dcubed-ojdk Nov 29, 2022

Choose a reason for hiding this comment

pchilano Nov 30, 2022

Choose a reason for hiding this comment

dcubed-ojdk Nov 30, 2022

Choose a reason for hiding this comment

dcubed-ojdk commented Nov 29, 2022

dcubed-ojdk commented Nov 29, 2022 • edited Loading

dcubed-ojdk commented Nov 29, 2022 • edited Loading

dcubed-ojdk commented Nov 29, 2022

dcubed-ojdk commented Nov 29, 2022

tstuefe commented Nov 30, 2022

dcubed-ojdk commented Dec 1, 2022

pchilano left a comment

Choose a reason for hiding this comment

dcubed-ojdk commented Dec 2, 2022

dcubed-ojdk commented Dec 2, 2022

openjdk bot commented Dec 2, 2022

openjdk bot commented Dec 2, 2022

dcubed-ojdk commented Nov 22, 2022 •

edited by openjdk bot

Loading

mlbridge bot commented Nov 22, 2022 •

edited

Loading

openjdk bot commented Nov 23, 2022 •

edited

Loading

dcubed-ojdk commented Nov 29, 2022 •

edited

Loading

dcubed-ojdk commented Nov 29, 2022 •

edited

Loading