Logging

This library contains helpful resources for .NET Core and ASP.NET Core logging using various logger frameworks and Microsoft.Extensions.Logging.ILogger interface.

• com.github.akovac35.Logging

  

• com.github.akovac35.Logging.AspNetCore

  

• com.github.akovac35.Logging.Testing

  

• com.github.akovac35.Logging.NLog - just helper methods

  

• com.github.akovac35.Logging.Serilog - just helper methods

  

Status

PRODUCTION READY starting from version 1.0.5.

Samples

Advanced samples utilizing library functionality are provided here: Logging.Samples

Contents

• Logging
  • Status
  • Samples
  • Contents
    • Logger helper
    • Invocation context logging
    • Method entry and exit logging
    • Log correlation
    • Unit test logging
    • 3rd party logger frameworks helper methods
    • Message template examples
  • Release history
  • Contributing
    • Contributors
  • License

Logging is an important aspect of any application framework. Compared to Java logging, configuring .NET Core and ASP.NET Core applications for logging seems trivial at first, until we encounter framework specifics related to async code execution that make it impossible to correlate log entries based on the thread id - async methods may switch threads during different stages of the execution, so it is not possible to distinguish which log entry belongs to a specific activity without some sort of log entry correlation being provided with each log entry. This logging library provides means with which it is possible to correlate application activity and log entries, and more.

The following functionality is provided for Microsoft.Extensions.Logging:

Logger helper

This library provides a static generic helper class LoggerHelper<T> using which it is possible to log application startup events or perform limited logging inside types without having to inject a logger instance:

using com.github.akovac35.Logging;
using Microsoft.Extensions.Logging;
using System;

// Import LoggerHelper<T> properties
using static com.github.akovac35.Logging.LoggerHelper<ConsoleApp.Program>;

namespace ConsoleApp
{
    public class Program
    {
        public static async Task Main(string[] args)
        {
            // Configure logger framework at application startup first and then
            // define a logger factory for this library to use:
            // ... logger framework initialization sufficient for logging application startup events ...
            LoggerFactoryProvider.LoggerFactory = new XYZLoggerFactory(); // SerilogLoggerFactory, NLogLoggerFactory, ...
            
	    // "Logger" property is imported with the "using static" directive and is provided by the LoggerHelper<T>
            Logger.Entering(args);

            try
            {
                // Perform work here

                Logger.Exiting(args);
            }
            catch (Exception ex)
            {
                Logger.LogError(ex, ex.Message);
                throw ex;
            }
            finally
            {
                // Dispose logger framework
            }
        }
    }
}

Do note that the LoggerFactoryProvider.LoggerFactory must be defined immediately when application is started. Failing to do so will cause NullLoggerFactory to provide logger instances, which do not perform logging. Update the LoggerFactoryProvider.LoggerFactory reference if logger factory changes during application lifetime.

LoggerHelper<T> should never be used inside static constructors because LoggerFactoryProvider.LoggerFactory may not yet be ready, or its reference used to initialize variables (reference will be stale when LoggerFactoryProvider.LoggerFactory changes).

Invocation context logging

Generally it is useful to have method name and source code line number included with the log entry for easier troubleshooting or simpler coding:

[2020-03-26 23:39:11.943 +01:00] INF 25 410eb646-d979-4814-9f17-8b622ec44ffb <WebApp.Pages.Counter:IncrementCount:29> currentCount: 1

This library includes Here(Action<ILogger> logAction) methods which do just that:

using com.github.akovac35.Logging;
_logger.Here(l => l.LogInformation("currentCount: {0}", currentCount));

//or

using static com.github.akovac35.Logging.LoggerHelper<WebApp.Pages.Counter>
Here(l => l.LogInformation("currentCount: {0}", currentCount));

It is important to note that instead of using reflection, invocation context is determined with the help of compiler service attributes, which minimizes performance impact. Benchmarking revealed that invocation overhead of _logger.Here(Action<ILogger> logAction) versus direct logger method invocation is less than 20%, which is negligible.

When this functionality is not disabled, invocation context is passed to logger frameworks via ILogger.BeginScope(), as follows:

using (logger.BeginScope(
    new[] { new KeyValuePair<string, object>(Constants.CallerMemberName, callerMemberName),
            new KeyValuePair<string, object>(Constants.CallerFilePath, callerFilePath),
            new KeyValuePair<string, object>(Constants.CallerLineNumber, callerLineNumber)})
    )
    {
        try
        {
            logAction(logger);
        }
        catch (Exception ex)
        {
            logger.LogTrace(ex, ex.Message);
        }
    }

Invocation context capture can be disabled by setting LoggerLibraryConfiguration.ShouldHerePassInvocationContextToLoggerScope = false.

Method entry and exit logging

Logging method entry and exit is generally a good practice because it makes production problem resolution easier and writing code simpler. It is much easier to troubleshoot problems when method input parameters and return values are available. It is also much simpler to write logging code knowing that log will first contain an entry statement with method name and source code line number from which it is possible to infer general context and meaning:

[2020-03-26 23:39:11.943 +01:00] VRB 25 410eb646-d979-4814-9f17-8b622ec44ffb <WebApp.Pages.Counter:IncrementCount:26> Entering
[2020-03-26 23:39:11.943 +01:00] INF 25 410eb646-d979-4814-9f17-8b622ec44ffb <WebApp.Pages.Counter:IncrementCount:29> currentCount: 1
[2020-03-26 23:39:12.454 +01:00] VRB 15 410eb646-d979-4814-9f17-8b622ec44ffb <WebApp.Pages.Counter:IncrementCount:35> Exiting

@using Microsoft.Extensions.Logging
@using com.github.akovac35.Logging

@inject ILogger<WebApp.Pages.Counter> logger

private async Task IncrementCount()
{
    logger.Here(l => l.Entering());

    currentCount++;
    // No need to write which counter we are increasing, which method etc.
    logger.Here(l => l.LogInformation("currentCount: {0}", currentCount));

    logger.Here(l => l.Exiting());
}

Method input parameters and return values can be logged as well:

[2020-03-26 23:36:14.420 +01:00] VRB 10 a90aead6-da9c-4adf-af70-d2e7aabd729e <Shared.Services.WeatherForecastService:GetForecastAsync:37> Entering: 03/26/2020 23:36:14
[2020-03-26 23:36:14.422 +01:00] VRB 10 a90aead6-da9c-4adf-af70-d2e7aabd729e <Shared.Services.WeatherForecastService:GetForecastAsync:49> Exiting: Task`1 {Result=[WeatherForecast {Date=03/27/2020 23:36:14, TemperatureC=-12, TemperatureF=11, Summary="Scorching"}, WeatherForecast {Date=03/28/2020 23:36:14, TemperatureC=42, TemperatureF=107, Summary="Chilly"}, WeatherForecast {Date=03/29/2020 23:36:14, TemperatureC=42, TemperatureF=107, Summary="Cool"}, WeatherForecast {Date=03/30/2020 23:36:14, TemperatureC=3, TemperatureF=37, Summary="Sweltering"}, WeatherForecast {Date=03/31/2020 23:36:14, TemperatureC=43, TemperatureF=109, Summary="Freezing"}], Id=1, Exception=null, Status=RanToCompletion, IsCanceled=False, IsCompleted=True, IsCompletedSuccessfully=True, CreationOptions=None, AsyncState=null, IsFaulted=False}

using com.github.akovac35.Logging;

public Task<WeatherForecast[]> GetForecastAsync(DateTime startDate)
{
    _logger.Here(l => l.Entering(startDate));

    // ...

    _logger.Here(l => l.Exiting(tmp));
    return tmp;
}

Because method entry and exit logging can be quite verbose,