Logging in Asp.Net Core Minimal APIs

Photo by Sam Albury on Unsplash

Logging in Asp.Net Core Minimal APIs

This article describes logging in Asp.Net Core Minimal APIs.

Logging

Logging is a means of tracking events that happen when some software runs. Logging is important for software developing, debugging, and running.

.NET supports a logging API that works with a variety of built-in and third-party logging providers.

Logging API

Microsoft.Extensions.Logging is an extensible logging mechanism with plug-in providers for many common logging systems. That means it's easy to aggregate the logs from the entire app, including the framework and the code, into one place.

This logging mechanism makes writing logs easy. All of the first-party libraries that make up ASP.NET Core and EF Core use this abstraction.

logging-api.png

ILoggerFactory

Represents a type used to configure the logging system and create instances of ILogger from the registered ILoggerProviders.

namespace Microsoft.Extensions.Logging
{
    public interface ILoggerFactory : IDisposable
    {
        ILogger CreateLogger(string categoryName);

        void AddProvider(ILoggerProvider provider);
    }
}

ILoggerProvider

The ILoggerProvider manages and creates an appropriate logger, specified by the logging category.

namespace Microsoft.Extensions.Logging
{
    public interface ILoggerProvider : IDisposable
    {
        ILogger CreateLogger(string categoryName);
    }
}

ILoger

ILogger is responsible for writing a log message of a given log level and creating logging scopes. The interface only exposes some generic log methods which are used by extension methods making the logging easy.

namespace Microsoft.Extensions.Logging
{
    public interface ILogger
    {
        void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter);

        bool IsEnabled(LogLevel logLevel);

        IDisposable? BeginScope<TState>(TState state) where TState : notnull;
    }
}

Logging Providers

The responsibility of the Logging providers is to persist logs, except for the Console provider, which only displays logs as standard output. For example, the Azure Application Insights provider stores logs in Azure Application Insights. Multiple providers can be enabled. Microsoft provides various logging providers as NuGet packages such as:

Microsoft.Extensions.Logging.Console

Microsoft.Extensions.Logging.Debug

Microsoft.Extensions.Logging.AzureAppServices

Microsoft.Extensions.Logging.EventLog

Microsoft.Extensions.Logging.EventSource

Microsoft.Extensions.Logging.TraceSource

Third-party providers

They use the same logging abstraction, after installing the nugget package it is necessary to call an ILoggerFactory or ILoggingBuilder extension method provided by the logging framework.

These are just some third-party logging frameworks: elmah.io, Serilog, Log4Net and NLog.

Log Levels

The LogLevel specifies the minimum level to log for selected categories. They are a way of filtering important information about the system’s state and reducing information noise or alert fatigue. LogLevel indicates the severity of the log and ranges from 0 to 6: Screenshot 2022-12-02 191020.png

Log Scopes

Log Scopes are used when it is necessary to add the same values to every log message. For example, adding a database transaction id to every log message until that transaction is committed.

Implementation

For this implementation the we will use the Microsoft.Extensions.Logging.Console package, so the first step is to install the package.

Configuration

The first change in the code is to override the default set of logging providers.

builder.Logging.ClearProviders();
builder.Logging.AddConsole();

Logging configuration is commonly provided by the Logging section of appsettings.json files. The following appsettings.Development.json file is what the app is using:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft.AspNetCore": "Information",
      "Microsoft.Hosting.Lifetime": "Information",
      "Microsoft.EntityFrameworkCore": "Information"
    },
    "Console": {
      "IncludeScopes": false,
      "LogLevel": {
        "Microsoft.EntityFrameworkCore": "Information",
        "Default": "Information"
      }
    }
  },

  "AllowedHosts": "*",

  "TodoApiKey": "6298ce01e3a143ac9ddb1e9e37664a2b"
}

This is the log when the app starts.

info: Microsoft.Hosting.Lifetime[14]
      Now listening on: https://localhost:7063
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5063
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/swagger/index.html - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/swagger/index.html - - - 200 - text/html;charset=utf-8 423.9127ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/_vs/browserLink - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/_framework/aspnetcore-browser-refresh.js - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/_framework/aspnetcore-browser-refresh.js - - - 200 12006 application/javascript;+charset=utf-8 9.2800ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/_vs/browserLink - - - 200 - text/javascript;+charset=UTF-8 20.1397ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/swagger/v1/swagger.json - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/swagger/v1/swagger.json - - - 200 - application/json;charset=utf-8 149.7433ms

Logging

Default Logger

To create the logger that will be used in the app, the following code can be used. After that we can use the object logger to log the information.

var logger = LoggerFactory.Create(config =>
{
    config.AddConsole();
}).CreateLogger("Program");
app.MapPost("v{version:apiVersion}/todoitems", [Authorize] async (IValidator<Todo> validator, Todo todo, TodoDb db) =>
{
    try
    {
        logger.LogInformation("Saving todoitem");

        ValidationResult validationResult = await validator.ValidateAsync(todo);

        if (!validationResult.IsValid)
        {
            return Results.ValidationProblem(validationResult.ToDictionary());
        }

        db.Todos.Add(todo);
        await db.SaveChangesAsync();

        logger.LogInformation("TodoItem was saved");

        return Results.Created($"/todoitems/{todo.Id}", todo);
    }
    catch(Exception ex)
    {
        logger.LogError(ex, "An unexpected exception occured");
        return Results.Problem();
    }
})
.WithApiVersionSet(versionSet)
.MapToApiVersion(version1);
info: Microsoft.AspNetCore.DataProtection.KeyManagement.XmlKeyManager[63]
      User profile is available. Using 'C:\Users\Jhonathan.oliveira\AppData\Local\ASP.NET\DataProtection-Keys' as key repository and Windows DPAPI to encrypt keys at rest.
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: https://localhost:7063
info: Microsoft.Hosting.Lifetime[14]
      Now listening on: http://localhost:5063
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/swagger/index.html - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/swagger/index.html - - - 200 - text/html;charset=utf-8 364.3598ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/_framework/aspnetcore-browser-refresh.js - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/_vs/browserLink - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/_framework/aspnetcore-browser-refresh.js - - - 200 12006 application/javascript;+charset=utf-8 11.4441ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/_vs/browserLink - - - 200 - text/javascript;+charset=UTF-8 20.3106ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:7063/swagger/v1/swagger.json - -
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/2 GET https://localhost:7063/swagger/v1/swagger.json - - - 200 - application/json;charset=utf-8 131.3444ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST https://localhost:7063/user application/json 100
info: ApiFluentValidator.Security.CustomBasicAuthenticationHandler[7]
      BasicAuthentication was not authenticated. Failure message: Header Not Found.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'HTTP: POST /user'
info: Microsoft.EntityFrameworkCore.Update[30100]
      Saved 1 entities to in-memory store.
info: Microsoft.AspNetCore.Http.Result.CreatedResult[1]
      Writing value of type 'ApiFluentValidator.Models.User' with status code '201'.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'HTTP: POST /user'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 POST https://localhost:7063/user application/json 100 - 201 - application/json;+charset=utf-8 698.5075ms
info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 POST https://localhost:7063/v1/todoitems application/json 51
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'HTTP: POST v{version:apiVersion}/todoitems'
info: Program[0]
      Saving todoitem
info: Microsoft.EntityFrameworkCore.Update[30100]
      Saved 1 entities to in-memory store.
info: Program[0]
      TodoItem was saved
info: Microsoft.AspNetCore.Http.Result.CreatedResult[1]
      Writing value of type 'ApiFluentValidator.Models.Todo' with status code '201'.
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'HTTP: POST v{version:apiVersion}/todoitems'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished HTTP/1.1 POST https://localhost:7063/v1/todoitems application/json 51 - 201 - application/json;+charset=utf-8 417.9473ms

Log Levels

To log different levels in the app just need to use different methods, the following code shows which method can be used.

app.MapGet("/", () =>
{
    logger.LogInformation("Logging information.");
    logger.LogCritical("Logging critical information.");
    logger.LogDebug("Logging debug information.");
    logger.LogError("Logging error information.");
    logger.LogTrace("Logging trace");
    logger.LogWarning("Logging warning.");

    return "Hello World!";
});

Screenshot 2022-12-03 113351.png

Wrapping Up

The next article is also going to be about logging but using Serilog and Elastic Search. Stay tuned :)

You can find the full code on my GitHub.