Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

8267924: Misleading G1 eager reclaim detail logging #4305

Conversation

tschatzl
Copy link
Contributor

@tschatzl tschatzl commented Jun 2, 2021

Hi,

can I have reviews for this change that brushes up gc+humongous logging?

In particular, during review of some logs several issues were found with the logging.
Both the "Live humongous region" and "Dead humongous region" logs

  • the remset count is always zero at the point of printing (end of gc) because G1 never pushes new cross-region references into remembered set entries during gc, and for candidates we actually just flushed them
  • the reclaim candidate flag is always zero at that point: if it got a "Live humongous" message, the source of that information must be false at that point. If "Dead humongous", it must have been true (one).

This change modifies the log output to try to give useful information: first, g1 prints information for all humongous regions when deciding whether something is a candidate. This means that the printed information is current. At the end of gc only reclaimed regions are printed, repeating the information from the printout at the beginning does not give more information.

E.g. a sample output from the test case

First, all humongous regions

Humongous region 0 (object size 41943056 @ 0x00000000f8000000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
Humongous region 71 (object size 25165840 @ 0x00000000fc700000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
Humongous region 41 (object size 4194320 @ 0x00000000fa900000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1
Humongous region 46 (object size 25165840 @ 0x00000000fae00000) remset 0 code roots 0 marked 0 reclaim candidate 1 type array 1

Later only reclaimed ones:

Reclaimed humongous region 46 (object size 25165840 @ 0x00000000fae00000)

Instead of currently:

Live humongous region 789 object size 2160888 start 0x00000006e2a00000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0

or

Dead humongous region 182 object size 16777232 start 0x000000074b600000 with remset 0 code roots 0 is marked 0 reclaim candidate 1 type array 1

This unfortunately kind of invalidates some websites trying to explain these log messages, but I still prefer to have useful output.

Thanks,
Thomas


Progress

  • Change must not contain extraneous whitespace
  • Commit message must refer to an issue
  • Change must be properly reviewed

Issue

  • JDK-8267924: Misleading G1 eager reclaim detail logging

Reviewers

Reviewing

Using git

Checkout this PR locally:
$ git fetch https://git.openjdk.java.net/jdk pull/4305/head:pull/4305
$ git checkout pull/4305

Update a local copy of the PR:
$ git checkout pull/4305
$ git pull https://git.openjdk.java.net/jdk pull/4305/head

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 4305

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

Using diff file

Download this PR as a diff file:
https://git.openjdk.java.net/jdk/pull/4305.diff

@bridgekeeper
Copy link

bridgekeeper bot commented Jun 2, 2021

👋 Welcome back tschatzl! 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
Copy link

openjdk bot commented Jun 2, 2021

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

  • hotspot-gc

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 openjdk bot added the hotspot-gc hotspot-gc-dev@openjdk.org label Jun 2, 2021
g1h->is_humongous_reclaim_candidate(region_idx),
obj->is_typeArray()
);
if (!g1h->is_humongous_reclaim_candidate(region_idx)) {
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Fwiw, the reason why the second clause has been removed is because it is useless: G1 does not add remembered set entries during gc, so if the remembered set has been empty before, it will be empty again.
Humongous regions with a large enough remembered set at the start are never candidates, and ones that are candidates have all of their outstanding references checked and if that is the case, their candidate state revoked, which is reflected in the is_humongous_reclaim_candidate check.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you update the comments a bit? Feels like they will be outdated after this change.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it would be nice to somehow highlight that this is no longer just a "candidate". When reading the code it looks like we early out if (!candidate) and that suggests that we then should check the candidate if it can be reclaimed. But that is already done during the GC, so anything still a candidate is reclaimable. What do you think about adding a helper to the closure:

// Any humongous object still a reclaim candidate at this point can be reclaimed.
bool should_reclaim(uint region) { 
  return G1CollectedHeap::heap()->is_humongous_reclaim_candidate(region_idx);
}

Maybe with a bit more thought through comment.

@tschatzl tschatzl marked this pull request as ready for review June 2, 2021 14:40
@openjdk openjdk bot added the rfr Pull request is ready for review label Jun 2, 2021
@mlbridge
Copy link

mlbridge bot commented Jun 2, 2021

Webrevs

g1h->is_humongous_reclaim_candidate(region_idx),
obj->is_typeArray()
);
if (!g1h->is_humongous_reclaim_candidate(region_idx)) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you update the comments a bit? Feels like they will be outdated after this change.

Copy link
Contributor

@kstefanj kstefanj left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks good.

A comment below, for a pre-existing thing, that you can skip if you like.

g1h->is_humongous_reclaim_candidate(region_idx),
obj->is_typeArray()
);
if (!g1h->is_humongous_reclaim_candidate(region_idx)) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think it would be nice to somehow highlight that this is no longer just a "candidate". When reading the code it looks like we early out if (!candidate) and that suggests that we then should check the candidate if it can be reclaimed. But that is already done during the GC, so anything still a candidate is reclaimable. What do you think about adding a helper to the closure:

// Any humongous object still a reclaim candidate at this point can be reclaimed.
bool should_reclaim(uint region) { 
  return G1CollectedHeap::heap()->is_humongous_reclaim_candidate(region_idx);
}

Maybe with a bit more thought through comment.

@openjdk
Copy link

openjdk bot commented Jun 7, 2021

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

8267924: Misleading G1 eager reclaim detail logging

Reviewed-by: ayang, 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 77 new commits pushed to the master branch:

  • 9fc914b: 8204686: Dynamic parallel reference processing support for Parallel GC
  • 908aca2: 8262891: Compiler implementation for Pattern Matching for switch (Preview)
  • 3e48244: 8268301: Closed test: compiler/c2/6371167/Test.java fails after JDK-8267904
  • 204b492: 8267703: runtime/cds/appcds/cacheObject/HeapFragmentationTest.java crashed with OutOfMemory
  • 2aeeeb4: 8268279: gc/shenandoah/compiler/TestLinkToNativeRBP.java fails after LibraryLookup is gone
  • b05fa02: 8267904: C2 crash when compile negative Arrays.copyOf length after loop
  • 95ddf7d: 8267839: trivial mem leak in numa
  • 52d88ee: 8268292: compiler/intrinsics/VectorizedMismatchTest.java fails with release VMs
  • 042f0bd: 8256465: [macos] Java frame and dialog presented full screen freeze application
  • 8abf36c: 8268289: build failure due to missing signed flag in x86 evcmpb instruction
  • ... and 67 more: https://git.openjdk.java.net/jdk/compare/a223189b069a7cfe49511d49b5b09e7107cb3cab...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 openjdk bot added the ready Pull request is ready to be integrated label Jun 7, 2021
@openjdk openjdk bot closed this Jun 7, 2021
@openjdk openjdk bot added integrated Pull request has been integrated and removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jun 7, 2021
@openjdk
Copy link

openjdk bot commented Jun 7, 2021

@tschatzl Since your change was applied there have been 83 commits pushed to the master branch:

  • e4d0454: 8267832: SimpleVisitors and Scanners in jdk.compiler should use @implSpec
  • 8130be5: 8268318: Missing comma in copyright header
  • b09d8b9: 8267926: AsyncLogGtest.java fails on assert with: decorator was not part of the decorator set specified at creation.
  • 5ebd419: 8267972: Inline cache cleaning is not monotonic
  • 6d1f3ac: 8149138: [javadoc] Fix SerialFormBuilder eliminate String bashing
  • 58bdabc: 8268164: Adopt cast notation for WorkerThread conversions
  • 9fc914b: 8204686: Dynamic parallel reference processing support for Parallel GC
  • 908aca2: 8262891: Compiler implementation for Pattern Matching for switch (Preview)
  • 3e48244: 8268301: Closed test: compiler/c2/6371167/Test.java fails after JDK-8267904
  • 204b492: 8267703: runtime/cds/appcds/cacheObject/HeapFragmentationTest.java crashed with OutOfMemory
  • ... and 73 more: https://git.openjdk.java.net/jdk/compare/a223189b069a7cfe49511d49b5b09e7107cb3cab...master

Your commit was automatically rebased without conflicts.

Pushed as commit 15715a8.

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

@tschatzl tschatzl deleted the submit/8267924-g1-eager-reclaim-logging branch June 11, 2021 07:41
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
hotspot-gc hotspot-gc-dev@openjdk.org integrated Pull request has been integrated
Development

Successfully merging this pull request may close these issues.

3 participants