Using Serilog sub-loggers in .NET Core/5

If you aren’t familiar with Serilog, it is a powerful, full-featured logging library that integrates seamlessly with .NET Core/5. Some of the features it provides are flat and structured logging, numerous plugins to write data to various endpoints (called sinks), and an implementation that can be easily extended.

One of the concepts that Serilog brings to the logging world is the ability to create sub-loggers. A standard logging setup will have logs written out to a file, console, and/or a database. But if you want to write out to multiple instances of a sink then what you’ll want to look into are sub-loggers. Sub-loggers enable the instantiation of more than one instance of a sink with a custom configuration applied to each one. Some reasons that you might want to do this would be:

  • Output multiple formats of logs to a file system for digestion by different monitoring applications.
  • Recording log output from specific classes to their own files.
  • Generating multiple log files based on specific filters.

In this post I’ll show an example where we use appsettings.json to configure the logging library. Within the SpaHost project two log files will be created. One will contain all log entries while the other will hold only log entries with the level error or above. Within a second project, CrossDomainApi, we’ll have another scenario defined where one log file will contain all log entries while a second log file will contain only the log entries that originate from the Api.TestController namespace.

In order to get this configuration working a few NuGet packages need to be added.

Within the startup code of the ASP.NET Core/5 application a small bit of standard code is required. Within the Program.cs:CreateWebHostBuilder() method we need to add .UseSerilog() to the call chain. This will set Serilog as the logger for the web app. In this implementation we also make calls set the configuration, use IIS settings and capture startup errors. Depending on your implementation you may not need those calls.

public static IWebHostBuilder CreateWebHostBuilder(string[] args)
{
   var configuration = GetConfiguration();
   return WebHost.CreateDefaultBuilder(args)
      .UseSerilog()
      .UseConfiguration(configuration)
      .UseIIS()
      .CaptureStartupErrors(true)
      .UseStartup<Startup>();
}

The rest of the core logging configuration is defined in the appsettings.Development.json file. If you would rather define the logging setting in code you can do so but I personally like defining the set up in configuration files so we can customize logging based on the environment where the application is executing.

Within this file there is a section named "Serilog" that defines how the logger will handle log events, what gets written, and where those events are written. The sample below is fromthe CrossDomainApi‘s configuration file. As mentioned earlier this configuration writes logs to two files, one with all log events and another with only log events from a specific namespace.

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
    "MinimumLevel": {
      "Default": "Information",
      "Override": {
        "Microsoft": "Warning",
        "System": "Warning"
      }
    },
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "{Timestamp:HH:mm:ss.fff zzz}|{Level}|{ThreadId}|{SourceContext}|{Message:lj}|{Exception}{NewLine}"
        }
      },
      {
        "Name": "Logger",
        "Args": {
          "configureLogger": {
            "WriteTo": [
              {
                "Name": "File",
                "Args": {
                  "rollingInterval": "Day",
                  "path": "C:/Logs/CrossDomainApi/all-.log",
                  "outputTemplate": "{Timestamp:HH:mm:ss.fff zzz}|{Level}|{ThreadId}|{SourceContext}|{Message:lj}|{Exception}{NewLine}"
                }
              }
            ]
          }
        }
      },
      {
        "Name": "Logger",
        "Args": {
          "configureLogger": {
            "Filter": [
              {
                "Name": "ByIncludingOnly",
                "Args": {
                  "expression": "Contains(SourceContext, 'Api.TestController')"
                }
              }
            ],
            "WriteTo": [
              {
                "Name": "File",
                "Args": {
                  "rollingInterval": "Day",
                  "path": "C:/Logs/CrossDomainApi/api-.log",
                  "outputTemplate": "{Timestamp:HH:mm:ss.fff zzz}|{Level}|{ThreadId}|{SourceContext}|{Message:lj}|{Exception}{NewLine}"
                }
              }
            ]
          }
        }
      }
    ],
    "Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ],
    "Properties": {
      "Application": "CrossDomainApi"
    }
  }
}

What makes this configuration use sub-loggers are the child definition of "WriteTo" within the array of "WriteTo" objects. In this case we have two sub-loggers, both write logs via the "File" sink. It is in the last Logger that we apply a filter within the "configureLogger" object definition. This filter first checks that the SourceContext value contains the string Api.TestController. All log events that match this check will be sent to the sub-logger for processing.

With this configuration in place you can add an ILogger<classname> parameter to your controllers for writing out the log files. The Dependency Injection system provided by .NET will automatically pass in the instance of ILogger that was defined during startup. Additionally, any logging output by referenced projects or libraries will also use the configured Serilog instance.

using Microsoft.AspNetCore.Authorization;
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;

namespace Api
{
    [Route("test")]
    public class TestController : ControllerBase
    {
        private readonly ILogger<TestController> _logger;

        public TestController(ILogger<TestController> logger)
        {
            _logger = logger;
        }
        public IActionResult Get()
        {
            _logger.LogDebug("Request received");
            return new JsonResult("OK");
        }
    }
}

To see the working solution take a look at the BackendForFrontend project. This project also demonstrates using an external Identity Server for authentication which was written up about in How to use Backend for Frontend to simplify authentication in an Angular SPA.

How to use Backend for Frontend to simplify authentication in an Angular SPA #aspnetcore #identityserver4 #angular

For longer than I care to admit I’ve been trying to find an easy to implement authentication system with my Angular SPA. I’ve looked at rolling my own, utilizing Identity Server and the oidc-connect.js library, Auth0, as well as probably a half dozen other options. After experimenting around, reading blogs and articles on the subject, and checking out some sample implementations I’ve settled on a solution geared towards Single Page Applications (SPAs).

What I’ve picked is known as a Backend for Frontend architecture that uses Identity Server to manage authentication. The structure of the solution moves a lot of the authentication logic out of the SPA and into the backend .NET API. This means that instead of the SPA receiving a JSON Web Token (JWT) after authentication, and then managing the refresh and expiration of said token, the backend API will take ownership of managing the authenticated session and provide the SPA with a way to associate itself with that session. Besides these reasons, there are also security reasons for picking this type of implementation over a more client heavy implementation. Take a look at the post by Dominick Baer on his blog Least Privilege where he goes over many of these reasons. In fact the basis for my example implementation is based on his example from that post.

What I’ve changed from Dominick’s example is that I’ve added an Angular SPA project with a .NET BFF to manage the authenticated sessions. Additionally I swapped out the usage of ProxyKit as a reverse proxy with Microsoft’s Reverse Proxy. ProxyKit‘s development has ceased and the owner recommends migrating over to Microsoft’s implementation. While Reverse Proxy is still in preview it hopefully we will have a 1.0 release in the next few months.

The code for my example project can be found on GitHub. Admittedly there is a lot going on in this project. If you are running the solution in Visual Studio you will want to kick off the SpaHost and CrossDomainApi projects at the same time. The SpaHost will run on it’s own but one of the pages does pull down data from the CrossDomainApi when the user is authenticated so it is good to have them both running.

As it is currently implemented the project uses the publicly available Demo Identity Server. Both the HostSpa and CrossDomainApi point to this Identity Server. The CrossDomainApi checks for a JWT encoded Bearer Authentication header that contains an audience of api. If this isn’t present then the API request from a client will be denied.

The HostSpa hosts the Angular SPA and a reverse proxy to direct some requests to external services, in this case the CrossDomainApi. The configuration for utilizing Identity Server and defining the Reverse Proxy are all performed in the Startup.cs. The Reverse Proxy itself reads it’s configuration out of the appsettings.Development.json. However, in order to include the Bearer token in requests to proxied endpoints, code is added to the endpoint mapping which pulls the JWT out of the context and adds it to the Header.

endpoints.MapReverseProxy(proxyPipeline =>
{
   // The proxied controllers need the bearer token
   proxyPipeline.Use(async (context, next) =>
   {
      // If we are authenticated than we should be able to get the access token
      // from the context associated with this session
      var token = await context.GetTokenAsync("access_token");
      context.Request.Headers.Add("Authorization", $"Bearer {token}");

      await next().ConfigureAwait(false);
   });
});

The majority of the remaining code in the class deals with setting up the identity provider. I highly recommend reading the documentation for Identity Server 4 if you are unsure what all is being defined. Besides the standard OIDC configuration there are also lines of code which setup the token management and storage.

Managing access tokens takes a lot of work. You need to handling refreshes, sliding windows, revocation, storage, etc. Luckily the developers of Identity Server created a .NET library, IdentityModel.AspNetCore, which handles all of this for you. Documentation on it can be found in the Identity Server 4 documentation site.

// We want to enable the automatic management of tokens, auto refresh, in-memory storage
services.AddAccessTokenManagement();

The other piece of the puzzle is where will the tokens be stored. For development purposes keeping the tokens in memory is a suitable solution. For that we can use the AddDistributedMemoryCache() feature which you can learn more about it and other options on the documentation site. This will keep the tokens in memory for as long as the site is running.

// Enable the in-memory storage of tokens. In production or a multi-hosting environment
// you will want to use a SQL Server or Redis-like cache so tokens aren't lost during a
// reboot or deployment.
services.AddDistributedMemoryCache();

Within the Angular SPA the authentication piece is very limited. We don’t handle any of the actual authentication process. Instead we redirect the user to a controller that returns a view which requires the user to be authorized via the [Authorize]decorator. By loading this view the user will be automatically directed to the Identity Server configured in the Startup.cs class if they don’t have an active session. To see the controller logic take a look at the AccountsController.cs class. Within it you will see a function called Index(string redirect) which takes a single parameter, redirect. The value of this variable determines where the user will be sent to after they have been authenticated.

Once the user is authenticated they will have full access to the SPA site. A demonstration of how to restrict users access via authorization guards and how to force a user to authenticate when they access a publicly available page is available in the SpaHost project. Review the fetch-authenticated-data, guarded-root, auth-guard, app.module for details.

Please take a look and let me know if you have any questions or suggestions. I hope this post and the BackendForFrontend GitHub project are able to help you on your project.

TLDR; Go to my BackendForFrontend project on GitHub to see an example solution which uses Microsoft’s Reverse Proxy, Identity Server 4, and Angular to simplify identity configuration in a SPA.