diff --git a/src/WinSW.Core/FormatExtensions.cs b/src/WinSW.Core/FormatExtensions.cs new file mode 100644 index 0000000..76ed0cb --- /dev/null +++ b/src/WinSW.Core/FormatExtensions.cs @@ -0,0 +1,20 @@ +using System; +using System.Diagnostics; + +namespace WinSW +{ + internal static class FormatExtensions + { + internal static string Format(this Process process) + { + try + { + return $"{process.ProcessName} ({process.Id})"; + } + catch (InvalidOperationException) + { + return $"({process.Id})"; + } + } + } +} diff --git a/src/WinSW.Core/LogAppenders.cs b/src/WinSW.Core/LogAppenders.cs index d018a3d..a0ff3ae 100644 --- a/src/WinSW.Core/LogAppenders.cs +++ b/src/WinSW.Core/LogAppenders.cs @@ -2,6 +2,7 @@ using System.Diagnostics; using System.IO; using System.IO.Compression; +using System.Threading.Tasks; using WinSW.Util; namespace WinSW @@ -30,7 +31,7 @@ namespace WinSW /// /// Convenience method to copy stuff from StreamReader to StreamWriter /// - protected async void CopyStreamAsync(StreamReader reader, StreamWriter writer) + protected async Task CopyStreamAsync(StreamReader reader, StreamWriter writer) { string? line; while ((line = await reader.ReadLineAsync()) != null) @@ -90,7 +91,7 @@ namespace WinSW } else { - this.LogOutput(outputReader); + this.SafeLogOutput(outputReader); } if (this.ErrFileDisabled) @@ -99,15 +100,39 @@ namespace WinSW } else { - this.LogError(errorReader); + this.SafeLogError(errorReader); } } protected StreamWriter CreateWriter(FileStream stream) => new StreamWriter(stream) { AutoFlush = true }; - protected abstract void LogOutput(StreamReader outputReader); + protected abstract Task LogOutput(StreamReader outputReader); - protected abstract void LogError(StreamReader errorReader); + protected abstract Task LogError(StreamReader errorReader); + + private async void SafeLogOutput(StreamReader outputReader) + { + try + { + await this.LogOutput(outputReader); + } + catch (Exception e) + { + this.EventLogger.LogEvent("Unhandled exception in task. " + e, EventLogEntryType.Error); + } + } + + private async void SafeLogError(StreamReader errorReader) + { + try + { + await this.LogError(errorReader); + } + catch (Exception e) + { + this.EventLogger.LogEvent("Unhandled exception in task. " + e, EventLogEntryType.Error); + } + } } public abstract class SimpleLogAppender : AbstractFileLogAppender @@ -126,14 +151,14 @@ namespace WinSW this.ErrorLogFileName = this.BaseLogFileName + ".err.log"; } - protected override void LogOutput(StreamReader outputReader) + protected override Task LogOutput(StreamReader outputReader) { - this.CopyStreamAsync(outputReader, this.CreateWriter(new FileStream(this.OutputLogFileName, this.FileMode))); + return this.CopyStreamAsync(outputReader, this.CreateWriter(new FileStream(this.OutputLogFileName, this.FileMode))); } - protected override void LogError(StreamReader errorReader) + protected override Task LogError(StreamReader errorReader) { - this.CopyStreamAsync(errorReader, this.CreateWriter(new FileStream(this.ErrorLogFileName, this.FileMode))); + return this.CopyStreamAsync(errorReader, this.CreateWriter(new FileStream(this.ErrorLogFileName, this.FileMode))); } } @@ -178,20 +203,20 @@ namespace WinSW this.Period = period; } - protected override void LogOutput(StreamReader outputReader) + protected override Task LogOutput(StreamReader outputReader) { - this.CopyStreamWithDateRotationAsync(outputReader, this.OutFilePattern); + return this.CopyStreamWithDateRotationAsync(outputReader, this.OutFilePattern); } - protected override void LogError(StreamReader errorReader) + protected override Task LogError(StreamReader errorReader) { - this.CopyStreamWithDateRotationAsync(errorReader, this.ErrFilePattern); + return this.CopyStreamWithDateRotationAsync(errorReader, this.ErrFilePattern); } /// /// Works like the CopyStream method but does a log rotation based on time. /// - private async void CopyStreamWithDateRotationAsync(StreamReader reader, string ext) + private async Task CopyStreamWithDateRotationAsync(StreamReader reader, string ext) { PeriodicRollingCalendar periodicRollingCalendar = new PeriodicRollingCalendar(this.Pattern, this.Period); periodicRollingCalendar.Init(); @@ -237,20 +262,20 @@ namespace WinSW { } - protected override void LogOutput(StreamReader outputReader) + protected override Task LogOutput(StreamReader outputReader) { - this.CopyStreamWithRotationAsync(outputReader, this.OutFilePattern); + return this.CopyStreamWithRotationAsync(outputReader, this.OutFilePattern); } - protected override void LogError(StreamReader errorReader) + protected override Task LogError(StreamReader errorReader) { - this.CopyStreamWithRotationAsync(errorReader, this.ErrFilePattern); + return this.CopyStreamWithRotationAsync(errorReader, this.ErrFilePattern); } /// /// Works like the CopyStream method but does a log rotation. /// - private async void CopyStreamWithRotationAsync(StreamReader reader, string ext) + private async Task CopyStreamWithRotationAsync(StreamReader reader, string ext) { StreamWriter writer = this.CreateWriter(new FileStream(this.BaseLogFileName + ext, FileMode.Append)); long fileLength = new FileInfo(this.BaseLogFileName + ext).Length; @@ -363,17 +388,17 @@ namespace WinSW this.ZipDateFormat = zipdateformat; } - protected override void LogOutput(StreamReader outputReader) + protected override Task LogOutput(StreamReader outputReader) { - this.CopyStreamWithRotationAsync(outputReader, this.OutFilePattern); + return this.CopyStreamWithRotationAsync(outputReader, this.OutFilePattern); } - protected override void LogError(StreamReader errorReader) + protected override Task LogError(StreamReader errorReader) { - this.CopyStreamWithRotationAsync(errorReader, this.ErrFilePattern); + return this.CopyStreamWithRotationAsync(errorReader, this.ErrFilePattern); } - private async void CopyStreamWithRotationAsync(StreamReader reader, string extension) + private async Task CopyStreamWithRotationAsync(StreamReader reader, string extension) { // lock required as the timer thread and the thread that will write to the stream could try and access the file stream at the same time var fileLock = new object(); diff --git a/src/WinSW.Core/Util/ProcessHelper.cs b/src/WinSW.Core/Util/ProcessHelper.cs index cd6de7e..b5a4a03 100644 --- a/src/WinSW.Core/Util/ProcessHelper.cs +++ b/src/WinSW.Core/Util/ProcessHelper.cs @@ -56,7 +56,7 @@ namespace WinSW.Util if ((int)information.InheritedFromUniqueProcessId == processId) { - Logger.Info("Found child process: " + process.Id + " Name: " + process.ProcessName); + Logger.Info($"Found child process '{process.Format()}'."); children.Add(process); } else @@ -129,7 +129,7 @@ namespace WinSW.Util /// Additional environment variables /// Working directory /// Priority - /// Completion callback. If null, the completion won't be monitored + /// Completion callback. If null, the completion won't be monitored /// Redirect standard input /// Log handler. If enabled, logs will be redirected to the process and then reported public static void StartProcessAndCallbackForExit( @@ -139,7 +139,7 @@ namespace WinSW.Util Dictionary? envVars = null, string? workingDirectory = null, ProcessPriorityClass? priority = null, - Action? callback = null, + Action? onExited = null, bool redirectStdin = true, LogHandler? logHandler = null, bool hideWindow = false) @@ -184,17 +184,17 @@ namespace WinSW.Util } // monitor the completion of the process - if (callback != null) + if (onExited != null) { processToStart.Exited += (sender, _) => { try { - callback((Process)sender!); + onExited((Process)sender!); } catch (Exception e) { - Logger.Error("Thread failed unexpectedly", e); + Logger.Error("Unhandled exception in event handler.", e); } }; diff --git a/src/WinSW/Logging/WrapperServiceEventLogProvider.cs b/src/WinSW/Logging/WrapperServiceEventLogProvider.cs index 462b419..5f78b57 100644 --- a/src/WinSW/Logging/WrapperServiceEventLogProvider.cs +++ b/src/WinSW/Logging/WrapperServiceEventLogProvider.cs @@ -9,16 +9,6 @@ namespace WinSW.Logging { public WrapperService? Service { get; set; } - public EventLog? Locate() - { - WrapperService? service = this.Service; - if (service != null && !service.IsShuttingDown) - { - return service.EventLog; - } - - // By default return null - return null; - } + public EventLog? Locate() => this.Service?.EventLog; } } diff --git a/src/WinSW/WrapperService.cs b/src/WinSW/WrapperService.cs index 8fbdfe6..ca339ea 100644 --- a/src/WinSW/WrapperService.cs +++ b/src/WinSW/WrapperService.cs @@ -38,7 +38,7 @@ namespace WinSW /// so don't try to kill us when the child exits. /// private bool orderlyShutdown; - private bool systemShuttingdown; + private bool shuttingdown; /// /// Version of Windows service wrapper @@ -48,11 +48,6 @@ namespace WinSW /// public static Version Version => Assembly.GetExecutingAssembly().GetName().Version!; - /// - /// Indicates that the system is shutting down. - /// - public bool IsShuttingDown => this.systemShuttingdown; - public WrapperService(ServiceDescriptor descriptor) { this.descriptor = descriptor; @@ -62,7 +57,7 @@ namespace WinSW this.CanStop = true; this.CanPauseAndContinue = false; this.AutoLog = true; - this.systemShuttingdown = false; + this.shuttingdown = false; // Register the event log provider eventLogProvider.Service = this; @@ -143,17 +138,13 @@ namespace WinSW public void LogEvent(string message) { - if (this.systemShuttingdown) + try { - /* NOP - cannot call EventLog because of shutdown. */ + this.EventLog.WriteEntry(message); } - else + catch (Exception e) { - try - { - this.EventLog.WriteEntry(message); - } - catch (Exception e) + if (!this.shuttingdown) { Log.Error("Failed to log event in Windows Event Log: " + message + "; Reason: ", e); } @@ -162,17 +153,13 @@ namespace WinSW public void LogEvent(string message, EventLogEntryType type) { - if (this.systemShuttingdown) + try { - /* NOP - cannot call EventLog because of shutdown. */ + this.EventLog.WriteEntry(message, type); } - else + catch (Exception e) { - try - { - this.EventLog.WriteEntry(message, type); - } - catch (Exception e) + if (!this.shuttingdown) { Log.Error("Failed to log event in Windows Event Log. Reason: ", e); } @@ -185,7 +172,51 @@ namespace WinSW Log.Info(message); } + internal void RaiseOnStart(string[] args) => this.OnStart(args); + + internal void RaiseOnStop() => this.OnStop(); + protected override void OnStart(string[] args) + { + try + { + this.DoStart(); + } + catch (Exception e) + { + Log.Error("Failed to start service.", e); + throw; + } + } + + protected override void OnStop() + { + try + { + this.DoStop(); + } + catch (Exception e) + { + Log.Error("Failed to stop service.", e); + throw; + } + } + + protected override void OnShutdown() + { + try + { + this.shuttingdown = true; + this.DoStop(); + } + catch (Exception e) + { + Log.Error("Failed to shut down service.", e); + throw; + } + } + + private void DoStart() { this.envs = this.descriptor.EnvironmentVariables; @@ -236,7 +267,7 @@ namespace WinSW { using Process process = this.StartProcess(prestartExecutable, this.descriptor.PrestartArguments); this.WaitForProcessToExit(process); - this.LogInfo($"Pre-start process '{GetDisplayName(process)}' exited with code {process.ExitCode}."); + this.LogInfo($"Pre-start process '{process.Format()}' exited with code {process.ExitCode}."); } } catch (Exception e) @@ -260,7 +291,7 @@ namespace WinSW // in the xml for readability. startArguments = Regex.Replace(startArguments, @"\s*[\n\r]+\s*", " "); - this.LogInfo("Starting " + this.descriptor.Executable + ' ' + startArguments); + this.LogInfo("Starting " + this.descriptor.Executable); // Load and start extensions this.ExtensionManager.LoadExtensions(); @@ -277,14 +308,10 @@ namespace WinSW string? poststartExecutable = this.descriptor.PoststartExecutable; if (poststartExecutable != null) { - using Process process = this.StartProcess(poststartExecutable, this.descriptor.PoststartArguments); - process.Exited += (sender, _) => + using Process process = this.StartProcess(poststartExecutable, this.descriptor.PoststartArguments, process => { - Process process = (Process)sender!; - this.LogInfo($"Post-start process '{GetDisplayName(process)}' exited with code {process.ExitCode}."); - }; - - process.EnableRaisingEvents = true; + this.LogInfo($"Post-start process '{process.Format()}' exited with code {process.ExitCode}."); + }); } } catch (Exception e) @@ -293,43 +320,10 @@ namespace WinSW } } - protected override void OnShutdown() - { - // WriteEvent("OnShutdown"); - - try - { - this.systemShuttingdown = true; - this.StopIt(); - } - catch (Exception ex) - { - Log.Error("Shutdown exception", ex); - } - } - - protected override void OnStop() - { - // WriteEvent("OnStop"); - - try - { - this.StopIt(); - } - catch (Exception ex) - { - Log.Error("Cannot stop exception", ex); - } - } - - internal void RaiseOnStart(string[] args) => this.OnStart(args); - - internal void RaiseOnStop() => this.OnStop(); - /// /// Called when we are told by Windows SCM to exit. /// - private void StopIt() + private void DoStop() { try { @@ -338,7 +332,7 @@ namespace WinSW { using Process process = this.StartProcess(prestopExecutable, this.descriptor.PrestopArguments); this.WaitForProcessToExit(process); - this.LogInfo($"Pre-stop process '{GetDisplayName(process)}' exited with code {process.ExitCode}."); + this.LogInfo($"Pre-stop process '{process.Format()}' exited with code {process.ExitCode}."); } } catch (Exception e) @@ -383,7 +377,7 @@ namespace WinSW { using Process process = this.StartProcess(poststopExecutable, this.descriptor.PoststopArguments); this.WaitForProcessToExit(process); - this.LogInfo($"Post-stop process '{GetDisplayName(process)}' exited with code {process.ExitCode}."); + this.LogInfo($"Post-stop process '{process.Format()}' exited with code {process.ExitCode}."); } } catch (Exception e) @@ -394,7 +388,7 @@ namespace WinSW // Stop extensions this.ExtensionManager.FireBeforeWrapperStopped(); - if (this.systemShuttingdown && this.descriptor.BeepOnShutdown) + if (this.shuttingdown && this.descriptor.BeepOnShutdown) { Console.Beep(); } @@ -435,15 +429,15 @@ namespace WinSW // Define handler of the completed process void OnProcessCompleted(Process process) { - string msg = process.Id + " - " + process.StartInfo.FileName + " " + process.StartInfo.Arguments; + string display = process.Format(); if (this.orderlyShutdown) { - this.LogInfo("Child process [" + msg + "] terminated with " + process.ExitCode); + this.LogInfo($"Child process '{display}' terminated with code {process.ExitCode}."); } else { - Log.Warn("Child process [" + msg + "] finished with " + process.ExitCode); + Log.Warn($"Child process '{display}' finished with code {process.ExitCode}."); // if we finished orderly, report that to SCM. // by not reporting unclean shutdown, we let Windows SCM to decide if it wants to @@ -465,13 +459,13 @@ namespace WinSW envVars: this.envs, workingDirectory: this.descriptor.WorkingDirectory, priority: this.descriptor.Priority, - callback: OnProcessCompleted, + onExited: OnProcessCompleted, logHandler: logHandler, redirectStdin: redirectStdin, hideWindow: this.descriptor.HideWindow); } - private Process StartProcess(string executable, string? arguments) + private Process StartProcess(string executable, string? arguments, Action? onExited = null) { var info = new ProcessStartInfo(executable, arguments) { @@ -481,13 +475,26 @@ namespace WinSW }; Process process = Process.Start(info); + + if (onExited != null) + { + process.Exited += (sender, _) => + { + try + { + onExited((Process)sender!); + } + catch (Exception e) + { + Log.Error("Unhandled exception in event handler.", e); + } + }; + + process.EnableRaisingEvents = true; + } + process.StandardInput.Close(); return process; } - - private static string GetDisplayName(Process process) - { - return $"{process.ProcessName} ({process.Id})"; - } } }