Logging in ASP.NET Core

Logging is essential part of any application nowadays. Logging brings value both to developers and business. When something unexpected happens in production first thing we will look at are logs and that will save us hours that we would spend tracking what happened. On the other side we can track how our users use our product and derive some conclusions from that and potentially improve or understand how our application should behave.

What is the problem with normal/plain-text logging? How structured logging solves that?

The problem with normal logging is that it produces unstructured plain text and if we want to extract any useful information from that we need to invest a big effort and that is very painful. Good side of plain-text logs is that they are easily understandable/human readable and easy to read. Nowadays when we have microservices architecture, where every service has its own logs and where we need to centralize all those logs, we are having something that we can’t consume right away. Logging system should help us easily track what is happening on all our parts of application/different machines on which some parts of our application lives.

So we have tones of plain-text logs that is not easily searchable. Those logs first needs to be consumed by a machine and to be in a format that is machine consumable. Plain text logs are not and that is the problem. For something to be machine consumable needs to be in some of structured formats as JSON, XML, … so machine can parse that.

Structured logging gives us extended format of our logs. There were many unsuccessful attempts of standardizing structure logging so we now have different approaches in this way of logging. With structured logging we have additional metadata that is sent along with our logs in a format that is machine parsable. So we can send this to some external logging management system that can index these logs and easily search through them.

Logging should be fast. If your logging medium is slow, don’t write to it directly. Write somewhere, to a fast store temporarily and then move them later. Logging should not be asynchronous code because of costs that it brings.

Logging in ASP.NET Core

ASP.NET Core supports logging. It has built-in API for logging that works both with built-in and third-party providers. With logging we can send our logs to various outputs (console, file, …). That defines the provider that we want to use. In ASP.NET Core if we want to use console provider we would add that with AddConsole in a place when we configure our logging.

When we create default web project we already have configured and runnable logging. That’s happening when we call CreateDefaultBuilder extension method that configures two providers Console, Debug and Event Source starting from ASP.NET Core 2.2. ILoggerFactory is already configured to instantiate ILogger of registered provider.

We can change defaults. There is extension method ConfigureLogging that gives us that possibility.

There we can clear all providers that are set and add those that we want, or some custom created. Also we have AddConfiguration method that accepts IConfiguration instance and configures logging from configuration file. There also we can specify different providers, configure them and minimum level of logs for all or per each provider.

Let’s have some BookStore API that has two endpoints for getting all books and getting one by id. If we want to log something we would inject ILogger into that API.

and log the information that we want …

And it is that simple.

Here we are logging two levels of logs Information and Warning.
In ASP.NET Core six levels of logging exist. From lower to higher severity:

• Trace that logs sensitive type of data and not valuable in production.
• Debug useful in development. Apply to production only when inspecting some anomaly.
• Information that is used to track application flow.
• Warning for some events that might be unexpected but not crash the app. Something that maybe needs to be inspected.
• Error for something that can’t be handled. Failure of current operation but not the app itself.
• Critical is something that needs to be investigated immediately.

And one special:

• None when specifying that logging category should not write any messages.

Next important thing is category from which logs come from. When we start default web application we can see some logs come from Microsoft even if we didn’t do any logging but is there by default. That is Category and we also specified it when we injected ILogger into our BookStore API.

ILogger<BookStoreController> logger

Here we specified BookStoreController as Category and all logs that come from this controller will be marked with this.

A lot of noise can come from some categories that we don’t maybe care at that time.

We can turn off/filter out some categories both programmatically and via file configuration.

Here are both ways:

Here we filtered out all the logs that come from Microsoft category. We could also configure that just for particular provider or for all of them like here. Also in code we can filter logs for particular provider, for example:

configureLogging.AddFilter<ConsoleLoggerProvider>(…)

would do the filtering just for ConsoleLoggerProvider.

Conclusion

ASP.NET Core is going in a right way but still has no built-in structured provider and no way to define your output format. For now we can just produce simple unstructured logs. Also it does not support logging to a file. But thanks to strongly configurable nature it provides us with hooks so we can easily plug-in some third-party provider that solves that.