dotnet
ExceptionOnStartIsPropagated test failed in CI
Build Information
Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=232981 Build error leg or test failing: Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated Pull request: https://github.com/dotnet/runtime/pull/84556
Error Message
Fill the error message using known issues guidance.
{
"ErrorMessage": "ExceptionOnStartIsPropagated",
"BuildRetry": false,
"ErrorPattern": "",
"ExcludeConsoleLog": true
}
Failing Configuration
net8.0-windows-Release-x86-CoreCLR_release-Windows.Amd64.Server2022.Open
Exception Message
Half-way through waiting for remote process.
Memory load: 25
Image Name PID Services
========================= ======== ============================================
svchost.exe 860 BrokerInfrastructure, DcomLaunch, PlugPlay,
Power, SystemEventsBroker
svchost.exe 964 RpcEptMapper, RpcSs
svchost.exe 72 LSM
svchost.exe 1036 TermService
svchost.exe 1064 lmhosts
svchost.exe 1112 CoreMessagingRegistrar
svchost.exe 1132 NcbService
svchost.exe 1240 EventLog
svchost.exe 1248 vmicheartbeat
svchost.exe 1260 vmickvpexchange
svchost.exe 1332 vmicshutdown
svchost.exe 1380 vmictimesync
svchost.exe 1472 DispBrokerDesktopSvc
svchost.exe 1520 FontCache
svchost.exe 1532 nsi
svchost.exe 1580 gpsvc
svchost.exe 1636 Dhcp
svchost.exe 1644 Winmgmt
svchost.exe 1668 UmRdpService
svchost.exe 1728 Schedule
svchost.exe 1920 NlaSvc
svchost.exe 1952 CertPropSvc
svchost.exe 2000 LanmanWorkstation
svchost.exe 2016 TimeBrokerSvc
svchost.exe 2036 ProfSvc
svchost.exe 1416 Themes
svchost.exe 1400 EventSystem
svchost.exe 2112 netprofm
svchost.exe 2152 SessionEnv
svchost.exe 2188 SENS
svchost.exe 2280 Dnscache
svchost.exe 2300 Wcmsvc
svchost.exe 2340 UserManager
svchost.exe 2400 ShellHWDetection
svchost.exe 2448 BFE, mpssvc
svchost.exe 2512 WinHttpAutoProxySvc
svchost.exe 2536 hns
svchost.exe 2624 nvagent
svchost.exe 2800 NetSetupSvc
svchost.exe 2896 AppHostSvc
svchost.exe 2904 CryptSvc
svchost.exe 2916 DiagTrack
svchost.exe 2948 iphlpsvc
svchost.exe 3052 sacsvr
svchost.exe 3060 RemoteRegistry
svchost.exe 1768 SysMain
CallStack
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose(Boolean disposing) in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 224
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose() in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 57
at Microsoft.Extensions.Hosting.WindowsServiceTester.Dispose(Boolean disposing) in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceTester.cs:line 147
at System.ComponentModel.Component.Dispose() in /_/src/libraries/System.ComponentModel.Primitives/src/System/ComponentModel/Component.cs:line 73
at Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated() in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceLifetimeTests.cs:line 82
at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodInvoker.cs:line 59
Report
| Build | Definition | Test | Pull Request |
|---|---|---|---|
| 533692 | dotnet/runtime | Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated | dotnet/runtime#95758 |
| 532325 | dotnet/runtime | Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated | dotnet/runtime#95758 |
| 531205 | dotnet/runtime | Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated | dotnet/runtime#95758 |
Summary
| 24-Hour Hit Count | 7-Day Hit Count | 1-Month Count |
|---|---|---|
| 0 | 3 | 3 |
Known issue validation
Build: :mag_right: https://dev.azure.com/dnceng-public/public/_build/results?buildId=323960
Error message validated: ExceptionOnStartIsPropagated
Result validation: :white_check_mark: Known issue matched with the provided build.
Validation performed at: 6/28/2023 9:03:34 PM UTC
Tagging subscribers to this area: @dotnet/area-extensions-hosting See info in area-owners.md if you want to be subscribed.
Issue Details
Build Information
Build: https://dev.azure.com/dnceng-public/cbb18261-c48f-4abb-8651-8cdcb5474649/_build/results?buildId=232981 Build error leg or test failing: Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated Pull request: https://github.com/dotnet/runtime/pull/84556
Error Message
Fill the error message using known issues guidance.
{
"ErrorMessage": "ExceptionOnStartIsPropagated",
"BuildRetry": false,
"ErrorPattern": "",
"ExcludeConsoleLog": false
}
Failing Configuration
net8.0-windows-Release-x86-CoreCLR_release-Windows.Amd64.Server2022.Open
Exception Message
Half-way through waiting for remote process.
Memory load: 25
Image Name PID Services
========================= ======== ============================================
svchost.exe 860 BrokerInfrastructure, DcomLaunch, PlugPlay,
Power, SystemEventsBroker
svchost.exe 964 RpcEptMapper, RpcSs
svchost.exe 72 LSM
svchost.exe 1036 TermService
svchost.exe 1064 lmhosts
svchost.exe 1112 CoreMessagingRegistrar
svchost.exe 1132 NcbService
svchost.exe 1240 EventLog
svchost.exe 1248 vmicheartbeat
svchost.exe 1260 vmickvpexchange
svchost.exe 1332 vmicshutdown
svchost.exe 1380 vmictimesync
svchost.exe 1472 DispBrokerDesktopSvc
svchost.exe 1520 FontCache
svchost.exe 1532 nsi
svchost.exe 1580 gpsvc
svchost.exe 1636 Dhcp
svchost.exe 1644 Winmgmt
svchost.exe 1668 UmRdpService
svchost.exe 1728 Schedule
svchost.exe 1920 NlaSvc
svchost.exe 1952 CertPropSvc
svchost.exe 2000 LanmanWorkstation
svchost.exe 2016 TimeBrokerSvc
svchost.exe 2036 ProfSvc
svchost.exe 1416 Themes
svchost.exe 1400 EventSystem
svchost.exe 2112 netprofm
svchost.exe 2152 SessionEnv
svchost.exe 2188 SENS
svchost.exe 2280 Dnscache
svchost.exe 2300 Wcmsvc
svchost.exe 2340 UserManager
svchost.exe 2400 ShellHWDetection
svchost.exe 2448 BFE, mpssvc
svchost.exe 2512 WinHttpAutoProxySvc
svchost.exe 2536 hns
svchost.exe 2624 nvagent
svchost.exe 2800 NetSetupSvc
svchost.exe 2896 AppHostSvc
svchost.exe 2904 CryptSvc
svchost.exe 2916 DiagTrack
svchost.exe 2948 iphlpsvc
svchost.exe 3052 sacsvr
svchost.exe 3060 RemoteRegistry
svchost.exe 1768 SysMain
CallStack
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose(Boolean disposing) in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 224
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose() in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 57
at Microsoft.Extensions.Hosting.WindowsServiceTester.Dispose(Boolean disposing) in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceTester.cs:line 147
at System.ComponentModel.Component.Dispose() in /_/src/libraries/System.ComponentModel.Primitives/src/System/ComponentModel/Component.cs:line 73
at Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated() in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceLifetimeTests.cs:line 82
at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
at System.Reflection.MethodInvoker.Invoke(Object obj, IntPtr* args, BindingFlags invokeAttr) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodInvoker.cs:line 59
| Author: | stephentoub |
|---|---|
| Assignees: | - |
| Labels: |
|
| Milestone: | - |
Most of the failures listed here were not the same as @stephentoub's OP issue. Many were due to the test running on a platform that didn't support RemoteExecutor (not part of default platform set) which was fixed in #84552.
I was able to pull down @stephentoub's test failure and dump with:
runfo get-helix-payload -j 4248a943-5561-4089-8b71-74bd05dc0faf -w Microsoft.Extensions.Hosting.WindowsServices.Tests -x -o .\
The test was inside the service dispatcher, which I would imagine would mean the service as Started.
09F0FCB8 73e1716f [DebuggerU2MCatchHandlerFrame: 09f0fcb8]
0:000> !dumpasync
Statistics:
MT Count TotalSize Class Name
09f86130 1 72 System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib],[Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions+<WaitForShutdownAsync>d__5, Microsoft.Extensions.Hosting.Abstractions]]
0968d1d8 1 80 System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[System.Threading.Tasks.VoidTaskResult, System.Private.CoreLib],[Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions+<RunAsync>d__4, Microsoft.Extensions.Hosting.Abstractions]]
Total 2 objects
Address MT Size State Description
03b7958c 0968d1d8 80 1 Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions+<RunAsync>d__4
03b8c898 09f86130 72 0 Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions+<WaitForShutdownAsync>d__5
So waiting here: https://github.com/dotnet/runtime/blob/018a37bda3f89080dbb52d257d838e824d56bca9/src/libraries/Microsoft.Extensions.Hosting.Abstractions/src/HostingAbstractionsHostExtensions.cs#L69 and here https://github.com/dotnet/runtime/blob/018a37bda3f89080dbb52d257d838e824d56bca9/src/libraries/Microsoft.Extensions.Hosting.Abstractions/src/HostingAbstractionsHostExtensions.cs#L107
The service status is running:
0:004> !DumpVC /d 076dee98 03b78944
Name: Interop+Advapi32+SERVICE_STATUS
MethodTable: 076dee98
EEClass: 0774e358
Size: 36(0x24) bytes
File: C:\h\w\95CF08EA\w\C2450A2C\e\System.ServiceProcess.ServiceController.dll
Fields:
MT Field Offset Type VT Attr Value Name
038ab574 400016e 0 System.Int32 1 instance 16 serviceType
038ab574 400016f 4 System.Int32 1 instance 4 currentState
038ab574 4000170 8 System.Int32 1 instance 5 controlsAccepted
038ab574 4000171 c System.Int32 1 instance 0 win32ExitCode
038ab574 4000172 10 System.Int32 1 instance 0 serviceSpecificExitCode
038ab574 4000173 14 System.Int32 1 instance 0 checkPoint
038ab574 4000174 18 System.Int32 1 instance 0 waitHint
What's interesting though, is that the service that's running is actually not ExceptionOnStartIsPropagated, it's
02D7ED38 03b6a354 System.String <CanCreateService>b__2_0
02D7ED3C 03b6a2d8 System.String Microsoft.Extensions.Hosting.UseWindowsServiceTests+<>c
02D7ED40 03b6a1e0 System.String Microsoft.Extensions.Hosting.WindowsServices.Tests, Version=8.0.0.0, Culture=neutral, PublicKeyToken=adb9793829ddae60
Now that test can run concurrently, since it's in another test class, but it should always create a different service - since the service name is determined by the calling method name. One thing that could happen is process ID recycling. https://github.com/dotnet/runtime/blob/7a57f6dd800e77508a4ba405e623059935c82f43/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceTester.cs#L40-L45
So if the process for ExceptionOnStartIsPropagated exited and a new process was created with the same ID before we could grab the handle, we could be tracking a different process than the one launched for the test case. However that wouldn't explain the process stuck in running case for that long -- since the CanCreateService test should proceed to stopped state as soon as it's up and running, and according to the log, all other tests passed:
Microsoft.Extensions.Hosting.WindowsServices.Tests Total: 12, Errors: 0, Failed: 1, Skipped: 0, Time: 109.919s
All failures here are
System.ComponentModel.Win32Exception : Access is denied.
at System.Diagnostics.ProcessManager.OpenProcess(Int32 processId, Int32 access, Boolean throwIfExited) in /_/src/libraries/System.Diagnostics.Process/src/System/Diagnostics/ProcessManager.Windows.cs:line 252
at System.Diagnostics.Process.GetProcessHandle(Int32 access, Boolean throwIfExited) in /_/src/libraries/System.Diagnostics.Process/src/System/Diagnostics/Process.Windows.cs:line 787
at System.Diagnostics.Process.WaitForExitCore(Int32 milliseconds) in /_/src/libraries/System.Diagnostics.Process/src/System/Diagnostics/Process.Windows.cs:line 167
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose(Boolean disposing) in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 110
at Microsoft.DotNet.RemoteExecutor.RemoteInvokeHandle.Dispose() in /_/src/Microsoft.DotNet.RemoteExecutor/src/RemoteInvokeHandle.cs:line 55
at Microsoft.Extensions.Hosting.WindowsServiceTester.Dispose(Boolean disposing) in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceTester.cs:line 147
at System.ComponentModel.Component.Dispose() in /_/src/libraries/System.ComponentModel.Primitives/src/System/ComponentModel/Component.cs:line 73
at Microsoft.Extensions.Hosting.WindowsServiceLifetimeTests.ExceptionOnStartIsPropagated() in /_/src/libraries/Microsoft.Extensions.Hosting.WindowsServices/tests/WindowsServiceLifetimeTests.cs:line 85
at System.RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
at System.Reflection.MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr) in /_/src/libraries/System.Private.CoreLib/src/System/Reflection/MethodBaseInvoker.cs:line 57
I'd bet that these cases the process is in the middle shutting down by the time we try to get its handle. I bet we could avoid this by either delaying start - or introducing a cross-process message like a global mutex to tell the process when it's ok to throw.
removing blocking-clean-ci as it has not failed in 30 days
| 24-Hour Hit Count | 7-Day Hit Count | 1-Month Count |
|---|---|---|
| 0 | 0 | 0 |
I don't believe this is hit at all anymore after the fix to not run in environments that don't support remote executor. Closing this out.