Test failure: JIT/Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.sh

[v-haren]

failed in job: runtime-coreclr outerloop 20201105.4

failed tests:
JIT/Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.sh
JIT\Regression\JitBlue\DevDiv_255294\DevDiv_255294\DevDiv_255294.cmd

R2R Linux arm64 Checked no_tiered_compilation @ (Alpine.312.Arm64.Open)[email protected]/dotnet-buildtools/prereqs:alpine-3.12-helix-arm64v8-20200602002604-25f8a3e

Error message

cmdLine:/root/helix/work/workitem/JIT/Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 11/6/2020 12:37:09 AM, end: 11/6/2020 12:47:09 AM)

Return code:      -100
Raw output file:      /root/helix/work/workitem/JIT/Regression/Reports/JIT.Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.output.txt
Raw output:
BEGIN EXECUTION
in takeLock
Microsoft (R) CoreCLR Native Image Generator - Version 6.0.0-ci

cmdLine:/root/helix/work/workitem/JIT/Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.sh Timed Out (timeout in milliseconds: 600000 from variable __TestTimeout, start: 11/6/2020 12:37:09 AM, end: 11/6/2020 12:47:09 AM)
Test Harness Exitcode is : -100
To run the test:
> set CORE_ROOT=/root/helix/work/correlation
> /root/helix/work/workitem/JIT/Regression/JitBlue/DevDiv_255294/DevDiv_255294/DevDiv_255294.sh
Expected: True
Actual:   False


Stack trace
   at JIT_Regression._JitBlue_DevDiv_255294_DevDiv_255294_DevDiv_255294_._JitBlue_DevDiv_255294_DevDiv_255294_DevDiv_255294_sh() in /__w/1/s/artifacts/tests/coreclr/Linux.arm64.Checked/TestWrappers/JIT.Regression/JIT.Regression.XUnitWrapper.cs:line 104264

[BruceForstall]

Same: #9810

[BruceForstall]

Same: #8034

[BruceForstall]

The slowness here (when crossgen2 compiling the test case) is in optRedundantBranch, which calls optReachable twice. The slowness in optReachable is simply in clearing the BBF_VISITED bit for every block. So, optReachable is O(N) where N is the number of blocks. If optRedundantBranch is calling optReachable for each block, we've got an O(N^2) algorithm.

In this test there are 124697 blocks. When JITing we drop down to MinOpts:

IL Code Size exceeded, using MinOpts for method Test_DevDiv_255294:HugeMethod():int:this
IL Code Size,Instr 810534,498790, Basic Block count 124697, Local Variable Num,Ref count   4,249394 for method Test_DevDiv_255294:HugeMethod():int:this

for R2R, we don't.

[BruceForstall]

Even though it appears optReachable is very frequently called, and it creates a worklist of items, that worklist doesn't consume much memory because the ArrayStack has 8 stack slots which are probably mostly used, so no dynamic memory is needed and "leaked".

[BruceForstall]

Given that this is a ridiculous test case, I'm going to push out this bug.

Theoretically, we could "audit" all the JIT algorithms, or do some measurements of crossgen (or forced non-MinOpts) throughput and find all the places where the JIT has non-linear behavior. Then, such as for optReachable used by optRedundantBranch, introduce "escape valves" such as our fallback-to-MinOpts behavior, or similar.

[BruceForstall]

@AndyAyersMS fyi

[AndyAyersMS]

I have plans to fix that aspect of optReachable, so let me take this one over.