Skip to content

Test failure: JIT/opt/Vectorization/UnrollEqualsStartsWIth/UnrollEqualsStartsWIth.dll #86265

Description

@BruceForstall

https://dev.azure.com/dnceng-public/public/_build/results?buildId=272907&view=ms.vss-test-web.build-test-results-tab

coreclr windows x86 Checked jitstress2_jitstressregs0x1000 @ Windows.10.Amd64.Open

set DOTNET_TieredCompilation=0
set DOTNET_JitStress=2
set DOTNET_JitStressRegs=0x1000

Looks like failure of this test brought down the whole run.

18:47:18.821 Running test: JIT/opt/Vectorization/UnrollEqualsStartsWIth/UnrollEqualsStartsWIth.dll
App Exit Code: 3
Expected: 100
Actual: 3
END EXECUTION - FAILED
FAILED
[XUnitLogChecker]: Item 'JIT.opt' did not finish running. Checking and fixing the log...
[XUnitLogChecker]: XUnit log file has been fixed!

211/292 tests run.
* 210 tests passed.
* 0 tests failed.
* 1 tests skipped.

[XUnitLogChecker]: Checking for dumps...
[XUnitLogChecker]: No crash dumps found. Continuing...
[XUnitLogChecker]: Finished!

A different run

coreclr windows x86 Checked jitstress2_jitstressregs1 @ Windows.10.Amd64.Open

with:

set DOTNET_TieredCompilation=0
set DOTNET_JitStress=2
set DOTNET_JitStressRegs=1

crashed:

18:57:33.193 Running test: JIT/opt/Vectorization/UnrollEqualsStartsWIth/UnrollEqualsStartsWIth.dll

Assert failure(PID 3456 [0x00000d80], Thread: 4432 [0x1150]): !PreemptiveGCDisabled()

CORECLR! Thread::DetachThread + 0xCF (0x727a9aa5)
CORECLR! TlsDestructionMonitor::~TlsDestructionMonitor + 0x8F (0x72bf72f5)
CORECLR! _dyn_tls_dtor + 0x86 (0x72c099b6)
NTDLL! RtlDecompressBuffer + 0xDE (0x77aaea4e)
NTDLL! LdrShutdownThread + 0x386 (0x77a7eeb6)
NTDLL! LdrSetAppCompatDllRedirectionCallback + 0x1052A (0x77ad3c6a)
NTDLL! LdrShutdownProcess + 0x15F (0x77a92d7f)
NTDLL! RtlExitUserProcess + 0x96 (0x77a93886)
KERNEL32! ExitProcess + 0x13 (0x7795b3d3)
CORECLR! exit_or_terminate_process + 0x38 (0x72c43f08)
    File: D:\a\_work\1\s\src\coreclr\vm\threads.cpp Line: 979
    Image: C:\h\w\AA420919\p\corerun.exe

App Exit Code: -1073740286
Expected: 100
Actual: -1073740286
END EXECUTION - FAILED
FAILED
[XUnitLogChecker]: Item 'JIT.opt' did not finish running. Checking and fixing the log...
[XUnitLogChecker]: XUnit log file has been fixed!

211/292 tests run.
* 210 tests passed.
* 0 tests failed.
* 1 tests skipped.

[XUnitLogChecker]: Checking for dumps...
[XUnitLogChecker]: No crash dumps found. Continuing...
[XUnitLogChecker]: Finished!

Another failure:

https://dev.azure.com/dnceng-public/public/_build/results?buildId=273272&view=ms.vss-test-web.build-test-results-tab

coreclr windows x86 Checked jitstress2_jitstressregs8 @ Windows.10.Amd64.Open

set DOTNET_TieredCompilation=0
set DOTNET_JitStress=2
set DOTNET_JitStressRegs=8
18:45:54.299 Running test: JIT/opt/Vectorization/UnrollEqualsStartsWIth/UnrollEqualsStartsWIth.dll
App Exit Code: 3
Expected: 100
Actual: 3
END EXECUTION - FAILED
FAILED
[XUnitLogChecker]: Item 'JIT.opt' did not finish running. Checking and fixing the log...
[XUnitLogChecker]: XUnit log file has been fixed!

211/292 tests run.
* 210 tests passed.
* 0 tests failed.
* 1 tests skipped.

[XUnitLogChecker]: Checking for dumps...
[XUnitLogChecker]: No crash dumps found. Continuing...
[XUnitLogChecker]: Finished!

@markples Another issue with merging?

cc @EgorBo

Activity

  1. added
    JitStressCLR JIT issues involving JIT internal stress modes
    area-CodeGen-coreclrCLR JIT compiler in src/coreclr/src/jit and related components such as SuperPMI
    on May 15, 2023
  2. added this to the 8.0.0 milestone on May 15, 2023
  3. EgorBo commented on May 15, 2023

    @EgorBo
    Member

    Note: this test may be quite slow in stress modes, although, it used to work fine

  4. markples commented on May 15, 2023

    @markples
    Contributor

    Do you think there is a JitStress/merged test group interaction here?

    This test is interesting. It internally has a merged test group implementation and apparently has 127512 tests. They are executed via reflection, and a normal failure would cause one of the internal (sub-)batches to be terminated. A crash will take out the entire group. This infrastructure seems much heavier than the new wrapper code.

    I think converting this to xunit-style tests would reduce the code, though a 100k+ test group would be a new stress to the system.

    To be clear, I'm not suggesting any of that as a fix for the test failure - just something that I noticed while looking at the test.

  5. markples commented on May 16, 2023

    @markples
    Contributor

    This has been inconsistent to repro across configurations. I have gotten it with -c Checked -lc Release and only in the merged group (and not in a "merged" group with just the one test. Visual Studio shuts down when this test is executed (and the report bug mechanism isn't properly searching for matching bugs for me). It isn't reproing under windbg.

    There are a number of exception that are thrown and caught throughout the merged group - divide by zeros and access violations (for null). [edit - was incorrect - This test itself is as well (though I need to double check because I don't see null in the test list] Is there possibly an interaction between accessing null literals and jitstress? (or somehow a history of exceptions given the merged group interaction, but perhaps that is misleading somehow).

    It seems like there is an actual problem even if merged groups are exposing it, though since it is jitstress it might be a jitstress issue and not a product one.

  6. markples commented on May 17, 2023

    @markples
    Contributor

    The actual failure that the logs don't seem to capture (or maybe I've ended up in a different configuration?) is an assertion failure:

    src/coreclr/vm/siginfo.cpp line 4928

    void PromoteCarefully(promote_func   fn,
                          PTR_PTR_Object ppObj,
                          ScanContext*   sc,
                          uint32_t       flags /* = GC_CALL_INTERIOR*/ )
    {
        LIMITED_METHOD_CONTRACT;
    
        //
        // Sanity check that the flags contain only these three values
        //
        assert((flags & ~(GC_CALL_INTERIOR|GC_CALL_PINNED)) == 0);
    
        //
        // Sanity check that GC_CALL_INTERIOR FLAG is set
        //
        assert(flags & GC_CALL_INTERIOR);
    
    #if !defined(DACCESS_COMPILE)
    
        //
        // Sanity check the stack scan limit
        //
    >>  assert(sc->stack_limit != 0);  <<

    This suggests that the difficulty reproing it might have to do with GC timing. Does jitstress do anything odd with GC (triggering, reporting, etc.)? I.e., is it likely a jitstress or product issue?

    I had previous seen a bit of a pattern where I can get the failure to happen the first time after building in src/tests but not again after that. It wasn't 100%, and it seems like confusing information since the test runs for a few seconds before failing (which makes some sort of cold start seem less likely).

    It's certainly an interesting assertion to hit, though.

  7. BruceForstall commented on May 17, 2023

    @BruceForstall
    ContributorAuthor

    Does jitstress do anything odd with GC (triggering, reporting, etc.)? I.e., is it likely a jitstress or product issue?

    It appears to hit with multiple different JitStressRegs values. Maybe it does or would hit without JitStressRegs set if run enough?

    It also appears to hit only with JitStress=2?

    JitStress doesn't do anything specific related to GC: it doesn't trigger GC more, though might change between fully and partially interruptible. GC reporting changes because the generated code changes.

  8. markples commented on May 18, 2023

    @markples
    Contributor

    Whether the "first time after building" observation is accurate or not, I was able to use it to get a case in windbg. Below is the stack trace. Note that, at first glance anyway, this doesn't look like a typical GC bug (misreporting, heap corruption, etc.) as the assertion is about the stack limit.

    ...
    [0xf]    coreclr!PromoteCarefully+0x58   0xceff140   0x6124d51b   
    [0x10]   coreclr!GcEnumObject+0x4b   0xceff15c   0x61067cae   
    [0x11]   coreclr!EECodeManager::EnumGcRefs+0xe3e   0xceff178   0x6124d782   
    [0x12]   coreclr!GcStackCrawlCallBack+0x152   0xceff5dc   0x611752fa   
    [0x13]   coreclr!Thread::MakeStackwalkerCallback+0x48   0xceff634   0x611769d4   
    [0x14]   coreclr!Thread::StackWalkFramesEx+0x186   0xceff650   0x611767ce   
    [0x15]   coreclr!Thread::StackWalkFrames+0x159   0xceff928   0x6124cc04   
    [0x16]   coreclr!ScanStackRoots+0x196   0xceffc60   0x6124addf   
    [0x17]   coreclr!GCToEEInterface::GcScanRoots+0xf1   0xceffd74   0x6148c192   
    [0x18]   coreclr!WKS::gc_heap::background_mark_phase+0x406   0xceffd98   0x61495ffe   
    [0x19]   coreclr!WKS::gc_heap::gc1+0x13b   0xceffe00   0x6148e51d   
    [0x1a]   coreclr!WKS::gc_heap::bgc_thread_function+0xcc   0xceffe24   0x6148e6c7   
    [0x1b]   coreclr!WKS::gc_heap::bgc_thread_stub+0x27   0xceffe44   0x6124976e   
    [0x1c]   coreclr!<lambda_6e1c80cead0a95b6f179a4ba7ad5e186>::operator()+0x84   0xceffe48   0x75a47d59   
    [0x1d]   KERNEL32!BaseThreadInitThunk+0x19   0xceffe68   0x77d0b74b   
    [0x1e]   ntdll!__RtlUserThreadStart+0x2b   0xceffe78   0x77d0b6cf   
    [0x1f]   ntdll!_RtlUserThreadStart+0x1b   0xceffed0   0x0   
    
  9. BruceForstall commented on May 18, 2023

    @BruceForstall
    ContributorAuthor

    Maybe @dotnet/gc or @janvorli have insight?

  10. mangod9 commented on May 18, 2023

    @mangod9
    Member

    @markples do you have the dumps available? @cshung is this related to any of your recent changes?

  11. janvorli commented on May 18, 2023

    @janvorli
    Member

    @markples if you can share the dump and the contents of the artifacts\tests\coreclr\Windows.x64.XXXXX\Tests\Core_Root, I can take a look.

  12. markples commented on May 18, 2023

    @markples
    Contributor

    Thanks @janvorli. I've copied a .dump /m, .dump /mf, and the contents of Windows.x86.checked\Tests\Core_Root to https://microsoft-my.sharepoint.com/:f:/p/markples/EmAjXtmylUxMoQPjBpFC9ucBd5mGrD0IKPPopBCkJr0H4g?e=7z4efq. This should have MSFT-organization access.

    A few key points from the discussion above:

    • Repro is so far x86 only
    • Repro is running under a jit stress mode
    • Repro is very unreliable, though I have seen a strong correlation between hitting one and the first execution after building in src\tests
  13. 13 remaining items

  14. janvorli commented on May 25, 2023

    @janvorli
    Member

    @jkotas you are right that the case when InlinedCallFrame is not active is problematic. However, that's the case on Windows only. On Unix, we always have an explicit frame that's at the lowest address we want to scan (when the thread is interrupted in managed code, we have the RedirectedThreadFrame there). We should never see inactive InlinedCallFrame as the first frame when doing GC scan on Unix. Since this stack_limit was introduced to fix a Unix specific issue, we can fix it just by making the stack_limit stuff Unix only.

  15. added and removed
    runtime-coreclrspecific to the CoreCLR runtime
    JitStressCLR JIT issues involving JIT internal stress modes
    on May 25, 2023
  16. janvorli commented on Aug 21, 2023

    @janvorli
    Member

    @jkotas I am unable to reproduce the problem using the repro that you've shared above. The only thing I am not sure about is what you've meant by "compile with /o+". I am building it using dotnet build -c Checked -a x86 and have <Optimize>True</Optimize> in the csproj.

  17. janvorli commented on Aug 21, 2023

    @janvorli
    Member

    Btw, after looking at the original dump with the issue again, the real culprit is actually elsewhere. During the GC scan, we should have some other frame on top of the stack than an inactive inlined call frame. I could see that besides the crash, the GC stack walk started in the middle of the managed stack.

  18. jkotas commented on Aug 21, 2023

    @jkotas
    Member

    @jkotas I am unable to reproduce the problem using the repro that you've shared above

    It still repros for me. Here are the exact repro steps that I have just tried:

    build -s clr -a x86 -c checked
    cd artifacts\bin\coreclr\windows.x86.Checked
    notepad test.cs (copy, paste and save my repro: https://github.com/dotnet/runtime/issues/86265#issuecomment-1555398337)
    csc /r:System.Private.CoreLib.dll /o+ test.cs (assumes csc alias that invokes recent C# compiler) 
    set DOTNET_TieredCompilation=0
    

    Result:

    ---------------------------
    Microsoft Visual C++ Runtime Library
    ---------------------------
    Assertion failed!
    
    Program: ...ifacts\bin\coreclr\windows.x86.Checked\coreclr.dll
    File: C:\runtime\src\coreclr\vm\siginfo.cpp
    Line: 4968
    
    Expression: sc->stack_limit != 0
    
    For information on how your program can cause an assertion
    failure, see the Visual C++ documentation on asserts
    
    (Press Retry to debug the application - JIT must be enabled)
    ---------------------------
    Abort   Retry   Ignore   
    ---------------------------
    
  19. added a commit that references this issue on Aug 22, 2023
    d9bda2f
  20. ghost added
    in-prThere is an active PR which will close this issue when it is merged
    on Aug 22, 2023
  21. added a commit that references this issue on Aug 24, 2023
    445f01d
  22. ghost removed
    in-prThere is an active PR which will close this issue when it is merged
    on Aug 24, 2023
  23. added a commit that references this issue on Aug 24, 2023
    d8d37e9
  24. added a commit that references this issue on Aug 26, 2023
    f0ad1a7
  25. ghost locked as resolved and limited conversation to collaborators on Sep 24, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions