8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 #14732

rwestrel · 2023-06-30T13:23:38Z

A long chain of nodes are sunk out of a loop. Every time a node is
moved out of the loop, a cast is created to pin the node out of the
loop. When its input is next sunk, the cast is removed (the cast is
replaced by its input) and a new cast is created. Some nodes on the
chain have 2 other nodes in the chain as uses. When such a node is
sunk, 2 cast nodes are created, one for each use. So as the compiler
moves forward in the chain, the number of cast to remove grows. From
some profiling, removing those casts is what takes a lot of time.

The fix I propose is, when a node is processed, to check whether a
cast at the out of loop control was already created for that node and
to reuse it.

The test case takes 6 minutes when I run it without the fix and 3
seconds with it.

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-8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 (Bug - P3)

Reviewers

Vladimir Kozlov (@vnkozlov - Reviewer) ⚠️ Review applies to cdb24902
Tobias Hartmann (@TobiHartmann - Reviewer) ⚠️ Review applies to cdb24902
Christian Hagedorn (@chhagedorn - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 14732

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

Using diff file

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

Webrev

Link to Webrev Comment

bridgekeeper · 2023-06-30T13:24:43Z

👋 Welcome back roland! 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 · 2023-06-30T13:27:34Z

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

hotspot-compiler

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.

mlbridge · 2023-06-30T13:32:12Z

Webrevs

01: Full - Incremental (c3ba2887)
00: Full (cdb24902)

vnkozlov · 2023-06-30T17:28:03Z

src/hotspot/share/opto/loopopts.cpp

+                  cast->destruct(&_igvn);
+                  cast = prev;
+                } else {
+                  register_new_node(cast, x_ctrl);


Can you move creation of cast here so you don't need to destroy it in case of previous cast existance?
Or it is possible that ConstraintCastNode::make_cast_for_type() can return null`?

Thanks for looking at this, Vladimir.
I'm not sure I understand what you're suggesting. Is it to not allocate a new node so it doesn't have to be destroyed if an identical node exist? But without a node it's not possible to rely on IGVN hashing?

You are right. Using hash to look for existing node is smart.

chhagedorn · 2023-07-03T06:05:09Z

test/hotspot/jtreg/compiler/loopopts/TestSinkingNodesCausesLongCompilation.java

+ * @test
+ * @bug 8308103
+ * @summary Massive (up to ~30x) increase in C2 compilation time since JDK 17
+ * @run main/othervm -Xcomp -XX:CompileOnly=TestSinkingNodesCausesLongCompilation::mainTest -XX:RepeatCompilation=30 TestSinkingNodesCausesLongCompilation


You should add -XX:+UnlockDiagnosticVMOptions since RepeatCompilation is diagnostic.

chhagedorn · 2023-07-03T06:05:59Z

test/hotspot/jtreg/compiler/loopopts/TestSinkingNodesCausesLongCompilation.java

+
+    public static void main(String[] strArr) {
+        TestSinkingNodesCausesLongCompilation _instance = new TestSinkingNodesCausesLongCompilation();
+        for (int i = 0; i < 10; i++ ) {


Suggested change

for (int i = 0; i < 10; i++ ) {

for (int i = 0; i < 10; i++) {

Thanks for the comments. I updated the change.

vnkozlov

Good.

openjdk · 2023-07-11T16:07:03Z

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

8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17

Reviewed-by: kvn, thartmann, chagedorn

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

82612e2: 8312329: Minimal build failure after JDK-8311541
702fea8: 8312147: Dynamic Exception Specification warnings are no longer required after JDK-8311380
e5ecbff: 8312203: Improve specification of Array.newInstance
c2f421b: 8311541: JavaThread::print_jni_stack doesn't support native stacks on all platforms
e31df3a: 6211126: ICC_ColorSpace.toCIEXYZ(float[]): NPE is not specified
7d9f5af: 6211202: ColorSpace.getInstance(int): IAE is not specified
28c4d19: 8311902: Concurrency regression in the PBKDF2 key impl of SunJCE provider
5c4623b: 8308682: Enhance AES performance
cb5f1b7: 8303376: Better launching of JDI
925138a: 8296565: Enhanced archival support
... and 74 more: https://git.openjdk.org/jdk/compare/aa7367f1ecc5da15591963e56e1435aa7b830f79...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.

TobiHartmann

The fix looks good to me but I still have a hard time to comprehend that this leads to a 30x increase in compilation time. And I'm worried that we have similar issues in other code. As a follow-up, could we have PhaseIdealLoop::register_new_node check the hash and return an existing node?

rwestrel · 2023-07-13T15:42:01Z

The fix looks good to me but I still have a hard time to comprehend that this leads to a 30x increase in compilation time. And I'm worried that we have similar issues in other code. As a follow-up, could we have PhaseIdealLoop::register_new_node check the hash and return an existing node?

There's an exponential increase of the number of casts that are created.

First node to be sunk is:

  386  RShiftI  === _ 385 316  [[ 441 417 429 ]]  !orig=[615] !jvms: TestSinkingNodesCausesLongCompilation::mainTest @ bci:104 (line 46)

It has 3 uses so 3 casts are created:

 1137  CastII  === 426 385  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1139  CastII  === 414 385  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1141  CastII  === 438 385  [[ ]]  #int unconditional dependency

385  AddI  === _ 384 605  [[ 1141 1137 1139 ]]  !jvms: TestSinkingNodesCausesLongCompilation::mainTest @ bci:99 (line 45)

(input of previous one)
The 3 previous casts are removed and new ones are created:

 1143  CastII  === 414 384  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1145  CastII  === 426 384  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1147  CastII  === 438 384  [[ ]]  #int unconditional dependency

  384  LShiftI  === _ 605 383  [[ 1147 1143 1145 ]]  !jvms: TestSinkingNodesCausesLongCompilation::mainTest @ bci:99 (line 45)

input of previous one. Same as step before, 3 just created casts are moved and new ones created:

 1149  CastII  === 426 605  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1151  CastII  === 414 605  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1153  CastII  === 438 605  [[ ]]  #int unconditional dependency

  605  RShiftI  === _ 606 316  [[ 1146 1153 1142 1144 1149 1151 ]]  !orig=[386],[615] !jvms: TestSinkingNodesCausesLongCompilation::mainTest @ bci:104 (line 46)

which was input to both 384 and 385 just sunk. It has 6 uses. The 3 casts above and 3 clones of 385.
So 3 casts are removed and 6 casts are created:

 1155  CastII  === 414 606  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1157  CastII  === 426 606  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1159  CastII  === 426 606  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1161  CastII  === 414 606  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1163  CastII  === 438 606  [[ ]]  #int unconditional dependency                                                                                                                                                                                                                  
 1165  CastII  === 438 606  [[ ]]  #int unconditional dependency

The same sequence of nodes repeats and every 3 nodes there's a RShiftI and the number of clones double. At the last step, the number of casts is 12288. That happens after 39 nodes are sunk.

All of this seems pretty specific to that transformation so a local fix seems good enough to me.

TobiHartmann · 2023-07-17T05:39:31Z

Makes sense. Thanks for the details, Roland.

chhagedorn

Looks good to me, too!

rwestrel · 2023-07-19T07:30:48Z

@vnkozlov @TobiHartmann @chhagedorn thanks for the reviews.

rwestrel · 2023-07-19T11:30:36Z

/integrate

openjdk · 2023-07-19T11:31:51Z

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

d33e8e6: 8312200: Fix Parse::catch_call_exceptions memory leak
f677793: 8312190: Fix c++11-narrowing warnings in hotspot code
82612e2: 8312329: Minimal build failure after JDK-8311541
702fea8: 8312147: Dynamic Exception Specification warnings are no longer required after JDK-8311380
e5ecbff: 8312203: Improve specification of Array.newInstance
c2f421b: 8311541: JavaThread::print_jni_stack doesn't support native stacks on all platforms
e31df3a: 6211126: ICC_ColorSpace.toCIEXYZ(float[]): NPE is not specified
7d9f5af: 6211202: ColorSpace.getInstance(int): IAE is not specified
28c4d19: 8311902: Concurrency regression in the PBKDF2 key impl of SunJCE provider
5c4623b: 8308682: Enhance AES performance
... and 76 more: https://git.openjdk.org/jdk/compare/aa7367f1ecc5da15591963e56e1435aa7b830f79...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-07-19T11:32:02Z

@rwestrel Pushed as commit c6ab9c2.

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

fix & test

cdb2490

openjdk bot added the rfr Pull request is ready for review label Jun 30, 2023

openjdk bot added the hotspot-compiler hotspot-compiler-dev@openjdk.org label Jun 30, 2023

vnkozlov reviewed Jun 30, 2023

View reviewed changes

chhagedorn reviewed Jul 3, 2023

View reviewed changes

vnkozlov approved these changes Jul 11, 2023

View reviewed changes

openjdk bot added the ready Pull request is ready to be integrated label Jul 11, 2023

TobiHartmann approved these changes Jul 12, 2023

View reviewed changes

Merge branch 'master' into JDK-8308103

c544c2f

review

c3ba288

chhagedorn approved these changes Jul 19, 2023

View reviewed changes

openjdk bot added the integrated Pull request has been integrated label Jul 19, 2023

openjdk bot closed this Jul 19, 2023

openjdk bot removed ready Pull request is ready to be integrated rfr Pull request is ready for review labels Jul 19, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 #14732

8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 #14732

rwestrel commented Jun 30, 2023 •

edited by openjdk bot

Loading

bridgekeeper bot commented Jun 30, 2023

openjdk bot commented Jun 30, 2023

mlbridge bot commented Jun 30, 2023 •

edited

Loading

vnkozlov Jun 30, 2023

rwestrel Jul 11, 2023

vnkozlov Jul 11, 2023

chhagedorn Jul 3, 2023

chhagedorn Jul 3, 2023

rwestrel Jul 19, 2023

vnkozlov left a comment

openjdk bot commented Jul 11, 2023 •

edited

Loading

TobiHartmann left a comment

rwestrel commented Jul 13, 2023

TobiHartmann commented Jul 17, 2023

chhagedorn left a comment

rwestrel commented Jul 19, 2023

rwestrel commented Jul 19, 2023

openjdk bot commented Jul 19, 2023

openjdk bot commented Jul 19, 2023

	for (int i = 0; i < 10; i++ ) {
	for (int i = 0; i < 10; i++) {

8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 #14732

8308103: Massive (up to ~30x) increase in C2 compilation time since JDK 17 #14732

Conversation

rwestrel commented Jun 30, 2023 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

Webrev

bridgekeeper bot commented Jun 30, 2023

openjdk bot commented Jun 30, 2023

mlbridge bot commented Jun 30, 2023 • edited Loading

Webrevs

vnkozlov Jun 30, 2023

Choose a reason for hiding this comment

rwestrel Jul 11, 2023

Choose a reason for hiding this comment

vnkozlov Jul 11, 2023

Choose a reason for hiding this comment

chhagedorn Jul 3, 2023

Choose a reason for hiding this comment

chhagedorn Jul 3, 2023

Choose a reason for hiding this comment

rwestrel Jul 19, 2023

Choose a reason for hiding this comment

vnkozlov left a comment

Choose a reason for hiding this comment

openjdk bot commented Jul 11, 2023 • edited Loading

TobiHartmann left a comment

Choose a reason for hiding this comment

rwestrel commented Jul 13, 2023

TobiHartmann commented Jul 17, 2023

chhagedorn left a comment

Choose a reason for hiding this comment

rwestrel commented Jul 19, 2023

rwestrel commented Jul 19, 2023

openjdk bot commented Jul 19, 2023

openjdk bot commented Jul 19, 2023

rwestrel commented Jun 30, 2023 •

edited by openjdk bot

Loading

mlbridge bot commented Jun 30, 2023 •

edited

Loading

openjdk bot commented Jul 11, 2023 •

edited

Loading