Skip to content

Commit

Permalink
Logging subsystem refactoring - use log4net (winsw#145)
Browse files Browse the repository at this point in the history 
* Save the progress

* Add log4net Log appender for Windows service events

* Get rid of the IEventLogger API, we use log4net now
  • Loading branch information
@oleg-nenashev
oleg-nenashev authored Dec 9, 2016
1 parent 2db4fb2 commit 12c16e4
Show file tree
Hide file tree
Showing 19 changed files with 231 additions and 138 deletions.
28 changes: 28 additions & 0 deletions src/Core/ServiceWrapper/Logging/WrapperServiceEventLogProvider.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,28 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Text;
using winsw.Logging;

namespace winsw.Logging
{
/// <summary>
/// Implements caching of the WindowsService reference in WinSW.
/// </summary>
public class WrapperServiceEventLogProvider : IServiceEventLogProvider
{
public WrapperService service {get; set;}

public EventLog locate()
{
WrapperService _service = service;
if (_service != null && !_service.IsShuttingDown)
{
return _service.EventLog;
}

// By default return null
return null;
}
}
}
109 changes: 54 additions & 55 deletions src/Core/ServiceWrapper/Main.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,11 @@
using ServiceType = WMI.ServiceType;
using winsw.Native;
using System.Reflection;
using winsw.Logging;

namespace winsw
{
public class WrapperService : ServiceBase, EventLogger, IEventWriter
public class WrapperService : ServiceBase, EventLogger
{
private SERVICE_STATUS _wrapperServiceStatus;

Expand All @@ -34,6 +35,7 @@ public class WrapperService : ServiceBase, EventLogger, IEventWriter
internal WinSWExtensionManager ExtensionManager { private set; get; }

private static readonly ILog Log = LogManager.GetLogger("WinSW");
private static readonly WrapperServiceEventLogProvider eventLogProvider = new WrapperServiceEventLogProvider();

/// <summary>
/// Indicates to the watch dog thread that we are going to terminate the process,
Expand All @@ -53,6 +55,13 @@ public static Version Version
get { return Assembly.GetExecutingAssembly().GetName().Version; }
}

/// <summary>
/// Indicates that the system is shutting down.
/// </summary>
public bool IsShuttingDown {
get { return _systemShuttingdown; }
}

public WrapperService(ServiceDescriptor descriptor)
{
_descriptor = descriptor;
Expand All @@ -63,6 +72,9 @@ public WrapperService(ServiceDescriptor descriptor)
CanPauseAndContinue = false;
AutoLog = true;
_systemShuttingdown = false;

// Register the event log provider
eventLogProvider.service = this;
}

public WrapperService() : this (new ServiceDescriptor())
Expand Down Expand Up @@ -135,7 +147,7 @@ private void StartThread(ThreadStart main)
}
catch (Exception e)
{
WriteEvent("Thread failed unexpectedly",e);
Log.Error("Thread failed unexpectedly",e);
}
}).Start();
}
Expand Down Expand Up @@ -171,7 +183,7 @@ public void LogEvent(String message)
}
catch (Exception e)
{
WriteEvent("Failed to log event in Windows Event Log: " + message + "; Reason: ", e);
Log.Error("Failed to log event in Windows Event Log: " + message + "; Reason: ", e);
}
}
}
Expand All @@ -190,28 +202,11 @@ public void LogEvent(String message, EventLogEntryType type)
}
catch (Exception e)
{
WriteEvent("Failed to log event in Windows Event Log. Reason: ", e);
Log.Error("Failed to log event in Windows Event Log. Reason: ", e);
}
}
}

private void WriteEvent(Exception exception)
{
//TODO: pass exception to logger
WriteEvent(exception.Message + "\nStacktrace:" + exception.StackTrace, Level.Error);
}

private void WriteEvent(String message, Exception exception)
{
//TODO: pass exception to logger
WriteEvent(message + "\nMessage:" + exception.Message + "\nStacktrace:" + exception.StackTrace, Level.Error);
}

private void WriteEvent(String message, Level logLevel = null, Exception ex = null)
{
Log.Logger.Log(GetType(), logLevel ?? Level.Info, message, ex);
}

protected override void OnStart(string[] _)
{
_envs = _descriptor.EnvironmentVariables;
Expand All @@ -233,7 +228,7 @@ protected override void OnStart(string[] _)
catch (Exception e)
{
LogEvent("Failed to download " + d.From + " to " + d.To + "\n" + e.Message);
WriteEvent("Failed to download " + d.From +" to "+d.To, e);
Log.Error("Failed to download " + d.From +" to "+d.To, e);
// but just keep going
}
}
Expand All @@ -250,23 +245,14 @@ protected override void OnStart(string[] _)
}

LogEvent("Starting " + _descriptor.Executable + ' ' + startarguments);
WriteEvent("Starting " + _descriptor.Executable + ' ' + startarguments);
Log.Info("Starting " + _descriptor.Executable + ' ' + startarguments);

// Load and start extensions
ExtensionManager.LoadExtensions(this);
try
{
ExtensionManager.OnStart(this);
}
catch (ExtensionException ex)
{
LogEvent("Failed to start extension " + ex.ExtensionId + "\n" + ex.Message, EventLogEntryType.Error);
WriteEvent("Failed to start extension " + ex.ExtensionId, ex);
//TODO: Exit on error?
}
ExtensionManager.LoadExtensions();
ExtensionManager.FireOnWrapperStarted();

LogEvent("Starting " + _descriptor.Executable + ' ' + startarguments);
WriteEvent("Starting " + _descriptor.Executable + ' ' + startarguments);
Log.Info("Starting " + _descriptor.Executable + ' ' + startarguments);

StartProcess(_process, startarguments, _descriptor.Executable);
ExtensionManager.FireOnProcessStarted(_process);
Expand All @@ -288,7 +274,7 @@ protected override void OnShutdown()
}
catch (Exception ex)
{
WriteEvent("Shutdown exception", ex);
Log.Error("Shutdown exception", ex);
}
}

Expand All @@ -302,7 +288,7 @@ protected override void OnStop()
}
catch (Exception ex)
{
WriteEvent("Stop exception", ex);
Log.Error("Cannot stop exception", ex);
}
}

Expand All @@ -313,14 +299,14 @@ private void StopIt()
{
string stoparguments = _descriptor.Stoparguments;
LogEvent("Stopping " + _descriptor.Id);
WriteEvent("Stopping " + _descriptor.Id);
Log.Info("Stopping " + _descriptor.Id);
_orderlyShutdown = true;

if (stoparguments == null)
{
try
{
WriteEvent("ProcessKill " + _process.Id);
Log.Debug("ProcessKill " + _process.Id);
ProcessHelper.StopProcessAndChildren(_process.Id, _descriptor.StopTimeout, _descriptor.StopParentProcessFirst);
ExtensionManager.FireOnProcessTerminated(_process);
}
Expand All @@ -345,29 +331,21 @@ private void StopIt()

StartProcess(stopProcess, stoparguments, executable);

WriteEvent("WaitForProcessToExit "+_process.Id+"+"+stopProcess.Id);
Log.Debug("WaitForProcessToExit " + _process.Id + "+" + stopProcess.Id);
WaitForProcessToExit(_process);
WaitForProcessToExit(stopProcess);
SignalShutdownComplete();
}

// Stop extensions
try
{
ExtensionManager.OnStop(this);
}
catch (ExtensionException ex)
{
LogEvent("Failed to stop extension " + ex.ExtensionId + "\n" + ex.Message, EventLogEntryType.Error);
WriteEvent("Failed to stop extension " + ex.ExtensionId, ex);
}
ExtensionManager.FireBeforeWrapperStopped();

if (_systemShuttingdown && _descriptor.BeepOnShutdown)
{
Console.Beep();
}

WriteEvent("Finished " + _descriptor.Id);
Log.Info("Finished " + _descriptor.Id);
}

private void WaitForProcessToExit(Process processoWait)
Expand Down Expand Up @@ -458,7 +436,7 @@ private void StartProcess(Process processToStart, string arguments, String execu
ps.EnvironmentVariables[WinSWSystem.ENVVAR_NAME_SERVICE_ID.ToLower()] = _descriptor.Id;

processToStart.Start();
WriteEvent("Started " + processToStart.Id);
Log.Info("Started " + processToStart.Id);

var priority = _descriptor.Priority;
if (priority != ProcessPriorityClass.Normal)
Expand Down Expand Up @@ -509,6 +487,7 @@ public static int Main(string[] args)
try
{
Run(args);
Log.Info("Completed. Exit code is 0");
return 0;
}
catch (WmiException e)
Expand Down Expand Up @@ -554,7 +533,7 @@ public static void Run(string[] _args, ServiceDescriptor descriptor = null)

if (isCLIMode) // CLI mode, in-service mode otherwise
{
Log.Debug("Starting ServiceWrapper in CLI mode");
Log.Info("Starting ServiceWrapper in the CLI mode");

// Get service info for the future use
Win32Services svc = new WmiRoot().GetCollection<Win32Services>();
Expand Down Expand Up @@ -761,17 +740,25 @@ public static void Run(string[] _args, ServiceDescriptor descriptor = null)
throw new Exception("Unknown command: " + args[0]);

}
else
{
Log.Info("Starting ServiceWrapper in the service mode");
}
Run(new WrapperService());
}

private static void InitLoggers(ServiceDescriptor d, bool enableCLILogging)
{
// TODO: Make logging levels configurable
Level logLevel = Level.Debug;
Level eventLogLevel = Level.Warn;

// Legacy format from winsw-1.x: (DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss") + " - " + message);
PatternLayout pl = new PatternLayout { ConversionPattern = "%d %-5p - %m%n" };
pl.ActivateOptions();

List<IAppender> appenders = new List<IAppender>();

// wrapper.log
String wrapperLogPath = Path.Combine(d.LogDirectory, d.BaseName + ".wrapper.log");
var wrapperLog = new FileAppender
Expand All @@ -785,7 +772,7 @@ private static void InitLoggers(ServiceDescriptor d, bool enableCLILogging)
Layout = pl
};
wrapperLog.ActivateOptions();
BasicConfigurator.Configure(wrapperLog);
appenders.Add(wrapperLog);

// Also display logs in CLI if required
if (enableCLILogging)
Expand All @@ -794,11 +781,23 @@ private static void InitLoggers(ServiceDescriptor d, bool enableCLILogging)
{
Name = "Wrapper console log",
Threshold = logLevel,
Layout = pl
Layout = pl,
};
consoleAppender.ActivateOptions();
((Logger)Log.Logger).AddAppender(consoleAppender);
appenders.Add(consoleAppender);
}

// System log
var systemEventLogger = new ServiceEventLogAppender
{
Name = "System event log",
Threshold = eventLogLevel,
provider = eventLogProvider
};
systemEventLogger.ActivateOptions();
appenders.Add(systemEventLogger);

BasicConfigurator.Configure(appenders.ToArray());
}

private static string ReadPassword()
Expand Down
1 change: 1 addition & 0 deletions src/Core/ServiceWrapper/winsw.csproj
View file
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,7 @@
</Compile>
<Compile Include="Properties\AssemblyInfo.cs" />
<Compile Include="SigIntHelper.cs" />
<Compile Include="Logging\WrapperServiceEventLogProvider.cs" />
</ItemGroup>
<ItemGroup>
<Content Include="manifest.xml" />
Expand Down
6 changes: 3 additions & 3 deletions src/Core/WinSWCore/Extensions/AbstractWinSWExtension.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,17 +9,17 @@ public abstract class AbstractWinSWExtension : IWinSWExtension
public abstract String DisplayName { get; }
public WinSWExtensionDescriptor Descriptor { get; set; }

public virtual void Configure(ServiceDescriptor descriptor, XmlNode node, IEventWriter logger)
public virtual void Configure(ServiceDescriptor descriptor, XmlNode node)
{
// Do nothing
}

public virtual void OnStart(IEventWriter eventWriter)
public virtual void OnWrapperStarted()
{
// Do nothing
}

public virtual void OnStop(IEventWriter eventWriter)
public virtual void BeforeWrapperStopped()
{
// Do nothing
}
Expand Down
6 changes: 3 additions & 3 deletions src/Core/WinSWCore/Extensions/IWinSWExtension.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,14 +29,14 @@ public interface IWinSWExtension
/// </summary>
/// <param name="descriptor">Service descriptor</param>
/// <param name="node">Configuration node</param>
void Configure(ServiceDescriptor descriptor, XmlNode node, IEventWriter logger);
void Configure(ServiceDescriptor descriptor, XmlNode node);

/// <summary>
/// Start handler. Called during startup of the service before the child process.
/// </summary>
/// <param name="logger">Logger</param>
/// <exception cref="ExtensionException">Any error during execution</exception>
void OnStart(IEventWriter logger);
void OnWrapperStarted();

/// <summary>
/// Handler, which is being invoked once the child process is started.
Expand All @@ -59,6 +59,6 @@ public interface IWinSWExtension
/// </summary>
/// <param name="logger">Logger</param>
/// <exception cref="ExtensionException">Any error during execution</exception>
void OnStop(IEventWriter logger);
void BeforeWrapperStopped();
}
}
Loading

0 comments on commit 12c16e4

Please sign in to comment.