Implementing an ASP.NET Core RC1 Logging Provider

I recently added a logging provider to my open source project (WilderBlog). I know I shouldn’t have implemented a provider myself, but I wanted to see how the sausage was made.

The reality is that I should have used an existing library like Serilog or others, but digging into the logging framework taught be how the system works. I’m hoping to show you what I learned.

Some Background

Before we get started with what I did, let’s talk about how logging works. In Startup.cs you can ask for the ILoggerFactory object which you can use to support different types of logs. For instance, here is the DebugLogger being added when we’re running under development:

public void Configure(IApplicationBuilder app,
                      ILoggerFactory loggerFactory,
                      WilderInitializer initializer,
                      IMailService mailService)
{

  // Add the following to the request pipeline only in development environment.
  if (_env.IsDevelopment())
  {
    loggerFactory.AddDebug(LogLevel.Information);
    app.UseDeveloperExceptionPage();
    app.UseDatabaseErrorPage(options => options.ShowExceptionDetails = true);
  }
  // ...
}

This essentially adds the ability to do logging and what level a specific logger is going to listen for. To use the logger, you can inject a logger into classes in the system and write to logs as necessary. The resulting use of the logger isn’t tied to a specific logger platform. For example, here in the RootController, I’m injecting an ILogger:

[Route("")]
public class RootController : Controller
{
  readonly int _pageSize = 25;

  private IMailService _mailService;
  private IWilderRepository _repo;
  private IMemoryCache _memoryCache;
  private ILogger<RootController> _logger;

  public RootController(IMailService mailService, 
                        IWilderRepository repo, 
                        IMemoryCache memoryCache, 
                        ILogger<RootController> logger)
  {
    _mailService = mailService;
    _repo = repo;
    _memoryCache = memoryCache;
    _logger = logger;
  }

Note that the ILogger takes a generic argument for the class that it’s going to log messages for so it will dump out where the log is coming from. So when you write to the log, you simply put what log level you want:

[HttpPost("contact")]
public async Task<IActionResult> Contact([FromBody]ContactModel model)
{
  try
  {
    if (ModelState.IsValid)
    {
      await _mailService.SendMail("ContactTemplate.txt", model.Name, model.Email, model.Subject, model.Msg);

      return Ok(new { Success = true, Message = "Message Sent" });
    }
    else
    {
      ModelState.AddModelError("", "Failed to send email");
      return HttpBadRequest(ModelState);
    }
  }
  catch (Exception ex)
  {
    _logger.LogError("Failed to send email from contact page", ex);
    return HttpBadRequest(new { Reason = "Error Occurred" });
  }

}

You can see here, I’m logging an error if an exception is thrown. This is the core of how to *use* logging, but what about implementing logging?

Implementing the Logger

Like I said earlier, it’s probably best if you use an existing logging system like Serilog, Elmah, or others. Some have ASP.NET Core support already.  I wanted to see how the sausage was made, so I implemented my own logging to send mail to me on critical errors.

To implement the logger, you first need to register a logger provider with the ILoggerFactory. This adds a new kind of logger to the factory. Then as your code requests a new logger, the logger factory uses the logger provider to create a new logger (remember how there are separate ILogger implementations for each class):

So to get started, I needed to create a class that implements ILoggerProvider:

public class EmailLoggerProvider : ILoggerProvider
{
  private readonly Func<string, LogLevel, bool> _filter;
  private readonly IMailService _mailService;

  public EmailLoggerProvider(Func<string, LogLevel, bool> filter, IMailService mailService)
  {
    _mailService = mailService;
    _filter = filter;
  }

  public ILogger CreateLogger(string categoryName)
  {
    return new EmailLogger(categoryName, _filter, _mailService);
  }

  public void Dispose()
  {
  }
}

The **ILoggerProvider **interface requires a **CreateLogger **method and a call to dispose of any disposable resources (of which I don’t have any). But the real trick here is in the constructor. You might assume that the constructor is going to supply dependencies via dependency injection, but it’s actually not. Instead, we’ll provide this data from the Startup.cs, but we’ll get to that in a minute.

The constructor arguments include a filter function (so that we can filter by more than just the log level) and in my case I need an implementation of the mail service to actually send the mail when logging. These two parameters are then passed into every logger that the provider has to create. Notice that the **CreateLogger **method constructs the logger object directly, not through dependency injection. So how does the actual logger class work?

Let’s look at the ILogger interface first:

public interface ILogger
{
  IDisposable BeginScopeImpl(object state);
  bool IsEnabled(LogLevel logLevel);
  void Log(LogLevel logLevel, 
           int eventId, 
           object state, 
           Exception exception, 
           Func<object, Exception, string> formatter);
}

The **BeginScopeImpl **gives the logger an opportunity to know about disposal for cleanup, but for my needs I don’t need that (AFAIK). The next method is **IsEnabled **which takes a logLevel and tells the caller whether a logLevel is necessary for this specific Logger. And finally, **Log **is where the logging actually happens.

In implementing my own logger, I first pass in the name of the logger, the filter and the IMailService interface:

public class EmailLogger : ILogger
{
  private string _categoryName;
  private Func<string, LogLevel, bool> _filter;
  private IMailService _mailService;

  public EmailLogger(string categoryName, Func<string, LogLevel, bool> filter, IMailService mailService)
  {
    _categoryName = categoryName;
    _filter = filter;
    _mailService = mailService;
  }

To implement the IsEnabled, I just use the filter to test for the LogLevel:

public bool IsEnabled(LogLevel logLevel)
{
  return (_filter == null || _filter(_categoryName, logLevel));
}

Remember, the **_filter **is a **Func **that the user can supply for filtering so that by supplying the category name and logLevel, it is returning whether the Log should be called for a certain **LogLevel **(e.g. LogLevel.Information).

The implementation of Log is really dependent on how the log is working, but here is my implementation:

public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func<object, Exception, string> formatter)
{
  if (!IsEnabled(logLevel))
  {
    return;
  }

  if (formatter == null)
  {
    throw new ArgumentNullException(nameof(formatter));
  }

  var message = formatter(state, exception);

  if (string.IsNullOrEmpty(message))
  {
    return;
  }

  message = $"{ logLevel }: {message}";

  if (exception != null)
  {
    message += Environment.NewLine + Environment.NewLine + exception.ToString();
  }

  _mailService.SendMail("logmessage.txt", "Shawn Wildermuth", "shawn@foo.com", "[WilderBlog Log Message]", message);

}

So with the provider and the log class, we’re set…except we need to have a way to wire it up to the ILoggerFactory implementation.

Wiring It Up

In the Startup.cs, I want to wire-up the logging:

// In Startup.cs's Configure method:

// Support logging to email
loggerFactory.AddEmail(mailService, LogLevel.Error);

But adding a method to loggerFactory is going to take an extension method. So we need a static class to add the extension method:

public static class EmailLoggerExtensions
{
  public static ILoggerFactory AddEmail(this ILoggerFactory factory, 
                                        IMailService mailService, 
                                        Func<string, LogLevel, bool> filter = null)
  {
    factory.AddProvider(new EmailLoggerProvider(filter, mailService));
    return factory;
  }

Here you can see, that I’m extending the ILoggerFactory method to supply a method that takes a IMailService and a filter function. But since I want to be able to just filter by LogLevel, I added an overload to construct the filter:

public static ILoggerFactory AddEmail(this ILoggerFactory factory, IMailService mailService, LogLevel minLevel)
{
  return AddEmail(
      factory,
      mailService,
      (_, logLevel) => logLevel >= minLevel);
}

Now that I have the extension methods, I can use the dependency injection in the Configure method to supply anything I need to pass into logging (like the IMailService interface):

public void Configure(IApplicationBuilder app,
                      ILoggerFactory loggerFactory,
                      WilderInitializer initializer,
                      IMailService mailService)
{

If you want to see the entire thing working, go get the code from github:

http://github.com/shawnwildermuth/wilderblog

Thanks for reading!