jdk icon indicating copy to clipboard operation
jdk copied to clipboard

Published 20 hours ago • verified publisher icon openjdk

8328278: Serial: Compute tenuring threshold before GC

Open lgxbslgx opened this issue 11 months ago • 4 comments

Hi all,

This patch places the SerialGC code that computes tenuring threshold before per GC instead of after per GC, so that the method AgeTable::print_on prints the right tenuring threshold. Just like the current G1 implementation.

Thanks for taking the time to review.

Best Regards, -- Guoxiong

Progress

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

Issue

  • JDK-8328278: Serial: Compute tenuring threshold before GC (Bug - P4)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 18329

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

Using diff file

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

Webrev

Link to Webrev Comment

lgxbslgx avatar Mar 15 '24 15:03 lgxbslgx

:wave: Welcome back gli! 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.

bridgekeeper[bot] avatar Mar 15 '24 16:03 bridgekeeper[bot]

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

8328278: Do not print the tenuring threshold in AgeTable::print_on

Reviewed-by: ayang, ysr

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

  • 92f5c0be8e3b47343b54a26940df691faaf49b23: 8323682: C2: guard check is not generated in Arrays.copyOfRange intrinsic when allocation is eliminated by EA
  • 866e7b6b7745928e559da8cdf622bf6a097ec995: 8329174: update CodeBuffer layout in comment after constants section moved
  • f88f31dcbf80e9a4cd3ba9d34be8b88128af97c6: 8328137: PreserveAllAnnotations can cause failure of class retransformation
  • 021ed6aea92f770ebeae65175d94797f7c418c82: 8328648: Remove applet usage from JFileChooser tests bug4150029
  • 3057dded4878b0110bc2c09b52019570a0a31c9f: 8329421: Native methods can not be selectively printed
  • db159149c1c13a98ee9a85750741c6a3cd39f408: 8328753: Open source few Undecorated Frame tests
  • 925d82931c09dc11ea5a3bc410ea5cfd67ee14aa: 8329013: StackOverflowError when starting Apache Tomcat with signed jar
  • dd5d7d0770609a414438041f40a69f8770afe25c: 8327002: (fs) java/nio/file/Files/CopyMoveVariations.java should be able to test across file systems
  • 6ae1cf12cee268ac7599eb9ade9c0861a89748f9: 8329368: Generational ZGC: Remove the unnecessary friend classes in ZAllocator
  • 7eb78e332080df3890b66ca04338a4ba69af45eb: 8320676: Manual printer tests have no Pass/Fail buttons, instructions close set 1
  • ... and 4 more: https://git.openjdk.org/jdk/compare/8b934aab1402ea74ac1fb7b56bfb9840f932ccb1...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[bot] avatar Mar 15 '24 16:03 openjdk[bot]

@lgxbslgx 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[bot] avatar Mar 15 '24 16:03 openjdk[bot]

Webrevs

mlbridge[bot] avatar Mar 16 '24 22:03 mlbridge[bot]

so that the method AgeTable::print_on prints the right tenuring threshold

Can you elaborate on this? As I understand the code, whether computing the threshold at the end of young-gc-pause or at the start of (next) young-gc-pause doesn't make any diff in the value of the threshold.

Also, why does this patch remove age_table()->print_age_table..?

albertnetymk avatar Mar 18 '24 15:03 albertnetymk

Can you elaborate on this? As I understand the code, whether computing the threshold at the end of young-gc-pause or at the start of (next) young-gc-pause doesn't make any diff in the value of the threshold.

Just like the G1, the normal flow is:

  • Compute the threshold according to the last age table
  • Run GC and tenure according to the threshold
  • Print the threshold and the age table

But in current serial GC, the flow is:

  • Run GC and tenure according to the new threshold.
  • Compute the new threshold according to the last age table.
  • Print the threshold and the age table.

The last two steps of the serial GC are wrong. Because the threshold we print is not the threshold we used during GC.

Also, why does this patch remove age_table()->print_age_table..?

I just moved it to the end of the GC. Notice the adjust_desired_tenuring_threshold is moved to the start of the GC.

lgxbslgx avatar Mar 18 '24 16:03 lgxbslgx

Thanks for the explanation.

Print the threshold and the age table.

I think there are two possible interpretations re the printed value here:

  1. the printed threshold and age-table are directly related -- the threshold is calculated from the age-table.

  2. the printed threshold and age-table are corresponding to the just finished gc-pause (since printing is at the end of gc-pause). IOW, threshold is used during scavenging and age-table is populated during scavenging.

I think what you have in mind is 2 (right?), and that is what G1 does.

It's not obvious that one is more "correct" than the other. (My first impression is 1, since AgeTable has a method to calculate the threshold.)

albertnetymk avatar Mar 18 '24 16:03 albertnetymk

  1. the printed threshold and age-table are directly related -- the threshold is calculated from the age-table.
  2. the printed threshold and age-table are corresponding to the just finished gc-pause (since printing is at the end of gc-pause). IOW, threshold is used during scavenging and age-table is populated during scavenging.

I think what you have in mind is 2 (right?), and that is what G1 does.

Yes, I think the second one is right.

If we use the first one, please consider such condition:

  • The threshold used by GC is 13, so the first 14 rows of the age table has non-zero values.
  • Assume the new threshold is computed to 12.
  • Then the message we print, Age table with threshold 12, is strange, because the age table we then print has 14 rows of non-zero values.

If you still think the second one is better. The Age table with threshold %u (max threshold %u) may be revised to a clearer message. And the G1 need to be adjusted too.

void AgeTable::print_on(outputStream* st, uint tenuring_threshold) {
  st->print_cr("Age table with threshold %u (max threshold %u)",
               tenuring_threshold, MaxTenuringThreshold);

lgxbslgx avatar Mar 18 '24 16:03 lgxbslgx

In https://bugs.openjdk.org/browse/JDK-8328278, you state:

But the Serial GC computes tenuring threshold and prints new age table both after per GC. It causes the method AgeTable::print_on prints the wrong tenuring threshold.

Can you provide examples on how it "prints the wrong tenuring threshold" to illustrate the bug you had in mind that this is attempting to fix?

ysramakrishna avatar Mar 19 '24 01:03 ysramakrishna

Where you state above that:

Then the message we print, Age table with threshold 12, is strange, because the age table we then print has 14 rows of non-zero values.

That's OK, because the threshold 12 is the new threshold computed based on the age table stats presented in the table, corresponding to the demographics recorded in this collection. The new tenuring threshold will be used in the next collection.

May be we can start by sharing, as I requested in my previous comment, with a G1GC and a SerialGC log and discuss what is the bug you are trying to fix. It's better to use concrete examples rather than just describing the output in English sentences.

ysramakrishna avatar Mar 19 '24 01:03 ysramakrishna

  1. the printed threshold and age-table are directly related -- the threshold is calculated from the age-table.
  2. the printed threshold and age-table are corresponding to the just finished gc-pause (since printing is at the end of gc-pause). IOW, threshold is used during scavenging and age-table is populated during scavenging.

@ysramakrishna Previously, I thought the second point is right. So I said It causes the method AgeTable::print_on prints the wrong tenuring threshold in my issue description.

That's OK, because the threshold 12 is the new threshold computed based on the age table stats presented in the table, corresponding to the demographics recorded in this collection. The new tenuring threshold will be used in the next collection.

But now, you and @albertnetymk said the first one is also acceptable and may be better. So currently, the main problem is not that AgeTable::print_on prints the wrong tenuring threshold. The problem becomes: G1 and Serial have inconsistent behaviour. The G1 prints the old threshold and the Serial GC prints the new threshold. Such inconsistence is obvious when reading the code. So what we should do now is decide which behaviour is right and unify the behaviour of these two GCs.

lgxbslgx avatar Mar 19 '24 02:03 lgxbslgx

That's OK, because the threshold 12 is the new threshold computed based on the age table stats presented in the table, corresponding to the demographics recorded in this collection. The new tenuring threshold will be used in the next collection.

So what we should do now is decide which behaviour is right and unify the behaviour of these two GCs.

And now, I lean to agree with you that the new threshold should be printed. The message Age table with threshold %u can be interpreted as: the threshold is computed according to the following age table.

lgxbslgx avatar Mar 19 '24 02:03 lgxbslgx

because the threshold 12 is the new threshold computed based on the age table stats presented in the table, corresponding to the demographics recorded in this collection.

This is how I interpreted the output as well, but Serial and G1 differ here. The printed format is identical, -Xlog:gc+age=trace:

# Serial
[4.318s][trace][gc,age] GC(2) Age table with threshold 15 (max threshold 15)

# G1
[3.156s][trace][gc,age] GC(4) Age table with threshold 1 (max threshold 15)

In the Serial case, threshold 15 refers to the threshold that will be use in next gc-pause GC(3), while threshold 1 refers to the value used in current gc-pause GC(4).

(One should check callers of AgeTable::print_age_table to get the actual semantics of the printed threshold.)

May be we can start by sharing, as I requested in my previous comment, with a G1GC and a SerialGC log and discuss what is the bug you are trying to fix.

Hopefully, with the example above, you agree this is a problem?

albertnetymk avatar Mar 19 '24 09:03 albertnetymk

Hopefully, with the example above, you agree this is a problem?

Thank you for the examples, and the explanation, Guoxiong and Albert. I agree that it would seem useful to fix the inconsistency. I'll take a look at the proposed changes in light of this. Sorry for the delay.

ysramakrishna avatar Mar 20 '24 15:03 ysramakrishna

I agree that it would seem useful to fix the inconsistency.

Terrific.

Regarding how to address the issue, after considering it further, I believe the threshold is not intrinsically linked to the age table. Therefore, it likely makes sense to exclude it from the age-table print_age_table. Specific collectors could choose to include the threshold in the log if they find it valuable. Then, this removes the ambiguity in the print_age_table output. What do others think?

albertnetymk avatar Mar 20 '24 17:03 albertnetymk

Regarding how to address the issue, after considering it further, I believe the threshold is not intrinsically linked to the age table. Therefore, it likely makes sense to exclude it from the age-table print_age_table. Specific collectors could choose to include the threshold in the log if they find it valuable. Then, this removes the ambiguity in the print_age_table output. What do others think?

I agree. The threshold doesn't need to be printed in print_age_table.

lgxbslgx avatar Mar 20 '24 17:03 lgxbslgx

Regarding how to address the issue, after considering it further, I believe the threshold is not intrinsically linked to the age table. Therefore, it likely makes sense to exclude it from the age-table print_age_table. Specific collectors could choose to include the threshold in the log if they find it valuable. Then, this removes the ambiguity in the print_age_table output. What do others think?

I agree. The threshold doesn't need to be printed in print_age_table.

If nobody disagrees, I will change the code today.

lgxbslgx avatar Mar 22 '24 02:03 lgxbslgx

@albertnetymk Thanks for the review. I updated one test.

And waiting for another review.

lgxbslgx avatar Mar 25 '24 14:03 lgxbslgx

It looks as if you are now suppressing the tenuring threshold printing entirely? In a sense that is a crucial part of what one looks at in GC logs. May be I am missing something.

When computing the threshold, the threshold will be printed. Please read the method AgeTable::compute_tenuring_threshold.

Could you share for both G1 and for Serial, the before and after logs with +PrintTenuringDistribution ?

Currently, the option -XX:+PrintTenuringDistribution is not available in mainline, we can use -Xlog:gc+age*=trace instead.

lgxbslgx avatar Mar 26 '24 09:03 lgxbslgx

Could you share for both G1 and for Serial, the before and after logs with +PrintTenuringDistribution ?

Using -Xlog:gc+age=trace:

## baseline
[5.527s][debug][gc,age] GC(0) Desired survivor size 6979584 bytes, new threshold 1 (max threshold 15)
[5.527s][trace][gc,age] GC(0) Age table with threshold 1 (max threshold 15)
[5.527s][trace][gc,age] GC(0) - age   1:   13959168 bytes,   13959168 total

## new
[4.196s][debug][gc,age] GC(0) Desired survivor size 6979584 bytes, new threshold 1 (max threshold 15)
[4.196s][trace][gc,age] GC(0) Age table:
[4.196s][trace][gc,age] GC(0) - age   1:   13959160 bytes,   13959160 total

@lgxbslgx Could you merge master?

albertnetymk avatar Apr 02 '24 10:04 albertnetymk

@lgxbslgx Could you merge master?

Merged just now.

lgxbslgx avatar Apr 02 '24 10:04 lgxbslgx

@albertnetymk @ysramakrishna Thanks for the review.

/integrate

lgxbslgx avatar Apr 03 '24 07:04 lgxbslgx

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

  • 16b842af8edd10c4071eec98caf838a2f6c49746: 8329355: Test compiler/c2/irTests/TestIfMinMax.java fails on RISC-V
  • 92f5c0be8e3b47343b54a26940df691faaf49b23: 8323682: C2: guard check is not generated in Arrays.copyOfRange intrinsic when allocation is eliminated by EA
  • 866e7b6b7745928e559da8cdf622bf6a097ec995: 8329174: update CodeBuffer layout in comment after constants section moved
  • f88f31dcbf80e9a4cd3ba9d34be8b88128af97c6: 8328137: PreserveAllAnnotations can cause failure of class retransformation
  • 021ed6aea92f770ebeae65175d94797f7c418c82: 8328648: Remove applet usage from JFileChooser tests bug4150029
  • 3057dded4878b0110bc2c09b52019570a0a31c9f: 8329421: Native methods can not be selectively printed
  • db159149c1c13a98ee9a85750741c6a3cd39f408: 8328753: Open source few Undecorated Frame tests
  • 925d82931c09dc11ea5a3bc410ea5cfd67ee14aa: 8329013: StackOverflowError when starting Apache Tomcat with signed jar
  • dd5d7d0770609a414438041f40a69f8770afe25c: 8327002: (fs) java/nio/file/Files/CopyMoveVariations.java should be able to test across file systems
  • 6ae1cf12cee268ac7599eb9ade9c0861a89748f9: 8329368: Generational ZGC: Remove the unnecessary friend classes in ZAllocator
  • ... and 5 more: https://git.openjdk.org/jdk/compare/8b934aab1402ea74ac1fb7b56bfb9840f932ccb1...master

Your commit was automatically rebased without conflicts.

openjdk[bot] avatar Apr 03 '24 07:04 openjdk[bot]

@lgxbslgx Pushed as commit e3e6c2a8991fbc4f56e051e9abe004f0aa5674a0.

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

openjdk[bot] avatar Apr 03 '24 07:04 openjdk[bot]