Use Trace and TraceSource in .NET Core Logging

Introduction

This article introduces how to use Trace and TraceSource in component design on .NET Core. And this might be useful if:

1. You have components being built for both .NET Framework and .NET Core / .NET Standard, and you prefer to keep Trace and TraceSource.
2. You have 3^rd party components which use Trace and TraceSource.
3. You are migrating a complex .NET Framework application to .NET Core, and you don't want to change the tracing and logging design for now.
4. You would keep tracing and logging separated and simple.
5. And the deployable is not going to be hosted in Linux.

And the targeted readers are those programmers who have rich experiences in .NET Framework programming, and the knowledge discussed here is up to date with .NET Core 3.0 and .NET Framework 2.0 while .NET Framework 4.8 is the last major release of .NET Framework.

Background

In .NET Core, the default tracing and logging has been escalated to ILogger<T>, and the respective logger object is expected to be instantiated through Dependency Injection of .NET Core. ILogger<T> may be comparable with System.Diagnostics.TraceSource, and the attached ILoggerProvider objects may be comparable with System.Diagnostics.TraceListener.

During the programming on .NET Core for a complex business application, I found there are very few articles/posts about using Trace and TraceSource in .NET Core, and almost all articles and examples about ILogger<T> that I could find through Google describe how to use ILogger which are immediately injected in Program, Startup and Controller, while I have been looking for examples or guidelines for using ILogger in components/assemblies far away from the Program project.

Logger

• Code Examples: https://github.com/zijianhuang/TraceSourceNetCore

The code examples contain multiple projects, each of which represent a simple scenario and a technical solution.

Presumably, you have read Logging in .NET Core and ASP.NET Core. Logging is not included in .NET Core runtime and startup logic, nor in the scaffolding codes of a console app. To use logging, package Microsoft.Extensions.Logging is needed.

However, this package alone is not enough for logging to console. Instead, use Microsoft.Extensions.Logging.Console:

And this package includes Microsoft.Extensions.Logging. Also, typically you won't hard code switches in codes but in a config file, and conventionally in .NET Core, a JSON config file is used, thus you need Microsoft.Extensions.Configuration.Json.

LoggerFactory

Code Example: ConsoleAppLoggerFactory

using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.Logging;

namespace ConsoleAppLoggerDemo
{
    class Program
    {
        static void Main(string[] args)
        {
            var configuration = new ConfigurationBuilder()
                                .AddJsonFile("appsettings.json", false, true)
                                .Build();

            using var loggerFactory = LoggerFactory.Create(
                builder =>
                    {
                        builder.AddConfiguration(configuration.GetSection("Logging"));
                        builder.AddConsole();
                    }
            );

            var logger = loggerFactory.CreateLogger<Program>();
            logger.LogInformation("1111logger information"); //settings in appsettings.json filters this out
            logger.LogWarning("2222logger warning");

            var fooLogger = loggerFactory.CreateLogger<FooService>();
            IFooService fooService = new FooService(fooLogger);
            fooService.DoWork();
        }
    }

    public interface IFooService
    {
        void DoWork();
    }

    public class FooService : IFooService
    {
        private readonly ILogger logger;

        public FooService(ILogger<FooService> logger)
        {
            this.logger = logger;
        }

        public void DoWork()
        {
            logger.LogInformation("3333Doing work.");
            logger.LogWarning("4444Something warning");
            logger.LogCritical("5555Something critical");
        }
    }
}

And appsettings.json is:

{
    "Logging": {
        "Console": {
            "disableColors": false
        },

        "LogLevel": {
            "Default": "Information",
            "Microsoft": "Information",
            "ConsoleAppLoggerDemo.FooService": "Warning",
            "ConsoleAppLoggerDemo.Program": "warning"
        }
    }
}

Hints

After reading the Logging section in appsettings.json, through DI .NET Core runtime configures the console logger provider and the loggers such as "Microsoft" and "ConsoleApp1.FooService", etc.

This is good enough for very simple scenarios, however, in complex apps, you may want to utilize Dependency Injection built in .NET Core, as described following.

ServiceCollection to Inject Logger

Code Example: ConsoleAppAddLogging

An instance of ILoggerFactory is built and registered in ServiceCollection, so the factory is then used to create a logger ILogger<Program>, through either way:

serviceProvider.GetService<ILoggerFactory>().CreateLogger<Program>()

or:

serviceProvider.GetService<ILogger<Program>>();

And when FooService is instantiated through DI, the defined logger ILogger<FooService> is instantiated and injected.

using Microsoft.Extensions.Logging;
using System;
using Microsoft.Extensions.Configuration;
using Microsoft.Extensions.DependencyInjection;

namespace ConsoleAppLoggerDemo
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine("Hello World! from console");

            var configuration = new ConfigurationBuilder()
                                .AddJsonFile("appsettings.json", false, true)
                                .Build();

            using var serviceProvider = new ServiceCollection()
                .AddSingleton<IFooService, FooService>()
                .AddLogging(builder =>
                {
                    builder.AddConfiguration(configuration.GetSection("Logging"));
                    builder.AddConsole();
                })
                .BuildServiceProvider();

            ILogger<Program> logger = serviceProvider.GetService<ILogger<Program>>();
            //logger = serviceProvider.GetService<ILoggerFactory>().CreateLogger<Program>(); 
            // Factory first. This works too.

            IFooService fooService = serviceProvider.GetService<IFooService>();

            logger.LogInformation("1111logger information");
            logger.LogWarning("2222logger warning");

            fooService.DoWork();
        }
    }

    public interface IFooService
    ...
}

Trace and TraceSource

System.Diagnostics.Trace and System.Diagnostics.TraceSource had been designed for separating tracing and logging, and the logging is realized through attached trace listeners.

Built-in Trace Listeners

Code Example: ConsoleAppTraceListener

Many of the TraceListener derived classes on .NET Framework are available on .NET Core, however, things like IisTraceListener are unavailable on .NET Core.

On .NET Framework, the application could initialize Trace and TraceSource and instantiate trace listeners through app.config which are loaded before the first line of the application codes is executed.

On .NET Core, you may still use various trace listeners like ConsoleTraceListener, however, as .NET Core won't load a config file by default and the built-in configuration does not care about trace listeners.

using (var listener = new TextWriterTraceListener("c:\\temp\\mylog.txt"))
using (var consoleListener = new ConsoleTraceListener())
{
    Trace.Listeners.Add(listener);
    Trace.Listeners.Add(consoleListener);

So you have to instantiate trace listeners and initialize Trace and TraceSources object in the application startup codes. Not too bad, however things move on and there are more and more 3^rd party components that may interface with ILogger<T> for tracing and logging. Considering various factors and tradeoffs, it may be better to build a bridge between TraceSource and ILogger<T>, so legacy components that use Trace and TraceSource could send trace messages to ILogger<T>.

LoggerTraceListener

This is a helper TraceListener to bridge from Trace and TraceSource to ILogger.

Code Example: ConsoleAppTrace

Since Trace and TraceSource has only Listeners to interface with logging, thus here's LoggerTraceListener to listen to tracing and write to ILogger<T> which eventually sends the tracing to logger providers.

public class LoggerTraceListener : TraceListener
{
    private readonly ILogger logger;

    public LoggerTraceListener(ILogger logger)
    {
        this.logger = logger;
    }

    public override void Write(string message)
    {
        logger.LogInformation(message);
    }

    public override void WriteLine(string message)
    {
        logger.LogInformation(message);
    }

    public override void WriteLine(string message, string category)
    {
        logger.LogInformation(category + ": " + message);
    }

    public override void TraceEvent
           (TraceEventCache eventCache, string source,
            TraceEventType eventType, int id)
    {
        switch (eventType)
        {
            case TraceEventType.Critical:
                logger.LogCritical(id, source);
                break;
            case TraceEventType.Error:
                logger.LogError(id, source);
                break;
            case TraceEventType.Warning:
                logger.LogWarning(id, source);
                break;
            case TraceEventType.Information:
                logger.LogInformation(id, source);
                break;
            case TraceEventType.Verbose:
                logger.LogTrace(id, source);
                break;
            case TraceEventType.Start:
                logger.LogInformation(id, "Start: " + source);
                break;
            case TraceEventType.Stop:
                logger.LogInformation(id, "Stop: " + source);
                break;
            case TraceEventType.Suspend:
                logger.LogInformation(id, "Suspend: " + source);
                break;
            case TraceEventType.Resume:
                logger.LogInformation(id, "Resume: " + source);
                break;
            case TraceEventType.Transfer:
                logger.LogInformation(id, "Transfer: " + source);
                break;
            default:
                throw new InvalidOperationException("Impossible");
        }
    }

Application startup:

using var serviceProvider = new ServiceCollection()
    .AddSingleton<IFooService, FooService>()
    .AddLogging(builder =>
    {
        builder.AddConfiguration(configuration.GetSection("Logging"));
        builder.AddConsole();
    })
    .BuildServiceProvider();

ILogger<Program> logger = serviceProvider.GetService<ILogger<Program>>();
IFooService fooService = serviceProvider.GetService<IFooService>();


logger.LogInformation("1111logger information");
logger.LogWarning("2222logger warning");

fooService.DoWork();

using (var listener = new LoggerTraceListener(logger))
{
    System.Diagnostics.Trace.Listeners.Add(listener);
    TraceSources.Instance.InitLoggerTraceListener(listener);

    TraceLover.DoSomething();
    TraceSourceLover.DoSomething();
}

Now, what logging mediums that Trace and TraceSource could use are determined by what logger providers are attached to ILogger.

Trace, TraceSource and Logger Providers in Harmony

Code Example: ConsoleappSeriLog

Microsoft had developed little concrete logger providers in .NET Core, and this is probably by business vision thus by design. There are quite a few 3^rd party logger providers around:

• NLog
• Log4net
• Serilog

And there's a very good article comparing these three:

• NLog vs log4net vs Serilog: Compare .NET Logging Framework

I would agree that Serilog is the best overall.

var configuration = new ConfigurationBuilder()
                    .AddJsonFile("appsettings.json", false, true)
                    .Build();

Serilog.Log.Logger = new Serilog.LoggerConfiguration()
                      .Enrich.FromLogContext()
                      //.WriteTo.Console() I prefer plugging
                      // through the config file
                      .ReadFrom.Configuration(configuration)
                      .CreateLogger();

using var serviceProvider = new ServiceCollection()
    .AddLogging(builder => builder.AddSerilog())
    .AddSingleton<IFooService, FooService>()
    .BuildServiceProvider();

var    logger = serviceProvider.GetService<ILogger<Program>>();
var    fooService = serviceProvider.GetService<IFooService>();

try
{
    Log.Information("Starting up");
    logger.LogInformation("1111logger information");
    logger.LogWarning("2222logger warning");

    fooService.DoWork();

    using (var listener = new LoggerTraceListener(logger))
    {
        System.Diagnostics.Trace.Listeners.Add(listener);
        TraceSources.Instance.InitLoggerTraceListener(listener);

        TraceLover.DoSomething();
        TraceSourceLover.DoSomething();
    }
}
catch (Exception ex)
{
    Log.Fatal(ex, "Application start-up failed");
}
finally
{
    Log.CloseAndFlush();
}

And the appsettings.json is:

{
    "TraceSource": {
        "WebApi": {
            "SourceLevels": "Information"
        },

        "HouseKeeping": { "SourceLevels": "Warning" },

        "DbAudit": {
            "SourceLevels": "Warning"
        }
    },

    "Serilog": {
        "MinimumLevel": {
            "Default": "Debug",
            "Override": {
                "Microsoft": "Information",
                "System": "Warning",
                "ConsoleAppLoggerDemo.FooService": "Warning",
                "ConsoleAppLoggerDemo.Program": "Warning"
            }
        },

        "WriteTo": [
            {
                "Name": "Console"
            },

            {
                "Name": "File",
                "Args": {
                    "path": "%PROGRAMDATA%/my/logs/CloudPosApi_Test.log",
                    "outputTemplate": "{Timestamp:MM-dd HH:mm:ss.fff zzz} 
                           [{Level}] {ThreadId} {Message}{NewLine}{Exception}",
                    "rollingInterval": "Day"
                }
            }
        ]
    }
}

Points of Interest

On .NET Framework, the runtime will load app.config and apply settings to some built-in components before the first line of the application codes is executed. And some other components like SMTPClient and System.Diagnostics components will read app.config by default.

On .NET Core, it is the application programmer's responsibility to configure either in codes, or through loading a config file.

History

• 27^th January, 2020: Initial version