Skip to content

8217327: G1 Post-Cleanup region liveness printing should not print out-of-date efficiency #2217

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

Closed
wants to merge 4 commits into from

Conversation

jaokim
Copy link
Contributor

@jaokim jaokim commented Jan 25, 2021

Description
This fix addresses the issue where gc-efficiency is printed incorrectly when logging post-marking and post-cleanup. The gc-efficiency is calculated in the end of the marking phase, to be logged in the post-cleanup section. It is however not reset, meaning that next phase's post-marking log will show the old value.

  • The gc-efficiency is initialized to -1 when it hasn't been calculated.
  • Negative gc-efficiency is displayed as a hyphen "-" in the summary.
  • The gc-efficiency is reset to -1 in HeapRegion::note_start_of_marking()

Note: there is a sister issue that moves the post-cleanup printing to a later stage. Without this fix, the logging will still be incorrect, so both fixes are needed. See: JDK-8260042: G1 Post-cleanup liveness printing occurs too early

This fix has been tested together with the above mentioned fix.

Example
This is what logging like after fix has been applied.

### PHASE Post-Marking @ 410.303
### HEAP  reserved: 0x0ffc00000-0x100000000  region-size: 1048576
###
###   type           address-range       used  prev-live  next-live          gc-eff     remset   state  code-roots
###                                                 (bytes)    (bytes)    (bytes)      (bytes/ms)    (bytes)            (bytes)
###   OLD  0x0ffc00000-0x0ffd00000    1048368    1048368    1048368               -       8464   UPDAT       6096
###   OLD  0x0ffd00000-0x0ffe00000     132856     132856     132856               -       2544   UPDAT         16
###   SURV 0x0ffe00000-0x0fff00000      21368      21368      21368               -       2544   CMPLT         16
###   FREE 0x0fff00000-0x100000000          0          0          0               -       2384   UNTRA         16
###
### SUMMARY  capacity: 4.00 MB  used: 1.15 MB / 28.67 %  prev-live: 1.15 MB / 28.67 %  next-live: 1.15 MB / 28.67 %  remset: 0.02 MB  code-roots: 0.01 MB
### PHASE Post-Cleanup @ 410.305
### HEAP  reserved: 0x0ffc00000-0x100000000  region-size: 1048576
###
###   type           address-range       used  prev-live  next-live          gc-eff     remset   state  code-roots
###                                                 (bytes)    (bytes)    (bytes)      (bytes/ms)    (bytes)            (bytes)
###   OLD  0x0ffc00000-0x0ffd00000    1048368    1048368    1048368               -       8624   UNTRA       6096
###   OLD  0x0ffd00000-0x0ffe00000     132856     132856     132856       1352923.9       2544   CMPLT         16
###   SURV 0x0ffe00000-0x0fff00000      21368      21368      21368               -       2544   CMPLT         16
###   FREE 0x0fff00000-0x100000000          0          0          0               -       2384   UNTRA         16
###
### SUMMARY  capacity: 4.00 MB  used: 1.15 MB / 28.67 %  prev-live: 1.15 MB / 28.67 %  next-live: 1.15 MB / 28.67 %  remset: 0.02 MB  code-roots: 0.01 MB
### PHASE Post-Marking @ 450.310
### HEAP  reserved: 0x0ffc00000-0x100000000  region-size: 1048576
###
###   type           address-range       used  prev-live  next-live          gc-eff     remset   state  code-roots
###                                                 (bytes)    (bytes)    (bytes)      (bytes/ms)    (bytes)            (bytes)
###   OLD  0x0ffc00000-0x0ffd00000    1048368    1048368    1048368               -       8624   UPDAT       6096
###   OLD  0x0ffd00000-0x0ffe00000     174456     174456     174456               -       2544   UPDAT         16
###   SURV 0x0ffe00000-0x0fff00000      21368      21368      21368               -       2544   CMPLT         16
###   FREE 0x0fff00000-0x100000000          0          0          0               -       2384   UNTRA         16
###
### SUMMARY  capacity: 4.00 MB  used: 1.19 MB / 29.66 %  prev-live: 1.19 MB / 29.66 %  next-live: 1.19 MB / 29.66 %  remset: 0.02 MB  code-roots: 0.01 MB
### PHASE Post-Cleanup @ 450.312
### HEAP  reserved: 0x0ffc00000-0x100000000  region-size: 1048576
###
###   type           address-range       used  prev-live  next-live          gc-eff     remset   state  code-roots
###                                                 (bytes)    (bytes)    (bytes)      (bytes/ms)    (bytes)            (bytes)
###   OLD  0x0ffc00000-0x0ffd00000    1048368    1048368    1048368               -       8624   UNTRA       6096
###   OLD  0x0ffd00000-0x0ffe00000     174456     174456     174456       1266519.2       2544   CMPLT         16
###   SURV 0x0ffe00000-0x0fff00000      21368      21368      21368               -       2544   CMPLT         16
###   FREE 0x0fff00000-0x100000000          0          0          0               -       2384   UNTRA         16
###

Testing

  • Manual testing
  • hs-tier1, hs-tier2

Progress

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

Issue

  • JDK-8217327: G1 Post-Cleanup region liveness printing should not print out-of-date efficiency

Reviewers

Download

$ git fetch https://git.openjdk.java.net/jdk pull/2217/head:pull/2217
$ git checkout pull/2217

@bridgekeeper
Copy link

bridgekeeper bot commented Jan 25, 2021

👋 Welcome back jaokim! 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 Jan 25, 2021

@jaokim 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 Jan 25, 2021
@jaokim jaokim marked this pull request as ready for review January 25, 2021 11:54
@openjdk openjdk bot added the rfr Pull request is ready for review label Jan 25, 2021
@mlbridge
Copy link

mlbridge bot commented Jan 25, 2021

Webrevs

Copy link
Contributor

@tschatzl tschatzl 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 otherwise; there are some strange Windows build failures here too.

Copy link
Contributor

@tschatzl tschatzl left a comment

Choose a reason for hiding this comment

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

Note that I think the code given is correct, so I am good if you think using snprintf is better but I want your feedback about this. Then I'll approve.

type, p2i(bottom), p2i(end),
used_bytes, prev_live_bytes, next_live_bytes, "-",
remset_bytes, remset_type, strong_code_roots_bytes);
snprintf(gc_efficiency, G1PPRL_DOUBLE_FORMAT_LEN+1, G1PPRL_DOUBLE_H_FORMAT, "-");
Copy link
Contributor

Choose a reason for hiding this comment

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

snprintf is fine with me too, but I had imagined something like this:

FormatBuffer<> efficiency(""); //  maybe better name this
if (gc_eff < 0.0) {
  efficiency.append("-");
} else {
  efficiency.append(G1PPRL_DOUBLE_H_FORMAT, gc_eff);
}

and in the log_trace use %s and efficiency.buffer(). That seems a lot easier to understand (for me) than wrangling with snprintf.

Maybe there is a reason to not use this?

Also, I am not sure that using G1PPRL_DOUBLE_H_FORMAT for this snprintf here to print only - is really correct. I would have naively have expected to require %s.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Again, you're absolutely right.
I looked for a FormatBuffer class in the codebase when you mentioned it (kind of what I wanted from the beginning). For whatever reason I couldn't find one (typo, temporary blindness, ignorance??). So I went with snprintf (even though I don't particular like it).
I'll fix this. Sorry for all the bother.

Copy link
Contributor

@tschatzl tschatzl left a comment

Choose a reason for hiding this comment

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

Lgtm, thanks for your effort.

@openjdk
Copy link

openjdk bot commented Jan 28, 2021

⚠️ @jaokim the full name on your profile does not match the author name in this pull requests' HEAD commit. If this pull request gets integrated then the author name from this pull requests' HEAD commit will be used for the resulting commit. If you wish to push a new commit with a different author name, then please run the following commands in a local repository of your personal fork:

$ git checkout JDK-8217327
$ git commit -c user.name='Preferred Full Name' --allow-empty -m 'Update full name'
$ git push

@openjdk
Copy link

openjdk bot commented Jan 28, 2021

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

8217327: G1 Post-Cleanup region liveness printing should not print out-of-date efficiency

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

  • 80760a3: 8260669: Missing quotes in fixpath.sh
  • c0cde7d: 8259814: test/jdk/tools/jlink/plugins/CompressorPluginTest.java has compilation issues
  • aec0377: 8257498: Remove useless skeleton predicates
  • ab727f0: 8260591: Shenandoah: improve parallelism for concurrent thread root scans
  • cf94208: 8259395: Patching automatic module with additional packages re-creates module without "requires java.base"
  • 039affc: 8260577: Unused code in AbstractCompiler after Shark compiler removal
  • 8a9004d: 8260574: Remove parallel constructs in GenCollectedHeap::process_roots
  • 0da9cad: 8260501: [Vector API] Improve register usage for shift operations on x86
  • a61ff87: 8260685: ProblemList 2 compiler/jvmci/compilerToVM tests in Xcomp configs
  • fcfe647: 8260462: Missing in Modality.html
  • ... and 242 more: https://git.openjdk.java.net/jdk/compare/b8ef2bad527734f36b431da22d3c12a3db901466...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.

As you do not have Committer status in this project an existing Committer must agree to sponsor your change. Possible candidates are the reviewers of this PR (@tschatzl, @kstefanj) but any other Committer may sponsor as well.

➡️ To flag this PR as ready for integration with the above commit message, type /integrate in a new comment. (Afterwards, your sponsor types /sponsor in a new comment to perform the integration).

@openjdk openjdk bot added the ready Pull request is ready to be integrated label Jan 28, 2021
@jaokim
Copy link
Contributor Author

jaokim commented Jan 28, 2021

Thanks @tschatzl for review and comments!

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.

@jaokim
Copy link
Contributor Author

jaokim commented Feb 1, 2021

Thanks for review @kstefanj.

@jaokim
Copy link
Contributor Author

jaokim commented Feb 1, 2021

/integrate

@openjdk openjdk bot added the sponsor Pull request is ready to be sponsored label Feb 1, 2021
@openjdk
Copy link

openjdk bot commented Feb 1, 2021

@jaokim
Your change (at version 201f785) is now ready to be sponsored by a Committer.

@tschatzl
Copy link
Contributor

tschatzl commented Feb 1, 2021

/sponsor

@openjdk openjdk bot closed this Feb 1, 2021
@openjdk openjdk bot added integrated Pull request has been integrated and removed sponsor Pull request is ready to be sponsored ready Pull request is ready to be integrated rfr Pull request is ready for review labels Feb 1, 2021
@openjdk
Copy link

openjdk bot commented Feb 1, 2021

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

  • e963ebd: 8260004: Shenandoah: Rename ShenandoahMarkCompact to ShenandoahFullGC
  • df33595: 8260309: Shenandoah: Clean up ShenandoahBarrierSet
  • 181d63f: 8260522: Clean up warnings in hotspot JTReg runtime tests
  • 02d586e: 8259398: Super word not applied to a loop with byteArrayViewVarHandle
  • 80760a3: 8260669: Missing quotes in fixpath.sh
  • c0cde7d: 8259814: test/jdk/tools/jlink/plugins/CompressorPluginTest.java has compilation issues
  • aec0377: 8257498: Remove useless skeleton predicates
  • ab727f0: 8260591: Shenandoah: improve parallelism for concurrent thread root scans
  • cf94208: 8259395: Patching automatic module with additional packages re-creates module without "requires java.base"
  • 039affc: 8260577: Unused code in AbstractCompiler after Shark compiler removal
  • ... and 246 more: https://git.openjdk.java.net/jdk/compare/b8ef2bad527734f36b431da22d3c12a3db901466...master

Your commit was automatically rebased without conflicts.

Pushed as commit 50f9a70.

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

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