Serilog Log Levels: When and How to Use Them

What are the log levels in Serilog?

When using logging, it is very useful to be able to specify the importance of a log message. This has been recognized at least since the 1980s, when the Unix-based Syslog standard used 8 logging levels of severity for its messages.

Modern logging frameworks follow the same principle, and while they mostly seem to have settled on 6 levels of severity with comparable meanings, the actual names of these levels can vary. This also applies to the two frameworks that are relevant when using Serilog in a modern .NET application: Serilog itself and Microsoft.Extensions.Logging.

The following table shows the mapping between the log levels of Serilog, Microsoft.Extensions.Logging, and the original Syslog:

When to use which log level?

The choice of log level depends on how important a message is and what is the chance that it will be useful in the future. Here are some guidelines:

How to set the log level of a message

When logging, the logging level is usually specified by choosing which method you call.

If you’re writing your error messages directly using the Serilog.Log namespace, it could look like this:

Log.Information( "Rolling a {sides}-sided die.", sides );

If you’re using the Microsoft.Extensions.Logging API to emit your log records, it could look like this:

this._logger.LogInformation( "Rolling a {sides}-sided die.", sides );

There are methods corresponding to each log level, with obvious names. In both cases, it is also possible to specify the log level as an argument, though that’s generally only useful when you’re building some kind of abstraction on top of the logging framework:

this._logger.Log( LogLevel.Information, "Rolling a {sides}-sided die.", sides ); // Microsoft.Extensions.Logging API
Log.Write( LogEventLevel.Information, "Rolling a {sides}-sided die.", sides ); // Serilog API

Another case is when using the Microsoft.Extensions.Logging source generator, where you specify the log level on the [LoggerMessage] attribute:

[LoggerMessage( LogLevel.Information, "Rolling a {sides}-sided die." )]
private partial void LogRollingDie( int sides );

this.LogRollingDie( sides );

How to filter log messages by minimum level

When configuring Serilog, it is possible to filter log messages by their LogLevel. This can be done by specifying the MinimumLevel when creating a configuration (by default, the minimum level is set to Information). You can also change the minimum level dynamically by using a LoggingLevelSwitch, or override the minimum level for a specific namespace prefix.

Another option is to restrict a specific sink to a certain log level by specifying the restrictedToMinimumLevel parameter when adding the sink.

A configuration that uses all these options would look something like this:

var acmeLogLevelSwitch = new LoggingLevelSwitch();
acmeLogLevelSwitch.MinimumLevel = LogEventLevel.Information;

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .MinimumLevel.Override( "Microsoft", LogEventLevel.Warning )
    .MinimumLevel.Override( "Acme", acmeLogLevelSwitch )
    .WriteTo.File( "log.txt" )
    .WriteTo.Console( restrictedToMinimumLevel: LogEventLevel.Information )
    .CreateLogger();

You can also read Serilog configuration from other sources, like Microsoft.Extensions.Configuration, which is usually stored in appsettings.json.

Using that approach, the code would look like this:

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

Log.Logger = new LoggerConfiguration()
    .ReadFrom.Configuration( configuration )
    .CreateLogger();

A comparable configuration file would then look like this:

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Warning"
      }
    },
    "WriteTo": [
      {
        "Name": "File",
        "Args": { "path": "log.txt" }
      },
      {
        "Name": "Console",
        "Args": { "restrictedToMinimumLevel": "Information" }
      }
    ]
  }
}

Error level: logging exceptions

Logging uncaught exceptions in ASP.NET Core

A common situation that justifies the Error log level in an ASP.NET Core app is an uncaught exception when processing a request. (Since this doesn’t crash the whole application, it shouldn’t be considered Fatal.)

Such exceptions are automatically logged either by DeveloperExceptionPageMiddleware, which is enabled by default in the Development environment, or by ExceptionHandlerMiddleware, which is commonly used in the Production environment and is enabled by calling app.UseExceptionHandler() in your startup code. (If no such middleware is enabled, the exception will still be logged by the Kestrel server.) Both of these middlewares allow customization of how exactly the exceptions are handled, which can include logging additional information about the exception.

Enriching exceptions with parameter values

When logging an exception, it can be useful to understand what the values of the parameters were at the time the exception was thrown. .NET doesn’t have a built-in way to do this, which is where Metalama comes in. Metalama is a free tool that allows you to modify the code of your methods en masse, which can be used exactly for this purpose. It does it on the fly during compilation, so your source code remains clean and succinct.

We do this by creating a class that inherits from OverrideMethodAspect, which lets us modify the behavior of a method. In this case, we want to attach information about the parameters to any exceptions thrown by the body of the method:

public class EnrichExceptionAttribute : OverrideMethodAspect
{
    public override dynamic? OverrideMethod()
    {
        try
        {
            return meta.Proceed();
        }
        catch ( Exception e )
        {
            // Compile-time code: create an interpolated string containing the method name and its arguments.
            var methodSignatureBuilder = new InterpolatedStringBuilder();
            methodSignatureBuilder.AddText( meta.Target.Type.ToString() );
            methodSignatureBuilder.AddText( "." );
            methodSignatureBuilder.AddText( meta.Target.Method.Name );
            methodSignatureBuilder.AddText( "(" );

            foreach ( var p in meta.Target.Parameters )
            {
                if ( p.Index > 0 )
                {
                    methodSignatureBuilder.AddText( ", " );
                }

                methodSignatureBuilder.AddExpression( p.Value );
            }

            methodSignatureBuilder.AddText( ")" );

            e.AppendContextFrame( (string) methodSignatureBuilder.ToValue() );

            throw;
        }
    }
}

How to actually attach extra information to the exception? We can use the Exception.Data property for that:

public static class EnrichExceptionHelper
{
    private const string _slotName = "MetalamaEnrichExceptionContext";

    [ExcludeAspect( typeof(EnrichExceptionAttribute) )]
    public static void AppendContextFrame( this Exception e, string frame )
    {
        // Get or create a StringBuilder for the exception where we will add additional context data.
        var stringBuilder = (StringBuilder?) e.Data[_slotName];

        if ( stringBuilder == null )
        {
            stringBuilder = new StringBuilder();
            e.Data[_slotName] = stringBuilder;
        }

        // Add current context information to the string builder.
        stringBuilder.AppendLine( frame );
    }

    public static string? GetContextInfo( this Exception e )
        => ((StringBuilder?) e.Data[_slotName])?.ToString();
}

Now you can apply the aspect class as an attribute to methods where capturing parameter values in exceptions is important (this is free), or you can apply the aspect to many or all methods in your application at once using a fabric (this is a paid feature):

public class Fabric : ProjectFabric
{
    public override void AmendProject( IProjectAmender amender )
    {
        amender.Outbound
            .SelectMany( p => p.Types )
            .SelectMany( t => t.Methods )
            .AddAspectIfEligible<EnrichExceptionAttribute>();
    }
}

Finally, in an ASP.NET Core app, you can use the ExceptionHandlerMiddleware to log the additional information about the exception (by default, this won’t work in the Development environment, since it doesn’t use ExceptionHandlerMiddleware):

public class EnchrichedExceptionLoggingHandler( ILogger<EnchrichedExceptionLoggingHandler> logger ) : IExceptionHandler
{
    public ValueTask<bool> TryHandleAsync(
        HttpContext httpContext, Exception exception, CancellationToken cancellationToken )
    {
        if ( exception.GetContextInfo() is { } contextInfo )
        {
            logger.LogError( "{contextInfo}", contextInfo );
        }

        // Never say that we handled the exception.
        return ValueTask.FromResult( false );
    }
}

builder.Services.AddExceptionHandler<EnchrichedExceptionLoggingHandler>();

Using this, when an exception occurs inside a controller, we will also see information about the parameter values in the log, for example:

[15:06:12 ERR] An unhandled exception has occurred while executing the request.
   ...
[15:06:12 ERR] DieRollerController.GetShapeName(1)
DieRollerController.Index(1)

Info level: Logging HTTP requests

In a web app, one of the most typical things you would log with info level is the beginning and the end of an HTTP request. You have several options.

Microsoft.AspNetCore.Hosting

The first one is basic logging performed by Microsoft.AspNetCore.Hosting, which looks like this:

[15:42:18 INF] Request starting HTTP/1.1 GET http://localhost:5004/DieRoller - null null
[15:42:18 INF] Request finished HTTP/1.1 GET http://localhost:5004/DieRoller - 200 null text/plain; charset=utf-8 40.5249ms

As you can see, this log manages to be quite verbose, while not providing much information. It’s also not customizable.

Serilog request logging middleware

A better option might be to use Serilog request logging middleware, which is enabled and configured by calling app.UseSerilogRequestLogging() in your startup code. Its default output looks like this:

[15:49:23 INF] HTTP GET /DieRoller responded 200 in 39.1169 ms

It can also be configured to include extra information about the request and response or have its log level changed.

ASP.NET Core HTTP logging middleware

Another option, which provides much more information by default, is the ASP.NET Core HTTP logging middleware. It can be enabled like this:

builder.Services.AddHttpLogging( _ => { } );

app.UseHttpLogging();

The default output of this middleware looks like this:

[16:00:33 INF] Request:
Protocol: HTTP/1.1
Method: GET
Scheme: http
PathBase:
Path: /DieRoller
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7
Connection: keep-alive
Host: localhost:5004
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/126.0.0.0 Safari/537.36 Edg/126.0.0.0
Accept-Encoding: gzip, deflate, br, zstd
Accept-Language: en-US,en;q=0.9
Cache-Control: max-age=0
Cookie: [Redacted]
Upgrade-Insecure-Requests: [Redacted]
sec-ch-ua: [Redacted]
sec-ch-ua-mobile: [Redacted]
sec-ch-ua-platform: [Redacted]
Sec-Fetch-Site: [Redacted]
Sec-Fetch-Mode: [Redacted]
Sec-Fetch-User: [Redacted]
Sec-Fetch-Dest: [Redacted]
[16:00:33 INF] Response:
StatusCode: 200
Content-Type: text/plain; charset=utf-8
Date: Wed, 17 Jul 2024 14:00:33 GMT
Server: Kestrel
Transfer-Encoding: chunked

As you can see, it provides a lot of information about the request and response, primarily their headers. This can be configured to log the start of the request and response bodies, log particular headers, or combine all this information into a single log message. (Though the log level can’t be changed and is always Information.)

Verbose level: logging every method execution

At the highest level of logging verbosity, you might want to consider logging every single method in your code, or every non-private method, including its arguments.

It’s important to understand that verbose logging should never be enabled by default – probably not even in your debug build. However, it’s good to have a high level of logging built into your application so that, when a problem arises in production, you can gather more detailed logs without redeploying your app – just by changing a configuration file. This is even more important when the app runs on your customers’ devices and not yours, since you might want to collect logs only for a specific customer.

This scenario is why you should always use a specific instance of the logger class for each type in your application. This will allow you to enable and disable logging for each namespace or type by using the Override node of the appsettings.json configuration file (see above).

For instance, the following configuration logs only warnings and errors by default, but verbose logging is enabled for My.Problematic.Namespace.

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Warning",
      "Override": {
        "My.Problematic.Namespace": "Verbose"
      }
    }
  }
}

In verbose logging, configuration is the easy part. It’s much more cumbersome to implement the logging code in every single method you want to instrument, at least if you plan to do it manually.

When implementing verbose logging, it is critical to avoid degrading performance when logging is disabled for this type. For instance, the following code allocates memory every time the Get method is called, even when logging is disabled:

public IEnumerable<WeatherForecast> Get( int days = 5 )
{
    // Don't do this!
    this._logger.LogTrace( "WeatherForecastController.Get(days: {days}) started.", days );

    // ...
}

In highly-used parts of your app, you should use this code instead:

public IEnumerable<WeatherForecast> Get( int days = 5 )
{
    // Do this instead.
    if ( this._logger.IsEnabled( LogLevel.Trace ) )
    {
        this._logger.LogTrace( "WeatherForecastController.Get(days: {days}) started.", days );
    }

    // ...
}

You probably don’t want to repeat this code all over your codebase. It’s not only work-intensive (and boring) to write, but what if you later decide to modify your code generation pattern? Will you modify the thousands of methods where you already implemented the patterns… wrongly?

Hopefully, a few frameworks allow you to generate this code automatically during compilation. One of them is Metalama, which we already mentioned above.

In the previous article in this series, we showed how to create a code pattern named an aspect, which generates verbose logging for all methods to which you apply the aspect. You can customize the aspect code to your needs. Once the aspect is written, you can apply it to all methods using a fabric as we’ve already demonstrated with the EnrichExceptionAttribute aspect.

If you’re a DIY diehard, consider using at least this string interpolation approach to logging, which is both compact and high-performance.

Conclusion

In this article, we reviewed the different logging levels in Serilog. We described how to configure them programmatically using the LoggerConfiguration API or using the appsettings.json configuration file. We also demonstrated techniques to log events of different verbosities – exceptions, HTTP requests, and method executions.