JDK-8258603 c1 IR::verify is expensive #6850

LudwikJaniuk · 2021-12-15T15:39:26Z

IR::verify iterates the whole object graph. This proves costly when used in e.g. BlockMerger inside of iterations over BlockLists, leading to quadratic or worse complexities as a function of bytecode length. In several cases, only a few Blocks were changed, and there was no need to go over the whole graph, but until now there was no less blunt tool for verification than IR::verify.

This PR introduces IR::verify_local, intended to be used when only a defined set of blocks have been modified. As a complement, expand_with_neighbors provides a way to also capture the neighbors of the "modified set" ahead of modification, so that afterwards the appropriate asserts can be made on all blocks which might possibly have been changed. All this should let us remove the expensive IR::verify calls, while still performing equivalent (or stricter) assertions.

Some changes have been made in the verifiers along the way. Some amount of refactoring, and even added invariants (see validate_edge_mutiality).

Progress

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

Issue

JDK-8258603: c1 IR::verify is expensive

Reviewers

Christian Hagedorn (@chhagedorn - Reviewer)
Vladimir Kozlov (@vnkozlov - Reviewer)

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 6850

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

Using diff file

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

bridgekeeper · 2021-12-15T15:40:28Z

👋 Welcome back LudwikJaniuk! 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 · 2021-12-15T15:42:24Z

@LudwikJaniuk 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 · 2021-12-15T15:47:13Z

Webrevs

chhagedorn

I think it's a good idea to narrow the verification down to the blocks which are actually changed and also add some additional verification steps. Even with the newly added checks, it should still be better than running a complete check each time. Did you observe a big gain in the C1 compilation time for debug builds with your new patch? Maybe you also want to check again with the tests from openjdk/jdk16#44.

chhagedorn · 2021-12-15T16:21:42Z

src/hotspot/share/c1/c1_IR.cpp

+}
+
+void IR::verify_local(BlockList& blocks) {
+#ifdef ASSERT


Do we need an ASSERT here? The code is already guarded with ifndef PRODUCT. Same for L1447.

chhagedorn · 2021-12-15T16:22:34Z

src/hotspot/share/c1/c1_IR.cpp

+    BlockBegin* block = blocks.at(h);
+
+    for (int i = 0; i < block->end()->number_of_sux(); i++) {
+      if (blocks.contains(block->end()->sux_at(i))) continue;


To avoid confusion, I think it's better to always use braces for one-line ifs and loops instead.

chhagedorn · 2021-12-15T16:23:45Z

src/hotspot/share/c1/c1_IR.cpp

@@ -1359,24 +1370,95 @@ class PredecessorValidator : public BlockClosure {
  }
 };

-class VerifyBlockBeginField : public BlockClosure {
+inline void verify_block_begin_field(BlockBegin* block) {
+  for ( Instruction *cur = block; cur != NULL; cur = cur->next()) {


Same here, could this method also be directly inlined into block_do below? Spacing and asterisk position can be improved here.

chhagedorn · 2021-12-15T16:25:56Z

src/hotspot/share/c1/c1_IR.cpp

+};
+
+// Validation goals:
+// * code() length == blocks length


Just a minor thing, might be better to use - for the itemization instead of * as it looks like they belong to a block comment..

chhagedorn · 2021-12-15T16:32:56Z

src/hotspot/share/c1/c1_IR.cpp

@@ -1261,20 +1261,41 @@ void IR::print(bool cfg_only, bool live_only) {
  }
 }

+inline void validate_end_not_null(BlockBegin* block) {
+  assert(block->end() != NULL, "Expect block end to exist.");


As this method is just a single assertion and used from one place, you could directly inline it into block_do() below.

chhagedorn · 2021-12-15T16:43:59Z

src/hotspot/share/c1/c1_Optimizer.cpp

@@ -248,7 +257,9 @@ void CE_Eliminator::block_do(BlockBegin* block) {
    tty->print_cr("%d. IfOp in B%d", ifop_count(), block->block_id());
  }

-  _hir->verify();
+#ifdef ASSERT
+  _hir->verify_local(blocks_to_verify_later);


You can use NOT_PRODUCT() for single line statements (assuming you change the ASSERT into ifndef PRODUCT).

chhagedorn · 2021-12-15T16:44:22Z

src/hotspot/share/c1/c1_Optimizer.cpp

+#endif // ASSERT
+
+#ifdef ASSERT


Can be merged into one ifdef block.

I'm removing that specific verify_local call anyway, left in by accident

chhagedorn · 2021-12-16T09:47:00Z

src/hotspot/share/c1/c1_IR.cpp

  }
 };

 typedef GrowableArray<BlockList*> BlockListList;

-class PredecessorValidator : public BlockClosure {
+void verify_successor_xentry_flag(const BlockBegin* block) {


Could this method also be directly inlined into block_do below? The class name and assertion message should give enough information about the purpose of the check.

chhagedorn · 2021-12-16T09:48:48Z

src/hotspot/share/c1/c1_IR.cpp

-    for ( Instruction *cur = block; cur != NULL; cur = cur->next()) {
-      assert(cur->block() == block, "Block begin is not correct");
-    }
+void validate_edge_mutuality(BlockBegin* block) {


Same here, could this method also be directly inlined into block_do below?

chhagedorn · 2021-12-16T10:22:21Z

src/hotspot/share/c1/c1_IR.cpp

-  PredecessorValidator pv(this);
-  EndNotNullValidator(this);
+  XentryFlagValidator xe;
+  this->iterate_postorder(&xe);


You can remove this->.

LudwikJaniuk · 2021-12-16T12:32:47Z

@chhagedorn Thank you for the review! I will get to cleaning up the comments, and I'll also get back about changes in compilations times.

LudwikJaniuk · 2021-12-16T13:24:07Z

small local interspersed test with 2 first rounds discarded seems to show a slight increase in compilation time, which can be explained by the added checks:

	C1 compile time		Emit LIR
	this PR	master	this PR	master
	1,63	1,705	1,34	1,412
	1,701	1,563	1,412	1,276
	1,694	1,564	1,405	1,27
	1,704	1,593	1,406	1,306
	1,696	1,709	1,407	1,415
	1,704	1,622	1,418	1,335
	1,72	1,732	1,427	1,433
	1,686	1,712	1,396	1,42
avg	1,691875	1,65	1,401375	1,358375

Invocation:
for i in {1..10}; do .../jdk-myfix/bin/java -Xbatch -XX:+CITime compiler.c2.cr6340864.TestLongVect > time/myfix-$i.txt; .../jdk-master/bin/java -Xbatch -XX:+CITime compiler.c2.cr6340864.TestLongVect > time/master-$i.txt; done

LudwikJaniuk · 2021-12-16T13:27:12Z

Note that the timeouts of openjdk/jdk16#44 were remediated, likely by accident, in https://bugs.openjdk.java.net/browse/JDK-8267806, thus making it a worse candidate for testing this.

LudwikJaniuk · 2021-12-16T15:12:44Z

The increase in the previous test was likely not statistically significant, I ran a new test with 100 iterations and the difference seems gone.

100-2 iterations	C1 compile time		Emit LIR		Linear Scan
	my fix	master	my fix	master	my fix	master
avg	1,6151	1,617	1,3228	1,3238	1,2886	1,2893
variance	0,0024	0,002	0,0022	0,0019	0,0021	0,0018

LudwikJaniuk · 2021-12-16T16:07:01Z

A test on -version shows a clear reduction in Optimize time, leading to a small reduction in c1 compile time. I call this a "boosted test" because -XX:RepeatCompilation=10 -Xcomp -XX:TieredStopAtLevel=1 is used to make the time spent compiling in c1 longer and thereby measureable.

100-2 iterations	C1 comp time		Bulid HIR		Optimize
boosted -version	this PR	master	this PR	master	this PR	master
diff	−3%		−6%		−66,7%
avg	1,6185	1,6685	0,7651	0,8143	0,0325	0,0976
variance	0,0019	0,0019	0,0004	0,0005	0	0

Invocation:
for i in {1..100}; do .../jdk-master/bin/java -XX:RepeatCompilation=10 -Xcomp -XX:+CITime -XX:TieredStopAtLevel=1 -version > time/mast-$i.txt; .../jdk-myfix/bin/java -XX:RepeatCompilation=10 -Xcomp -XX:+CITime -XX:TieredStopAtLevel=1 -version > time/myfix-$i.txt; echo $i; done

LudwikJaniuk · 2021-12-16T16:08:52Z

And again, it's important to remember that the point of this fix is to protect against "worst cases" with e.g. functions with very long bytecode. The compile time improvement in the general case, if any, is only a bonus.

LudwikJaniuk · 2022-01-03T09:47:24Z

Whichever way the PRODUCT/ASSERT pendulum swings, what's for sure is that it needs to be consistent, so I decided to move it around "single source of truth"-style.

I'm not from the compiler team so I don't know the implications or the build process, but I'm surprised there isn't an answer to "how do we want to guard debug code?" I need a clear decision and guideline from the compiler team here.

chhagedorn · 2022-01-03T13:22:43Z

@vnkozlov You proposed changing c1_IR.cpp:1244 (I think you meant :1224) to #ifdef ASSERT. I tried it with an optimized build and this gave linking errors, specifically "undefined reference to IR::verify()." Seems likely to me that this is caused by mismatch withuse of PRODUCT_RETURN in c1_IR.hpp.

When applying these changes:

So the whole block of code in c1_IR.cpp is under #ifndef PRODUCT. But is it used in optimized build or only in debug?
I suggest to change #ifndef PRODUCT at line 1224 to #ifdef ASSERT and try to build optimized VM to see if it is used in it. I see only prints and asserts.

Shouldn't we leave BlockPrinter and IR::print() under #ifndef PRODUCT? These seem to be about printing things only which is probably good to have in optimized builds as well. We could instead just add an #ifdef ASSERT on L1263 for the validators and the IR verification and change the places using this code accordingly to #ifdef ASSERT/DEBUG_ONLY(). Then we would have everything under ASSERT instead of !PRODUCT. This would be in line with the original code which used #ifdef ASSERT in IR::verify().

I agree with christian's suggestion.

Then you can change PRODUCT_RETURN into NOT_DEBUG_RETURN to compile it and change __DO_DELAYED_VERIFICATION back to ASSERT.

My understanding is that assertion/verification code should be under ASSERT while additional debugging/printing code that is not available in product should be under !PRODUCT. But I don't know if that is documented somewhere officially and there are some places where it is mixed. I think there were also some discussions to move away from optimized builds completely.

chhagedorn · 2022-01-03T13:27:07Z

./build/optimized/images/jdk/bin/java -XX:+PrintCFG -version
CFG after parsing
B1 [0, 0] -> B2
B2 (S) [0, 0] -> B0 pred: B1
B0 (SV) [0, 0] pred: B2

CFG after optimizations
B1 [0, 0] -> B2
B2 (S) [0, 0] -> B0 pred: B1
B0 (SV) [0, 0] pred: B2

CFG after null check elimination
B1 [0, 0] -> B2
B2 (S) [0, 0] -> B0 dom B1 pred: B1
B0 (SV) [0, 0] dom B2 pred: B2

CFG before code generation
B1 [0, 0] -> B2
B2 (S) [0, 0] -> B0 dom B1 pred: B1
B0 (SV) [0, 0] dom B2 pred: B2
openjdk version "19-internal" 2022-09-20
OpenJDK Runtime Environment (build 19-internal+0-adhoc.opjaniuk.jdk)
OpenJDK 64-Bit Server VM (build 19-internal+0-adhoc.opjaniuk.jdk, mixed mode, sharing)

Is this as it should be?

Yes, that looks good. It accepts the non-product flag PrintCFG

vnkozlov · 2022-01-03T18:31:57Z

@vnkozlov You proposed changing c1_IR.cpp:1244 (I think you meant :1224) to #ifdef ASSERT. I tried it with an optimized build and this gave linking errors, specifically "undefined reference to IR::verify()." Seems likely to me that this is caused by mismatch withuse of PRODUCT_RETURN in c1_IR.hpp.

I did say 1224: "I suggest to change #ifndef PRODUCT at line 1224 to #ifdef ASSERT"

As Christian said, use NOT_DEBUG_RETURN for cases when the method body is defined only in debug build (under #ifdef ASSERT).

Note, my suggestion for changing !PRODUCT to ASSERT at line 1224 and build optimized VM was experiment we frequently use to find which functions are not use in optimized VM and which are used. It is usually faster than tracing usage in sources. I don't mean to use it in final changes. By using this experiment you can separate methods between !PRODUCT and ASSERT.

Please, use #ifdef ASSERT or DEBUG_ONLY() instead of __DO_DELAYED_VERIFICATION.

My understanding is that assertion/verification code should be under ASSERT while additional debugging/printing code that is not available in product should be under !PRODUCT. But I don't know if that is documented somewhere officially and there are some places where it is mixed. I think there were also some discussions to move away from optimized builds completely.

Yes, this is correct. The assertion/verification is used in our regular testing when we use fastdebug builds to catch issues.
Optimized build is mostly used to understand what is going on in build which is very similar to product.

Yes, we have RFE to remove optimized build and replace it with separate value check:
https://bugs.openjdk.java.net/browse/JDK-8202283

chhagedorn · 2022-01-04T08:34:03Z

Yes, this is correct. The assertion/verification is used in our regular testing when we use fastdebug builds to catch issues. Optimized build is mostly used to understand what is going on in build which is very similar to product.

Thanks for confirming that.

Yes, we have RFE to remove optimized build and replace it with separate value check: https://bugs.openjdk.java.net/browse/JDK-8202283

That's good to know!

LudwikJaniuk · 2022-01-04T11:45:32Z

There might be a prettier alternative than __DO_DELAYED_VERIFICATION, but I want to stress that my delayed-verification mechanism needs to be enabled in full, or not at all. I worry someone might change from ASSERT to !PRODUCT or vice versa on one but not all of the parts in the future. I worry that might lead to hard-to-debug problems. So, are you sure you'd like me to drop this SSOT-approach? If you're sure, I'll do it the way you wish.

So I understand the conclusion was to use ASSERT, NOT_DEBUG, and NOT_DEBUG_RETURN for all the code in this PR. Thank you.

@vnkozlov apologies if I got the line numbering wrong in my head somewhere there.

vnkozlov · 2022-01-04T20:02:07Z

I am not comfortable with repeated #ifdef around verification methods calls. But you have to pass local blocks_to_verify_later which is defined only in debug VM.

I'm fine with using __DO_DELAYED_VERIFICATION but add comment to the definition explaining what it is for.
Also don't use leading __ - we don't do that.

I think you can simply put verification methods declaration undo ASSERT in c1_IR.hpp:

   void print(bool cfg_only, bool live_only = false)                           PRODUCT_RETURN;
-  void verify()                                                               PRODUCT_RETURN;
+
+#ifdef ASSERT
+  void verify();
+  void expand_with_neighborhood();
+  void verify_local();
+#endif // ASSERT
 };

And put everything from class EndNotNullValidator to IR::verify() under #ifdef ASSERT in c1_IR.cpp.
(And move #endif // PRODUCT before class EndNotNullValidator.)
This way verification code will be defined only in debug VM and print code will be in optimized and debug VM.

vnkozlov · 2022-01-04T20:04:45Z

And please update copyright year to 2022 in changed files headers.

LudwikJaniuk · 2022-01-05T11:56:11Z

@vnkozlov Done, although using ASSERT in c1_IR.hpp didn't work because c1_Compilation.cpp makes several unguarded calls to IR::verify. I've left it with NOT_DEBUG_RETURN, hope that is ok.

I hope I've covered all the issues now, but please point it out if I've missed something.

chhagedorn

@vnkozlov Done, although using ASSERT in c1_IR.hpp didn't work because c1_Compilation.cpp makes several unguarded calls to IR::verify. I've left it with NOT_DEBUG_RETURN, hope that is ok.

I think that is fine. Otherwise, you need to wrap the calls in c1_compilation.cpp with NOT_DEBUG().

Thanks for doing the updates, they look good to me! If not already done, please verify once again that the optimized build is working with your latest changes before eventually integrating this ;-)

LudwikJaniuk · 2022-01-05T17:06:58Z

Yes, I did verify that.

vnkozlov

Looks good.

LudwikJaniuk · 2022-01-07T09:17:01Z

/integrate

openjdk · 2022-01-07T09:19:12Z

@LudwikJaniuk
Your change (at version de13762) is now ready to be sponsored by a Committer.

LudwikJaniuk · 2022-01-12T16:10:15Z

@vnkozlov @chhagedorn Could you please sponsor?

vnkozlov · 2022-01-12T19:23:29Z

/sponsor

openjdk · 2022-01-12T19:25:01Z

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

0a094d7: 8268081: Upgrade Unicode Data Files to 14.0.0
ddddec7: 8274243: Implement fast-path for ASCII-compatible CharsetEncoders on aarch64
8fed8ab: 8278065: Refactor subclassAudits to use ClassValue
f54ce84: 8238161: use os::fopen in HS code where possible
ff0cb98: 8279536: jdk/nio/zipfs/ZipFSOutputStreamTest.java timed out
ece98d8: 8278461: Use Executable.getSharedParameterTypes() instead of Executable.getParameterTypes() in trusted code
525b20f: 8279676: Dubious YMM register clearing in x86_64 arraycopy stubs
4f0b650: 8278581: Improve reference processing statistics log output
bd339aa: 8277627: Fix copyright years in some jvmci files
319d230: 8277463: JFileChooser with Metal L&F doesn't show non-canonical UNC path in - Look in
... and 234 more: https://git.openjdk.java.net/jdk/compare/3f9638d124076019f49eb77bc3ff8b466e4beb53...master

Your commit was automatically rebased without conflicts.

openjdk · 2022-01-12T19:25:16Z

@vnkozlov @LudwikJaniuk Pushed as commit d70545d.

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

LudwikJaniuk added 16 commits December 14, 2021 16:27

missing endif comment

034fd49

comment abouit blockmerger verif

bb027f8

whitespace in IR::verify

9973c51

restructure EndNotNullValidator

5637458

extract validate block begin field

d56dc5d

extract verify successor xentry flag

d4ae4eb

add blockEnd::is_sux

5a066ae

add validate edge mutuality

115cf0a

Comment: validation goals

fea638d

XentryFlag closure split from PredecessorValidator

7301a4d

rename PredecessorValidator

001199a

Assert edge mutuality in IR::verify

74f9a31

add verify_local

fd6e79f

first use verify_local

96f7421

add expand_with_neighborhood

22760e6

Use delayed asserts

716803b

openjdk bot added the rfr Pull request is ready for review label Dec 15, 2021

openjdk bot added the hotspot-compiler hotspot-compiler-dev@openjdk.org label Dec 15, 2021

chhagedorn suggested changes Dec 16, 2021

View reviewed changes

remove unneeded check

396b204

cleanup

8b5f511

LudwikJaniuk added 6 commits January 5, 2022 11:33

remove __

7480801

explain DO_DELAYED_VERIFICATION

5e38138

update copyright year

2048112

oops

b84ea8d

reorganize

a6f138b

work with normal build

de13762

chhagedorn approved these changes Jan 5, 2022

View reviewed changes

vnkozlov approved these changes Jan 5, 2022

View reviewed changes

openjdk bot added the sponsor Pull request is ready to be sponsored label Jan 7, 2022

openjdk bot added the integrated Pull request has been integrated label Jan 12, 2022

openjdk bot closed this Jan 12, 2022

openjdk bot 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 Jan 12, 2022

JDK-8258603 c1 IR::verify is expensive #6850

JDK-8258603 c1 IR::verify is expensive #6850

Conversation

LudwikJaniuk commented Dec 15, 2021 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

bridgekeeper bot commented Dec 15, 2021

openjdk bot commented Dec 15, 2021

mlbridge bot commented Dec 15, 2021 • edited Loading

Webrevs

chhagedorn left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

LudwikJaniuk commented Dec 16, 2021

LudwikJaniuk commented Dec 16, 2021 • edited Loading

LudwikJaniuk commented Dec 16, 2021

LudwikJaniuk commented Dec 16, 2021

LudwikJaniuk commented Dec 16, 2021

LudwikJaniuk commented Dec 16, 2021

LudwikJaniuk commented Jan 3, 2022

chhagedorn commented Jan 3, 2022

chhagedorn commented Jan 3, 2022

vnkozlov commented Jan 3, 2022

chhagedorn commented Jan 4, 2022

LudwikJaniuk commented Jan 4, 2022

vnkozlov commented Jan 4, 2022

vnkozlov commented Jan 4, 2022

LudwikJaniuk commented Jan 5, 2022

chhagedorn left a comment • edited Loading

Choose a reason for hiding this comment

LudwikJaniuk commented Jan 5, 2022

vnkozlov left a comment

Choose a reason for hiding this comment

LudwikJaniuk commented Jan 7, 2022

openjdk bot commented Jan 7, 2022

LudwikJaniuk commented Jan 12, 2022

vnkozlov commented Jan 12, 2022

openjdk bot commented Jan 12, 2022

openjdk bot commented Jan 12, 2022

LudwikJaniuk commented Dec 15, 2021 •

edited by openjdk bot

Loading

mlbridge bot commented Dec 15, 2021 •

edited

Loading

LudwikJaniuk commented Dec 16, 2021 •

edited

Loading

chhagedorn left a comment •

edited

Loading