System.Net.Mail.Tests.SmtpClientTest.TestZeroTimeout hangs in CI

[jaredpar]

System.Net.Mail.Functional.Tests Work Item

Console Log Summary

===========================================================================================================
/root/helix/work/workitem /root/helix/work/workitem
  Discovering: System.Net.Mail.Functional.Tests (method display = ClassAndMethod, method display options = None)
  Discovered:  System.Net.Mail.Functional.Tests (found 145 of 146 test cases)
  Starting:    System.Net.Mail.Functional.Tests (parallel test collections = on, max threads = 2)
   System.Net.Mail.Functional.Tests: [Long Running Test] 'System.Net.Mail.Tests.SmtpClientTest.TestZeroTimeout', Elapsed: 00:02:10
   System.Net.Mail.Functional.Tests: [Long Running Test] 'System.Net.Mail.Tests.SmtpClientTest.TestZeroTimeout', Elapsed: 00:04:10
Process terminated. TestZeroTimeout
   at System.Environment.FailFast(System.String)
   at System.Net.Mail.Tests.SmtpClientTest.TestZeroTimeout()
   at System.RuntimeMethodHandle.InvokeMethod(System.Object, System.Object[], System.Signature, Boolean, Boolean)
   at System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
   at System.Reflection.MethodBase.Invoke(System.Object, System.Object[])
   at Xunit.Sdk.TestInvoker`1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].CallTestMethod(System.Object)
   at Xunit.Sdk.TestInvoker`1+<>c__DisplayClass48_1+<<InvokeTestMethodAsync>b__1>d[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].MoveNext()
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Xunit.Sdk.TestInvoker`1+<>c__DisplayClass48_1+<<InvokeTestMethodAsync>b__1>d[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], xunit.execution.dotnet, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<<InvokeTestMethodAsync>b__1>d<System.__Canon> ByRef)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[Xunit.Sdk.TestInvoker`1+<>c__DisplayClass48_1+<<InvokeTestMethodAsync>b__1>d[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]], xunit.execution.dotnet, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<<InvokeTestMethodAsync>b__1>d<System.__Canon> ByRef)
   at Xunit.Sdk.TestInvoker`1+<>c__DisplayClass48_1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].<InvokeTestMethodAsync>b__1()
   at Xunit.Sdk.ExecutionTimer+<AggregateAsync>d__4.MoveNext()
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Xunit.Sdk.ExecutionTimer+<AggregateAsync>d__4, xunit.execution.dotnet, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<AggregateAsync>d__4 ByRef)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[Xunit.Sdk.ExecutionTimer+<AggregateAsync>d__4, xunit.execution.dotnet, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<AggregateAsync>d__4 ByRef)
   at Xunit.Sdk.ExecutionTimer.AggregateAsync(System.Func`1<System.Threading.Tasks.Task>)
   at Xunit.Sdk.TestInvoker`1+<>c__DisplayClass48_1[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].<InvokeTestMethodAsync>b__0()
   at Xunit.Sdk.ExceptionAggregator+<RunAsync>d__9.MoveNext()
   at System.Runtime.CompilerServices.AsyncMethodBuilderCore.Start[[Xunit.Sdk.ExceptionAggregator+<RunAsync>d__9, xunit.core, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<RunAsync>d__9 ByRef)
   at System.Runtime.CompilerServices.AsyncTaskMethodBuilder.Start[[Xunit.Sdk.ExceptionAggregator+<RunAsync>d__9, xunit.core, Version=2.4.1.0, Culture=neutral, PublicKeyToken=8d05b1bb7a6fdb6c]](<RunAsync>d__9 ByRef)
   at Xunit.Sdk.ExceptionAggregator.RunAsync(System.Func`1<System.Threading.Tasks.Task>)
   at Xunit.Sdk.TestInvoker`1+<InvokeTestMethodAsync>d__48[[System.__Canon, System.Private.CoreLib, Version=5.0.0.0, Culture=neutral, PublicKeyToken=7cec85d7bea7798e]].MoveNext()

Eventually leads to core dump

./RunTests.sh: line 161:    21 Aborted                 (core dumped) "$RUNTIME_PATH/dotnet" exec --runtimeconfig System.Net.Mail.Functional.Tests.runtimeconfig.json --depsfile System.Net.Mail.Functional.Tests.deps.json xunit.console.dll System.Net.Mail.Functional.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing -notrait category=nonnetcoreapptests -notrait category=nonlinuxtests $RSP_FILE
/root/helix/work/workitem
----- end Tue Feb 4 11:52:04 UTC 2020 ----- exit code 134 ----------------------------------------------------------
exit code 134 means SIGABRT Abort. Managed or native assert, or runtime check such as heap corruption, caused call to abort(). Core dumped.

Builds

Build	Pull Request	Test Failure Count
#505231	#2052	1
#507937	#1787	30
#508637	Rolling	1
#508988	Rolling	2

Configurations

• netcoreapp5.0-Linux-Debug-x64-Mono_release-RedHat.7.Amd64.Open
• netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Alpine.311.Amd64.Open)ubuntu.1604.amd64.Open@mcr.microsoft.com/dotnet-buildtools/prereqs:alpine-3.11-helix-bfcd90a-20200123191053
• netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Fedora.30.Amd64.Open)ubuntu.1604.amd64.open@mcr.microsoft.com/dotnet-buildtools/prereqs:fedora-30-helix-4f8cef7-20200121150022
• netcoreapp5.0-Linux-Release-x64-CoreCLR_release-(Ubuntu.1910.Amd64.Open)ubuntu.1604.amd64.open@mcr.microsoft.com/dotnet-buildtools/prereqs:ubuntu-19.10-helix-amd64-cfcfd50-20191030180623
• netcoreapp5.0-OSX-Debug-x64-CoreCLR_checked-OSX.1013.Amd64.Open
• netcoreapp5.0-OSX-Debug-x64-CoreCLR_release-OSX.1013.Amd64.Open
• netcoreapp5.0-OSX-Debug-x64-CoreCLR_release-OSX.1014.Amd64.Open
• netcoreapp5.0-OSX-Debug-x64-Mono_release-OSX.1013.Amd64.Open
• netcoreapp5.0-OSX-Debug-x64-Mono_release-OSX.1014.Amd64.Open
• netcoreapp5.0-Windows_NT-Debug-x64-CoreCLR_checked-Windows.10.Amd64.Open
• netcoreapp5.0-Windows_NT-Debug-x64-CoreCLR_release-(Windows.Nano.1809.Amd64.Open)windows.10.amd64.serverrs5.open@mcr.microsoft.com/dotnet-buildtools/prereqs:nanoserver-1809-helix-amd64-08e8e40-20200107182504
• netcoreapp5.0-Windows_NT-Debug-x64-CoreCLR_release-Windows.10.Amd64.Server19H1.ES.Open
• netcoreapp5.0-Windows_NT-Debug-x64-CoreCLR_release-Windows.7.Amd64.Open
• netcoreapp5.0-Windows_NT-Debug-x64-CoreCLR_release-Windows.81.Amd64.Open
• netcoreapp5.0-Windows_NT-Debug-x86-CoreCLR_release-Windows.10.Amd64.Server19H1.Open
• netcoreapp5.0-Windows_NT-Release-x86-CoreCLR_checked-Windows.10.Amd64.Open
• netcoreapp5.0-Windows_NT-Release-x86-CoreCLR_release-Windows.10.Amd64.Server19H1.ES.Open
• netcoreapp5.0-Windows_NT-Release-x86-CoreCLR_release-Windows.7.Amd64.Open
• netcoreapp5.0-Windows_NT-Release-x86-CoreCLR_release-Windows.81.Amd64.Open

Helix Logs

Build	Pull Request	Console	Core	Test Results
#505231	#2052	console.cf5d4a18.log
#507937	#1787	console.52c06ff7.log
#507937	#1787	console.8a6875b5.log
#507937	#1787	console.77373743.log
#507937	#1787	console.0fa5991f.log
#507937	#1787	console.b46de469.log
#507937	#1787	console.f47b82b1.log
#507937	#1787	console.d80c958c.log
#507937	#1787	console.3fc3b863.log
#507937	#1787	console.1fc50d75.log
#507937	#1787	console.6201955d.log
#507937	#1787	console.3be7d884.log
#507937	#1787	console.5358a763.log
#507937	#1787	console.14572e15.log
#507937	#1787	console.ca81541b.log
#507937	#1787
#507937	#1787	console.bd751177.log
#507937	#1787
#507937	#1787	console.6311394b.log
#507937	#1787
#507937	#1787	console.2c6f447c.log
#507937	#1787	console.6c139f05.log
#507937	#1787	console.abb6fc5a.log
#507937	#1787	console.918dd10f.log
#507937	#1787	console.c2f0ae3a.log
#507937	#1787	console.a9417280.log
#507937	#1787	console.9a7171ac.log
#507937	#1787	console.7bce9a2f.log
#507937	#1787	console.44857451.log
#507937	#1787	console.d7c6b863.log
#507937	#1787	console.8e713a49.log
#508637	Rolling	console.3fff95b3.log
#508988	Rolling	console.2139154d.log	core.1000.24
#508988	Rolling	console.a8515b7c.log	core.1000.58

[stephentoub]

cc: @tmds

[stephentoub]

@jaredpar, did we successfully get a coredump?

runtime/src/libraries/System.Net.Mail/tests/Functional/SmtpClientTest.cs

Line 330 in 9a8f52c

// Abort in order to get a coredump if this test takes too long.

[jaredpar]

@stephentoub

It doesn't appear like we got a coredump. It's not present in the Work Items info. Also looking through the log it seems like the core just wasn't found on the helix machine at all

exit code 134 means SIGABRT Abort. Managed or native assert, or runtime check such as heap corruption, caused call to abort(). Core dumped.
Looking around for any Linux dump...
... found no dump in /root/helix/work/workitem
+ export '_commandExitCode=134'

[stephentoub]

@danmosemsft, who's working on ensuring coredumps are working correctly in CI?

[danmoseley]

@dotnet/dnceng @mjanecke who owns the coredump facility in Helix jobs?

[missymessa]

Which build(s) are missing the dump files? I peeked at a couple of the build links noted above and it looks like there are dump files attached to the failing work item.

[jaredpar]

@mjanecke

You're correct. The code I had for grabbing dump file links was busted (simple Regex error). I've updated the bug with all of the core dump links.

[danmoseley]

Thank you @mjanecke !

[ViktorHofer]

@tmds we finally got a dump: https://helix.dot.net/api/2019-06-17/jobs/7eec8737-2b16-4911-a4c3-b5171573bcb1/workitems/System.Net.Mail.Functional.Tests/files/core.1000.21

[tmds]

This unexpected. I thought we had solved this with #22867. I will take a look at the dump.