runtime
runtime copied to clipboard
Published
20 hours ago •
dotnet
dotnet
Test failure "RemoteExecutionException : Half-way through waiting for remote process." in System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest
trafficstars
Important: This was found in a 9.0 PR shortly after the snap, so whatever fix will have to get backported.
Build Information
Build: https://dev.azure.com/dnceng-public/public/_build/results?buildId=776432
Build error leg or test failing: System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest in Libraries Test Run release coreclr windows x64 Debug
Error Message
{
"ErrorMessage" : "at System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest(Int32 ioCompletionPortCount)",
"BuildRetry" : false,
"ExcludeConsoleLog" : false
}
- PR: https://github.com/dotnet/runtime/pull/106429
- Queue:
Libraries Test Run release coreclr windows x64 Debug - Job result: https://dev.azure.com/dnceng-public/public/_build/results?buildId=776432&view=logs&j=cb131f87-d5af-5ecc-6e5f-6dc86994859c&t=6a61743b-4295-56b4-b08a-082e36892f8d&l=117
- Log file: https://helixre107v0xd1eu3ibi6ka.blob.core.windows.net/dotnet-runtime-refs-pull-106429-merge-8a077d37470941fb90/System.Threading.ThreadPool.Tests/1/console.bb045b5b.log?helixlogtype=result
- Output:
----- start Thu 08/15/2024 2:15:18.45 =============== To repro directly: =====================================================
pushd C:\h\w\A1E808D0\w\B00D09BE\e\
"C:\h\w\A1E808D0\p\dotnet.exe" exec --runtimeconfig System.Threading.ThreadPool.Tests.runtimeconfig.json --depsfile System.Threading.ThreadPool.Tests.deps.json xunit.console.dll System.Threading.ThreadPool.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
popd
===========================================================================================================
C:\h\w\A1E808D0\w\B00D09BE\e>"C:\h\w\A1E808D0\p\dotnet.exe" exec --runtimeconfig System.Threading.ThreadPool.Tests.runtimeconfig.json --depsfile System.Threading.ThreadPool.Tests.deps.json xunit.console.dll System.Threading.ThreadPool.Tests.dll -xml testResults.xml -nologo -nocolor -notrait category=IgnoreForCI -notrait category=OuterLoop -notrait category=failing
Discovering: System.Threading.ThreadPool.Tests (method display = ClassAndMethod, method display options = None)
Discovered: System.Threading.ThreadPool.Tests (found 48 test cases)
Starting: System.Threading.ThreadPool.Tests (parallel test collections = on [2 threads], stop on fail = off)
System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest(ioCompletionPortCount: 7) [FAIL]
Microsoft.DotNet.RemoteExecutor.RemoteExecutionException : Half-way through waiting for remote process.
Memory load: 17
Image Name PID Services
========================= ======== ============================================
svchost.exe 596 BrokerInfrastructure, DcomLaunch, LSM,
PlugPlay, Power, SystemEventsBroker
svchost.exe 628 RpcEptMapper, RpcSs
svchost.exe 740 AppIDSvc, Dhcp, EventLog, lmhosts,
vmictimesync, Wcmsvc
svchost.exe 776 AeLookupSvc, Appinfo, BITS, CertPropSvc,
gpsvc, iphlpsvc, LanmanServer, ProfSvc,
sacsvr, Schedule, SENS, SessionEnv,
ShellHWDetection, Themes, Winmgmt
svchost.exe 840 EventSystem, FontCache, netprofm, nsi,
W32Time, WinHttpAutoProxySvc
svchost.exe 936 CryptSvc, Dnscache, LanmanWorkstation,
NlaSvc, WinRM
svchost.exe 376 BFE, DPS, MpsSvc, pla
svchost.exe 1104 AppHostSvc
svchost.exe 1124 DiagTrack
svchost.exe 1324 TrkWks, UALSVC, UmRdpService,
vmickvpexchange, vmicshutdown
svchost.exe 1348 W3SVC, WAS
svchost.exe 1652 TermService
svchost.exe 1704 vmicheartbeat
svchost.exe 5928 AppXSvc
Timed out at 8/15/2024 2:16:26 AM after 60000ms waiting for remote process.
Wrote mini dump to: C:\h\w\A1E808D0\w\B00D09BE\uploads\4972.wy2cwqn1.5f1.dmp
Process ID: 4972
Handle: 980
Name: dotnet
MainModule: C:\h\w\A1E808D0\p\dotnet.exe
StartTime: 8/15/2024 2:15:26 AM
TotalProcessorTime: 00:00:00.3281250
Threads:
Thread #1 (OS 0x154C) [MTA]
[PrestubMethodFrame] (System.DateTimeFormat.CoreLib]])
System.DateTimeFormat.TryFormat[[System.Char, System.Private.CoreLib]](System.DateTime, System.Span`1<Char>, Int32 ByRef, System.ReadOnlySpan`1<Char>, System.IFormatProvider, System.TimeSpan)
System.DateTimeFormat.TryFormat[[System.Char, System.Private.CoreLib]](System.DateTime, System.Span`1<Char>, Int32 ByRef, System.ReadOnlySpan`1<Char>, System.IFormatProvider)
System.DateTime.TryFormat(System.Span`1<Char>, Int32 ByRef, System.ReadOnlySpan`1<Char>, System.IFormatProvider)
System.Text.StringBuilder+AppendInterpolatedStringHandler.AppendFormatted[[System.DateTime, System.Private.CoreLib]](System.DateTime)
Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose(Boolean)
Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose()
System.Threading.ThreadPools.Tests.ThreadPoolTests+<>c.<IOCompletionPortCountConfigVarTest>b__47_0(System.String)
[HelperMethodFrame_PROTECTOBJ] (System.RuntimeMethodHandle.InvokeMethod)
System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(System.Object, IntPtr*)
System.Reflection.MethodBaseInvoker.InvokeDirectByRefWithFewArgs(System.Object, System.Span`1<System.Object>, System.Reflection.BindingFlags)
System.Reflection.MethodBaseInvoker.InvokeWithOneArg(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
System.Reflection.RuntimeMethodInfo.Invoke(System.Object, System.Reflection.BindingFlags, System.Reflection.Binder, System.Object[], System.Globalization.CultureInfo)
System.Reflection.MethodBase.Invoke(System.Object, System.Object[])
Microsoft.DotNet.RemoteExecutor.Program.Main(System.String[])
Thread #2 (OS 0x1298) [Finalizer] [Background]
[DebuggerU2MCatchHandlerFrame]
Thread #3 (OS 0x104C) [Background] [MTA]
[DebuggerU2MCatchHandlerFrame]
Stack Trace:
/_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs(225,0): at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose(Boolean disposing)
/_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs(55,0): at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose()
/_/src/libraries/System.Threading.ThreadPool/tests/ThreadPoolTests.cs(1348,0): at System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest(Int32 ioCompletionPortCount)
at InvokeStub_ThreadPoolTests.IOCompletionPortCountConfigVarTest(Object, Span`1)
/_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs(95,0): at System.Reflection.MethodBaseInvoker.InvokeWithOneArg(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
Unhandled exception. System.AggregateException: One or more errors occurred. (Assert.True() Failure
Expected: True
Actual: False)
---> Xunit.Sdk.TrueException: Assert.True() Failure
Expected: True
Actual: False
at Xunit.Assert.True(Nullable`1 condition, String userMessage) in /_/src/Microsoft.DotNet.XUnitAssert/src/BooleanAsserts.cs:line 146
at Xunit.Assert.True(Boolean condition) in /_/src/Microsoft.DotNet.XUnitAssert/src/BooleanAsserts.cs:line 97
at System.Threading.Tests.ThreadTestHelpers.CheckedWait(WaitHandle wh) in /_/src/libraries/Common/tests/System/Threading/ThreadTestHelpers.cs:line 153
at System.Threading.ThreadPools.Tests.ThreadPoolTests.<IOCompletionPortCountConfigVarTest>g__RunAsyncIOTest|47_3() in /_/src/libraries/System.Threading.ThreadPool/tests/ThreadPoolTests.cs:line 1428
--- End of inner exception stack trace ---
at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 1892
at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2782
at System.Threading.Tasks.Task.Wait() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 2626
at System.Threading.ThreadPools.Tests.ThreadPoolTests.<>c.<IOCompletionPortCountConfigVarTest>b__47_1() in /_/src/libraries/System.Threading.ThreadPool/tests/ThreadPoolTests.cs:line 1367
at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
at System.Reflection.MethodBaseInvoker.InterpretedInvoke_Method(Object obj, IntPtr* args) in /_/src/coreclr/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.CoreCLR.cs:line 36
at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs:line 57
--- End of stack trace from previous location ---
at Microsoft.DotNet.RemoteExecutor.Program.Main(String[] args) in /_/src/Microsoft.DotNet.RemoteExecutor/src/Program.cs:line 97
Unhandled exception. System.Net.Sockets.SocketException (995): The I/O operation has been aborted because of either a thread exit or an application request.
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken) in /_/src/libraries/System.Net.Sockets/src/System/Net/Sockets/Socket.Tasks.cs:line 1386
at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource<System.Net.Sockets.Socket>.GetResult(Int16 token) in /_/src/libraries/System.Net.Sockets/src/System/Net/Sockets/Socket.Tasks.cs:line 1323
at System.Threading.Tasks.ValueTask`1.ValueTaskSourceAsTask.<>c.<.cctor>b__4_0(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/ValueTask.cs:line 665
--- End of stack trace from previous location ---
at System.Threading.ThreadPools.Tests.ThreadPoolTests.<>c__DisplayClass47_1.<<IOCompletionPortCountConfigVarTest>b__5>d.MoveNext() in /_/src/libraries/System.Threading.ThreadPool/tests/ThreadPoolTests.cs:line 1408
--- End of stack trace from previous location ---
at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state) in /_/src/libraries/System.Private.CoreLib/src/System/Threading/Tasks/Task.cs:line 1926
at System.Threading.QueueUserWorkItemCallbackDefaultContext.Execute() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 1503
at System.Threading.ThreadPoolWorkQueue.Dispatch() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/ThreadPoolWorkQueue.cs:line 1099
at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart() in /_/src/libraries/System.Private.CoreLib/src/System/Threading/PortableThreadPool.WorkerThread.cs:line 128
at System.Threading.Thread.StartCallback() in /_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs:line 100
System.Threading.ThreadPools.Tests.ThreadPoolTests.ReadWriteAsyncTest [SKIP]
Condition(s) not met: "UseWindowsThreadPool"
System.Threading.ThreadPools.Tests.ThreadPoolTests.MetricsTest [SKIP]
Condition(s) not met: "IsMetricsTestSupported"
Finished: System.Threading.ThreadPool.Tests
=== TEST EXECUTION SUMMARY ===
System.Threading.ThreadPool.Tests Total: 78, Errors: 0, Failed: 1, Skipped: 2, Time: 81.136s
----- end Thu 08/15/2024 2:16:40.52 ----- exit code 1 ----------------------------------------------------------
Known issue validation
Build: :mag_right: https://dev.azure.com/dnceng-public/public/_build/results?buildId=776432
Error message validated: [at System.Threading.ThreadPools.Tests.ThreadPoolTests.IOCompletionPortCountConfigVarTest(Int32 ioCompletionPortCount)]
Result validation: :white_check_mark: Known issue matched with the provided build.
Validation performed at: 8/15/2024 7:24:24 PM UTC
Report
Summary
| 24-Hour Hit Count | 7-Day Hit Count | 1-Month Count |
|---|---|---|
| 1 | 58 | 137 |
![dotnet-policy-service[bot] avatar](https://avatars.githubusercontent.com/in/285228?v=4 "Published by a pub.dev verified publisher"){kind=small}
cc @kouvel
Likely introduced by #106408. Note that the CI did not run trigger on this PR.
It's not clear to me from the failure what the issue is. I'll disable the test for now and see if I can repro.
Note that the CI did not run trigger on this PR.
It ran successfully, the results are here. The CI results can be seen for the first commit. When trying to merge I had clicked the wrong button, which caused a merge commit to be added to the PR and that restarted the CI. The rerun felt unnecessary, as merging the PR would have yielded a similar result.
@kouvel in general it is a good idea to leave the KnownBuidError open until the fix has been in all impacted branches for a day or two so that recent failures are correctly identified by Build Analysis
Yes I think this can be closed, https://github.com/dotnet/runtime/issues/106371 is tracking the issue.