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

JDK-8296931: NMT tests slowed down considerably by JDK-8242181 #11135

Conversation

tstuefe
Copy link
Member

@tstuefe tstuefe commented Nov 14, 2022

We noticed that NMT tests on our slower PPC machines started failing.

The reason is that NMT detail reports have become 2-5x slower. This is caused by us now parsing the dwarf debug information to extract source information for each PC in each call stack. That is nice but costly.

The slowdown is not limited to PPC, it affects all Elf platforms. On my Linux x64 box, runtime/NMT/VirtualAllocCommitMerge.java increased from 20 to 90 seconds.


This patch simply removes source info from NMT call stacks. They are not that important for pinpointing leaks and such. I considered more involved solutions, like making them optional via an argument to the NMT report command, but decided against it. The added benefit would be small, not worth much complexity.

With this patch, on my box with -conc 4 all NMT together are about 2.5 x faster (2m56 -> 1m09).


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-8296931: NMT tests slowed down considerably by JDK-8242181

Reviewers

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 11135

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

Using diff file

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

@bridgekeeper
Copy link

bridgekeeper bot commented Nov 14, 2022

👋 Welcome back stuefe! 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 Nov 14, 2022

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

  • hotspot

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 hotspot-dev@openjdk.org label Nov 14, 2022
@tstuefe tstuefe changed the title JDK-8296931: NMT detail reports seriously slowed down by JDK-8242181 JDK-8296931: NMT tests slowed down considerably by JDK-8242181 Nov 14, 2022
@tstuefe tstuefe force-pushed the JDK-8296931-NMT-detail-reports-costly-since-JDK-8242181 branch from fe7f710 to 76330a6 Compare November 14, 2022 15:04
@tstuefe tstuefe marked this pull request as ready for review November 14, 2022 15:12
@openjdk openjdk bot added the rfr Pull request is ready for review label Nov 14, 2022
@mlbridge
Copy link

mlbridge bot commented Nov 14, 2022

Webrevs

@dholmes-ora
Copy link
Member

I think we need some input from @chhagedorn on this.

Copy link
Member

@chhagedorn chhagedorn left a comment

Choose a reason for hiding this comment

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

Thanks for the closer analysis of execution time. I agree with your proposed solution and deciding against an additional option/flag, given the complexity and the limited benefit. The main purpose and motivation behind JDK-8242181 was to get the additional source information in hs_err files.

}
// Note: we deliberately omit printing source information here. NativeCallStack::print_on()
// can be called thousands of times as part of NMT detail reporting, and source printing
// can slow down reporting by a factor of 5 or more depending on platform (see JDK-8296931).
Copy link
Member

Choose a reason for hiding this comment

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

I'm not sure what the convention is, should we still directly refer to bug numbers in comments?

@openjdk
Copy link

openjdk bot commented Nov 15, 2022

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

8296931: NMT tests slowed down considerably by JDK-8242181

Reviewed-by: chagedorn, mbaesken

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

  • c49e484: 8294739: jdk/jshell/ToolShiftTabTest.java timed out
  • a45c9af: 8295814: jdk/jshell/CommandCompletionTest.java fails with "lists don't have the same size expected [2] but found [1]"
  • d0fae43: 8294947: Use 64bit atomics in patch_verified_entry on x86_64
  • 6f467cd: 8295934: IGV: keep node selection when changing view or graph
  • 9adb728: 8295070: Introduce more target combinations for compiler flags
  • 8ab70d3: 8294775: Shenandoah: reduce contention on _threads_in_evac
  • 5551cb6: 8293166: jdk/jfr/jvm/TestDumpOnCrash.java fails on Linux ppc64le and Linux aarch64
  • 8a9eabb: 8296786: Limit VM modes for com/sun/jdi/JdbLastErrorTest.java
  • 873eccd: 8296923: JFR: jfr --version should return System.getProperty("java version")
  • 93d6b1f: 8295711: Rename ZBarrierSetAssembler::load_at parameter name from "tmp_thread" to "tmp2"
  • ... and 12 more: https://git.openjdk.org/jdk/compare/3f401b309124eecef7a39aac663bb5e8808a4476...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 Nov 15, 2022
@tstuefe
Copy link
Member Author

tstuefe commented Nov 15, 2022

Thank you @chhagedorn!

I also think NMT is special since we print thousands of callstacks, not just one as we do in error reporting.

About mentioning JBS issues, not sure. Not sure what the harm would be. Lets ask @dholmes-ora ?

Copy link
Member

@MBaesken MBaesken left a comment

Choose a reason for hiding this comment

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

LGTM

@tstuefe
Copy link
Member Author

tstuefe commented Nov 15, 2022

LGTM

Thank you!

@tstuefe
Copy link
Member Author

tstuefe commented Nov 16, 2022

No feedback from David. Since this matter is a bit pressing - affects runtime of our GHAs and internal tests - I'll commit now.

/integrate

@openjdk
Copy link

openjdk bot commented Nov 16, 2022

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

  • 65f7de2: 8022403: sun/java2d/DirectX/OnScreenRenderingResizeTest/OnScreenRenderingResizeTest.java fails
  • 3f2f128: 8295952: Problemlist existing compiler/rtm tests also on x86
  • 6ead2b0: 8296548: Improve MD5 intrinsic for x86_64
  • bd3acbe: 8297089: [BACKOUT] JDK-8297088 Update LCMS to 2.14
  • 6a60d31: 8295369: Update LCMS to 2.14
  • 0cbf084: 8296969: C1: PrintC1Statistics is broken after JDK-8292878
  • f662a06: 8296970: Remove sysThreadAvailableStackWithSlack from hotspot-symbols
  • 7357a1a: 8296889: Race condition when cancelling a request
  • 87530e6: 8296913: Correct enable preview idiom in JdbLastErrorTest.java
  • fafe682: 8295861: get rid of list argument in debug agent's removeNode() API
  • ... and 27 more: https://git.openjdk.org/jdk/compare/3f401b309124eecef7a39aac663bb5e8808a4476...master

Your commit was automatically rebased without conflicts.

@openjdk openjdk bot added the integrated Pull request has been integrated label Nov 16, 2022
@openjdk openjdk bot closed this Nov 16, 2022
@openjdk openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Nov 16, 2022
@openjdk
Copy link

openjdk bot commented Nov 16, 2022

@tstuefe Pushed as commit 5e08b3f.

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

@dholmes-ora
Copy link
Member

Sorry have been swamped past couple of days.

From the style guide:

As a general rule don't add bug numbers to comments (they would soon overwhelm the code). But if the bug report contains significant information that can't reasonably be added as a comment, then refer to the bug report.

I would probably not have added it in this case but its a judgment call.

@tstuefe
Copy link
Member Author

tstuefe commented Nov 17, 2022

Sorry have been swamped past couple of days.

From the style guide:

As a general rule don't add bug numbers to comments (they would soon overwhelm the code). But if the bug report contains significant information that can't reasonably be added as a comment, then refer to the bug report.

I would probably not have added it in this case but its a judgment call.

Okay, good to know. I'll remove it should I touch the code again. Not worth a separate RFE.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
hotspot hotspot-dev@openjdk.org integrated Pull request has been integrated
4 participants