dotnet / runtime

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

Test failure: GC/API/GC/GetTotalAllocatedBytes/GetTotalAllocatedBytes.sh #106242

Open v-wenyuxu opened 2 months ago

v-wenyuxu commented 2 months ago

Failed in: runtime-coreclr jitstress-isas-arm 20240810.1

Failed tests:

coreclr osx arm64 Checked jitstress_isas_incompletehwintrinsic @ OSX.1200.ARM64.Open
    - GC/API/GC/GetTotalAllocatedBytes/GetTotalAllocatedBytes.sh

Error message:


Assert failure(PID 40598 [0x00009e96], Thread: 2901095 [0x2c4467]): (g_fEEShutDown&ShutDown_Finalize1) && GetThread() == FinalizerThread::GetFinalizerThread()
    File: /Users/runner/work/1/s/src/coreclr/vm/appdomain.cpp:3670
    Image: /private/tmp/helix/working/A8B4092F/p/corerun

waitpid() returned successfully (wstatus 00000000) WEXITSTATUS 0 WTERMSIG 0
/private/tmp/helix/working/A8B4092F/w/A7A2096B/e/GC/API/GC/GetTotalAllocatedBytes/GetTotalAllocatedBytes.sh: line 439: 40598 Abort trap: 6           (core dumped) $LAUNCHER $ExePath "${CLRTestExecutionArguments[@]}"

Return code:      1
Raw output file:      /tmp/helix/working/A8B4092F/w/A7A2096B/uploads/Reports/GC.API/GC/GetTotalAllocatedBytes/GetTotalAllocatedBytes.output.txt
Raw output:
BEGIN EXECUTION
/tmp/helix/working/A8B4092F/p/corerun -p System.Reflection.Metadata.MetadataUpdater.IsSupported=false -p System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true GetTotalAllocatedBytes.dll ''
[createdump] Gathering state for process 40598 
[createdump] Crashing thread 2c4467 signal 6 (0006)
[createdump] Writing crash report to file /cores/coredump.40598.dmp.crashreport.json
[createdump] Crash report successfully written
[createdump] Writing minidump with heap to file /cores/coredump.40598.dmp
[createdump] Written 489799848 bytes (29895 pages) to core file
[createdump] Target process is alive
[createdump] Dump successfully written in 1319ms
Expected: 100
Actual: 134
END EXECUTION - FAILED
Test failed. Trying to see if dump file was created in /cores since 8/10/2024 1:23:56 PM
Processing /cores/coredump.40598.dmp.crashreport.json
Printing stacktrace from '/cores/coredump.40598.dmp.crashreport.json'
Invoking llvm-symbolizer --pretty-print
Errors while running llvm-symbolizer --pretty-print
System.ComponentModel.Win32Exception (2): An error occurred trying to start process 'llvm-symbolizer' with working directory '/private/tmp/helix/working/A8B4092F/w/A7A2096B/e'. No such file or directory
   at System.Diagnostics.Process.ForkAndExecProcess(ProcessStartInfo startInfo, String resolvedFilename, String[] argv, String[] envp, String cwd, Boolean setCredentials, UInt32 userId, UInt32 groupId, UInt32[] groups, Int32& stdinFd, Int32& stdoutFd, Int32& stderrFd, Boolean usesTerminal, Boolean throwOnNoExec)
   at System.Diagnostics.Process.StartCore(ProcessStartInfo startInfo)
   at System.Diagnostics.Process.Start()
   at CoreclrTestLib.CoreclrTestWrapperLib.TryPrintStackTraceFromCrashReport(String crashReportJsonFile, TextWriter outputWriter)
Test Harness Exitcode is : 1
To run the test:
> set CORE_ROOT=/tmp/helix/working/A8B4092F/p
> /private/tmp/helix/working/A8B4092F/w/A7A2096B/e/GC/API/GC/GetTotalAllocatedBytes/GetTotalAllocatedBytes.sh

Stack trace:

   at GC_API._GC_GetTotalAllocatedBytes_GetTotalAllocatedBytes_._GC_GetTotalAllocatedBytes_GetTotalAllocatedBytes_sh()

   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
dotnet-policy-service[bot] commented 2 months ago

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

v-wenyuxu commented 2 months ago

Failed in: runtime-coreclr jitstressregs 20240818.1

Failed tests:

coreclr osx arm64 Checked jitstressregs0x2000 @ OSX.1200.ARM64.Open
    - profiler/handles/handles/handles.sh

Error message:


Assert failure(PID 1564 [0x0000061c], Thread: 18210 [0x4722]): (g_fEEShutDown&ShutDown_Finalize1) && GetThread() == FinalizerThread::GetFinalizerThread()
    File: /Users/runner/work/1/s/src/coreclr/vm/appdomain.cpp:3661
    Image: /private/tmp/helix/working/B24F0A0D/p/corerun

waitpid() returned successfully (wstatus 00000000) WEXITSTATUS 0 WTERMSIG 0
Unhandled exception. System.Exception: Profiler tests are expected to contain the text 'PROFILER TEST PASSES' in the console output of the profilee app to indicate a passing test. Usually it is printed from the Shutdown() method of the profiler implementation. This text was not found in the output above. Profilee returned exit code 134.
   at Profiler.Tests.ProfilerTestRunner.FailFastWithMessage(String error)
   at Profiler.Tests.ProfilerTestRunner.Run(String profileePath, String testName, Guid profilerClsid, String profileeArguments, ProfileeOptions profileeOptions, Dictionary`2 envVars, String reverseServerName, Boolean loadAsNotification, Int32 notificationCopies)
   at Profiler.Tests.HandlesTests.Main(String[] args)
waitpid() returned successfully (wstatus 00000000) WEXITSTATUS 0 WTERMSIG 0
/private/tmp/helix/working/B24F0A0D/w/A66808DF/e/profiler/handles/handles/handles.sh: line 446:  1563 Abort trap: 6           (core dumped) $LAUNCHER $ExePath "${CLRTestExecutionArguments[@]}"

Return code:      1
Raw output file:      /tmp/helix/working/B24F0A0D/w/A66808DF/uploads/Reports/profiler.handles/handles/handles.output.txt
Raw output:
BEGIN EXECUTION
/tmp/helix/working/B24F0A0D/p/corerun -p System.Reflection.Metadata.MetadataUpdater.IsSupported=false -p System.Runtime.Serialization.EnableUnsafeBinaryFormatterSerialization=true handles.dll ''
Profiler path: /private/tmp/helix/working/B24F0A0D/w/A66808DF/e/profiler/handles/handles/libProfiler.dylib
Profilee STDOUT: Profiler.dll!DllGetClassObject
Profilee STDOUT: Profiler.dll!Profiler::Initialize
Profilee STDOUT: Handles started. Control-C to exit
Profilee STDOUT: Worker thread started
Profilee STDOUT: Allocating Weak
Profilee STDOUT: Allocating Strong
Profilee STDOUT: Allocating Pinned
Profilee STDOUT: weak = 1-W
Profilee STDOUT: strong = 2-S
Profilee STDOUT: weak = 3-P
Profilee STDOUT: Collection #1
Profilee STDOUT: HandlesProfiler::ObjectAllocated: weak handle created.
Profilee STDOUT: HandlesProfiler::ObjectAllocated: strong handle created.
Profilee STDOUT: HandlesProfiler::ObjectAllocated: pinned handle created.
Profilee STDOUT: HandlesProfiler::CheckIfAlive(weak): object not alive as expected.
Profilee STDOUT: HandlesProfiler::CheckIfAlive(strong): object alive as expected (Profiler.Tests.TestClassForStrongHandle)
Profilee STDOUT: HandlesProfiler::CheckIfAlive(pinned): object alive as expected (Profiler.Tests.TestClassForPinnedHandle)
Profilee STDOUT: Collection #2
Profilee STDOUT: HandlesProfiler::GarbageCollectionFinished(#1): pinned handle object address did not changed as expected.
Profilee STDOUT: HandlesProfiler::CheckIfAlive(strong): object alive as expected (Profiler.Tests.TestClassForStrongHandle)
Profilee STDOUT: HandlesProfiler::CheckIfAlive(pinned): object alive as expected (Profiler.Tests.TestClassForPinnedHandle)
Profilee STDOUT: Collection #3
Profilee STDOUT: Test Passed
Profilee STDOUT: HandlesProfiler::GarbageCollectionFinished(#2): strong handle destroyed.
Profilee STDOUT: HandlesProfiler::GarbageCollectionFinished(#2): pinned handle destroyed.
Profilee STDOUT: HandlesProfiler::GarbageCollectionFinished(#3): Checking handles:
Profilee STDOUT: HandlesProfiler::CheckIfAlive(strong): object not alive as expected.
Profilee STDOUT: HandlesProfiler::CheckIfAlive(pinned): object not alive as expected.
Profilee STDOUT: [createdump] Gathering state for process 1564 
Profilee STDOUT: [createdump] Crashing thread 4722 signal 6 (0006)
Profilee STDOUT: [createdump] Writing crash report to file /cores/coredump.1564.dmp.crashreport.json
Profilee STDOUT: [createdump] Crash report successfully written
Profilee STDOUT: [crea

Stack trace:

   at profiler_handles._handles_handles_._handles_handles_sh()

   at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
   at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
AndyAyersMS commented 2 months ago

@VSadov this looks like some kind of assert during finalization, can you take a look?

VSadov commented 2 months ago

Seems like something with RaiseShutdownEvents sequence. I wonder what part of this assert did not actually hold. Only finalizer thread ever calls this function and the quit flag is set after setting up global ShutDown_Finalize1.

Perhaps due to some race theGetThread() == FinalizerThread::GetFinalizerThread() is not holding - i.e. something with identity of the finalizer thread was not right.

VSadov commented 2 months ago

the failures that were reported are in completely different tests, but both times on osx-arm64.