dotnet / runtime

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

Test failure: Regressions/coreclr/GitHub_89834/test89834/test89834.cmd #104057

Open JulieLeeMSFT opened 4 days ago

JulieLeeMSFT commented 4 days ago

Pipeline: runtime-coreclr gcstress-extra / 20240625.2

coreclr windows x64 Checked gcstress0xc_disabler2r_heapverify1 @ Windows.10.Amd64.Open

cmdLine:C:\h\w\AA4A09D7\w\BC0F0993\e\Regressions\Regressions\../coreclr/GitHub_89834/test89834/test89834.cmd Timed Out (timeout in milliseconds: 5400000 from variable __TestTimeout, start: 6/26/2024 12:24:36 AM, end: 6/26/2024 1:54:36 AM)

Return code:      -100
Raw output file:      C:\h\w\AA4A09D7\w\BC0F0993\uploads\coreclr\GitHub_89834\test89834\output.txt
Raw output:
BEGIN EXECUTION
 "C:\h\w\AA4A09D7\p\corerun.exe" -p "System.Reflection.Metadata.MetadataUpdater.IsSupported=false" -p "System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true"  test89834.dll 
boo
Begin Observing Exception: System.Threading.Tasks.TaskCanceledException
Throwing Frame: [ThrowForNonSuccess, 0x56]
Begin Checking Thread Frames:
- [ValidateExceptionStackFrame, 0x9F]
- [FirstChanceExceptionCallback, 0x39]
- [RhpAppendExceptionStackFrame, 0xFFFFFFFF]
- [RhpAppendExceptionStackFrame, 0xFFFFFFFF]
- [DispatchEx, 0x0]
- [RhThrowEx, 0x20]
- [ThrowForNonSuccess, 0x56]
End Checking Thread Frames:
End Observing Exception: System.Threading.Tasks.TaskCanceledException

cmdLine:C:\h\w\AA4A09D7\w\BC0F0993\e\Regressions\Regressions\../coreclr/GitHub_89834/test89834/test89834.cmd Timed Out (timeout in milliseconds: 5400000 from variable __TestTimeout, start: 6/26/2024 12:24:36 AM, end: 6/26/2024 1:54:36 AM)
Test Harness Exitcode is : -100
To run the test:
Set up CORE_ROOT and run.
> C:\h\w\AA4A09D7\w\BC0F0993\e\Regressions\Regressions\../coreclr/GitHub_89834/test89834/test89834.cmd

Stack trace

   at Xunit.Assert.True(Nullable`1 condition, String userMessage) in /_/src/Microsoft.DotNet.XUnitAssert/src/BooleanAsserts.cs:line 146
   at TestLibrary.OutOfProcessTest.RunOutOfProcessTest(String assemblyPath, String testPathPrefix)
   at Program.<<Main>$>g__TestExecutor73|0_74(StreamWriter tempLogSw, StreamWriter statsCsvSw, <>c__DisplayClass0_0&)
dotnet-policy-service[bot] commented 4 days ago

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

JulieLeeMSFT commented 4 days ago

@AndyAyersMS, PTAL.

AndyAyersMS commented 4 days ago

The test timed out after 1h30min.

Timed Out (timeout in milliseconds: 5400000 from variable __TestTimeout, 
start: 6/26/2024 12:24:36 AM, end: 6/26/2024 1:54:36 AM)
Test Harness Exitcode is : -100

This behavior was first seen on 6/22 and the last successful runs were perhaps on 6/16. Other GC stress modes are also failing.

AndyAyersMS commented 3 days ago

Seems like some kind of lost race at shutdown? There is only one thread in the process and it is stuck waiting for GC:

0:000> ~kb
 # RetAddr               : Args to Child                                                           : Call Site
00 00007ff8`b6c8952e     : 00000000`00001df5 00007ff8`b6fb0000 000002db`5e13c860 00007ff8`2727e8af : ntdll!ZwWaitForSingleObject+0x14 [minkernel\ntdll\daytona\objfre\amd64\usrstubs.asm @ 251] 
01 00007ff8`27021747     : 000002db`5c28aa50 00000000`00000000 00000000`00000000 00000000`0000020c : KERNELBASE!WaitForSingleObjectEx+0x8e [minkernel\kernelbase\synch.c @ 1328] 
02 00007ff8`26a8a2ec     : 000002db`5c28aa50 00000000`00002a14 000002db`5c28aa50 00000000`00000009 : coreclr!Thread::RareDisablePreemptiveGC+0x297 [C:\repos\runtime2\src\coreclr\vm\threadsuspend.cpp @ 2193] 
03 00007ff8`26a71d7f     : 000000e4`df97f6a0 000002db`5c26f790 000002db`00000000 000000e4`00000000 : coreclr!Thread::DisablePreemptiveGC+0x11c [C:\repos\runtime2\src\coreclr\vm\threads.h @ 1311] 
04 (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!GCHolderBase::EnterInternalCoop+0xdc [C:\repos\runtime2\src\coreclr\vm\threads.h @ 4718] 
05 00007ff8`26d4da86     : 000002db`5c28aa50 000002db`5c26f790 00000000`00000000 00000000`00000000 : coreclr!GCCoop::GCCoop+0x13f [C:\repos\runtime2\src\coreclr\vm\threads.h @ 4838] 
06 00007ff8`275792cd     : 00000000`00000000 000002db`5c28aa50 00000000`00000001 00007ff8`b956aff1 : coreclr!Thread::DetachThread+0x256 [C:\repos\runtime2\src\coreclr\vm\threads.cpp @ 968] 
07 (Inline Function)     : --------`-------- --------`-------- --------`-------- --------`-------- : coreclr!TlsDestructionMonitor::{dtor}+0x103 [C:\repos\runtime2\src\coreclr\vm\ceemain.cpp @ 1745] 
08 00007ff8`27407aea     : 00000000`7ffe0385 00000000`00000000 00000000`7ffe0384 00007ff8`27407a30 : coreclr!`dynamic atexit destructor for 'tls_destructionMonitor''+0x11d
09 00007ff8`b95abfaa     : 00007ff8`26a70000 00000000`00000000 00000000`00000000 00007ff8`b71f0000 : coreclr!__dyn_tls_dtor+0xba [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\tls\tlsdtor.cpp @ 122] 
0a 00007ff8`b9558b7f     : 00000000`00000001 000002db`5c217510 00000000`00000000 00000000`0000001c : ntdll!ImageTlsCallbackCaller+0x1a [minkernel\ntdll\ldrtls.c @ 1123] 
0b 00007ff8`b9559809     : 00007ff8`2757ba48 00007ff8`26a70000 000002db`00000000 000002db`5c1e9170 : ntdll!LdrpCallInitRoutine+0x6b [minkernel\ntdll\ldr.c @ 231] 
0c 00007ff8`b9581571     : 000002db`5c1e9170 000002db`5c26dd60 00007ff8`27407a30 000000e4`df699000 : ntdll!LdrpCallTlsInitializers+0xc5 [minkernel\ntdll\ldrtls.c @ 1187] 
0d 00007ff8`b958117d     : 00000000`00000064 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!LdrShutdownProcess+0x161 [minkernel\ntdll\ldrinit.c @ 7350] 
0e 00007ff8`b7797fab     : 00007ff7`e7098e70 00007ff7`e7098f70 ffffffff`fffffffe 000000e4`df97fac4 : ntdll!RtlExitUserProcess+0xad [minkernel\ntdll\rtlstrt.c @ 1584] 
0f 00007ff7`e7048e0a     : 000000e4`00000064 000000e4`df97fac8 ffffffff`fffffffe 00007ff7`e6ff0100 : KERNEL32!ExitProcessImplementation+0xb [clientcore\base\win32\client\process.c @ 2522] 
10 00007ff7`e7048dc2     : 000000e4`00000064 000000e4`df97fb01 000000e4`df97fb70 000000e4`df97fb20 : corerun!exit_or_terminate_process+0x3a [minkernel\crts\ucrt\src\appcrt\startup\exit.cpp @ 144] 
11 00007ff7`e70490f6     : 00000000`00000064 000002db`00000000 00007ff7`00000000 00007ff7`e6ff0100 : corerun!common_exit+0x92 [minkernel\crts\ucrt\src\appcrt\startup\exit.cpp @ 280] 
12 00007ff7`e7012a2b     : 00007ff7`00000064 00007ff7`e70874b0 00000000`00000000 00000000`00000000 : corerun!exit+0x16 [minkernel\crts\ucrt\src\appcrt\startup\exit.cpp @ 294] 
13 00007ff7`e70128ce     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : corerun!__scrt_common_main_seh+0x14b [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 295] 
14 00007ff7`e7012b6e     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : corerun!__scrt_common_main+0xe [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 331] 
15 00007ff8`b779257d     : 000000e4`df698000 00000000`00000000 00000000`00000000 00000000`00000000 : corerun!wmainCRTStartup+0xe [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_wmain.cpp @ 17] 
16 00007ff8`b958af28     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0x1d [clientcore\base\win32\client\thread.c @ 75] 
17 00000000`00000000     : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x28 [minkernel\ntdll\rtlstrt.c @ 1166] 

At any rate, looks like a runtime issue.

cc @mangod9

dotnet-policy-service[bot] commented 3 days ago

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