System.ServiceProcess.Tests.ServiceBaseTests.TestOnStartThenStop failed in CI

[KristinXie1]

Failed test: System.ServiceProcess.Tests.ServiceBaseTests.TestOnStartThenStop

Detail: https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_netcoreapp_win7_release/lastCompletedBuild/testReport/System.ServiceProcess.Tests/ServiceBaseTests/TestOnStartThenStop/

Configuration: OuterLoop_netcoreapp_win7_release

MESSAGE:

System.InvalidOperationException : Cannot open 40da180b-bbda-4b43-a0dc-256ebc6130e6 service on computer '.'.
    ---- System.ComponentModel.Win32Exception : The specified service does not exist as an installed service

STACK TRACE:

at System.ServiceProcess.ServiceController.GetServiceHandle(Int32 desiredAccess) in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs:line 638 
at System.ServiceProcess.ServiceController.GenerateStatus() in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs:line 473 
at System.ServiceProcess.ServiceController.Stop() in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs:line 882 
at System.ServiceProcess.Tests.TestServiceInstaller.RemoveService() in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\tests\System.ServiceProcess.ServiceController.TestService\TestServiceInstaller.cs:line 136 
at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices() in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs:line 95 
at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices() in D:\j\workspace\outerloop_net---15cfbbd5\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs:line 111 
at ReflectionAbstractionExtensions.DisposeTestClass(ITest test, Object testClass, IMessageBus messageBus, ExecutionTimer timer, CancellationTokenSource cancellationTokenSource) in C:\BuildAgent\work\cb37e9acf085d108\src\xunit.execution\Extensions\ReflectionAbstractionExtensions.cs:line 76 
----- Inner Stack Trace -----

[danmoseley]

same in System.ServiceProcess.Tests.ServiceControllerTests/ConstructWithServiceName_ToUpper

https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20170822.02/workItem/System.ServiceProcess.ServiceController.Tests/analysis/xunit/System.ServiceProcess.Tests.ServiceControllerTests~2FConstructWithServiceName_ToUpper

System.InvalidOperationException : Cannot open 7b3cce7b-768c-4959-b7a1-58c14b684a41 service on computer '.'.
---- System.ComponentModel.Win32Exception : The specified service does not exist as an installed service
Stack Trace :
   at System.ServiceProcess.ServiceController.GetServiceHandle(Int32 desiredAccess)
   at System.ServiceProcess.ServiceController.GenerateStatus()
   at System.ServiceProcess.ServiceController.Stop()
   at System.ServiceProcess.Tests.TestServiceInstaller.RemoveService()
   at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
   at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
   at System.ServiceProcess.Tests.ServiceControllerTests.Dispose()
   at ReflectionAbstractionExtensions.DisposeTestClass(ITest test, Object testClass, IMessageBus messageBus, ExecutionTimer timer, CancellationTokenSource cancellationTokenSource)
----- Inner Stack Trace -----

something is flaky.

[KristinXie1]

same in System.ServiceProcess.Tests.ServiceControllerTests/ConstructWithServiceName_ToUpper
Detail: https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20170828.01/workItem/System.ServiceProcess.ServiceController.Tests/analysis/xunit/System.ServiceProcess.Tests.ServiceControllerTests~2FConstructWithServiceName_ToUpper

[KristinXie1]

failed again in CI: https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_netcoreapp_windows_nt_debug/166/testReport/System.ServiceProcess.Tests/ServiceBaseTests/TestOnPauseThenStop/

[danmoseley]

dotnet/corefx#24042

[KristinXie1]

Test: System.ServiceProcess.Tests.ServiceControllerTests.ConstructWithServiceName_ToUpper failed with same issue.

Detail: https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_netcoreapp_windows_nt_debug/170/testReport/System.ServiceProcess.Tests/ServiceControllerTests/ConstructWithServiceName_ToUpper/

[KristinXie1]

failed again: https://ci.dot.net/job/dotnet_corefx/job/master/job/outerloop_netcoreapp_windows_nt_debug/182/testReport/System.ServiceProcess.Tests/ServiceBaseTests/TestOnContinueBeforePause/

[KristinXie1]

Following test: System.ServiceProcess.Tests.ServiceControllerTests/ConstructWithServiceName failed with same issue, detail: https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20171025.04/workItem/System.ServiceProcess.ServiceController.Tests/analysis/xunit/System.ServiceProcess.Tests.ServiceControllerTests~2FConstructWithServiceName

The test System.ServiceProcess.Tests.ServiceControllerTests/ConstructWithServiceName has failed.

System.InvalidOperationException : Cannot open bdc32291-dc03-46f0-b1ba-5fb3c91922c0 service on computer '.'.\r
---- System.ComponentModel.Win32Exception : The specified service does not exist as an installed service

    Stack Trace:

       at System.ServiceProcess.ServiceController.GetServiceHandle(Int32 desiredAccess)
   at System.ServiceProcess.ServiceController.GenerateStatus()
   at System.ServiceProcess.ServiceController.Stop()
   at System.ServiceProcess.Tests.TestServiceInstaller.RemoveService()
   at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
   at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
   at System.ServiceProcess.Tests.ServiceControllerTests.Dispose()
   at ReflectionAbstractionExtensions.DisposeTestClass(ITest test, Object testClass, IMessageBus messageBus, ExecutionTimer timer, CancellationTokenSource cancellationTokenSource)
----- Inner Stack Trace -----

Build : Master - 20171025.04 (Core Tests)
Failing configurations:

• Windows.10.Amd64.Core-x86
  • Release

[Sunny-pu]

failed again in master:
https://mc.dot.net/#/product/netcore/master/source/official~2Fcorefx~2Fmaster~2F/type/test~2Ffunctional~2Fcli~2F/build/20171204.01/workItem/System.ServiceProcess.ServiceController.Tests/analysis/xunit/System.ServiceProcess.Tests.ServiceBaseTests~2FTestOnContinueBeforePause

[danmoseley]

Possibly related to two test classes uninstalling services at about the same time, see timestamps, although that wasn't noted above

2017-12-11 22:38:48,298: INFO: proc(54): run_and_log_output: Output:    System.ServiceProcess.Tests.ServiceControllerTests.ConstructWithServiceName_ToUpper [FAIL]
2017-12-11 22:38:48,305: INFO: proc(54): run_and_log_output: Output:       System.InvalidOperationException : Cannot open d9f31687-ae98-40b9-be0c-a404d773ddd0 service on computer '.'.
2017-12-11 22:38:48,305: INFO: proc(54): run_and_log_output: Output:       ---- System.ComponentModel.Win32Exception : The specified service does not exist as an installed service
2017-12-11 22:38:48,305: INFO: proc(54): run_and_log_output: Output:       Stack Trace:
2017-12-11 22:38:48,440: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(638,0): at System.ServiceProcess.ServiceController.GetServiceHandle(Int32 desiredAccess)
2017-12-11 22:38:48,440: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(473,0): at System.ServiceProcess.ServiceController.GenerateStatus()
2017-12-11 22:38:48,441: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(882,0): at System.ServiceProcess.ServiceController.Stop()
2017-12-11 22:38:48,441: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\System.ServiceProcess.ServiceController.TestService\TestServiceInstaller.cs(151,0): at System.ServiceProcess.Tests.TestServiceInstaller.RemoveService()
2017-12-11 22:38:48,441: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs(95,0): at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
2017-12-11 22:38:48,441: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs(111,0): at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
2017-12-11 22:38:48,443: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\ServiceControllerTests.cs(197,0): at System.ServiceProcess.Tests.ServiceControllerTests.Dispose()
2017-12-11 22:38:48,443: INFO: proc(54): run_and_log_output: Output:          C:\BuildAgent\work\cb37e9acf085d108\src\xunit.execution\Extensions\ReflectionAbstractionExtensions.cs(76,0): at ReflectionAbstractionExtensions.DisposeTestClass(ITest test, Object testClass, IMessageBus messageBus, ExecutionTimer timer, CancellationTokenSource cancellationTokenSource)
2017-12-11 22:38:48,444: INFO: proc(54): run_and_log_output: Output:          ----- Inner Stack Trace -----
2017-12-11 22:38:48,444: INFO: proc(54): run_and_log_output: Output:          
2017-12-11 22:38:50,404: INFO: proc(54): run_and_log_output: Output:    System.ServiceProcess.Tests.ServiceBaseTests.TestOnPauseAndContinueThenStop [FAIL]
2017-12-11 22:38:50,405: INFO: proc(54): run_and_log_output: Output:       System.InvalidOperationException : Cannot open 2924c2c7-7bff-4daa-ae59-36c2960ee89a service on computer '.'.
2017-12-11 22:38:50,405: INFO: proc(54): run_and_log_output: Output:       ---- System.ComponentModel.Win32Exception : The specified service does not exist as an installed service
2017-12-11 22:38:50,405: INFO: proc(54): run_and_log_output: Output:       Stack Trace:
2017-12-11 22:38:50,405: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(638,0): at System.ServiceProcess.ServiceController.GetServiceHandle(Int32 desiredAccess)
2017-12-11 22:38:50,405: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(473,0): at System.ServiceProcess.ServiceController.GenerateStatus()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\src\System\ServiceProcess\ServiceController.cs(882,0): at System.ServiceProcess.ServiceController.Stop()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\System.ServiceProcess.ServiceController.TestService\TestServiceInstaller.cs(151,0): at System.ServiceProcess.Tests.TestServiceInstaller.RemoveService()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs(95,0): at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\TestServiceProvider.cs(111,0): at System.ServiceProcess.Tests.TestServiceProvider.DeleteTestServices()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          E:\A\_work\667\s\corefx\src\System.ServiceProcess.ServiceController\tests\ServiceBaseTests.cs(182,0): at System.ServiceProcess.Tests.ServiceBaseTests.Dispose()
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          C:\BuildAgent\work\cb37e9acf085d108\src\xunit.execution\Extensions\ReflectionAbstractionExtensions.cs(76,0): at ReflectionAbstractionExtensions.DisposeTestClass(ITest test, Object testClass, IMessageBus messageBus, ExecutionTimer timer, CancellationTokenSource cancellationTokenSource)
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          ----- Inner Stack Trace -----
2017-12-11 22:38:50,407: INFO: proc(54): run_and_log_output: Output:          

[danmoseley]

It's always in ServiceController.Stop() even though just above we have

            using (ServiceController svc = new ServiceController(ServiceName))
            {
                if (svc.Status != ServiceControllerStatus.Stopped)
               { 
                      svc.Stop();

getting Status successfully requires that the service existed at that point or GetServiceDisplayName would have failed.

We can see from the logging that even though this is happening about the same time, the service names they are deleting are different.

We already added logging to check we weren't getting called twice for hte same service, and it's not firing.

My guess is that the OpenService call is not robust when called concurrently. Let's just ignore this failure. @Anipik can you please add a catch thus:

            using (ServiceController svc = new ServiceController(ServiceName))
            {
                if (svc.Status != ServiceControllerStatus.Stopped)
                {
                    try
                    {
                        svc.Stop();
                    }
                    catch (InvalidOperationException) // OpenService does not seem robust to concurrent calls
                    {
                        ServiceName == null;
                        return;
                    }

                    svc.WaitForStatus(ServiceControllerStatus.Stopped, TimeSpan.FromSeconds(30));
                }
            }