[Question] JIT/Directed/debugging/debuginfo/tester fail with DOTNET_TieredCompilation=0 on Linux

[gbalykov]

Test JIT/Directed/debugging/debuginfo/tester passes with tiered jit and other env vars specified for it:

export DOTNET_JitNoForwardSub=1
export DOTNET_JitEnableHeadTailMerge=0
export DOTNET_JitEnableCrossBlockLocalAssertionProp=0
export DOTNET_JitEnableOptRepeat=0

Output:

  0.0s: ==TEST STARTING==
  0.3s: Started sending sentinel events...
  0.3s: Connecting to EventPipe...
  0.5s: Creating EventPipeEventSource...
  0.5s: EventPipeEventSource created
  0.5s: Dynamic.All callback registered
  0.5s: Running optional trace validator
  0.6s: Finished running optional trace validator
  0.6s: Starting stream processing...
  0.6s: Saw new provider 'Microsoft-Windows-DotNETRuntime'
  0.8s: Saw sentinel event
  0.8s: Stopped sending sentinel events
  0.8s: Starting event generating action...
  0.8s: Stopping event generating action
  0.8s: Sending StopTracing command...
  0.9s: Saw new provider 'Microsoft-DotNETCore-EventPipe'
  0.9s: Saw new provider 'Microsoft-Windows-DotNETRuntimeRundown'
  1.0s: Stopping stream processing
  1.0s: Dropped 0 events
  1.0s: Finished StopTracing command
  1.0s: Reader task finished
  1.0s: Validating optional callback...
[tests_d]DebugInfoMethods.TestUninlined: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestControlFlow: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_r]DebugInfoMethods.TestUninlined: Validate mappings for optimized codegen (tier: QuickJitted)
[tests_r]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for optimized codegen (tier: QuickJitted)
[tests_r]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for optimized codegen (tier: QuickJitted)
[tests_r]DebugInfoMethods.TestControlFlow: Validate mappings for optimized codegen (tier: QuickJitted)
  1.0s: ==TEST FINISHED: PASSED!==

However, setting DOTNET_TieredCompilation=0 leads to fail:

  0.0s: ==TEST STARTING==
  0.5s: Started sending sentinel events...
  0.5s: Connecting to EventPipe...
  0.8s: Creating EventPipeEventSource...
  0.8s: EventPipeEventSource created
  0.8s: Dynamic.All callback registered
  0.8s: Running optional trace validator
  0.9s: Finished running optional trace validator
  0.9s: Starting stream processing...
  1.0s: Saw new provider 'Microsoft-Windows-DotNETRuntime'
  1.2s: Saw sentinel event
  1.2s: Stopped sending sentinel events
  1.2s: Starting event generating action...
  1.2s: Stopping event generating action
  1.2s: Sending StopTracing command...
  1.3s: Saw new provider 'Microsoft-DotNETCore-EventPipe'
  1.3s: Saw new provider 'Microsoft-Windows-DotNETRuntimeRundown'
  1.3s: Stopping stream processing
  1.3s: Dropped 0 events
  1.3s: Finished StopTracing command
  1.3s: Reader task finished
  1.3s: Validating optional callback...
[tests_d]DebugInfoMethods.TestUninlined: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestControlFlow: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_r]DebugInfoMethods.TestUninlined: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestControlFlow: Validate mappings for optimized codegen (tier: Optimized)
  Validation failed: expected mappings at IL offsets 000, 006, 00e, 012, 01c, 02c
  Actual (IL <-> native):
    Prolog <-> 000
    000 <-> 008
    012 <-> 00c
    02c <-> 020
    034 <-> 032
    Epilog <-> 032
  1.3s: ==TEST FINISHED: FAILED!==
Xunit.Sdk.EqualException: Assert.Equal() Failure: Values differ
Expected: 100
Actual:   -1
   at Xunit.Assert.Equal[T](T expected, T actual, IEqualityComparer`1 comparer) in /_/src/Microsoft.DotNet.XUnitAssert/src/EqualityAsserts.cs:line 168
   at __GeneratedMainWrapper.Main() in /home/runtime/artifacts/tests/coreclr/obj/linux.x64.Release/Managed/JIT/Directed/debugging/debuginfo/tester/XUnitWrapperGenerator/XUnitWrapperGenerator.XUnitWrapperGenerator/SimpleRunner.g.cs:line 10

This happens independently from architecture. According to original PR that added it (#61962), README and other files, it seems that it should support such mode. Looks like now debug info generated for Optimized differs from QuickJitted and MinOptJitted and test seems to need update for such case. Is this correct?

Build of e78b72b:

./build.sh --arch x64 --runtimeConfiguration Release --librariesConfiguration Release --subset clr+libs
BuildAllTestsAsStandalone=true ./src/tests/build.sh -Release -x64 -priority1

cc @jakobbotsch @dotnet/samsung

[dotnet-policy-service]

Tagging subscribers to this area: @JulieLeeMSFT, @jakobbotsch
See info in area-owners.md if you want to be subscribed.

[jakobbotsch]

Looks like now debug info generated for Optimized differs from QuickJitted and MinOptJitted and test seems to need update for such case. Is this correct?

The test already has different debug info expected for unoptimized and optimized versions of the test cases.
It's odd that we do not see this failing in our CI if it really does fail with TieredCompilation=0. CI should be running this test with TC=0 regularly.

[gbalykov]

CI should be running this test with TC=0 regularly.

Is this done for each PR or some weekly testing? For example, I've tried to find such test in #104432 and it seems it wasn't run there (please correct me if I'm wrong). Note that this issue happens only with release build of runtime and tests, and not sure if this test is part of pri0 or not.

[jakobbotsch]

Is this done for each PR or some weekly testing? For example, I've tried to find such test in #104432 and it seems it wasn't run there (please correct me if I'm wrong).

The test is part of Directed_3. Here is the run of Directed_3 with DOTNET_TieredCompilation=0 in that PR: https://helixre107v0xdcypoyl9e7f.blob.core.windows.net/dotnet-runtime-refs-pull-104432-merge-c83008598e104e0fb6/Directed_3/1/console.ef8e5326.log?helixlogtype=result

14:29:18.611 Running test: JIT/Directed/debugging/debuginfo/tester/tester.cmd

Return code:      0
Raw output file:      C:\h\w\A26508E8\w\AFDE09A2\uploads\debugging\debuginfo\tester\output.txt
Raw output:
BEGIN EXECUTION
 "C:\h\w\A26508E8\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  tester.dll 
  0.0s: ==TEST STARTING==
  0.6s: Started sending sentinel events...
  0.7s: Connecting to EventPipe...
  1.2s: Creating EventPipeEventSource...
  1.3s: EventPipeEventSource created
  1.3s: Dynamic.All callback registered
  1.3s: Running optional trace validator
  1.8s: Finished running optional trace validator
  1.8s: Starting stream processing...
  2.1s: Saw new provider 'Microsoft-Windows-DotNETRuntime'
  2.9s: Saw sentinel event
  2.9s: Stopped sending sentinel events
  2.9s: Starting event generating action...
  3.0s: Stopping event generating action
  3.0s: Sending StopTracing command...
  3.1s: Saw new provider 'Microsoft-DotNETCore-EventPipe'
  3.3s: Saw new provider 'Microsoft-Windows-DotNETRuntimeRundown'
  3.3s: Stopping stream processing
  3.3s: Dropped 0 events
  3.3s: Finished StopTracing command
  3.3s: Reader task finished
  3.3s: Validating optional callback...
[tests_d]DebugInfoMethods.TestUninlined: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_d]DebugInfoMethods.TestControlFlow: Validate mappings for debuggable codegen (tier: MinOptJitted)
[tests_r]DebugInfoMethods.TestUninlined: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestLateFailingInlineCandidate: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestSucceedingInlineCandidate: Validate mappings for optimized codegen (tier: Optimized)
[tests_r]DebugInfoMethods.TestControlFlow: Validate mappings for optimized codegen (tier: Optimized)
  3.4s: ==TEST FINISHED: PASSED!==
Expected: 100
Actual: 100
END EXECUTION - PASSED
PASSED

On PRs we run all tests with DOTNET_TieredCompilation=0, while on rolling builds (twice a day I believe) we run with both DOTNET_TieredCompilation=0 and DOTNET_TieredCompilation=1.

Note that this issue happens only with release build of runtime and tests, and not sure if this test is part of pri0 or not.

Does the failure reproduce with release builds but not with checked builds? That would definitely be something to investigate.

[gbalykov]

Does the failure reproduce with release builds but not with checked builds?

I did some more testing with DOTNET_TieredCompilation=0:

• Release runtime, release libs and release tests (build as in [Question] JIT/Directed/debugging/debuginfo/tester fail with DOTNET_TieredCompilation=0 on Linux #104451 (comment)): issue reproduces 10 out of 10 times
• Checked runtime, release libs and release tests: no issue, reproduces 0 out of 10 times
• Checked runtime, debug libs and release tests: no issue, reproduces 0 out of 10 times

[jakobbotsch]

Ok, that needs to be investigated. Definitely seems like it has been failing for a while (https://dev.azure.com/dnceng-public/public/_build?definitionId=135&_a=summary has the failures).

[jakobbotsch]

I think the problem is that the environment variables that are disabling various JIT opts just aren't available in release builds. Need to either disable the testing in release or to make the test more robust to JIT optimizations.

[jakobbotsch]

Going to move this to .NET 10 since the failure is explained from the environment variables. Should still handle it asap to get this pipeline clean.