Logger – Part 1

I think most .NET Core developers are probably familiar with the Microsoft logging abstractions that are a part of the Microsoft.Extensions.Logging NUGET package. If not, you should probably take a look because the ILogger type, which is part of the Microsoft.Extensions.Logging assembly, is a fundamental part of most .NET Core web applications. Sooner or later, if you work with .NET Core on a regular basis, you’ll need to come to terms with the ILogger abstractions.

The good news is, the library is well crafted and the logger does pretty much everything one might need a logger to do – with one exception: it doesn’t support logging to a centralized logging service. That makes sense, of course, because if Microsoft supported logging to a centralized logging service, as part of the Microsoft.Extensions.Logging package, then they’d also have to release a centralized logging service to write to.

No worries though, a centralized logging service isn’t that difficult to write. In fact, that might be a good project for me to tackle later this year. Hmm …

In any event, in this article I wanted to explore how to integrate a 3rd party component, such as a messaging client, with the ILogger type from Microsoft. My thinking is, that’s exactly the kind of integration point that would be required in order to transparently log through an ILogger object to a centralized logging service, or I guess, anything not already supported by Microsoft. The key goal here though is to make our new integration work easily and efficiently, without requiring our customers to jump through hoops to make it all work.

 

The Microsoft.Extensions.Logging package uses a custom builder to construct ILogger objects at runtime. The builder internally constructs one or more provider objects (depending on how it was configured by the caller) that each implement the ILoggerProvider interface. The ILoggerProvider interface has a single method, called CreateLogger, which is called by the builder in order to create the ILogger instances. If we want to support a custom ILogger type we’ll have to start by supporting a custom ILoggerProvider type.

For my example here, I’m going to draw from my CG.Logging.Bus NUGET package, which contains extensions to support logging through my IBus messaging abstraction. However, the steps I’m going through here should work no matter what you need to integrate with in your project.

Let’s look at code for the custom log provider first:

 

As we can see, the BusLoggerProvider class derives from the DisposableBase type and implements the ILogProvider interface. DisposableBase is part of my CG.Core NUGET package. It’s a class that makes it easier to implement optional IDisposable support without explicitly implementing the .NET “Dispose pattern” over and over again.

There are three properties on the class:

  1. ScopeProvider, which is an instance of IExternalScopeProvider, and is used to implement the scoping mechanism supported by the Microsoft.Extensions.Logging library.
  2. Settings, which is just an instance of the BusLoggerSettings class and contains any configuration settings needed by the provider at runtime.
  3. Bus, which contains the instance of our IBus object. This is the object that publishes log messages at runtime.

BusLoggerProvider has two constructors, a default with no parameters and another that accepts a BusLoggerSettings object. We haven’t covered BusLoggerSettings yet but it’s a custom class that we’ll use to pass in any configuration information required by our custom logger object.

The CreateLogger method is where we create and return an instance of our BusLogger class. This class is what uses the resources in our provider, at runtime, to post messages to our IBus object.

The Initialize method is used to create an instance of our IBus object, which, again, is the thing we’ll use to post log messages at runtime. This example uses my IBus library but you could substitute

almost anything here, a REST client, a socket client, anything, really. By default, this version of initialize builds an in-memory instance of my IBus component. In a later article, I’ll demonstrate how to create a Rabbit MQ and then a MSMQ IBus instance.

Finally, the BusLoggerProvider class also uses the Dispose override, from our DisposableBase, to cleanup the IBus object when the provider is eventually destroyed.

Let’s look at the code for our custom BusLogger class now:

 

BusLogger implements the ILogger interface, which is part of the Microsoft.Extensions.Logger package and is the abstraction everyone is familiar with for logging.

BusLogger has two properties:

  1. Provider, which is a back reference to the provider. This is required because Microsoft designed their library in such a way that the ILoggerProvider, not the ILogger, is the disposable compoment. That means, the ILoggerProvider object has to be the thing that holds all the disposable resources at runtime. If ILogger based objects did that, they would need to be derived from IDisposable through the ILogger interface. They aren’t. I don’t know why Microsoft chose to make the provider disposable instead of the logger, but they did.
  2. CategoryName, which is just an identifier for the logger type. This is used within the Microsoft library for a variety of things. We more or less just keep it around so that we can add it to the formatted log messages.

The BusLogger class has one constructor that accepts a provider reference and a category name. We store those values in their respective properties.

The BeginScope method is part of the ILogger interface and is used to support the notion of logging scopes, which is a feature of the Microsoft library. Really, all we do is defer to the scope provider object that’s part of the provider, for all the scoping related behavior.

The IsEnabled method is also part of the ILogger interface and is used to indicate whether logging is supported for a specific log level. This also part of the Microsoft logging library. Log levels allow us selectively turn different levels of logging on or off at runtime. We start by looking for a filter delegate, in our settings object. If one exists, we use it to dynamically determine whether the specified log level is enabled, or not. If the filter delegate is not present we simply perform a comparison between the log level passed to us in the parameters, and the log level passed to us in the settings. This allows us to specify a minimal logging level even if dynamic filtering isn’t used.

The Log method is the last part of the ILogger interace. This is the method that actually writes log events to a log. We start by checking if the specified log level is enabled, or not. If not, we do nothing. If it is enabled, we continue on to format a message for the log event. Then we check for a scope provider. If one is found, we iterate through all the scopes and add each scope to formatted message. Finally, we populate a BusLogMessage object with all the properties for the current log operation and then we send that message through the IBus object in the provider.

The end result of all that effort is, we log the event through the IBus library, which publishes the information to a message queue for a service to pick up, later, and process.

The BusLogMessage class is pretty simple. Here is the code for that:

 

Think of the class as a model for the IBus library. These are simply the properties that I care about, for a standard log event. You could, of course, add any additional information that might be required by your project.

The BusLoggerSettings class is also pretty simple. Here is the code for that:

 

As I’ve mentioned already, this class is simply used to pass configuration settings to the ILogger object at runtime. In this case, for my bus library, I simply need the log level, the host name, the queue name and any filter delegate that seems appropriate.

So, how would anyone use this code in their project? Well, the easiest way to pull all the parts together is through a simple extension method on the ILoggerFactory type. Normally, since the library we’re extending has a builder class, I’d create an extension for the builder. However, in this particular case, Microsoft decided to make the builder class internal, so, we can’t deal with it directly. Instead, I’ll have to work with the ILoggerFactory type instead. Anyway, here’s the code for the extension method:

 

This method creates a BusLoggerProvider object, passing in the settings from the method’s parameters. After the provider is created, the initialize method is called in order to make sure the provider is ready to operate. Finally, the provider is added to the factory’s internal provider collection and the factory reference is returned to the caller.

Here is a quick example of how to use this extension method in a console application:

 

Notice how we use the AddBusLog extension method to inject our custom provider into the logger factory? After that, the factory creates instances of our BusLogger whenever the ILoggerFactory.CreateLogger method is called.

So, how would we use this in a .Net Core web application? It’s almost as easy as our previous example except that, this time, we’ll need one more extension class, this time on the ILoggingBuilder type, which is part of the Microsoft library. Here is what that class looks like:

 

This method does the exact same thing that the LoggerFactoryExtensions.AddBusLog method does, except that it does it to the ILoggingBuilder type, instead of the ILoggerFactory type. We need this additional extension method because, as we’ll see below, when we use the AddLogging extension method on the IServiceCollection type, it allows us to pass an ILoggingBuilder reference to a custom delegate and that’s the build instance we’ll use our new extension method for.

Here, this is an example of our new extension method in action:

 

This injects our custom provider into the builder object that .NET is using for the web application. Afterwards, the .NET dependency injector will be able to resolve the type whenever we ask for it in our code. Here’s an example of how we might use our customer in a standard .NET controller:

 

I hope everyone enjoyed this quick example of customizing the standard Microsoft.Extensions.Logging library to use our custom logger implementation. If logging to a messaging object isn’t what you’re after, you should be able to take what I’ve laid out here and easily come up with your own alternative logging mechanism – and the rest of your .NET Core web application need never know you’ve done that!

In my next article I’ll demonstrate how to create a Rabbit MQ and a MSMQ version of this extension.

See ya then.

The code for this article is part of my NUGET package CG.Logging.Bus, which can be downloaded for free at https://github.com/CodeGator/CG.Logging.Bus

 

The source code for the CG.Logging.Bus project lives on Github and can be obtained for free at

https://www.nuget.org/packages/CG.Logging.Bus