Profiler ReJIT reverts are partially broken

[kg]

Investigating #109310 revealed that profiler rejit reverts are partially broken, at least on windows. The way the profiler rejit test is written hides this by making it hard to tell from the output that it's not working right, and the test itself does not fully validate that the revert worked. It's not immediately obvious to me when this regressed or whether it's always been partially broken in this way - I'm going to do some git bisecting to try and find out.

You can see that reverts don't work correctly by inspecting the stdout from the test after modifying it to dump more precise information to stdout via the replacement strings generated by the profiler.

before the initial profiler rejits (unimportant stdout stripped and important messages marked with -->):

maxinlining
TriggerDirectInlining
Inline.InlineeTarget
CallMethodWithoutInlining
Inline.InlineeTarget
TriggerInlining
Inline.InlineeChain1
Inline.InlineeTarget

Then we rejit and almost all of the strings get replaced:

--> ReJIT should be triggered after this method...
Hello from profiler rejit method 'TriggerDirectInlining'!
Hello from profiler rejit method 'InlineeTarget'!
CallMethodWithoutInlining
Hello from profiler rejit method 'InlineeTarget'!
Hello from profiler rejit method 'TriggerInliningChain'!
Inline.InlineeChain1
Hello from profiler rejit method 'InlineeTarget'!

Now we revert, which should return all the methods to their original behavior. It does not.

--> Revert should be triggered after this method...
Hello from profiler rejit method 'TriggerDirectInlining'!
Inline.InlineeTarget
CallMethodWithoutInlining
Inline.InlineeTarget
Hello from profiler rejit method 'TriggerInliningChain'!
Inline.InlineeChain1
Inline.InlineeTarget

Based on outerloop CI runs it seems like the test itself is less likely to fail on certain platforms than others, but I think that doesn't necessarily indicate that rejit reverts are working anywhere.

[kg]

#117826 is an attempt at fixing the test.

[AndyAyersMS]

@kg not sure I can help much here.

I looked at the test program and the profiler driver, and it would take me a while to reconstruct what all it is trying to do and whether that happens successfully or not, and it looks like you've already done this.

Seems like the behavior should not be platform sensitive and not depend on what methods went through R2R. More of an audit trail on the profiler side would certainly be a plus.

Perhaps @noahfalk can help?

[kg]

@kg not sure I can help much here.

I looked at the test program and the profiler driver, and it would take me a while to reconstruct what all it is trying to do and whether that happens successfully or not, and it looks like you've already done this.

Seems like the behavior should not be platform sensitive and not depend on what methods went through R2R. More of an audit trail on the profiler side would certainly be a plus.

Perhaps @noahfalk can help?

Thank you for looking anyway! I'm in the middle of doing a git bisect to try and identify whether this is a regression.

[kg]

Based on a git bisect, revisions as old as 29f726e appear to have this bug, though the ability to actually build the runtime and tests successfully is really flaky once you get past mid-2024.

[dotnet-policy-service]

Tagging subscribers to this area: @steveisok, @dotnet/dotnet-diag
See info in area-owners.md if you want to be subscribed.

[kg]

I got #117826 working on linux and mac, and the output is the same there. I updated the test to produce more diagnostic output so it's obvious what's going on:

Profilee STDOUT: Revert should be triggered after this method...
Profilee STDOUT: Hello from profiler rejit method 'TriggerDirectInlining'! 
Profilee STDOUT:   Inline.InlineeTarget (Hello from profiler rejit method 'TriggerDirectInlining'! )
Profilee STDOUT: CallMethodWithoutInlining
Profilee STDOUT:   Inline.InlineeTarget (CallMethodWithoutInlining)
Profilee STDOUT: Hello from profiler rejit method 'TriggerInliningChain'! 
Profilee STDOUT:  Inline.InlineeChain1
Profilee STDOUT:   Inline.InlineeTarget (InlineeChain1)

In this output, InlineeTarget (InlineeChain1) means InlineeTarget was called by InlineeChain1.
We can see that TriggerDirectInlining was not reverted, and neither was TriggerInliningChain. However, the actual InlineeTarget code appears to be correct - it's not printing the profiler-generated string. I'm not sure how to explain this.

Before the revert, the output looks like this:

Profilee STDOUT: Hello from profiler rejit method 'TriggerDirectInlining'!
Profilee STDOUT: Hello from profiler rejit method 'InlineeTarget'!  (Hello from profiler rejit method 'TriggerDirectInlining'! )
Profilee STDOUT: CallMethodWithoutInlining
Profilee STDOUT: Hello from profiler rejit method 'InlineeTarget'!  (CallMethodWithoutInlining)
Profilee STDOUT: Hello from profiler rejit method 'TriggerInliningChain'!
Profilee STDOUT:  Inline.InlineeChain1
Profilee STDOUT: Hello from profiler rejit method 'InlineeTarget'!  (InlineeChain1)

I'm not sure why InlineeChain1's string isn't being replaced - it has inlining enabled.

[noahfalk]

I think the test is using the feature in an unusual way and the runtime rejit behavior is correct, albeit unintuitive. If you skip down the bottom the reason the test failed in #109310 is because it expected InlineeTarget to get inlined at least once and it wasn't. Perhaps something with crossgen is changing the normal inlining behavior? The test is marked as being optimization sensitive so I think its fair game for it to have an inlining behavior dependency.

I'm not sure why InlineeChain1's string isn't being replaced - it has inlining enabled.

RejitWithInliners() works by identifying all the method compilations that have included the code of the target method and recompiling them. Looking at the test I'd expect there were three of those compilations under normal jit settings:

1. InlineeTarget was compiled directly when it was invoked by CallMethodWithoutInlining
2. InlineeTarget was inlined inside of TriggerDirectInlining
3. InlineeTarget was inlined inside of TriggerInliningChain (indirectly through the InlineeChain1 function)

The intended purpose of recompilations (2) and (3) is to let the profiler change the inlining behavior so that the old version of InlineeTarget code won't get inlined any longer. Its legal to make IL changes to TriggerDirectInlining and TriggerInliningChain during the same recompilation, but its a strange way to use the feature.

Now we revert, which should return all the methods to their original behavior. It does not.

The design of Revert() is that it only affects the method you call it on. In the case of this test Revert() was called on InlineeTarget only and that method does correctly revert to its original behavior. If the test wanted to revert the behavior of the other methods whose IL was changed it would have needed to explicitly call Revert() on them as well. Revert() isn't the symmetric opposite of RejitWithInliners().

This test would be more realistic and make more sense if the call to GetReJITParameters() only modified the IL for the InlineeTarget method. That is the only method whose modification isn't conditional on inlining as well as the only method that is reverted later.

So if runtime is working correctly, why did the test fail?

Looking at the test output in #109310 I see this at the end:

Profilee STDOUT: **INFO** ReJITProfiler::Shutdown -  rejit count=1 expected rejit count=ffffffff

The source shows that this comparison not matching is why the test didn't print the "PROFILER TEST PASSES" message. Showing ffffffff in the expected rejit count means the if conditional below wasn't true which in turn means the test didn't find any places where InlineeTarget was inlined:

    int expectedRejitCount = -1;
    auto it = _inlinings.find(_targetFuncId);
    if (it != _inlinings.end())
    {
        // The number of inliners are expected to ReJIT, plus the method itself
        expectedRejitCount = (int)((*it).second->size() + 1);
    }

The test implicitly expects the InlineeTarget to be inlined at least once. The error messaging could certainly be better but I think the inlining dependency is reasonable. HTH!

[kg]

Now we revert, which should return all the methods to their original behavior. It does not.

The design of Revert() is that it only affects the method you call it on. In the case of this test Revert() was called on InlineeTarget only and that method does correctly revert to its original behavior. If the test wanted to revert the behavior of the other methods whose IL was changed it would have needed to explicitly call Revert() on them as well. Revert() isn't the symmetric opposite of RejitWithInliners().

OK, that makes sense. And I'm guessing this block in ReJitManager::UpdateActiveILVersions:

runtime/src/coreclr/vm/rejit.cpp

Lines 548 to 567 in 2e4770f

	if ((flags & COR_PRF_REJIT_BLOCK_INLINING) == COR_PRF_REJIT_BLOCK_INLINING)
	{
	hr = UpdateNativeInlinerActiveILVersions(&mgrToCodeActivationBatch, pModule, rgMethodDefs[i], fIsRevert, flags);
	if (FAILED(hr))
	{
	return hr;
	}
	if (pMD != NULL)
	{
	// If pMD is not null, then the method may have already been inlined somewhere. Go check.
	hr = UpdateJitInlinerActiveILVersions(&mgrToCodeActivationBatch, pMD, fIsRevert, flags);
	if (FAILED(hr))
	{
	return hr;
	}
	}
	}
	} // for (ULONG i = 0; i < cFunctions; i++)

Is just for a specific scenario where we have to walk all the methods that have the given method inlined into them, as a special case. I spent a while investigating this since it seemed like it was intended for this to be happening in the revert case based on the test (we do pass COR_PRF_REJIT_BLOCK_INLINING, so I thought this code should be running and reverting all the modified methods.)

But it sounds like it's not intended for the RequestReJITWithInliners and RequestRevert operations to be symmetric, where triggering the rejit will let you recompile every inlined call site and reverting the target method would revert all the inlined call sites.

I agree with you that the inlining dependency in the test is reasonable, so what I'm probably going to do is:

• Update the test to pass in this specific scenario (no inlinings happened, only the test method was rejitted) since it makes sense that it is possible
• Update the test to verify the current revert behavior, with comments, so that if it gets worse/better the test will fail and can be updated

Thanks for your time, Noah!