search

dotnet / runtime

.NET is a cross-platform runtime for cloud, mobile, desktop, and IoT apps.
https://docs.microsoft.com/dotnet/core/
MIT License
15.45k stars 4.76k forks source link

Crossgen outerloop regression: ReJIT profiler test does not pass #109310

Open kg opened 1 month ago

kg commented 1 month ago

The ReJIT profiler test does not pass on the crossgen outerloop lanes. It's not clear to me whether we should expect this to pass; I don't know much about ReJIT but it seems like it might not be conceptually compatible with what crossgen does. The profiler events seem to be working but something is going wrong with the test.


Unhandled exception. System.Exception: Profiler tests are expected to contain the text 'PROFILER TEST PASSES' in the console output of the profilee app to indicate a passing test. Usually it is printed from the Shutdown() method of the profiler implementation. This text was not found in the output above. Profilee returned exit code 100.
   at Profiler.Tests.ProfilerTestRunner.FailFastWithMessage(String error)
   at Profiler.Tests.ProfilerTestRunner.Run(String profileePath, String testName, Guid profilerClsid, String profileeArguments, ProfileeOptions profileeOptions, Dictionary`2 envVars, String reverseServerName, Boolean loadAsNotification, Int32 notificationCopies)
   at Profiler.Tests.RejitWithInlining.Main(String[] args)

Return code:      1
Raw output file:      C:\h\w\A5E609B0\w\A0EB08E2\uploads\rejit\rejit\output.txt
Raw output:
BEGIN EXECUTION
eventpipe_common.dll
Microsoft.Diagnostics.NETCore.Client.dll
Profiler.dll
profiler_common.dll
rejit.dll
TestLibrary.dll
        6 file(s) copied.
 7:02:43.86
Response file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll.rsp
C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\IL-CG2\*.dll
-o:C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll
--targetarch:x64
--targetos:windows
--verify-type-and-field-layout
--method-layout:random
-r:C:\h\w\A5E609B0\p\System.*.dll
-r:C:\h\w\A5E609B0\p\Microsoft.*.dll
-r:C:\h\w\A5E609B0\p\xunit.*.dll
-r:C:\h\w\A5E609B0\p\mscorlib.dll
-r:C:\h\w\A5E609B0\p\netstandard.dll
"Running CrossGen2:  "C:\h\w\A5E609B0\p\crossgen2\crossgen2.exe" @"C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll.rsp"   --composite  --composite"
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\eventpipe_common.dll
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\Microsoft.Diagnostics.NETCore.Client.dll
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\profiler_common.dll
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\rejit.dll
Emitting R2R PE file: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\TestLibrary.dll
"Running R2RDump:  "dotnet" "C:\h\w\A5E609B0\p\r2rdump\r2rdump.dll" --header --sc --in C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll --out C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\\composite-r2r.dll.r2rdump --val"
 7:02:44.92
 "C:\h\w\A5E609B0\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  rejit.dll 
Profiler path: C:\h\w\A5E609B0\w\A0EB08E2\e\profiler\rejit\rejit\Profiler.dll
Disabling tiered compilation, jitstress, and minopts.
Profilee STDOUT: Profiler.dll!DllGetClassObject
Profilee STDOUT: Profiler.dll!Profiler::Initialize
Profilee STDOUT: **INFO** ReJITProfiler::Initialize - Initialize started
Profilee STDOUT: maxinlining
Profilee STDOUT: TriggerDirectInlining
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - Found function id for target method
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: CallMethodWithoutInlining
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: TriggerInlining
Profilee STDOUT: Inline.InlineeChain1
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - ReJIT Trigger method jitting finished: TriggerReJIT
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - Requesting rejit with inliners for method InlineeTarget
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - ModuleID=7ff898074388 and MethodDef=6000008
Profilee STDOUT: ReJIT should be triggered after this method...
Profilee STDOUT: TriggerDirectInlining
Profilee STDOUT: **INFO** ReJITProfiler::GetReJITParameters - Starting to build IL for method InlineeTarget
Profilee STDOUT: **INFO** ReJITProfiler::GetReJITParameters - Replaced function string with new one.
Profilee STDOUT: **INFO** ReJITProfiler::GetReJITParameters - IL build successful for methodDef=6000008
Profilee STDOUT: **INFO** ReJITProfiler::ReJITCompilationStarted - Saw a ReJIT for function InlineeTarget
Profilee STDOUT: Hello from profiler rejit!
Profilee STDOUT: CallMethodWithoutInlining
Profilee STDOUT: Hello from profiler rejit!
Profilee STDOUT: TriggerInlining
Profilee STDOUT: Inline.InlineeChain1
Profilee STDOUT: Hello from profiler rejit!
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - Revert trigger method jitting finished: TriggerRevert
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - Requesting revert for method InlineeTarget
Profilee STDOUT: **INFO** ReJITProfiler::FunctionSeen - ModuleID=7ff898074388 and MethodDef=6000008
Profilee STDOUT: Revert should be triggered after this method...
Profilee STDOUT: TriggerDirectInlining
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: CallMethodWithoutInlining
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: TriggerInlining
Profilee STDOUT: Inline.InlineeChain1
Profilee STDOUT: Inline.InlineeTarget
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=get_IsSupported Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=OnProcessExit Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=Enter Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=GetEnumerator Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=get_Current Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=get_Value Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=TryGetTarget Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=RaiseUnloadEvent Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=OnProcessExit Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=ThrowLockTakenException Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetEnumerator Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGetTarget Inlinee=get_Target Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=get_Target Inlinee=GetTarget Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetTarget Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetTarget Inlinee=get_Target Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=get_IsSupported Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=get_EventListenersLock Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Enter Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=GetEnumerator Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=MoveNext Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=get_Current Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=TryGetTarget Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Add Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=get_EventListenersLock Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=IsEntered Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=GetEnumerator Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=MoveNext Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=get_Current Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=DisposeOnShutdown Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=.ctor Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=ThrowLockTakenException Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetEnumerator Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGetTarget Inlinee=get_Target Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=get_Target Inlinee=GetTarget Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetTarget Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetTarget Inlinee=get_Target Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=MoveNext Inlinee=MoveNextRare Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=MoveNextRare Inlinee=ThrowInvalidOperationException_InvalidOperation_EnumFailedVersion Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=IsEntered Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetEnumerator Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=SuppressFinalize Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=SuppressFinalize Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=MoveNext Inlinee=MoveNextRare Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=MoveNextRare Inlinee=ThrowInvalidOperationException_InvalidOperation_EnumFailedVersion Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=StelemRef_Helper Inlinee=TryGet Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=StelemRef_Helper Inlinee=StelemRef_Helper_NoCacheLookup Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGet Inlinee=TableData Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGet Inlinee=KeyToBucket Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGet Inlinee=Element Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TryGet Inlinee=TableMask Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=TableData Inlinee=GetRawData Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=KeyToBucket Inlinee=HashShift Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=StelemRef_Helper_NoCacheLookup Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=StelemRef_Helper_NoCacheLookup Inlinee=ThrowArrayMismatchException Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=get_IsSupported Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=get_EventListenersLock Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=IsEntered Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=Dispose Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=IsEntered Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=SuppressFinalize Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=SuppressFinalize Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=SuppressFinalize Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=SuppressFinalize Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=get_EventListenersLock Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=Enter Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=get_EventListenersLock Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=IsEntered Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Dispose Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Enter Inlinee=ThrowLockTakenException Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=IsEntered Inlinee=ThrowIfNull Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfNull Inlinee=Throw Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Assert Inlinee=Assert Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Disable Inlinee=Disable Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Unregister Inlinee=get_IsAllocated Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Unregister Inlinee=Free Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=ThrowIfInvalid Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=GetHandleValue Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=InternalFree Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfInvalid Inlinee=ThrowInvalidOperationException_HandleIsNotInitialized Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetHandleValue Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Unregister Inlinee=get_IsAllocated Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Unregister Inlinee=Free Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=ThrowIfInvalid Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=GetHandleValue Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=Free Inlinee=InternalFree Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=ThrowIfInvalid Inlinee=ThrowInvalidOperationException_HandleIsNotInitialized Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: **INFO** ReJITProfiler::AddInlining - Inlining occurred! Inliner=GetHandleValue Inlinee=.ctor Inlinee module name=C:\h\w\A5E609B0\p\System.Private.CoreLib.dll
Profilee STDOUT: Profiler.dll!Profiler::Shutdown
Profilee STDOUT: **INFO** ReJITProfiler::Shutdown -  rejit count=1 expected rejit count=ffffffff
Profilee STDOUT: **FAIL** ReJITProfiler::Shutdown - Test failed number of failures=0
Test failed: Profiler tests are expected to contain the text 'PROFILER TEST PASSES' in the console output of the profilee app to indicate a passing test. Usually it is printed from the Shutdown() method of the profiler implementation. This text was not found in the output above. Profilee returned exit code 100.
Expected: 100
Actual: -532462766
END EXECUTION - FAILED
FAILED
kg commented 1 month ago

Notes about rejit and crossgen from David Mason on discord:

ReJIT is a concept in the ICorProfiler interface, and it's a little confusingly named versus tiered compilation. ReJIT is talking about the ability of an ICorProfiler (C++ library that can hook in to extension points in the runtime) to be able to arbitrarily rewrite the IL of a method. The intended case is for APM stuff like AppInsights, etc, to be able to inject instrumentation in methods to keep track of http calls, exceptions thrown, whatever In the desktop days the way we did ReJIT was incompatible with NGEN images so profilers had to block the whole image or at least the methods they cared about from loading (there are APIs for that too) and force them to jit normally so they could participate In the modern runtime and R2R images you can ReJIT methods that are already loaded via R2R Let me know if you want more details on any specific area PS if anyone from the jit team is talking about rejit they almost always mean tiered compilation

EDIT: The issue may be related to how some of the crossgen lanes have tiered compilation turned off.

kg commented 1 month ago

In this test, InlineeTarget is not being inlined when it's expected to. The expected rejit count is -1 because it wasn't inlined.

kg commented 1 month ago

CompositeBuildMode=1 causes this to pass (EDIT: Intermittently 🤷‍♀️), with a rejit count of 3. CompositeBuildMode=0 makes it fail.