Logging events to diagnose stop sequence (#4823)

* Log when application is done to determine if process was killed

* Logging when Raven.Embedded.EmbeddedServer started/completed as this operation can take a while and can take longer than the host allows

* Improve logging and code comments

---------

Co-authored-by: Mauro Servienti <[email protected]>

Author: ramonsmits

src/ServiceControl.Audit/Program.cs

@@ -7,31 +7,40 @@
 using ServiceControl.Configuration;
 using ServiceControl.Infrastructure;
 
-AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
+try
+{
+    AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
 
-// Hack: See https://github.com/Particular/ServiceControl/issues/4392
-var exitCode = await IntegratedSetup.Run();
+    // Hack: See https://github.com/Particular/ServiceControl/issues/4392
+    var exitCode = await IntegratedSetup.Run();
 
-if (exitCode != 0)
-{
-    return exitCode;
-}
+    if (exitCode != 0)
+    {
+        return exitCode;
+    }
 
-ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
+    ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
 
-var arguments = new HostArguments(args);
+    var arguments = new HostArguments(args);
 
-if (arguments.Help)
-{
-    arguments.PrintUsage();
-    return 0;
-}
+    if (arguments.Help)
+    {
+        arguments.PrintUsage();
+        return 0;
+    }
 
-var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
-LoggingConfigurator.ConfigureLogging(loggingSettings);
+    var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
+    LoggingConfigurator.ConfigureLogging(loggingSettings);
 
-var settings = new Settings(loggingSettings: loggingSettings);
+    var settings = new Settings(loggingSettings: loggingSettings);
 
-await new CommandRunner(arguments.Command).Execute(arguments, settings);
+    await new CommandRunner(arguments.Command).Execute(arguments, settings);
 
-return 0;
+    return 0;
+}
+finally
+{
+    // The following log statement is meant to leave a trail in the logs to determine if the process was killed
+    NLog.LogManager.GetCurrentClassLogger().Info("Shutdown complete");
+    NLog.LogManager.Shutdown();
+}

src/ServiceControl.Monitoring/Program.cs

@@ -5,25 +5,34 @@
 using ServiceControl.Infrastructure;
 using ServiceControl.Monitoring;
 
-AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
+try
+{
+    AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
 
-// Hack: See https://github.com/Particular/ServiceControl/issues/4392
-var exitCode = await IntegratedSetup.Run();
+    // Hack: See https://github.com/Particular/ServiceControl/issues/4392
+    var exitCode = await IntegratedSetup.Run();
 
-if (exitCode != 0)
-{
-    return exitCode;
-}
+    if (exitCode != 0)
+    {
+        return exitCode;
+    }
 
-ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
+    ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
 
-var arguments = new HostArguments(args);
+    var arguments = new HostArguments(args);
 
-var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
-LoggingConfigurator.ConfigureLogging(loggingSettings);
+    var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
+    LoggingConfigurator.ConfigureLogging(loggingSettings);
 
-var settings = new Settings(loggingSettings: loggingSettings);
+    var settings = new Settings(loggingSettings: loggingSettings);
 
-await new CommandRunner(arguments.Command).Execute(arguments, settings);
+    await new CommandRunner(arguments.Command).Execute(arguments, settings);
 
-return 0;
+    return 0;
+}
+finally
+{
+    // The following log statement is meant to leave a trail in the logs to determine if the process was killed
+    NLog.LogManager.GetCurrentClassLogger().Info("Shutdown complete");
+    NLog.LogManager.Shutdown();
+}

src/ServiceControl.RavenDB/EmbeddedDatabase.cs

@@ -176,7 +176,9 @@ public void Dispose()
             EmbeddedServer.Instance.ServerProcessExited -= OnServerProcessExited;
 
             shutdownTokenSource.Cancel();
+            Logger.Debug("Disposing RavenDB server");
             EmbeddedServer.Instance.Dispose();
+            Logger.Debug("Dispose RavenDB server");
             shutdownTokenSource.Dispose();
             applicationStoppingRegistration.Dispose();
 

src/ServiceControl/Program.cs

@@ -7,31 +7,40 @@
 using ServiceControl.Hosting.Commands;
 using ServiceControl.Infrastructure;
 
-AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
+try
+{
+    AppDomain.CurrentDomain.UnhandledException += (s, e) => LogManager.GetLogger(typeof(Program)).Error("Unhandled exception was caught.", e.ExceptionObject as Exception);
 
-// Hack: See https://github.com/Particular/ServiceControl/issues/4392
-var exitCode = await IntegratedSetup.Run();
+    // Hack: See https://github.com/Particular/ServiceControl/issues/4392
+    var exitCode = await IntegratedSetup.Run();
 
-if (exitCode != 0)
-{
-    return exitCode;
-}
+    if (exitCode != 0)
+    {
+        return exitCode;
+    }
 
-ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
+    ExeConfiguration.PopulateAppSettings(Assembly.GetExecutingAssembly());
 
-var arguments = new HostArguments(args);
+    var arguments = new HostArguments(args);
 
-if (arguments.Help)
-{
-    arguments.PrintUsage();
-    return 0;
-}
+    if (arguments.Help)
+    {
+        arguments.PrintUsage();
+        return 0;
+    }
 
-var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
-LoggingConfigurator.ConfigureLogging(loggingSettings);
+    var loggingSettings = new LoggingSettings(Settings.SettingsRootNamespace);
+    LoggingConfigurator.ConfigureLogging(loggingSettings);
 
-var settings = new Settings(loggingSettings: loggingSettings);
+    var settings = new Settings(loggingSettings: loggingSettings);
 
-await new CommandRunner(arguments.Command).Execute(arguments, settings);
+    await new CommandRunner(arguments.Command).Execute(arguments, settings);
 
-return 0;
+    return 0;
+}
+finally
+{
+    // The following log statement is meant to leave a trail in the logs to determine if the process was killed
+    NLog.LogManager.GetCurrentClassLogger().Info("Shutdown complete");
+    NLog.LogManager.Shutdown();
+}