dotnet test in AzP captures 64-bit dump of 32-bit test runner process #3031
Description
Description
A test run failed with a timeout in Azure Pipelines and a 30 second inactivity dump was collected.
But although the test run was in a 32-bit process:
Blame: Attaching crash dump utility to process testhost.net472.x86 (1116).
The dump was collected with procdump64.exe instead of procdump.exe, which essentially made the dump useless for analyzing the hang.
Steps to reproduce
git clone https://github.com/microsoft/vs-streamjsonrpc
cd vs-streamjsonrpc
git checkout a9cd051d685281ab2779ae0f946cb86e557afad0
.\init
Open the PerfTests.cs file and add this test:
[Fact]
public async Task Wait60()
{
await Task.Delay(60000);
}Then at the command line run this from the root of the repo:
dotnet test .\test\StreamJsonRpc.Tests\ --filter "FullyQualifiedName~Wait60" -f net472 --settings .\azure-pipelines\Windows_NT.runsettings
The output looks like:
Test run for C:\git\streamjsonrpc\bin\StreamJsonRpc.Tests\Debug\net472\StreamJsonRpc.Tests.dll (.NETFramework,Version=v4.7.2)
Microsoft (R) Test Execution Command Line Tool Version 16.11.0
Copyright (c) Microsoft Corporation. All rights reserved.
Starting test execution, please wait...
A total of 1 test files matched the specified pattern.
The active test run was aborted. Reason: Test host process crashed
Data collector 'Blame' message: The specified inactivity time of 30 seconds has elapsed. Collecting hang dumps from testhost and its child processes.
Data collector 'Blame' message: Dumping 31036 - testhost.net472.x86.
Attachments:
C:\git\streamjsonrpc\test\StreamJsonRpc.Tests\TestResults\f9e971a6-1ecc-4419-811a-b1fba5a7d539\testhost.net472.x86_31036_20210902T111733_hangdump.dmp
C:\git\streamjsonrpc\test\StreamJsonRpc.Tests\TestResults\f9e971a6-1ecc-4419-811a-b1fba5a7d539\testhost.net472.x86_31036_20210902T111733_hangdump.dmp
C:\git\streamjsonrpc\test\StreamJsonRpc.Tests\TestResults\f9e971a6-1ecc-4419-811a-b1fba5a7d539\Sequence_054f10aa67a9436aae63f4543bf70dba.xml
Test Run Aborted.
Build FAILED.
0 Warning(s)
0 Error(s)
Time Elapsed 00:00:41.50
Open the dump file in windbg and enter the k command.
Expected behavior
The k command prints out a useful callstack.
0:000> k
# ChildEBP RetAddr
00 00d9edb8 76d1b1b3 ntdll!NtWaitForMultipleObjects+0xc [minkernel\ntdll\wow6432\objfre\i386\usrstubs.asm @ 825]
01 00d9edb8 745b4461 KERNELBASE!WaitForMultipleObjectsEx+0x103 [minkernel\kernelbase\synch.c @ 1551]
02 00d9ee08 745b40b0 clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x3c [f:\dd\ndp\clr\src\vm\threads.cpp @ 4302]
03 (Inline) -------- clr!Thread::DoAppropriateAptStateWait+0x35 [f:\dd\ndp\clr\src\vm\threads.cpp @ 4336]
04 00d9ee8c 745b41de clr!Thread::DoAppropriateWaitWorker+0x1eb [f:\dd\ndp\clr\src\vm\threads.cpp @ 4476]
05 00d9eef8 745b4327 clr!Thread::DoAppropriateWait+0x64 [f:\dd\ndp\clr\src\vm\threads.cpp @ 4143]
06 (Inline) -------- clr!SOIntolerantTransitionHandler::SetNoException+0xfffffffe [f:\dd\ndp\clr\src\inc\genericstackprobe.h @ 204]
07 00d9ef44 744c333b clr!CLREventBase::WaitEx+0x121 [f:\dd\ndp\clr\src\vm\synch.cpp @ 850]
08 00d9ef5c 746003c1 clr!CLREventBase::Wait+0x1a [f:\dd\ndp\clr\src\vm\synch.cpp @ 773]
09 (Inline) -------- clr!Thread::Wait+0x17 [f:\dd\ndp\clr\src\vm\threads.cpp @ 4961]
0a 00d9ef70 74600618 clr!Thread::Block+0x25 [f:\dd\ndp\clr\src\vm\threads.cpp @ 4918]
0b 00d9f020 7460072e clr!SyncBlock::Wait+0x189 [f:\dd\ndp\clr\src\vm\syncblk.cpp @ 3560]
0c (Inline) -------- clr!ObjHeader::Wait+0x24 [f:\dd\ndp\clr\src\vm\syncblk.cpp @ 2742]
0d (Inline) -------- clr!Object::Wait+0x24 [f:\dd\ndp\clr\src\vm\object.h @ 542]
0e 00d9f0c4 733942c8 clr!ObjectNative::WaitTimeout+0xcb [f:\dd\ndp\clr\src\classlibnative\bcltype\objectnative.cpp @ 315]
0f 00d9f0d4 733a23fd mscorlib_ni!System.Threading.Monitor.Wait(System.Object, Int32, Boolean)+0x18 [f:\dd\ndp\clr\src\BCL\system\threading\monitor.cs @ 203]
10 00d9f12c 7341f5a9 mscorlib_ni!System.Threading.Monitor.Wait(System.Object, Int32)+0xd [f:\dd\ndp\clr\src\BCL\system\threading\monitor.cs @ 213]
11 00d9f12c 7341d8f8 mscorlib_ni!System.Threading.ManualResetEventSlim.Wait(Int32, System.Threading.CancellationToken)+0x219 [f:\dd\ndp\clr\src\BCL\system\threading\ManualResetEventSlim.cs @ 521]
12 00d9f16c 734804f9 mscorlib_ni!System.Threading.Tasks.Task.SpinThenBlockingWait(Int32, System.Threading.CancellationToken)+0x98 [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 3320]
13 00d9f1d0 7341d7b6 mscorlib_ni!System.Threading.Tasks.Task.InternalWait(Int32, System.Threading.CancellationToken)+0x165 [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 3259]
14 00d9f1e0 02fc58b3 mscorlib_ni!System.Threading.Tasks.Task.Wait(Int32, System.Threading.CancellationToken)+0x36 [f:\dd\ndp\clr\src\BCL\system\threading\Tasks\Task.cs @ 3167]
15 00d9f228 02fc0dce testhost_net472_x86!Microsoft.VisualStudio.TestPlatform.TestHost.DefaultEngineInvoker.Invoke(System.Collections.Generic.IDictionary`2<System.String,System.String>)+0x233 [C:\A\1\41\s\src\testhost.x86\DefaultEngineInvoker.cs @ 123]
16 00d9f234 02fc0ceb testhost_net472_x86!Microsoft.VisualStudio.TestPlatform.TestHost.Program.Run(System.String[])+0x2e [C:\A\1\41\s\src\testhost.x86\Program.cs @ 61]
17 00d9f258 744af036 testhost_net472_x86!Microsoft.VisualStudio.TestPlatform.TestHost.Program.Main(System.String[])+0x2b [C:\A\1\41\s\src\testhost.x86\Program.cs @ 36]
18 00d9f264 744b22da clr!CallDescrWorkerInternal+0x34 [f:\dd\ndp\clr\src\vm\i386\asmhelpers.asm @ 763]
19 00d9f2b8 744b859b clr!CallDescrWorkerWithHandler+0x6b [f:\dd\ndp\clr\src\vm\callhelpers.cpp @ 91]
1a 00d9f328 7465b11b clr!MethodDescCallSite::CallTargetWorker+0x16a [f:\dd\ndp\clr\src\vm\callhelpers.cpp @ 655]
1b (Inline) -------- clr!MethodDescCallSite::Call_RetArgSlot+0x21e56 [f:\dd\ndp\clr\src\vm\callhelpers.h @ 423]
1c 00d9f44c 7465b7fa clr!RunMain+0x1b3 [f:\dd\ndp\clr\src\vm\assembly.cpp @ 2681]
1d 00d9f6b8 7465b727 clr!Assembly::ExecuteMainMethod+0xf7 [f:\dd\ndp\clr\src\vm\assembly.cpp @ 2795]
1e 00d9fb9c 7465b8a8 clr!SystemDomain::ExecuteMainMethod+0x5ef [f:\dd\ndp\clr\src\vm\appdomain.cpp @ 3756]
1f 00d9fbf4 7465b9ce clr!ExecuteEXE+0x4c [f:\dd\ndp\clr\src\vm\ceemain.cpp @ 3055]
20 00d9fc34 74657305 clr!_CorExeMainInternal+0xdc [f:\dd\ndp\clr\src\vm\ceemain.cpp @ 2887]
21 00d9fc70 74c7fa84 clr!_CorExeMain+0x4d [f:\dd\ndp\clr\src\vm\ceemain.cpp @ 2815]
22 00d9fca8 74d0e81e mscoreei!_CorExeMain+0xd6 [f:\dd\ndp\clr\src\dlls\shim\shim.cpp @ 6425]
23 00d9fcb8 74d14338 MSCOREE!ShellShim__CorExeMain+0x9e [onecore\com\netfx\windowsbuilt\shell_shim\v2api.cpp @ 277]
24 00d9fcd0 751bfa29 MSCOREE!_CorExeMain_Exported+0x8 [onecore\com\netfx\windowsbuilt\shell_shim\v2api.cpp @ 1223]
25 00d9fcd0 76f17a7e KERNEL32!BaseThreadInitThunk+0x19 [clientcore\base\win32\client\thread.c @ 64]
26 00d9fd2c 76f17a4e ntdll!__RtlUserThreadStart+0x2f [minkernel\ntdll\rtlstrt.c @ 1153]
27 00d9fd3c 00000000 ntdll!_RtlUserThreadStart+0x1b [minkernel\ntdll\rtlstrt.c @ 1070]
Actual behavior
The output of the command is useless, revealing that the 32-bit test process was dumped with a 64-bit tool.
0:000> k
# Child-SP RetAddr Call Site
00 00000000`0083e708 00000000`76ea1856 wow64cpu!CpupSyscallStub+0xc [onecore\base\wow64\cpu\wow64cpu\amd64\simulate.asm @ 1049]
01 00000000`0083e710 00000000`76ea11b9 wow64cpu!WaitForMultipleObjects32+0x1d [onecore\base\wow64\cpu\wow64cpu\amd64\simulate.asm @ 722]
02 00000000`0083e7c0 00007ffc`f59638c9 wow64cpu!BTCpuSimulate+0x9 [onecore\base\wow64\cpu\wow64cpu\amd64\cpuamd64.c @ 577]
03 (Inline Function) --------`-------- wow64!CpuSimulate+0x9 [onecore\base\wow64\wow64\cpumain.c @ 971]
04 00000000`0083e800 00007ffc`f59632bd wow64!RunCpuSimulation+0xd [onecore\base\wow64\wow64\wow64.c @ 1830]
05 00000000`0083e830 00007ffc`f6443652 wow64!Wow64LdrpInitialize+0x12d [onecore\base\wow64\wow64\wow64.c @ 270]
06 (Inline Function) --------`-------- ntdll!Wow64LdrpInitialize+0x11 [minkernel\ntdll\ldrinit.c @ 153]
07 00000000`0083eae0 00007ffc`f63e4ceb ntdll!LdrpInitializeProcess+0x1932 [minkernel\ntdll\ldrinit.c @ 5369]
08 00000000`0083ef10 00007ffc`f63e4b73 ntdll!_LdrpInitialize+0x15f [minkernel\ntdll\ldrinit.c @ 1652]
09 00000000`0083efb0 00007ffc`f63e4b1e ntdll!LdrpInitialize+0x3b [minkernel\ntdll\ldrinit.c @ 1455]
0a 00000000`0083efe0 00000000`00000000 ntdll!LdrInitializeThunk+0xe [minkernel\ntdll\ldrstart.c @ 91]
Diagnostic logs
Environment
This is on an amd64 Windows installation, with VS 16.11-preview.3.
.NET SDK: 5.0.400