8314452: Explicitly indicate inlining success/failure in PrintInlining #15315

JornVernee · 2023-08-16T17:42:42Z

This patch proposes to add a + or - to messages produced by PrintInlining, to indicate whether inlining succeeded or failed. This makes it easier to find inlining failures in an inlining trace, without having to rely on the message to figure out whether inlining succeeded or failed. Looking at inlining failures is often useful for diagnosing the results of benchmarks, but it can be hard to find inlining failures in lengthy traces.

A sample of what this looks like:

                            +@ 0   java.lang.foreign.Arena::ofConfined (10 bytes)   inline (hot)
                              +@ 0   java.lang.Thread::currentThread (0 bytes)   (intrinsic)
                              +@ 3   jdk.internal.foreign.MemorySessionImpl::createConfined (9 bytes)   inline (hot)
                                +@ 5   jdk.internal.foreign.ConfinedSession::<init> (18 bytes)   inline (hot)
                                  +@ 6   jdk.internal.foreign.ConfinedSession$ConfinedResourceList::<init> (5 bytes)   inline (hot)
                                    +@ 1   jdk.internal.foreign.MemorySessionImpl$ResourceList::<init> (5 bytes)   inline (hot)
                                      +@ 1   java.lang.Object::<init> (1 bytes)   inline (hot)
                                  +@ 9   jdk.internal.foreign.MemorySessionImpl::<init> (20 bytes)   inline (hot)
                                    +@ 1   java.lang.Object::<init> (1 bytes)   inline (hot)
                              +@ 6   jdk.internal.foreign.MemorySessionImpl::asArena (9 bytes)   inline (hot)
                                +@ 5   jdk.internal.foreign.MemorySessionImpl$1::<init> (10 bytes)   inline (hot)
                                  +@ 6   java.lang.Object::<init> (1 bytes)   inline (hot)
                            -@ 8   java.lang.foreign.SegmentAllocator::allocate (24 bytes)   already compiled into a big method

Using grep/sls to find inlining failures:

> Get-Content inlining_trace.txt | sls '-@'
                            -@ 8   java.lang.foreign.SegmentAllocator::allocate (24 bytes)   already compiled into a big method
                            -@ 34   java.lang.foreign.SegmentAllocator::allocate (24 bytes)   already compiled into a big method
                                        -@ 19   java.lang.invoke.MethodHandle::linkToNative(JJJL)D (0 bytes)   native call
                                    -@ 95   java.lang.foreign.Arena::close (0 bytes)   virtual call
                                    -@ 107   jdk.internal.foreign.MemorySessionImpl::release0 (0 bytes)   virtual call
                                        -@ 14   jdk.internal.misc.Unsafe::freeMemory0 (0 bytes)   native method

Note on the implementation: I opted for an enum to indicate inlining success/failure. I was using bool first, but ran into issues in some cases because the 'message' pointer was being implicitly converted to bool, and since the message itself is optional (nullptr by default) this didn't result in compilation errors, but silently omitted the inlining message instead. Using an enum avoids that issue. It also makes the call site a little easier to read, since there are no more true and false literals.

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-8314452: Explicitly indicate inlining success/failure in PrintInlining (Enhancement - P4)

Reviewers

Vladimir Kozlov (@vnkozlov - Reviewer)
Aleksey Shipilev (@shipilev - Reviewer)
Tobias Hartmann (@TobiHartmann - Reviewer) ⚠️ Review applies to f2f2245d

Reviewing

Using git

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

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

Using Skara CLI tools

Checkout this PR locally:
$ git pr checkout 15315

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

Using diff file

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

Webrev

Link to Webrev Comment

bridgekeeper · 2023-08-16T17:44:09Z

👋 Welcome back jvernee! 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-08-16T17:45:07Z

@JornVernee 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-08-17T17:15:35Z

Webrevs

shipilev · 2023-08-17T17:32:09Z

The idea looks interesting, but I am not a fan of +@ and -@. Yes, it makes convenient to grep, I can see that. We need to bikeshed this a bit :)

JornVernee · 2023-08-17T18:48:25Z

The idea looks interesting, but I am not a fan of +@ and -@. Yes, it makes convenient to grep, I can see that. We need to bikeshed this a bit :)

Yes... I wanted something that is easy to grep/crtrl+f for.

Another option would be to add another column to the left of the inlining messages, similar to the one we have for ex handler/synchronize/has monitors. Then it's possible to search for just -/+, but I'm not sure if the rest of the message doesn't contain a - as hyphen for example. -@ seems like it would be a pretty unique pattern on the other hand.

TobiHartmann · 2023-08-21T09:45:16Z

Why not simply add a "failed to inline:" message? Something like:

                            @ 8   java.lang.foreign.SegmentAllocator::allocate (24 bytes)   failed to inline: already compiled into a big method
                            @ 34   java.lang.foreign.SegmentAllocator::allocate (24 bytes)   failed to inline: already compiled into a big method
                                        @ 19   java.lang.invoke.MethodHandle::linkToNative(JJJL)D (0 bytes)   failed to inline: native call
                                    @ 95   java.lang.foreign.Arena::close (0 bytes)   failed to inline: virtual call
                                    @ 107   jdk.internal.foreign.MemorySessionImpl::release0 (0 bytes)   failed to inline: virtual call
                                        @ 14   jdk.internal.misc.Unsafe::freeMemory0 (0 bytes)   failed to inline: native method

JohnTortugo · 2023-08-23T23:48:29Z

Why not simply add a "failed to inline:" message? Something like:

+1 to this.

navyxliu · 2023-08-25T18:56:50Z

I also feel explicit message 'fail to inline' is better than +/-

Sigil here is essentially the value of a tree node. '+' denotes inline succeed. The problem is it increases the cognitive loads for java developers.

I think we can establish a general rule: a failed inline emits a message starting with "fail to inline". reason is optional. Everything else are successful inlines.

I think we still meet your goal: easily distinct inline or not inline method.
to get all successful inline, we just use invert grep: grep -v "fail to inline"

JornVernee · 2023-09-04T08:40:44Z

Coming back to this after vacation. I'll switch to "failed to inline: " if that's what people prefer.

JornVernee · 2023-09-04T09:00:55Z

Switched the message. Example:

                            @ 4   TestJIT$Scope::<init> (16 bytes)   inline (hot)
                              @ 1   java.lang.Object::<init> (1 bytes)   inline (hot)
                              @ 9   java.util.ArrayList::<init> (12 bytes)   inline (hot)
                                @ 1   java.util.AbstractList::<init> (10 bytes)   inline (hot)
                                  @ 1   java.util.AbstractCollection::<init> (5 bytes)   inline (hot)
                                    @ 1   java.lang.Object::<init> (1 bytes)   inline (hot)
                            @ 13   TestJIT$Scope::addCloseAction (12 bytes)   inline (hot)
                              @ 5   java.util.ArrayList::add (25 bytes)   failed to inline: already compiled into a big method
                               \-> TypeProfile (5120/5120 counts) = java/util/ArrayList
                            @ 17   TestJIT$Scope::close (39 bytes)   inline (hot)
                              @ 4   java.util.ArrayList::iterator (9 bytes)   inline (hot)
                               \-> TypeProfile (5120/5120 counts) = java/util/ArrayList
                                @ 5   java.util.ArrayList$Itr::<init> (26 bytes)   inline (hot)
                                  @ 6   java.lang.Object::<init> (1 bytes)   inline (hot)
                              @ 11   java.util.ArrayList$Itr::hasNext (20 bytes)   inline (hot)
                              @ 20   java.util.ArrayList$Itr::next (66 bytes)   inline (hot)
                                @ 1   java.util.ArrayList$Itr::checkForComodification (23 bytes)   inline (hot)
                              @ 30   TestJIT$$Lambda/0x000001c3ab000a10::run (4 bytes)   inline (hot)
                                @ 0   TestJIT::lambda$new$0 (1 bytes)   inline (hot)
                              @ 11   java.util.ArrayList$Itr::hasNext (20 bytes)   inline (hot)

grep:

> sls -path .\inlining.txt -pattern 'failed to inline'

inlining.txt:13:                              @ 5   java.util.ArrayList::add (25 bytes)   failed to inline: already compiled into a big method

vnkozlov · 2023-09-05T16:19:24Z

I like new output. But it affects few tests - see failures in testing in GitHubtesting:

stderr: [openjdk version "22-internal" 2024-03-19
OpenJDK Runtime Environment (fastdebug build 22-internal-JornVernee-391ca8fd366b4cc9ba90fa92eaf25f72144b0fba)
OpenJDK 64-Bit Server VM (fastdebug build 22-internal-JornVernee-391ca8fd366b4cc9ba90fa92eaf25f72144b0fba, mixed mode, sharing)
]
 exitValue = 0

java.lang.RuntimeException: 'TestNull::testArg .* inline' found in stdout: 'TestNull::testArg (8 bytes)   failed to inline'
	at jdk.test.lib.process.OutputAnalyzer.shouldNotMatch(OutputAnalyzer.java:396)
	at compiler.c2.unloaded.TestInlineUnloaded.lambda$main$0(TestInlineUnloaded.java:213)
	at compiler.c2.unloaded.TestInlineUnloaded.run(TestInlineUnloaded.java:204)

vnkozlov · 2023-09-05T17:46:53Z

I suggest to fix affected tests.

JornVernee · 2023-09-05T19:00:02Z

@vnkozlov Thanks, I'll take a look.

JornVernee · 2023-09-07T09:15:27Z

I've fixed the two failing tests locally. I'm going to run a new tier 1-4 job as well

shipilev · 2023-09-07T09:28:50Z

test/hotspot/jtreg/compiler/inlining/ResolvedClassTest.java

@@ -128,7 +128,7 @@ static void testIndy() throws IOException {
        analyzer.shouldNotMatch("java\\.lang\\.invoke\\..+::linkToTargetMethod \\(9 bytes\\)   not inlineable");


This needs failed to inline: too, right? Maybe we want to sweep tests for the common inlining failure messages and put failed to inline: in relevant tests.

This needs failed to inline: too, right?

Hmm right, there are probably some tests looking for inlining failures that are now trivially passing, since the inlining message changed.

Maybe we want to sweep tests for the common inlining failure messages and put failed to inline: in relevant tests.

Okay, I'll have another look.

I did a sweep through the hotspot code to try and find all inlining failure messages. Then I looked through ./test/hotspot/jtreg/compiler for these messages, to see if any test was referencing them. I did find a few and fixed them. I also found one (TestConflictInlineCommands) that looked for a failure message alone. I've left that one as is, since I think it still works as intended.

I looked for all of the following strings:

not inlineable

no static binding

disallowed by ciReplay

unloaded signature classes

inlining too deep

disallowed by CompileCommand

virtual call

many throws

already compiled into a medium method

hot method too big

too big

don't inline by annotation

native method

abstract method

cannot be parsed

intrinsic method inlining disabled

inlining prohibited by policy

callee has exception handlers

callee is synchronized

callee's klass not linked yet

callee's klass not initialized yet

callee's monitors do not match

jsrs not handled properly by inliner yet

mdo allocation failed

receiver is always null

MaxForceInlineLevel

recursive inlining too deep

callee is too large

callee uses too much stack

don't inline Throwable constructors

total inlining greater than DesiredMethodLimit

signatures mismatch

not static or statically bindable

receiver not constant

MemberName not constant

native call

method holder not initialized

method changes current thread

already compiled into a big method

exception method

never executed

low call site frequency

size > DesiredMethodLimit

NodeCountInliningCutoff

call site not reached

not an accessor

failed initial checks

too cold to inline

failed to generate predicate for intrinsic

method not annotated

failed to inline (intrinsic, virtual)

failed to inline (intrinsic)

vnkozlov

Looks good. Thank you for finding and fixing affected tests.

openjdk · 2023-09-07T18:30:12Z

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

8314452: Explicitly indicate inlining success/failure in PrintInlining

Reviewed-by: kvn, shade, thartmann

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

a62c48b: 8315891: java/foreign/TestLinker.java failed with "error occurred while instantiating class TestLinker: null"
9559e03: 8315578: PPC builds are broken after JDK-8304913
e409d07: 8315696: SignedLoggerFinderTest.java test failed
ab6a87e: 8314838: 3 compiler tests ignore vm flags
b3dfc39: 8315930: Revert "8315220: Event NativeLibraryLoad breaks invariant by taking a stacktrace when thread is in state _thread_in_native"
ebc718f: 8315818: vmTestbase/nsk/jvmti/Allocate/alloc001/alloc001.java fails on libgraal
4a6bd81: 8315854: G1: Remove obsolete comment in G1ReclaimEmptyRegionsTask
c664f1c: 8307352: AARCH64: Improve itable_stub
8ddf9ea: 8315686: G1: Disallow evacuation of marking regions in a Prepare Mixed gc
7ef059a: 8315605: G1: Add number of nmethods in code roots scanning statistics
... and 22 more: https://git.openjdk.org/jdk/compare/e22eb06a3b59f83eb38881f7e1aed1c18ee7e193...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.

shipilev

Looks good to me.

But I would probably call the new enum InliningResult, rather than InliningKind. "Kind" kinda implies the method of achieving inline, not the end result of it.

TobiHartmann

Looks good to me.

JornVernee · 2023-09-08T11:50:18Z

But I would probably call the new enum InliningResult, rather than InliningKind. "Kind" kinda implies the method of achieving inline, not the end result of it.

I like this suggestion, and have applied it: 855550a

I did some local testing of the flag, and ran hotspot_compiler tests locally just to be sure.

P.S. wait, more changes are needed than just the rename of the enum.

shipilev

Looks good!

JornVernee · 2023-09-08T12:22:05Z

That should do it. I'll wait a bit before integrating in case there are any more comments for the last few commits.

vnkozlov

I agree with renaming.

JornVernee · 2023-09-09T10:30:47Z

/integrate

openjdk · 2023-09-09T10:32:25Z

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

b482e6d: 8315580: Remove unused java_lang_String::set_value_raw()
9b0da48: 8315410: Undocumented exceptions in java.text.StringCharacterIterator
578ded4: 8312418: Add Elements.getEnumConstantBody
dccf670: 8306632: Add a JDK Property for specifying DTD support
a62c48b: 8315891: java/foreign/TestLinker.java failed with "error occurred while instantiating class TestLinker: null"
9559e03: 8315578: PPC builds are broken after JDK-8304913
e409d07: 8315696: SignedLoggerFinderTest.java test failed
ab6a87e: 8314838: 3 compiler tests ignore vm flags
b3dfc39: 8315930: Revert "8315220: Event NativeLibraryLoad breaks invariant by taking a stacktrace when thread is in state _thread_in_native"
ebc718f: 8315818: vmTestbase/nsk/jvmti/Allocate/alloc001/alloc001.java fails on libgraal
... and 26 more: https://git.openjdk.org/jdk/compare/e22eb06a3b59f83eb38881f7e1aed1c18ee7e193...master

Your commit was automatically rebased without conflicts.

openjdk · 2023-09-09T10:32:32Z

@JornVernee Pushed as commit 68f6941.

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

JornVernee added 2 commits August 16, 2023 17:56

Explicitly track inlining success/failure

43aad97

kind -> kind_of

a8ea335

openjdk bot added the hotspot-compiler label Aug 16, 2023

polish

f846b6d

JornVernee marked this pull request as ready for review August 17, 2023 17:09

openjdk bot added the rfr label Aug 17, 2023

switch to 'failed to inline' message

391ca8f

JornVernee added 2 commits September 7, 2023 10:54

Merge branch 'master' into Explicit_inlining_msg

7bbf70d

fix failing inlining tests

27c2425

shipilev reviewed Sep 7, 2023

View reviewed changes

fix more tests

f2f2245

vnkozlov approved these changes Sep 7, 2023

View reviewed changes

openjdk bot added the ready label Sep 7, 2023

shipilev approved these changes Sep 8, 2023

View reviewed changes

TobiHartmann approved these changes Sep 8, 2023

View reviewed changes

InliningKind -> InliningResult

855550a

JornVernee added 2 commits September 8, 2023 14:14

rename variables and inlining_kind_of too

79d8e58

trim excess whitespace

4fd183d

shipilev approved these changes Sep 8, 2023

View reviewed changes

vnkozlov approved these changes Sep 8, 2023

View reviewed changes

openjdk bot added the integrated label Sep 9, 2023

openjdk bot closed this Sep 9, 2023

openjdk bot removed ready rfr labels Sep 9, 2023

JornVernee deleted the Explicit_inlining_msg branch September 9, 2023 10:32

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

8314452: Explicitly indicate inlining success/failure in PrintInlining #15315

8314452: Explicitly indicate inlining success/failure in PrintInlining #15315

JornVernee commented Aug 16, 2023 •

edited by openjdk bot

Loading

bridgekeeper bot commented Aug 16, 2023

openjdk bot commented Aug 16, 2023

mlbridge bot commented Aug 17, 2023 •

edited

Loading

shipilev commented Aug 17, 2023

JornVernee commented Aug 17, 2023 •

edited

Loading

TobiHartmann commented Aug 21, 2023 •

edited

Loading

JohnTortugo commented Aug 23, 2023

navyxliu commented Aug 25, 2023

JornVernee commented Sep 4, 2023

JornVernee commented Sep 4, 2023

vnkozlov commented Sep 5, 2023 •

edited

Loading

vnkozlov commented Sep 5, 2023

JornVernee commented Sep 5, 2023

JornVernee commented Sep 7, 2023

shipilev Sep 7, 2023

JornVernee Sep 7, 2023

JornVernee Sep 7, 2023 •

edited

Loading

vnkozlov left a comment

openjdk bot commented Sep 7, 2023 •

edited

Loading

shipilev left a comment

TobiHartmann left a comment

JornVernee commented Sep 8, 2023 •

edited

Loading

shipilev left a comment

JornVernee commented Sep 8, 2023

vnkozlov left a comment

JornVernee commented Sep 9, 2023

openjdk bot commented Sep 9, 2023

openjdk bot commented Sep 9, 2023

		@@ -128,7 +128,7 @@ static void testIndy() throws IOException {
		analyzer.shouldNotMatch("java\\.lang\\.invoke\\..+::linkToTargetMethod \\(9 bytes\\) not inlineable");

8314452: Explicitly indicate inlining success/failure in PrintInlining #15315

8314452: Explicitly indicate inlining success/failure in PrintInlining #15315

Conversation

JornVernee commented Aug 16, 2023 • edited by openjdk bot Loading

Progress

Issue

Reviewers

Reviewing

Webrev

bridgekeeper bot commented Aug 16, 2023

openjdk bot commented Aug 16, 2023

mlbridge bot commented Aug 17, 2023 • edited Loading

Webrevs

shipilev commented Aug 17, 2023

JornVernee commented Aug 17, 2023 • edited Loading

TobiHartmann commented Aug 21, 2023 • edited Loading

JohnTortugo commented Aug 23, 2023

navyxliu commented Aug 25, 2023

JornVernee commented Sep 4, 2023

JornVernee commented Sep 4, 2023

vnkozlov commented Sep 5, 2023 • edited Loading

vnkozlov commented Sep 5, 2023

JornVernee commented Sep 5, 2023

JornVernee commented Sep 7, 2023

shipilev Sep 7, 2023

Choose a reason for hiding this comment

JornVernee Sep 7, 2023

Choose a reason for hiding this comment

JornVernee Sep 7, 2023 • edited Loading

Choose a reason for hiding this comment

vnkozlov left a comment

Choose a reason for hiding this comment

openjdk bot commented Sep 7, 2023 • edited Loading

shipilev left a comment

Choose a reason for hiding this comment

TobiHartmann left a comment

Choose a reason for hiding this comment

JornVernee commented Sep 8, 2023 • edited Loading

shipilev left a comment

Choose a reason for hiding this comment

JornVernee commented Sep 8, 2023

vnkozlov left a comment

Choose a reason for hiding this comment

JornVernee commented Sep 9, 2023

openjdk bot commented Sep 9, 2023

openjdk bot commented Sep 9, 2023

JornVernee commented Aug 16, 2023 •

edited by openjdk bot

Loading

mlbridge bot commented Aug 17, 2023 •

edited

Loading

JornVernee commented Aug 17, 2023 •

edited

Loading

TobiHartmann commented Aug 21, 2023 •

edited

Loading

vnkozlov commented Sep 5, 2023 •

edited

Loading

JornVernee Sep 7, 2023 •

edited

Loading

openjdk bot commented Sep 7, 2023 •

edited

Loading

JornVernee commented Sep 8, 2023 •

edited

Loading