1 Introduction
You don’t need logging to write a fully functional ASP.NET Core application, but you'll likely deal with it a lot in a real-world production environment.
Say you need to cook up a console application that runs in the background and automates a mundane task. If something breaks when no one’s around, your only source of useful information is going to be that logging system you proactively set up to prepare for such scenarios.
That’s going to be doubly useful when your colleagues, not familiar with the application, need to step in.
Logs help to identify errors from code you didn’t write. Rather than spending hours stepping through it with different input scenarios, a well-designed logging will point to the line of code and input that caused the error.
That’s why logging is essential and should not be disregarded until it’s needed.
This article is going to explore the built-in logging framework introduced in ASP.NET Core 3. Microsoft have ramped up logging in Core making it a first-class citizen in ASP.Net and there’s plenty of get your teeth into
__You can access the example project at this link. __
Did you know?
Even if you do not do include logging in your application, Windows will still detect a crash and create an entry in the Event Viewer. The Windows Event Viewer is a tool for troubleshooting Windows and shows a log of application and system messages, including errors, information messages and alerts. Despite this, it is still important to implement logging in your application as you can customise your error messages to be much more informative. An error logged to the Event Viewer doesn't show what caused the error, just the location and affected line of code.
Figure 1: The Windows Event Viewer
2 Setting up Logger
In order to start logging, ensure you have the following NuGet packages.
$ dotnet add package Microsoft.Extensions.Logging
$ dotnet add package Microsoft.Extensions.DependencyInjection
Once you’ve obtained the Nuget packages, logging is ready to use out of the box without any additional configuration. It’s designed to be used with dependency injection and all you need to do is inject an instance of ILogger into the controller or class where logging is needed.
For example, if you want to add logging to a class named MyClass, you just need to add an ILogger<MyClass> parameter to the class’ constructor and then store it to a local variable of the same type.
using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;
public class MyClass
{
private readonly ILogger _logger;
MyClass(ILogger<MyClass> logger)
{
_logger = logger;
}
}
Huh? What's going on?
Where our basic logger is being configured is not very obvious!
You need to head over to your main method and it's there, under your nose at Host.CreateDefaultBuilder(). (As you may know, an .NET Core 3 is configured on IHost - here's an article about that)
Need proof? Hit F12 to checkout its definition to get a good overview of what’s going on. F12'ing stuff in Visual Studio is always a good habit!
You will notice that when we ask for an ILogger from our Dependency Injection system, we also pass in the type of the class we’re currently in.
ILogger<MyClass> logger
This is called a category and by specifying this you indicate that the class’ fully qualified name be used as the description when the logger logs any messages.
You can also define your own category, by doing something like this:
// constructor
MyClass(ILoggerFactory factory)
{
_logger = factory.CreateLogger(“CustomCategory”);
}
Note: There's no impact on performance whichever way you use.
3 Configure Logging
Up to this point, our logging configuration is mystifying. So, how can we customise logging to work to our own tastes?
Well, we can chain an additional action to Host.CreateDefaultBuilder() :
Host.CreateDefaultBuilder().ConfigureLogging(IHostBuilder, Action<ILoggingBuilder>)
IHostBuilder is our context and Action<ILoggingBuilder> is an interface for configuring logging providers. Logging providers are explained below.
We can expand this method with expression-bodied members to add some good ol' configuration.
Here is the code from the example project:
.ConfigureLogging((hostContext, loggingBuilder) =>
{
// used to pull config from appsetting.json
loggingBuilder.AddConfiguration(hostContext.Configuration);
// clear out the default providers (everything that's listening to logging events).
loggingBuilder.ClearProviders();
// now we add our own loggers, things to log to
loggingBuilder.AddDebug();
loggingBuilder.AddConsole();
// Other loggers: ///////////////////////////////////////////////////////////////////
// EventSource,
// Eventlog(this is in your windows machine),
// TraceSource
// AzureAppServicesFiles & AwureAppSerivcesBlob
// ApplicationInsights
// Last 4 require a nuget packages to add them but are provided by Microsoft
})
You’ll notice that after pulling our configuration from appsettings.js (more on that later!), we start by calling loggingBuilder.ClearProviders();
What is a logging provider?
A logging provider displays or stores logs. For example, the Console provider displays logging output to the console and Debug logging to the Output window in Visual Studio.
We’re clearing providers as .Net Core automatically adds the following providers:
- Console
- Debug
- EventSource
- EventLog (only when running on Windows)
We don’t need to do this. But for example’s sake, clearing and re-adding providers gives us more control over how we want to log.
Other providers we can write to include AzureAppServices and TraceSource.
Did you know? We can also configure logging for our output window in Visual Studio by heading to Debug > Options and selecting the Output menu under the Debugging section.
4 Using Logger
The simplest logging messages require a call to the extension method ILogger.Log(). This method requires at a minimum two parameters, LogLevel and your custom message string.
LogLevel is an enum that defines logging severity levels, we will cover that in section 5.
_logger.Log(LogLevel.Information, "some text");
The logging package also provides helper extension methods for each LogLevel value, so that you can call LogInformation(), instead of the more verbose version mention above.
_logger.LogInformation("some text");
You could also define meaningful variables/objects as a parameter and use string interpolation because all of the logging extension methods accept a params object[] args parameter.
_logger.LogInformation("The server went down temporarily at {Time}", DateTime.UtcNow);
You can add any number of additional objects which will always correspond to the order of expressions defined within a bracket .
_logger.LogInformation("The server {ServerID} went down temporarily at {Time}", ServerID, DateTime.UtcNow);
TRIVIA What is params?
paramsis an important keyword in C# and can be used as a parameter for a method which can take a variable number of arguments.This works by sending either an array of arguments of the specified type or a comma-separated list of arguments of the type specified in the parameter declaration.
string.Format()an example of a method that usesparams:
string.Format("Your name is {0}, {1}", lastName, firstName);If you provide no arguments, the length of the
paramslist is zero.Additional parameters are not permitted after the
paramskeyword in a method declaration. Only oneparamskeyword is allowed in a method declaration.
Logging exceptions
We can also pass an exception as a parameter as part of our log message. This is useful information to log as exceptions contain textual snapshot of the error that can help to find its source.
try
{
throw new Exception("You forgot to catch me");
}
catch (Exception ex)
{
_logger.LogCritical(ex, "There was a fatal exception as {Time}", DateTime.UtcNow);
}
Using EventId
Another overload you can use is EventId by passing an additional parameter before your text message.
_logger.LogInformation(someEventId, "some text for id: {someUsefulId}", someUsefulId);
EventId is an integer value of your choice that you can associate with a custom error message of your choice.
The
EventIdtype has an implicit operator converting an int toEventId:
public static implicit operator EventId(int)
Using an Event Id can help you easily find specific messages in a crowded log. They also come in handy during testing when doing asserts.
I recommend defining your own sets of integers in another class, like in the example project.
class LoggingEvents
{
public const int ProcessStarted = 1000;
public const int ProcessEnded = 1001;
public const int InitiatedSomethingImportant = 1002;
public const int SomethingImportantFailed = 1003;
}
public void SomeProcess()
{
_logger.LogInformation(LoggingEvents.ProcessStarted, "Some process launched at {Time}", DateTime.UtcNow);
_logger.LogInformation(LoggingEvents.InitiatedSomethingImportant, "Something important started at {Time}", DateTime.UtcNow);
_logger.LogCritical(LoggingEvents.SomethingImportantFailed, "Oh no, it failed at {Time}", DateTime.UtcNow);
_logger.LogInformation(LoggingEvents.ProcessEnded, "Some process ended at {Time}", DateTime.UtcNow);
}
If you don't specify any Event Id, the log will output [0].
You can also opt to use enums instead of the static class shown in the example.
5 Logging Verbosity levels
As seen in section 4, when using .NET CORE’s logger, you must always specify a LogLevel when adding logging statements to your application.
In general, the more you log, the better your situation is going to be when trouble arises. However, although logging everything is good for troubleshooting, it can consume disk usage and large logs can be difficult to search.
Logging levels are used to filter your logging output, tailoring your logging output to particular conditions and context. For example, a typical production environment may be configured to log only ERROR and FATAL levels. If you need more context to fix a bug, the logging level can be changed to include DEBUG and WARN events.
You can also pipe different Loglevel messages to different loggers. For example, you may want to log errors to the machine’s event log or a database but log debug messages to a local file.
The six levels of logging verbosity defined by ASP.NET Core are:
(in order of their importance or severity)
Trace
These messages are the most detailed log reports, usually only helpful for debugging. These messages can sometimes contain sensitive application data are therefore not used in a production environment.
Debug
As the name implies, debug messages output information useful for resolving specific issues.
Information
These messages are not critical and help track the general flow of the application.
Warning
The warning level should be used for any unexpected inconsistencies. These may not lead the current flow of the application to stop but do require reviewing in the future. Such inconsistencies can be when memory or CPU usage is high.
Error
Errors are logged when they cause the application to stop abruptly such as when an exception appear that cannot be handled. However, these messages should indicate a failure in the current activity or operation and not an application-wide stoppage. Error level examples including being unable to insert a database record due to duplicate key violation or when a file is corrupted and couldn’t be written to.
Critical
Reserved for unrecoverable system failure requiring immediate attention. Examples: data loss scenarios, out of disk space.
As we can see, DEBUG, INFO, and TRACE events are typically non-error conditions that report on the behaviour of an application. They aid in development and debugging and, as they reveal much about the application’s inner workings, are usually disabled in production.
Production environments typically have ERROR and WARN levels enabled to log problems limiting production logging to only critical, time-sensitive data.
Bear in mind, these are guidelines and developers as individuals have some freedom in how they choose to use each logging level provided by a given framework. As a team though, a consistent pattern should be established. For guidance, refer to Microsoft’s documentation.
In my own development, I’ve found that I mostly use Information and Warning levels. Generally, we don’t develop an application expecting to have critical errors!
In the console window output, different log levels will be shown as different colours.
6 JSON Configuration
We saw that we can pull configuration information from our appsettings.json file - that's a pretty neat way to configure logging.
Below is an example of the syntax we should adopt taken from the sample project:
{
"Logging": {
"Console": {
"LogLevel": {
"Default": "Information",
"Microsoft": "Warning"
"Microsoft.Hosting.Lifetime": "Warning",
}
},
"Debug": {
"LogLvel": {
"Default": "Information",
"Microsoft": "Warning"
}
},
"LogLvel": {
"Default": "Information",
"Microsoft": "Warning",
"Microsoft.Hosting.Lifetime": "Warning",
"Microsoft*": "Warning"
}
}
}
We set out what we want to see for a specific provider.
Each provider sets out one or more categories (what is getting logged) and the minimum level of logging information we want to see for each.
Here are some of categories used by ASP.NET Core and Entity Framework Core from Microsoft's .NET Core logs:
“Default”: is the minimal level of logging we apply for all categories.
This configuration is hierarchical and where a particular provider is not specified, will drop down to "LogLvel": { }.
You’ll notice that when we want to capture everything under a particular category, we can use * For example, “Microsoft”: “Warning. Which will not log anything from the table above.
What’s cool is that because this configuration comes from an appsettings.json file, you can easy change these values in production in order to hear more information about what’s going on inside of your app.
You can configure your logging information in C# code, but it’s not as dynamic as .json so that these values can adjustable depending on the client it’s deployed on and the situation.
7 Store logs in a text file
The .NET Core Logging system is not really hard to implement, but it is limited in its extendibility, it won't write logs to files or databases out of the box.
That’s because Microsoft have designed the .NET Core logging framework as a sort of wrapper on the myriad of other logging frameworks.
__Why?
Developers often need to switch logging frameworks or write listeners that take messages from libraries unexpectedly using other random frameworks. This can really mess up your day!
To write messages to log files as simply as possible, do the following:
Install the NuGet package
Serilog.Extensions.Logging.FileAdd
LoggingBuilder.AddFile("Logs/mylog-{Date}.txt");to your.ConfigureLoggingHostBuilder Extension method. The example project contains an implementation of this.
8 Choosing a third-party logger
Although we will not delve deeply into 3rd-party logging solutions in this particular article, you will need to explore them in order to extend .NET Core’s existing logging functionality.
There are many solutions that work with ASP .NET Core, including (but not limited to)
- elmah,
- NLog,
- Log4NET
- Serilog
Each of these libraries have their advantages and are quick to set up. You might want to try a couple of them before you decide which fits your application best.
Stay tuned for a future article on third party logging solutions!
9 END
This blog post provided an overview of how you can use the ASP.NET Core logging functionality.
Remember : Effective logging can make your application a dream to maintain. Poor logging can make your life and that of your colleagues a nightmare. Know what data to log and use consistent patterns!
Cover photo by Markus Spiske from Pexels
About the Author
