[JitStressWithRandomNumbers] UnmanagedCallersOnlyTest fails.

[sandreenko]

Example:
https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-57900-merge-a85ae37fa53e48b5ba/Interop/1/console.dc3b4346.log?sv=2019-07-07&se=2021-09-12T00%3A17%3A58Z&sr=c&sp=rl&sig=Fmv2Y4%2BRpAP8bSulCAB8K9aOy29%2BoxOtgzZYwPLR%2FnA%3D

Repro steps (x86 windows):

set COMPlus_TieredCompilation=0
set COMPlus_JitStress=71
Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest\UnmanagedCallersOnlyTest.cmd

Failure log:

      Assert failure(PID 3060 [0x00000bf4], Thread: 10212 [0x27e4]): GetThreadNULLOk() == NULL || GetThread()->GetFrame() == (Frame*)-1 || GetThread()->GetFrame() <= pFrame

the issue from a quality week JitStress experiment.

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

Issue Details

---

Example:
https://helixre8s23ayyeko0k025g8.blob.core.windows.net/dotnet-runtime-refs-pull-57900-merge-a85ae37fa53e48b5ba/Interop/1/console.dc3b4346.log?sv=2019-07-07&se=2021-09-12T00%3A17%3A58Z&sr=c&sp=rl&sig=Fmv2Y4%2BRpAP8bSulCAB8K9aOy29%2BoxOtgzZYwPLR%2FnA%3D

Repro steps (x86 windows):

set COMPlus_TieredCompilation=0
set COMPlus_JitStress=71
Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest\UnmanagedCallersOnlyTest.cmd

Failure log:

      Assert failure(PID 3060 [0x00000bf4], Thread: 10212 [0x27e4]): GetThreadNULLOk() == NULL || GetThread()->GetFrame() == (Frame*)-1 || GetThread()->GetFrame() <= pFrame

the issue from a quality week JitStress experiment.

Author:	sandreenko
Assignees:	-
Labels:	JitStress, area-CodeGen-coreclr
Milestone:	6.0.0

[AndyAyersMS]

In Program:CallbackViaUnmanagedCalliThrows(int):int we throw from an RPinvoke method.

JitStress-71 adds a cookie/set check and makes the method fully interruptible. Not clear what goes wrong yet and having trouble getting the right flavor of SOS/windbg to drill in properly.

[AndyAyersMS]

In the assert that fires:

    _ASSERTE(GetThreadNULLOk() == NULL || GetThread()->GetFrame() == (Frame*)-1 || GetThread()->GetFrame() <= pFrame);

There's a thread, and it has a frame, and it's at a higher address (...E5F8) than pFrame (..E598)

[AndyAyersMS]

Ok, this is more complicated -- the issue requires two methods to be stressed:

• we must inline TestUnmanagedCallersOnlyValid_ThrowException into Main (via STRESS_LEGACY_INLINE)
• we must decide not to do an inline pinvoke in TestUnmanagedCallersOnlyViaUnmanagedCalli_ThrowException (via STRESS_BB_PROFILE)

Note that Main does two throwing tests back to back:

            // Exception handling is only supported on Windows.
            if (TestLibrary.Utilities.IsWindows)
            {
                TestUnmanagedCallersOnlyValid_ThrowException();
                TestUnmanagedCallersOnlyViaUnmanagedCalli_ThrowException();
            }

and the first of these is inlined (and so main has an inline pinvoke frame) and the second is not and eventually pinvokes via helpers.

Initial guess is that this is some kind of runtime issue -- somehow perhaps the inline pinvoke frame state in Main is not properly reset (deactivated?) from the first pinvoke, and so when the second one throws we hit an assert as the thread frame list is in an unexpected state?

@AaronRobinsonMSFT @jkoritzinsky any advice on how to proceed from here?

[AaronRobinsonMSFT]

@AndyAyersMS I would agree this seems like a runtime issue. These tests were added because we wanted to validate the SEH scenarios – as you can see these involved managed exceptions crossing the interop boundary. This would likely be something I'd lean on @janvorli for guidance on as it seems to involve the exception walk.

runtime/src/coreclr/vm/i386/excepx86.cpp

Lines 164 to 178 in e4a455f

	Frame *GetCurrFrame(EXCEPTION_REGISTRATION_RECORD *pEstablisherFrame)
	{
	Frame *pFrame;
	WRAPPER_NO_CONTRACT;
	_ASSERTE(IsUnmanagedToManagedSEHHandler(pEstablisherFrame));
	if (NExportSEH(pEstablisherFrame))
	pFrame = ((ComToManagedExRecord *)pEstablisherFrame)->GetCurrFrame();
	else
	pFrame = ((FrameHandlerExRecord *)pEstablisherFrame)->GetCurrFrame();
	// Assert that the exception frame is on the thread or that the exception frame is the top frame.
	_ASSERTE(GetThreadNULLOk() == NULL || GetThread()->GetFrame() == (Frame*)-1 || GetThread()->GetFrame() <= pFrame);
	return pFrame;
	}

[AaronRobinsonMSFT]

so when the second one throws we hit an assert as the thread frame list is in an unexpected state?

So the "second one" here is not a typical P/Invoke. Instead it is a managed method marked with UnmanagedCallersOnly which we call via a C# function pointer. I wonder if this is causing the confusion.

[AaronRobinsonMSFT]

@AndyAyersMS I can easily reproduce this locally. I did try a few things with the tests to get an idea of the state. I confirmed that having both is required. I also tried inverting the order of the calls and the same behavior was exhibited. I will take a stab and trying to figure out why this is happening.

[AndyAyersMS]

Keep me posted... I'll procrastinate a bit and hope I don't need to re-discover how all this works on x86.

[AaronRobinsonMSFT]

@AndyAyersMS Guidance here would be helpful as I am not an authority on SEH and unsure if I will be able to untangle this dance better than anyone else.

I observe the managed stack and this makes sense. I can also observe the points from the capture stack prior to dispatch of the exception in IL_Throw. Prior to throw I also inspected the m_pFrame field in the current Thread object, that is also below. The gist is the assert in question will fail with the frame set on the Thread object being to the second inlined frame (02f7e464) as opposed to the first (02f7e404).

I am hitting a ton of reliability issues in mscordaccore.dll due to #57577. WinDBG keeps crashing or asserting. I am going to try a TTD tomorrow, but with all the issues in mscordaccore.dll I'm not sure how successful I or perhaps anyone is going to be.

0:000> !clrstack
OS Thread Id: 0x599c (0)
Child SP       IP Call Site
02F7E334 79c4a94a [HelperMethodFrame: 02f7e334] 
02F7E3D4 096d2bd4 Program.CallbackViaUnmanagedCalliThrows(Int32) [D:\runtime\src\tests\Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest.cs @ 268]
02F7E400 096d2b4f ILStubClass.IL_STUB_PInvoke(Int32)
02F7E440 0940ec59 Program.TestUnmanagedCallersOnlyViaUnmanagedCalli_ThrowException() [D:\runtime\src\tests\Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest.cs @ 280]
02F7E460 0940eae8 Program.Main(System.String[]) [D:\runtime\src\tests\Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest.cs @ 57]
02F7E464 79d07af1 [InlinedCallFrame: 02f7e464] 

Stack at time of managed throw.

0:000> dps @esp L100
02f7e284  10b00d0f
02f7e288  02f7e404
02f7e28c  057c4d98
02f7e290  02f7ea94
02f7e294  cccccccc
02f7e298  cccccccc
02f7e29c  057c4d98
...
02f7e304  057c4d98
...
02f7e31c  02f7e334
02f7e320  00000000
02f7e324  01cccccc
02f7e328  031cec20
02f7e32c  cccccccc
02f7e330  12345678
02f7e334  7a1ec4b0 coreclr!HelperMethodFrame::`vftable'
02f7e338  02f7e404
02f7e33c  00000000
02f7e340  00000001
02f7e344  7a834f60 coreclr!__haveCheckedRestoreState
02f7e348  031cec20
02f7e34c  00000000
02f7e350  02f7e288
02f7e354  02f7e404
02f7e358  02f7e28c
02f7e35c  057c4d98
02f7e360  02f7e290
02f7e364  02f7ea94
02f7e368  02f7e3cc
02f7e36c  02f7e3f4
02f7e370  02f7e3d4
02f7e374  02f7e3d0
02f7e378  02f7e3cc
02f7e37c  02f7e280
02f7e380  798d1a28 coreclr!IL_Throw+0xe8 [D:\runtime\src\coreclr\vm\jithelpers.cpp @ 4068]
02f7e384  cccccccc
02f7e388  00000000
02f7e38c  cccccccc
02f7e390  031cec20
02f7e394  00000000
02f7e398  cccc0100
02f7e39c  cccccccc
02f7e3a0  00000000
02f7e3a4  00000000
02f7e3a8  cccccccc
02f7e3ac  031cec20
02f7e3b0  00000000
02f7e3b4  00000000
02f7e3b8  057c4d98
02f7e3bc  02f7e284
02f7e3c0  02f7e3dc
02f7e3c4  7a11cfd8 coreclr!_filter_x86_sse2_floating_point_exception_default+0x5a228
02f7e3c8  00000001
02f7e3cc  02f7e3f4
02f7e3d0  096d2bd4 UnmanagedCallersOnlyTest!
02f7e3d4  031cec20
02f7e3d8  02f7e3e0
02f7e3dc  02f7e970
02f7e3e0  79c52580 coreclr!FastNExportExceptHandler [D:\runtime\src\coreclr\vm\i386\excepx86.cpp @ 3369]
02f7e3e4  02f7e404
02f7e3e8  02f7e404
02f7e3ec  12345678
02f7e3f0  031cec20
02f7e3f4  02f7e438
02f7e3f8  096d2b4f*** WARNING: Unable to verify checksum for D:\runtime\artifacts\tests\coreclr\windows.x86.Debug\Tests\Core_Root\system.console.dll
 system_console!ILStubClass.IL_STUB_PInvoke(Int32)+0x3f
02f7e3fc  000004d2
02f7e400  12345678
02f7e404  7a2237bc coreclr!InlinedCallFrame::`vftable'
02f7e408  02f7e464
02f7e40c  00000004
02f7e410  02f7e3fc
02f7e414  096d2b4f system_console!ILStubClass.IL_STUB_PInvoke(Int32)+0x3f
02f7e418  02f7e438
02f7e41c  09407ab8 CLRStub[MethodDescPrestub]@2fe5a29c09407ab8
02f7e420  09407ab8 CLRStub[MethodDescPrestub]@2fe5a29c09407ab8
02f7e424  000004d2
02f7e428  12345678
02f7e42c  02f7ea94
02f7e430  031cec20
02f7e434  02f7e464
02f7e438  02f7e458
02f7e43c  0940ec59 UnmanagedCallersOnlyTest! [D:\runtime\src\tests\Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest.cs @ 281]
02f7e440  00000000
02f7e444  00000000
02f7e448  00000000
02f7e44c  00000000
02f7e450  031cec20
02f7e454  031cec20
02f7e458  02f7e4c0
02f7e45c  0940eae8 UnmanagedCallersOnlyTest! [D:\runtime\src\tests\Interop\UnmanagedCallersOnly\UnmanagedCallersOnlyTest.cs @ 58]
02f7e460  12345678
02f7e464  7a2237bc coreclr!InlinedCallFrame::`vftable'
02f7e468  ffffffff
02f7e46c  0000001f
02f7e470  7a180490 coreclr!PrestubWorker_V1
02f7e474  00000000
02f7e478  02f7e4c0
02f7e47c  7a17ffbc coreclr!StartupId
02f7e480  057c26d4
02f7e484  031cec20

((coreclr!Frame *)0x2f7e334)                 : 0x2f7e334 [Type: HelperMethodFrame * (derived from Frame *)]
    [+0x004] m_Next           : 0x2f7e404 [Type: Frame *]
    [+0x008] m_pMD            : 0x0 [Type: MethodDesc *]
    [+0x00c] m_Attribs        : 0x1 [Type: unsigned int]
    [+0x010] m_pDoneCheck     : 0x7a834f60 : 0 [Type: int *]
    [+0x014] m_pThread        : 0x31cec20 [Type: Thread *]
    [+0x018] m_FCallEntry     : 0x0 [Type: unsigned long]
    [+0x01c] m_MachState      [Type: LazyMachState]
0:000> dx -r1 ((coreclr!Frame *)0x2f7e404)
((coreclr!Frame *)0x2f7e404)                 : 0x2f7e404 [Type: InlinedCallFrame * (derived from Frame *)]
    [+0x004] m_Next           : 0x2f7e464 [Type: Frame *]
    [+0x008] m_Datum          : 0x4 [Type: NDirectMethodDesc *]
    [+0x00c] m_pCallSiteSP    : 0x2f7e3fc [Type: void *]
    [+0x010] m_pCallerReturnAddress : 0x96d2b4f [Type: unsigned long]
    [+0x014] m_pCalleeSavedFP : 0x2f7e438 [Type: unsigned long]
    [+0x018] m_pThread        : 0x9407ab8 [Type: void *]
0:000> dx -r1 ((coreclr!Frame *)0x2f7e464)
((coreclr!Frame *)0x2f7e464)                 : 0x2f7e464 [Type: InlinedCallFrame * (derived from Frame *)]
    [+0x004] m_Next           : 0xffffffff [Type: Frame *]
    [+0x008] m_Datum          : 0x1f [Type: NDirectMethodDesc *]
    [+0x00c] m_pCallSiteSP    : 0x7a180490 [Type: void *]
    [+0x010] m_pCallerReturnAddress : 0x0 [Type: unsigned long]
    [+0x014] m_pCalleeSavedFP : 0x2f7e4c0 [Type: unsigned long]
    [+0x018] m_pThread        : 0x7a17ffbc [Type: void *]