ASP.NET Core Logging Tutorial

This is part 4 in our series about ASP.NET Core:

• Part 1: AppSettings in ASP.NET Core
• Part 2: Config transformations in ASP.NET Core
• Part 3: Configuration with Azure App Services and ASP.NET Core
• Part 4: ASP.NET Core Logging Tutorial
• Part 5: Error Logging Middleware in ASP.NET Core
• Part 6: ASP.NET Core Routing Tutorial
• Part 7: ASP.NET Core Health Checks Explained

Most parts of elmah.io consist of small services. While they may not be microservices, they are in fact small and each do one thing. We recently started experimenting with ASP.NET Core (or just Core for short) for some internal services and are planning a number of blog posts about the experiences we have made while developing these services. This is the fourth part in the series.

In the previous posts, the focus was on configuration. In this post, we will take a look at the new logging features in Core. Where previous versions of ASP.NET had hooks to capture information about exceptions and similar, ASP.NET Core comes with its own logging framework called Microsoft.Extensions.Logging. Microsoft.Extensions.Logging is available on NuGet and isn't bound to ASP.NET Core in any way. This mean that you will be able to utilize this new logging framework from Microsoft throughout all of your applications and services. Logging is based on providers which works as appenders in log4net and sinks in Serilog. A range of providers are available on NuGet for existing logging frameworks like NLog, Serilog and elmah.io. In other words, you don't need to switch to another logging framework, since you can always configure a provider for a logging framework of choice.

Let's learn about Microsoft.Extensions.Logging from an example. Create a new ASP.NET Core project through Visual Studio or the command line. In my case, I'm using Visual Studio 2017 RC, but the generated code looks similar when generated from VS2015 or the CLI. When generated, open the Startup.cs file and navigate to the Configure method:

// This method gets called by the runtime. Use this method to configure the HTTP request pipeline.
public void Configure(IApplicationBuilder app, IHostingEnvironment env, ILoggerFactory loggerFactory)
{
    loggerFactory.AddConsole(Configuration.GetSection("Logging"));
    loggerFactory.AddDebug();

    ...
}

As stated in the comment in the top, the Configure method is called when starting the website. See the ILoggerFactory parameter sent to the method? That's our main entry point for configuring logging. ILoggerFactory provides a fluent API for setting up our logging needs. To do some logging, we need an instance of another interface called ILogger, but let's with that for a minute. While you can create an instance of ILoggerFactory yourself, using the instance provided by Core, ensures that you capture log events from Kestrel and other components already initialized at this point.

The code is pretty much self-documented. We tell Microsoft.Extensions.Logging to log messages to the console and debug (through System.Diagnostics.Debug.WriteLine). In a future post, I'll show you how to configure different aspects of logging. For now, the only thing I'll mention is log levels. Like Serilog, NLog etc., Microsoft.Extensions.Logging implements a range of different log levels from Trace to Critical. As default, most providers only logs from Information and up. If you want to extend this to also log Trace and Debug messages, you can configure this as part of adding each provider:

loggerFactory.AddDebug(LogLevel.Trace);

The console provider configured as part of the generated code, uses the appsettings.json file as explained in the previous three posts. To change the minimum log level for this provider, either configure the provider all through C# code or change the Logging.LogLevel.Default setting in appsettings.json:

{
  "Logging": {
    "IncludeScopes": false,
    "LogLevel": {
      "Default": "Trace",
      "System": "Information",
      "Microsoft": "Information"
    }
  }
}

Until now, we haven't logged anything. To do so, use dependency injection in Core to inject an instance of ILoggerFactory in your controller:

public class HomeController : Controller
{
    ILoggerFactory _loggerFactory;

    public HomeController(ILoggerFactory loggerFactory)
    {
        _loggerFactory = loggerFactory;
    }

    public IActionResult Index()
    {
        var logger = _loggerFactory.CreateLogger("MyLogger");
        logger.LogInformation("Calling the Index action");
        return View();
    }
}

I've injected ILoggerFactory into the HomeController. To start logging, call the CreateLogger method to get an instance of ILogger. As previously mentioned, ILogger is the client used to log messages to the configured providers. In this example, we log an information message. The MyLogger string sent to the CreateLogger method, tells Microsoft.Extensions.Logging that all messages logged to this logger, will be in the MyLogger category. Categories is something that I want to elaborate on in a future post.

Instead of creating a new logger every time, we can simply inject an instance of ILogger instead:

public class HomeController : Controller
{
    ILogger<HomeController> _logger;

    public HomeController(ILogger<HomeController> logger)
    {
        _logger = logger;
    }

    public IActionResult Index()
    {
        _logger.LogInformation("Calling the Index action");
        return View();
    }
}

Decorating the ILogger with a generic parameter of HomeController, automatically generates a logger with a category of the HomeController.

In the next post, I'll show you how to implement custom Error Logging Middleware in ASP.NET Core. Also make sure to visit our post Best practices logging in Web API and MVC with C#