Provide TraceSource Support in SLF Core

Coordinator
Dec 2, 2009 at 7:12 PM
Edited Dec 2, 2009 at 7:21 PM

Basically, the logger below (and the complementary factory which ensures it can be declared in app.config) should provide everything that's needed to support trace source logging through SLF.
Let's say we run this code, assuming SLF returns a TraceSourceLogger:

var logger = LoggerService.GetLogger("Foo.Bar");
logger.Warn("hello world");

...this is equivalent to:

var ts = new TraceSource("Foo.Bar", SourceLevels.All);
ts.TraceEvent(TraceEventType.Warning, 0, "hello world");
ts.Flush();

 

...would you need more control over the naming scheme built into the logger or the factory, or not? Furthermore: Should we create a new TraceSource with every invocation or keep it as long as the logger lives (as below)? Or make this even configurable in both loggers and app.config?

Here's the Implementation:

 

 

using System;
using System.Diagnostics;


namespace Slf
{
  /// <summary>
  /// A logger that logs received items to a given
  /// <see cref="TraceSource"/>, which by default
  /// matches the logger's name.
  /// </summary>
  public class TraceSourceLogger : FormattableLoggerBase
  {
    private TraceSource traceSource;

    /// <summary>
    /// The targeted trace source.
    /// </summary>
    public TraceSource TraceSource
    {
      get { return traceSource; }
      set
      {
        Ensure.ArgumentNotNull(value, "value");
        traceSource = value;
      }
    }


    /// <summary>
    /// Creates a named logger which logs to a <see cref="TraceSource"/> with
    /// a matching name. By default, all source levels are enabled.
    /// </summary>
    /// <param name="name">The logger name.</param>
    public TraceSourceLogger(string name) : base(name)
    {
      if (String.IsNullOrEmpty(name)) name = "Default";
      traceSource = new TraceSource(name, SourceLevels.All);
    }


    /// <summary>
    /// Creates a logger which logs to a <see cref="TraceSource"/> with
    /// a name of <c>Default</c>.
    /// By default, all source levels are enabled.
    /// </summary>
    public TraceSourceLogger() : this(LoggerService.DefaultLoggerName)
    {
    }


    /// <summary>
    /// Creates a new log entry based on a given log item.
    /// </summary>
    /// <param name="item">Encapsulates logging information.</param>
    /// <exception cref="ArgumentNullException">If <paramref name="item"/>
    /// is a null reference.</exception>
    public override void Log(LogItem item)
    {
      Ensure.ArgumentNotNull(item, "item");

      string message = FormatItem(item);
      TraceEventType eventType = GetTraceEventType(item.LogLevel);
      TraceSource.TraceEvent(eventType, item.EventId ?? 0, message);
      TraceSource.Flush();
    }


    private TraceEventType GetTraceEventType(LogLevel logLevel)
    {
      switch (logLevel)
      {
        case LogLevel.Debug:
          return TraceEventType.Verbose;
        case LogLevel.Undefined:
        case LogLevel.Info:
          return TraceEventType.Information;
        case LogLevel.Warn:
          return TraceEventType.Warning;
        case LogLevel.Error:
          return TraceEventType.Error;
        case LogLevel.Fatal:
          return TraceEventType.Critical;
        default:
          var diagnosticLogger = LoggerService.GetDiagnosticLogger(GetType().FullName);
          diagnosticLogger.Error("Unknown log level received: " + logLevel);
          return TraceEventType.Critical;
      }
    }
  }


  public class TraceSourceLoggerFactory : NamedLoggerFactoryBase<TraceSourceLogger>
  {
    protected override TraceSourceLogger CreateLogger(string name)
    {
      return new TraceSourceLogger(name);
    }
  }

}

 

Aug 20, 2010 at 5:40 PM

I am late to comment on this, but I have just started looking in detail at SLF.  I think it is a good idea to provide a TraceSource support in SLF.  The one additional suggestion that I would make is to consider support for hierarchical logger naming (maybe your existing hierarchical logger naming support elsewhere in SLF would be sufficient???).  Castle provides a TraceSource-based logging facility (maybe facility is more of a NInject term, I don't can't remember) that supports hierarchical naming.  In essence, if logger "ABC.123.xyz" is requested and there is not a TraceSource with that exact name (case insensitive) that was configured in the app.config file, then it backs up to "ABC.123", "ABC", and, finally "" until it finds a TraceSource that was configured.  If it finds an ancestor, then the TraceSource with the requested name is configured to have the same properties (Switch, TraceListener(s)) as the ancestor.  In other words, if "ABC" was configured in the app.config, then requestes for "ABC.123" and "ABC.123.xyz" would yield TraceSources with the same properties as the first-found parent.

If none are found, then a "Default" TraceSource is used.  The way Castle checks to see if a TraceSource with the given name was configured in the app.config is to check the returned TraceSource's properties.  If the returned TraceSource has exactly 1 TraceListener and that TraceListener is the DefaultTraceListener and the name is "Default", then a TraceSource with that name is assumed to have not been configured.

Castle also keeps a dictionary of all created TraceSources, checking the dictionary first for a TraceSource and then delegating to app.config (TraceSource ts = new TraceSource("xyz")) if they haven't already created that TraceSource.

So, with what you outlined above and with hierarchical naming support, you could write logging code like this:

// If TraceSource "Foo" is configured in app.config and the others are not, "Foo.Bar" and "Foo.Bar.What" will yield TraceSources configured identically to "Foo".
// If TraceSource "Foo" and "Foo.Bar.What" are configured in app.config and "Foo.Bar" is not, "Foo.Bar" will yield a TraceSource configured identically to "Foo".
// If TraceSource "Foo" and "Foo.Bar" are configured in app.config and "Foo.Bar.What" is not, "Foo.Bar.What" yield yield a TraceSource configured identically to "Foo.Bar".

var logger1 = LoggerService.GetLogger("Foo");
var logger2 = LoggerService.GetLogger("Foo.Bar");
var logger3 = LoggerService.GetLogger("Foo.Bar.What");

logger1.Warn("Hello from Foo");
logger2.Info("Hello from Foo.Bar");
logger3.Error("Hello from Foo.Bar.What");

You can see exactly what they did here:

http://github.com/castleproject/Castle.Core/blob/master/src/Castle.Core/Core/Logging/TraceLogger.cs

Note that I have not used Castle so I can't comment on how good or not this approach is from experience, but it looks like a pretty good approach.

I will also make a comment about formatting the log messages.  There are extensions to System.Diagnostics (such as Ukadc.Diagnostics here on codeplex http://ukadcdiagnostics.codeplex.com/) that support formatting similar to how log4net and NLog support formatting (via a formatting string in the app.config file).  For Ukadc.Diagnostics, the formatting support is implemented in the TraceListener.  Formatting tokens are supported for the message, event id, time, timestamp, machine, thread, process, etc.  Depending on what FormatItem (in the Log method) does to build the message string that is sent to TraceSource.TraceEvent, could there be a conflict with the formatting that will be applied later by Ukadc.Diagnostics?  For example, if FormatItem adds the time so that "Hello World!" becomes "20-Aug-2010 12:32 pm, Hello World!", then when Ukadc.Diagnostics formats the message, it might apply the date/time (if specified in the formatting string), resulting in a message that might look like: "20-Aug-2010 12:32 pm, 20-Aug-2010 12:32 pm, Hello World!".  I guess that FormatItem might not do anything, so "formatting" a message that has "Hello World!" might just return "Hello World!" and everything would be ok.