Add to better error handling in service tester when silo forcibly clo…

…se (#174)

* Add to better error handling in service tester when silo forcibly close

Gigya.Microdot.Hosting/Service/ServiceHostBase.cs

@@ -43,7 +43,7 @@ public abstract class ServiceHostBase : IDisposable
         private DelegatingServiceBase WindowsService { get; set; }
         private ManualResetEvent StopEvent { get; }
         private TaskCompletionSource<object> ServiceStartedEvent { get; set; }
-        private TaskCompletionSource<object> ServiceStoppedEvent { get; set; }
+        private TaskCompletionSource<StopResult> ServiceGracefullyStopped { get; set; }
         private Process MonitoredShutdownProcess { get; set; }
         private readonly string _serviceName;
         protected CrashHandler CrashHandler { get; set; }
@@ -67,8 +67,8 @@ protected ServiceHostBase()
 
             StopEvent = new ManualResetEvent(true);
             ServiceStartedEvent = new TaskCompletionSource<object>();
-            ServiceStoppedEvent = new TaskCompletionSource<object>();
-            ServiceStoppedEvent.SetResult(null);
+            ServiceGracefullyStopped = new TaskCompletionSource<StopResult>();
+            ServiceGracefullyStopped.SetResult(StopResult.None);
 
             _serviceName = GetType().Name;
 
@@ -82,7 +82,7 @@ protected ServiceHostBase()
         /// </summary>
         public void Run(ServiceArguments argumentsOverride = null)
         {
-            ServiceStoppedEvent = new TaskCompletionSource<object>();
+            ServiceGracefullyStopped = new TaskCompletionSource<StopResult>();
             Arguments = argumentsOverride ?? new ServiceArguments(Environment.GetCommandLineArgs().Skip(1).ToArray());
             CurrentApplicationInfo.Init(ServiceName, Arguments.InstanceName, InfraVersion);
 
@@ -118,6 +118,7 @@ public void Run(ServiceArguments argumentsOverride = null)
                     {
                         Console.WriteLine($"Service cannot start because monitored PID {Arguments.ShutdownWhenPidExits} is not running. Exception: {e}");
                         Environment.ExitCode = 1;
+                        ServiceGracefullyStopped.SetResult(StopResult.None);
                         return;
                     }
 
@@ -180,11 +181,15 @@ public void Run(ServiceArguments argumentsOverride = null)
 
                 Console.WriteLine("   ***   Shutting down...   ***   ");
 
+                var maxShutdownTime = TimeSpan.FromSeconds((Arguments.OnStopWaitTimeSec ?? 0) + (Arguments.ServiceDrainTimeSec ?? 0));
+                bool isServiceGracefullyStopped =  Task.Run(() => OnStop()).Wait(maxShutdownTime);
+
+                if( isServiceGracefullyStopped ==false )
+                    Console.WriteLine($"   ***  Service failed to stop gracefully in the allotted time ({maxShutdownTime}), continuing with forced shutdown.   ***   ");
 
-                Task.Run(() => OnStop()).Wait(TimeSpan.FromSeconds(Arguments.OnStopWaitTimeSec  + Arguments.ServiceDrainTimeSec ?? 0));
-
                 ServiceStartedEvent = new TaskCompletionSource<object>();
-                ServiceStoppedEvent.SetResult(null);
+
+                ServiceGracefullyStopped.SetResult(isServiceGracefullyStopped ? StopResult.Graceful : StopResult.Force);
                 MonitoredShutdownProcess?.Dispose();
 
                 if (Arguments.ServiceStartupMode == ServiceStartupMode.CommandLineInteractive)
@@ -215,9 +220,9 @@ public Task WaitForServiceStartedAsync()
             return ServiceStartedEvent.Task;
         }
 
-        public Task WaitForServiceStoppedAsync()
+        public Task<StopResult> WaitForServiceGracefullyStoppedAsync()
         {
-            return ServiceStoppedEvent.Task;
+            return ServiceGracefullyStopped.Task;
         }
 
 
@@ -235,7 +240,7 @@ public void Stop()
         protected virtual void OnCrash()
         {
             Stop();
-            WaitForServiceStoppedAsync().Wait(5000);
+            WaitForServiceGracefullyStoppedAsync().Wait(5000);
             Dispose();
         }
 
@@ -354,4 +359,6 @@ protected override void OnStop()
             }
         }
     }
+    public enum StopResult { None, Graceful, Force}
+
 }

Gigya.Microdot.Testing/Service/ServiceTester.cs

@@ -55,14 +55,14 @@ namespace Gigya.Microdot.Testing.Service
 
         private HttpListener LogListener { get; set; }
 
-        public ServiceTester(int? basePortOverride, bool isSecondary, ILog log, IResolutionRoot resolutionRoot, TimeSpan? shutdownWaitTime = null, bool writeLogToFile = false,int? serviceDrainTimeSec=null)
+        public ServiceTester(int? basePortOverride, bool isSecondary, ILog log, IResolutionRoot resolutionRoot, TimeSpan? shutdownWaitTime = null, bool writeLogToFile = false, int? serviceDrainTimeSec = null)
         {
             Log = log;
             ResolutionRoot = resolutionRoot;
             // ReSharper disable VirtualMemberCallInContructor
             InitializeInfrastructure();
 
-            var serviceArguments = GetServiceArguments(basePortOverride, isSecondary, shutdownWaitTime.HasValue?(int?)shutdownWaitTime.Value.TotalSeconds:null,serviceDrainTimeSec);
+            var serviceArguments = GetServiceArguments(basePortOverride, isSecondary, shutdownWaitTime.HasValue ? (int?)shutdownWaitTime.Value.TotalSeconds : null, serviceDrainTimeSec);
 
             BasePort = serviceArguments.BasePortOverride.Value;
             ServiceAppDomain = Common.CreateDomain(typeof(TServiceHost).Name + BasePort);
@@ -173,25 +173,39 @@ public virtual void Kill()
 
         public override void Dispose()
         {
-            if (GrainClient.IsInitialized)
-                GrainClient.Uninitialize();
 
-            if (ServiceAppDomain != null)
+            if (GrainClient.IsInitialized)
+                  GrainClient.Uninitialize();
+
+            try
             {
-                ServiceAppDomain.RunOnContext(() =>
+                if (ServiceAppDomain != null)
                 {
-                    Host.Stop();//don't use host.dispose, host.stop should do all the work
-
-                    var completed = StopTask.Wait(60000);
+                    ServiceAppDomain.RunOnContext(() =>
+                    {
+                        Host.Stop(); //don't use host.dispose, host.stop should do all the work
+
+                        var completed = StopTask.Wait(60000);
 
-                    if (!completed)
-                        throw new TimeoutException("ServiceTester: The service failed to shutdown within the 60 second limit.");
-                });
+                        if (!completed)
+                            throw new TimeoutException("ServiceTester: The service failed to shutdown within the 60 second limit.");
 
-                Kill();
+                        if (Host.WaitForServiceGracefullyStoppedAsync().IsCompleted &&
+                            Host.WaitForServiceGracefullyStoppedAsync().Result == StopResult.Force)
+                            throw new TimeoutException("ServiceTester: The service failed to shutdown gracefully.");
+
+                    });
+
+                    Kill();
+                }
+            }
+            finally
+            {
+                LogListener.Close();
             }
+
 
-            LogListener.Close();
+
         }
 
 
@@ -202,27 +216,27 @@ protected virtual void InitializeInfrastructure()
         }
 
 
-        protected virtual ServiceArguments GetServiceArguments(int? basePortOverride, bool isSecondary, int? shutdownWaitTime,int? serviceDrainTime)
+        protected virtual ServiceArguments GetServiceArguments(int? basePortOverride, bool isSecondary, int? shutdownWaitTime, int? serviceDrainTime)
         {
             if (isSecondary && basePortOverride == null)
                 throw new ArgumentException("You must specify a basePortOverride when running a secondary silo.");
 
             var siloClusterMode = isSecondary ? SiloClusterMode.SecondaryNode : SiloClusterMode.PrimaryNode;
-            ServiceArguments arguments = new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, basePortOverride: basePortOverride, siloClusterMode: siloClusterMode, shutdownWaitTimeSec: shutdownWaitTime,serviceDrainTimeSec:serviceDrainTime);
+            ServiceArguments arguments = new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, basePortOverride: basePortOverride, siloClusterMode: siloClusterMode, shutdownWaitTimeSec: shutdownWaitTime, serviceDrainTimeSec: serviceDrainTime);
 
             if (basePortOverride != null)
                 return arguments;
 
-            var serviceArguments = new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, siloClusterMode: siloClusterMode, shutdownWaitTimeSec: shutdownWaitTime,serviceDrainTimeSec:serviceDrainTime);
+            var serviceArguments = new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, siloClusterMode: siloClusterMode, shutdownWaitTimeSec: shutdownWaitTime, serviceDrainTimeSec: serviceDrainTime);
             var commonConfig = new BaseCommonConfig(serviceArguments);
             var mapper = new OrleansServiceInterfaceMapper(new AssemblyProvider(new ApplicationDirectoryProvider(commonConfig), commonConfig, Log));
             var basePort = mapper.ServiceInterfaceTypes.First().GetCustomAttribute<HttpServiceAttribute>().BasePort;
 
-            return new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, basePortOverride: basePort, shutdownWaitTimeSec: shutdownWaitTime,serviceDrainTimeSec:serviceDrainTime);
+            return new ServiceArguments(ServiceStartupMode.CommandLineNonInteractive, basePortOverride: basePort, shutdownWaitTimeSec: shutdownWaitTime, serviceDrainTimeSec: serviceDrainTime);
         }
 
 
-        protected virtual void StartLogListener(int basePort, AppDomain appDomain,bool writeLogToFile)
+        protected virtual void StartLogListener(int basePort, AppDomain appDomain, bool writeLogToFile)
         {
             //Start Listen to http log
             var httpLogListenPort = basePort - 1;
@@ -237,7 +251,7 @@ private async void LogListenerLoop(bool writeLogToFile)
         {
             if (writeLogToFile)
             {
-                File.WriteAllText("TestLog.txt","");
+                File.WriteAllText("TestLog.txt", "");
             }
             while (true)
             {
@@ -256,8 +270,8 @@ private async void LogListenerLoop(bool writeLogToFile)
                         string log = await new StreamReader(context.Request.InputStream).ReadToEndAsync().ConfigureAwait(false);
                         Console.WriteLine(log);
                         //write to file, nunit has problem that if it crath we don't have any log
-                        if(writeLogToFile)
-                            File.AppendAllLines("TestLog.txt",new []{log});
+                        if (writeLogToFile)
+                            File.AppendAllLines("TestLog.txt", new[] { log });
 
                         context.Response.StatusCode = 200;
                     }
@@ -315,7 +329,7 @@ public class TestTraceConfiguration : ITraceConfiguration
 
     public static class ServiceTesterExtensions
     {
-        public static ServiceTester<TServiceHost> GetServiceTester<TServiceHost>(this IResolutionRoot kernel, int? basePortOverride = null, bool isSecondary = false, TimeSpan? shutdownWaitTime = null, bool writeLogToFile = false,int? serviceDrainTimeSec=null)
+        public static ServiceTester<TServiceHost> GetServiceTester<TServiceHost>(this IResolutionRoot kernel, int? basePortOverride = null, bool isSecondary = false, TimeSpan? shutdownWaitTime = null, bool writeLogToFile = false, int? serviceDrainTimeSec = null)
             where TServiceHost : MicrodotOrleansServiceHost, new()
         {
             ServiceTester<TServiceHost> tester = kernel.Get<ServiceTester<TServiceHost>>(

SolutionVersion.cs

@@ -28,9 +28,9 @@
 [assembly: AssemblyCopyright("© 2018 Gigya Inc.")]
 [assembly: AssemblyDescription("Microdot Framework")]
 
-[assembly: AssemblyVersion("1.10.4.0")]
-[assembly: AssemblyFileVersion("1.10.4.0")] 
-[assembly: AssemblyInformationalVersion("1.10.4.0")]
+[assembly: AssemblyVersion("1.10.5.0")]
+[assembly: AssemblyFileVersion("1.10.5.0")] 
+[assembly: AssemblyInformationalVersion("1.10.5.0")]
 
 
 // Setting ComVisible to false makes the types in this assembly not visible 

tests/Gigya.Microdot.Orleans.Hosting.UnitTests/Gigya.Microdot.Orleans.Hosting.UnitTests.csproj

@@ -58,6 +58,7 @@
     <Compile Include="Microservice\ProgrammableHealthGrain.cs" />
     <Compile Include="Properties\orleans.codegen.cs" />
     <Compile Include="ReflectionMetaDataExtensionTests.cs" />
+    <Compile Include="ServiceTesterTests.cs" />
     <Compile Include="SchemaEndpointTests.cs" />
     <Compile Include="Properties\AssemblyInfo.cs" />
     <Compile Include="SpyEventPublisher.cs" />

tests/Gigya.Microdot.Orleans.Hosting.UnitTests/ServiceTesterTests.cs

@@ -0,0 +1,52 @@
+#region Copyright 
+// Copyright 2017 Gigya Inc.  All rights reserved.
+// 
+// Licensed under the Apache License, Version 2.0 (the "License"); 
+// you may not use this file except in compliance with the License.  
+// You may obtain a copy of the License at
+// 
+//     http://www.apache.org/licenses/LICENSE-2.0
+// 
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDER AND CONTRIBUTORS "AS IS"
+// AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+// IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+// ARE DISCLAIMED.  IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
+// LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
+// CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
+// SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
+// INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
+// CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
+// ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
+// POSSIBILITY OF SUCH DAMAGE.
+#endregion
+
+using System;
+using System.Linq;
+using System.Threading.Tasks;
+using Gigya.Common.Contracts.HttpService;
+using Gigya.Microdot.Orleans.Hosting.UnitTests.Microservice.CalculatorService;
+using Gigya.Microdot.ServiceProxy;
+using Gigya.Microdot.Testing.Service;
+using NUnit.Framework;
+using Shouldly;
+
+namespace Gigya.Microdot.Orleans.Hosting.UnitTests
+{
+    [TestFixture]
+    public class ServiceTesterTests
+    {
+        private ServiceTester<CalculatorServiceHost> _tester;
+
+
+        [Test]
+        public async Task ServiceTesterWhenServiceFailedToGracefullyShutdownShouldThrow()
+        {
+            _tester = AssemblyInitialize.ResolutionRoot.GetServiceTester<CalculatorServiceHost>(8555,shutdownWaitTime:TimeSpan.Zero);
+
+            Action act = () => _tester.Dispose();
+            act.ShouldThrow<Exception>().Message.ShouldContain("service failed to shutdown gracefully");
+        }
+
+    }
+
+}