Skip to content

Conversation

@sercher
Copy link
Contributor

@sercher sercher commented Jul 23, 2021

Dear colleagues,

Please review the patch that replaces the lambdas with anonymous classes which solves the startup time regression as shown below.

I attached the Bytestacks flamegraphs for both original (regression) and fixed versions. The flamegraphs clearly show the lambdas were causing the performance issue.

bytestacks_flamegraphs.zip

Although the proposed JDK-8270321 patch fixes the startup time (it might appear even better than it was before the regression was introduced, i.e. before JDK-8266310) and generally fixes the footprint regression, it may increase MaxRSS slightly compared to the version before JDK-8266310, which is shown in the below graphs. (updated)

StartupTime2

MaxRSS

(update: added ZGC graphs)

StartupTime_ZGC

MaxRSS_ZGC

I additionally include the heap objects histograms to show the change does not increase the total live objects size significantly with only 1000 bytes the total difference, namely 1116128 bytes in 25002 live objects after the proposed fix JDK-8270321 compared to 1115128 bytes in 24990 objects in the version with the original patch reverted (i.e. before JDK-8266310).

histograms.zip

The patch was tested w/hotspot/tier1/tier2 test groups.


Progress

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

Issue

  • JDK-8270321: Startup regressions in 18-b5 caused by JDK-8266310

Reviewers

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 4893

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

Using diff file

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

@bridgekeeper
Copy link

bridgekeeper bot commented Jul 23, 2021

👋 Welcome back sercher! 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 openjdk bot added the rfr Pull request is ready for review label Jul 23, 2021
@openjdk
Copy link

openjdk bot commented Jul 23, 2021

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

  • core-libs

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 core-libs core-libs-dev@openjdk.org label Jul 23, 2021
@mlbridge
Copy link

mlbridge bot commented Jul 23, 2021

Webrevs

@forax
Copy link
Member

forax commented Jul 23, 2021

I don't understand your analysis, you are testing the startup time with -Xint which disable JITs, but there is no mention of -Xint in the bug report.
It's obvious to me that there is a regression with -Xint given that the lambda creation is using invokedynamic which is only optimizable by JITs.

I think you should first try to reproduce the issue with the correct flags and then follow the advice from Mandy on how to implement the fix. Using an anonymous class may introduce more allocation than using a lambda once the code is JITed.

@sercher
Copy link
Contributor Author

sercher commented Jul 25, 2021

Hi Rémi,

I don't understand your analysis, you are testing the startup time with -Xint which disable JITs, but there is no mention of -Xint in the bug report.
It's obvious to me that there is a regression with -Xint given that the lambda creation is using invokedynamic which is only optimizable by JITs.

I apologize, perhaps I wasn't quite clear describing the analysis. Also, there was a faulty picture, -Xint was only used to grab the opcode traces to build the flamegraphs. I replaced the faulty image and posted additional graphs with -XX:+UseZGC.
Performance (startup) testing, as well as the live objects dumps were obtained with JIT enabled and with G1GC and ZGC. Would you think more data is needed with -Xint? (in addition to the flamegraphs which are obtained with -Xint)

I think you should first try to reproduce the issue with the correct flags and then follow the advice from Mandy on how to implement the fix.

In my opinion removing computeXXX methods defeats the purpose of the entire deadlock fix. It is sufficient to avoid using lambdas in order not to trigger the method handles initialization, which is what Mandy Chung is really suggesting in the first note in JBS.

Using an anonymous class may introduce more allocation than using a lambda once the code is JITed.

I provided live objects dumps after noop.jar has been loaded with JIT enabled. Please see the attached histograms. The difference is always the same after full GC (1000 bytes in 12 objects compared to pre JDK-8266310 version tested w/G1) and it doesn't change with subsequent executions. The patch resolves the memory regression as you may observe in RSS graphs and heap dumps. Please see 'fixed.histogram' in comparison with the object dump before the fix (post JDK-8266310) in 'original.histogram'.

@AlanBateman
Copy link
Contributor

I don't understand your analysis, you are testing the startup time with -Xint which disable JITs, but there is no mention of -Xint in the bug report.
It's obvious to me that there is a regression with -Xint given that the lambda creation is using invokedynamic which is only optimizable by JITs.

Eric Caspole (the submitter) may be able to share more data but the startup regression looks plausible given that this code executes early in the startup.

@mlchung
Copy link
Member

mlchung commented Jul 26, 2021

NativeLibraries was called early during VM startup and the startup benchmark is just a Noop. So the lambda creation by NativeLibraries is likely still running in interpreted mode.

Looks like replacing it with an anonymous class may be an alternative. I ran a few startup benchmarks on linux x64 with this patch. It does show that the startup regression is fixed and also the footprint benchmark I included does not show any regression.

@forax
Copy link
Member

forax commented Jul 26, 2021

Hi Sergey,
thanks for the explanation, i don't think there is a need for more data with -Xint.

Using anonymous classes instead of lambdas is good for me.

@openjdk
Copy link

openjdk bot commented Jul 26, 2021

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

8270321: Startup regressions in 18-b5 caused by JDK-8266310

Reviewed-by: mchung, alanb

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

  • 89f5c96: 8232066: Remove outdated code/methods from PKIX implementation
  • 9856ace: 8268963: [IR Framework] Some default regexes matching on PrintOptoAssembly in IRNode.java do not work on all platforms
  • b59418f: 8270060: (jdeprscan) tools/jdeprscan/tests/jdk/jdeprscan/TestRelease.java failed with class file for jdk.internal.util.random.RandomSupport not found
  • 4f42eb6: 8269523: runtime/Safepoint/TestAbortOnVMOperationTimeout.java failed when expecting 'VM operation took too long'
  • 77fbd99: 8270341: Test serviceability/dcmd/gc/HeapDumpAllTest.java timed-out
  • 048fb2c: Merge
  • 286d313: 8271489: (doc) Clarify Filter Factory example
  • d09b028: 8271396: Spelling errors
  • 489e5fd: 8268019: C2: assert(no_dead_loop) failed: dead loop detected
  • 6afcf5f: 8270886: Crash in PhaseIdealLoop::verify_strip_mined_scheduling
  • ... and 62 more: https://git.openjdk.java.net/jdk/compare/ec71e2d891fdb9b102ce232f65cfcc5c6a1a9580...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 (@mlchung, @AlanBateman) 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 Jul 26, 2021
@voitylov
Copy link

Thanks Sergey for dealing with this while I was on vacation, and sorry for causing this regression! Looks good (not a reviewer).

@sercher
Copy link
Contributor Author

sercher commented Jul 30, 2021

/integrate

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

openjdk bot commented Jul 30, 2021

@sercher
Your change (at version 6940aac) is now ready to be sponsored by a Committer.

@AlexanderScherbatiy
Copy link

/sponsor

@openjdk
Copy link

openjdk bot commented Jul 30, 2021

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

  • baf7797: 8049301: Suspicious use of string identity checks in JComponent.setUIProperty
  • 89f5c96: 8232066: Remove outdated code/methods from PKIX implementation
  • 9856ace: 8268963: [IR Framework] Some default regexes matching on PrintOptoAssembly in IRNode.java do not work on all platforms
  • b59418f: 8270060: (jdeprscan) tools/jdeprscan/tests/jdk/jdeprscan/TestRelease.java failed with class file for jdk.internal.util.random.RandomSupport not found
  • 4f42eb6: 8269523: runtime/Safepoint/TestAbortOnVMOperationTimeout.java failed when expecting 'VM operation took too long'
  • 77fbd99: 8270341: Test serviceability/dcmd/gc/HeapDumpAllTest.java timed-out
  • 048fb2c: Merge
  • 286d313: 8271489: (doc) Clarify Filter Factory example
  • d09b028: 8271396: Spelling errors
  • 489e5fd: 8268019: C2: assert(no_dead_loop) failed: dead loop detected
  • ... and 63 more: https://git.openjdk.java.net/jdk/compare/ec71e2d891fdb9b102ce232f65cfcc5c6a1a9580...master

Your commit was automatically rebased without conflicts.

@openjdk openjdk bot closed this Jul 30, 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 sponsor Pull request is ready to be sponsored labels Jul 30, 2021
@openjdk
Copy link

openjdk bot commented Jul 30, 2021

@AlexanderScherbatiy @sercher Pushed as commit 5b3c418.

💡 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

core-libs core-libs-dev@openjdk.org integrated Pull request has been integrated

Development

Successfully merging this pull request may close these issues.

6 participants