.NET’s greatest strength is its long history of supporting developers through each industry paradigm shift, but just because there’s a new way of doing things doesn’t mean the established method goes away. It’s also a source of confusion and frustration for many. Developers spend time trying to merge the past with the present while also thinking about the future. One of the problem domains folks have to think about is some form of tracing in their apps.

This post will show how to take one of the oldest tracing methods, System.Diagnostics.Trace, and adapt your newer .NET applications (.NET 5+) to take advantage of the messages some of your older dependencies may be emitting.

Credit for the solution goes to Damian Edwards, and thank you for his help on the C# code.

What Is System.Diagnostics.Trace?

In the early days of systems development, you typically had very simple architectures with few running processes. Traces allow for publishing specific messages during the execution of your application that you can scan over later to glean information about a running process at a particular time. Developers will put their messages into four general categories:

  • Critical: Serious failure that likely causes immediate loss of information or user functionality.
  • Error:: An unexpected failure in a particular sub-system that may result in a loss of user functionality, but it is otherwise recoverable.
  • Warning: An unexpected situation, but standard processing can continue.
  • Information: Messages that may be helpful when diagnosing a system, but otherwise are there for developers to learn more at their convenience.

You can find traces in many .NET Dependencies, but messages are usually are not surfaced until you register a Listener. A listener redirects messages to a destination, whether a log file, the event log in Windows, the console output, or a third-party repository.

If you’re reading this post, you’re likely wondering: “How do I get my traces to show up through my ILogger configuration?” As your ILogger setup likely also has the configuration for logging targets like files, event logs, and third-party services. Nobody likes doing things twice, especially developers like you.

Well, let’s see how.

Passing Trace Messages To ILogger

Our goal is to pass Trace messages directly to an ILogger implementation, piggy-backing off our application’s configuration. Most importantly, the approach would allow us to see into older dependencies that may still be utilizing System.Diagnostics.Trace calls.

Our first step in the process is to write a Listener, which we’ll call LoggerTraceListener.

public class LoggerTraceListener : TraceListener
{
    private readonly ILoggerFactory _loggerFactory;
    private readonly ILogger _defaultLogger;
    private readonly ConcurrentDictionary<string, ILogger> _loggers = new();
    private readonly StringBuilder _builder = new();

    public LoggerTraceListener(ILoggerFactory loggerFactory)
    {
        _loggerFactory = loggerFactory;
        _defaultLogger = loggerFactory.CreateLogger(nameof(LoggerTraceListener));
    }

    public override void TraceEvent(TraceEventCache? eventCache, string source, TraceEventType eventType, int id, string? message)
    {
        var logger = _loggers.GetOrAdd(
            source,
            static (s, factory) => factory.CreateLogger(s),
            _loggerFactory);
        
        logger.Log(MapLevel(eventType), message);
    }

    public override void TraceEvent(TraceEventCache? eventCache, string source, TraceEventType eventType, int id, string? format,
        params object?[]? args)
    {
        var logger = _loggers.GetOrAdd(
            source,
            static (s, factory) => factory.CreateLogger(s),
            _loggerFactory);
        
        logger.Log(MapLevel(eventType), format, args ?? Array.Empty<object>());
    }

    public override void Write(string? message)
    {
        _builder.Append(message);
    }

    public override void WriteLine(string? message)
    {
        _builder.AppendLine(message);
        _defaultLogger.LogInformation(_builder.ToString());
        _builder.Clear();
    }

    private LogLevel MapLevel(TraceEventType eventType) => eventType switch
    {
        TraceEventType.Verbose => LogLevel.Debug,
        TraceEventType.Information => LogLevel.Information,
        TraceEventType.Critical => LogLevel.Critical,
        TraceEventType.Error => LogLevel.Error,
        TraceEventType.Warning => LogLevel.Warning,
        _ => LogLevel.Trace
    };
}

Note that the LoggerTraceListener takes a dependency on an ILoggerFactory, which will help us preserve the source of our messages when we log with our ILogger implementation.

Now, let’s make use of our newly created listener. Next, assuming you’re working in an ASP.NET Core application, we need to register our listener with the System.Diagnostics.Trace.Listeners collection.

using System.Diagnostics;

var builder = WebApplication.CreateBuilder(args);
var app = builder.Build();

// get logger factory and add listener
var factory = app.Services.GetRequiredService<ILoggerFactory>();
Trace.Listeners.Add(new LoggerTraceListener(factory));

Great! Now we can start getting traces in the output of our running application, assuming we have the console logger enabled. Finally, Let’s add some trace calls to an endpoint to see it all in action.

app.MapGet("/", async () =>
{
    Trace.TraceInformation("Cool Beans!");
    Trace.TraceWarning("Fudge!");
    Trace.TraceError("F#$@!");
    
    return "Hello World!";
});

Let’s take a look at the run output.

ilogger outputing trace messages

Neat! Now we can see our traces alongside all of our logging calls. But wait, there’s more! Since we are using the ILogger interface, we can also use the configuration options to limit what trace output gets passed to our logger. For example, in the appSettings.json, we can choose the level of information we want to log.

Note: Lumberjack is the assembly from which we emit our traces.

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Warning",
      "Lumberjack" : "Warning"
    }
  },
  "AllowedHosts": "*"
}

Let’s make sure it work.

ilogger outputing trace messages filtering out Information

Fantastic!

Conclusion

As modern software development improves its techniques around tracing and observability, there will be a significant legacy codebase still heavily using System.Diagnostics.Trace. This post shows a method in which we can continue building modern applications with the latest and greatest tech while still taking advantage of the messages emitted by previous developers. I hope you found this post helpful, and thanks again for reading.

References