Logging is an essential and valuable part of software development. It becomes like a ‘must-have’ thing in any library or application. Logging can help to find problems and issues on any step of software development, but especially in cases when you can’t use debugging in the usual way.
For example, when you deploy your application to production, and there is no way to see how it is doing your code, you can just read logged information and find out if everything is doing right. Finally, logging can help in the late stages – after product release. If something goes wrong after a long time of stable work, you can just check the logging information, and in most cases, it will be enough to understand what went wrong.
This article was written for .NET developers who want to implement logging in their projects and are not familiar with different third-party logging frameworks and features that can be provided. It describes the main steps of the logging implementation, from framework installation and configuration to writing first application logs. In this article, you will learn about the structured data logging in different frameworks, advantages, and disadvantages of each of them. Examples in this article were written using the .NET Core framework.
What is structured logging?
To get all advantages of logging, you should implement a logging feature in the right way. The more useful and necessary information you can provide by the logging – the easier you will get answers on the question ‘what went wrong’. It doesn’t mean that you should log everything, you just need to find out cases, when logging should be. But just logging exception messages can be useless. For example, if you get in logs something like ‘Object null reference’ without any context, parameter name, or even function name, where exception was thrown. You should provide enough information to make the bug search process easier. To get this done in a simple way, you can use special .Net Logging Frameworks that can provide many features as structured logging.
Simply logging means that all records are stored as strings. But many problems can’t be clearly transmitted in a few words. In this case, we should use structured logging – storing entire objects in logs. For example, request body, user model, transaction query, etc. It can help to reproduce an error and find out what went wrong.
Also, structured logging can provide some sorting and ability to search in log files. For example, you can provide the user’s model on failed requests and then just search by ClientId in logs. With the help of logging frameworks, you can pass any object you want in your logs simply.
For example, if we use simple logging, our logs will be like:
1 2 3 |
2019-02-04T12:23:34Z INFO Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms) |
It won’t be really useful if we get an error, so we can improve this log with the help of structured logging. In this case, we can get something like:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
{ "dt": "2020-04-07T12:23:34Z", "level": "info", "message": "Completed 200 OK in 79ms (Views: 78.8ms | ActiveRecord: 0.0ms)", "context": { "host": "34.225.155.83", "user_id": 5, "path": "/welcome", "method": "GET" }, "http_response_sent": { "status": 200, "duration_ms": 79.0, "view_ms": 78.8, "active_record_ms": 0.0 } } |
Looks better and we got some benefits:
- Well structured data in official encoding format (JSON).
- No special parsing rules.
- Working with data in a simple way (search, filter, sorting, human-readable view, etc.).
But before we start with structured logs, we need to implement logging in a general way.
Built-in logging API
To start working with logging API, you need a provider that displays or stores logs. You can choose the Console provider to see logs in your application console, or Azure Application Insights provider to store them in Azure. By the way, you can use multiple providers to store logs in different places. If you use an application with Generic Host, you should just call the method AddConsole (or any other provider name). Let’s try on the default Web API project template.
1 2 3 4 5 6 7 8 9 10 11 |
public static IHostBuilder CreateHostBuilder(string[] args) => Host.CreateDefaultBuilder(args) .ConfigureLogging(configureLogging => { configureLogging.ClearProviders(); configureLogging.AddConsole(); }) .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup(); }); |
Method ClearProviders is used to clear any already added (default) providers. So you can replace defaults to any providers you like.
After adding logging providers, you can create logs. This can be done by using the ILogger<> object, which can be obtained from dependency injection. Then you should create a logger with the specific category (string), it can be a controller or class name:
1 2 3 4 5 6 7 8 |
public class WeatherForecastController : ControllerBase { private readonly ILogger _logger; public WeatherForecastController(ILogger logger) { _logger = logger; } |
Then you are ready to write logs. It can be done with methods LogInformation, LogError, LogWarning, etc. For example:
1 2 3 4 5 6 7 8 9 10 11 12 13 |
public IEnumerable Get() { _logger.LogInformation("Method 'Get' called at {0}", DateTime.UtcNow); var rng = new Random(); return Enumerable.Range(1, 5).Select(index => new WeatherForecast { Date = DateTime.Now.AddDays(index), TemperatureC = rng.Next(-20, 55), Summary = Summaries[rng.Next(Summaries.Length)] }) .ToArray(); } } |
Then, if you added Console as a provider, after any call of this method you can see in output console something like:
1 2 3 |
Method `Get` called 04/07/2020 09:58:06 |
To write logs, you can use one of the following log levels, which provides by .NET Core:
- Trace = 0. Typically used only for development, disabled by default to prevent sensitive data going to production.
- Debug = 1. Any debug information (for example, parameter value on some step of executing code), can be enabled on production for troubleshooting.
- Information = 2. General information used to provide some messages about the current step or state of the system.
- Warning = 3. Used to provide any unexpected events, that doesn’t crash or block application execution.
- Error = 4. Used for errors and exceptions that weren’t handled and can indicate a failure in the current operation.
- Critical = 5. Used to provide information about any errors that required immediate attention. For example, low disk memory, etc.
.NET logging frameworks
Using a third-party framework is very similar to using built-in providers. You just need to add a NuGet package to your project and then call an ILoggerFactory extension method that your logging framework provides. These frameworks can provide you more abilities and features to improve your logging process, perform semantic logging, and improve the view of created logs.
In this article, we will take a look at three different Logging frameworks for .NET – NLog, Serilog, and Log4Net.
NLog logging framework
NLog is a free logging platform for .NET platforms. NLog supports changing the logging configuration on-the-fly, structured logging, and can easily write to several targets. The main advantages of using NLog are: easy to use, extend, configure, and high performance.
To start using the NLog framework you need to install the latest version of NLog and NLog.Web.AspNetCore packages via NuGet package manager.
Then you need to create the nlog.config file in the root of the project. This file describes the targets to write logs to and some additional rules to start logging.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
<!--?xml version="1.0" encoding="utf-8" ?--> <!-- enable asp.net core layout renderers --> <!-- the targets to write to --> <!-- write logs to file --> <!-- another file log, only own logs. Uses some ASP.NET core renderers --> <!-- rules to map from logger name to target --> <!--All logs, including from Microsoft--> <!--Skip non-critical Microsoft logs and so log only own logs--> <!-- BlackHole without writeTo --> |
The next step is to enable copying the bin folder for nlog.config. It can be done in the following way:
In a Solution explorer open properties of nlog.config file and then set parameter ‘Copy to Output Directory’ to ‘Copy if newer’.
Then you need to update the Program.cs file to init NLog.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 |
public class Program { public static void Main(string[] args) { var logger = NLog.Web.NLogBuilder.ConfigureNLog("nlog.config").GetCurrentClassLogger(); try { logger.Debug("init main"); CreateHostBuilder(args).Build().Run(); } catch (Exception exception) { //NLog: catch setup errors logger.Error(exception, "Stopped program because of exception"); throw; } finally { // Ensure to flush and stop internal timers/threads before application-exit (Avoid segmentation fault on Linux) NLog.LogManager.Shutdown(); } } public static IHostBuilder CreateHostBuilder(string[] args) => Host.CreateDefaultBuilder(args) .ConfigureLogging(configureLogging => { configureLogging.ClearProviders(); configureLogging.SetMinimumLevel(Microsoft.Extensions.Logging.LogLevel.Trace); }) .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup(); }) .UseNLog(); // NLog: Setup NLog for Dependency injection } |
The next step is to configure appsettings.json. You need to remove “Default” or put correct values. Otherwise, it will override any call to SetMinimumLevel. You can configure logging in this way:
1 2 3 4 5 6 7 8 9 10 11 12 13 |
{ "Logging": { "IncludeScopes": false, "LogLevel": { "Default": "Trace", "Microsoft": "Warning", "Microsoft.Hosting.Lifetime": "Information" } }, "AllowedHosts": "*" } |
In case you have different environments and use different configuration files, remember to specify these parameters in each of them.
Now, when you complete all the steps above, you can try to write logs. For example, you can write logs in your controller like this:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 |
public class WeatherForecastController : ControllerBase { private readonly ILogger _logger; public WeatherForecastController(ILogger logger) { _logger = logger; _logger.LogDebug(1, "NLog injected into WeatherForecastController"); } private static readonly string[] Summaries = new[] { "Freezing", "Bracing", "Chilly", "Cool", "Mild", "Warm", "Balmy", "Hot", "Sweltering", "Scorching" }; [HttpGet] public IEnumerable Get() { _logger.LogInformation("Method 'Get' called at {0}", DateTime.UtcNow); var rng = new Random(); return Enumerable.Range(1, 5).Select(index => new WeatherForecast { Date = DateTime.Now.AddDays(index), TemperatureC = rng.Next(-20, 55), Summary = Summaries[rng.Next(Summaries.Length)] }) .ToArray(); } } |
As you can see, using NLog is pretty similar as the default .NET Core logging. Now you can check your logs in the place you configured in the nlog.config file. It will be like:
1 2 3 4 5 6 7 |
2020-04-07 14:31:58.4400||DEBUG|LoggingSample.Program|init main 2020-04-07 14:31:59.1861||INFO|Microsoft.Hosting.Lifetime|Application started. Press Ctrl+C to shut down. 2020-04-07 14:31:59.1861||INFO|Microsoft.Hosting.Lifetime|Hosting environment: Development 2020-04-07 14:31:59.1979||INFO|Microsoft.Hosting.Lifetime|Content root path: C:UsersAdminsourcereposLoggingSampleLoggingSample 2020-04-07 14:31:59.2970||INFO|LoggingSample.Controllers.WeatherForecastController|Method 'Get' called at 07-Apr-20 11:31:59 |
To use structured logging in NLog you can simply control formatting by preceding @
. For example:
1 2 3 4 5 6 7 |
var order = new Order { OrderId = 2, Status = OrderStatus.Processing }; logger.Info("Order updated: {@value1}", order); |
Output result:
1 2 3 |
Order updated: {"OrderId":2, "Status":"Processing"} |
If we use this statement without @
symbol, like:
1 2 3 |
logger.Info("Order updated: {value1}", order); |
So, as you can see, using structured logging in the NLog framework is really easy. Just one symbol provides the ability to give your logs more context, which can help in the error handling process.
Summarizing the NLog framework, it is really similar to default logging and really easy to configure and start working with it. By the way, there is only one thing you should know before using this framework – you won’t get any hint if something went wrong with NLog. For example, if you miss your configuration file, NLog doesn’t start working. You won’t get any notification about that. It was done to prevent any application’s taking down because of logging. But it can be not a good surprise if something goes wrong, and you will find out that logs are empty because of an incorrect configuration file.
Serilog logging framework
Serilog is another library that provides logging to console, files, or elsewhere. It has a clean API and is easy to set up. It is built with powerful, structured event data in mind.
To start working with Serilog you need to install two packages using NuGet – Serilog and Serilog.Sinks.Console. To create logger, you just need to write the code below:
1 2 3 4 5 |
var logger = new LoggerConfiguration() .WriteTo.Console() .CreateLogger(); |
After that you can easily use logger in the same way as built-in logger:
1 2 3 |
log.Information("Hello, Serilog!"); |
Also, you can change the provider to any other you like using the WriteTo extension method. For example, to use file output you can try the code below:
1 2 3 4 5 6 |
Log.Logger = new LoggerConfiguration() .MinimumLevel.Debug() .WriteTo.File("logs\myapp.txt", rollingInterval: RollingInterval.Day) .CreateLogger(); |
Log.Information(“Hello, world!”);
Serilog supports structured logging. If you need to log some object, you can just use the next statement:
1 2 3 4 5 6 |
var position = new { Latitude = 25, Longitude = 134 }; var elapsedMs = 34; log.Information("Processed {@Position} in {Elapsed:000} ms.", position, elapsedMs); |
This ‘@’ operator tells Serilog to serialize the object and convert it using the ToString method.
One more interesting feature of Serilog is enricher. This is some part of code which runs with each log request and provides additional information to request. With the help of enricher, you can provide more information without any special moves on each request. You can just append any additional properties to your request. It helps to make stack traces more understandable.
If you check logs, you will get something like that:
1 2 3 4 5 6 |
[15:46:03 INF] Hello, world! [15:46:03 INF] Processed { Latitude: 25, Longitude: 134 } in 034 ms. [15:46:03 DBG] Dividing 10 by 0 [15:46:03 ERR] Something went wrong |
As you can see, structured logging provided the entire object model in JSON format into logs. So it enables all the features of structured logging without any problems, and it is really easy to implement in your application.
Summarizing, Serilog is a relatively easy-to-use tool. The structured logging support is pretty nice, and logs can be sent to a huge number of destinations.
Apache log4net logging framework
Log4net is a library that provides the ability to show logger output to any of the output targets. Log4net provides a feature to enable or disable logging at runtime without modifying the application code. The main advantages are speed and flexibility.
To start working with lo4net you need to install it via NuGet. Then we need to create a configuration file. It has XML format and should contain something like this:
1 2 3 |
<!-- Pattern to output the caller's file name and line number --> |
After that, we can start working with log4net. Structured logs in log4net can be created without special syntax, just by passing an object as a parameter. The code below showing an example of using log4net to create simple and structured logs:
1 2 3 4 5 6 7 8 9 10 11 12 13 |
class Program { private static readonly ILog log = LogManager.GetLogger(typeof(Program)); static void Main(string[] args) { var logRepository = LogManager.GetRepository(Assembly.GetEntryAssembly()); XmlConfigurator.Configure(logRepository, new FileInfo("log4net.config")); log.Debug("Starting up"); log.Debug(new { color = "red", num = 1 }); log.Debug("Shutting down"); Console.ReadLine(); } } |
If we run this application and then check out output, we can see:
1 2 3 4 5 |
2018-08-18 18:57:37,278 DEBUG 1 LoggingDemo.Log4Net.Program - Starting up 2018-08-18 18:57:37,298 DEBUG 1 LoggingDemo.Log4Net.Program - { color = red, int1 = 1 } 2018-08-18 18:57:37,298 DEBUG 1 LoggingDemo.Log4Net.Program - Shutting down |
Summarizing log4net, I have to pay attention to a few important things. It is not well documented at all, and it can be difficult to start working with it. The default configuration file is not the right choice. You should configure it yourself. So if you need a quick start and want to have proper documentation, maybe you should try something else.
Conclusion
Let’s compare some basic steps to implement structured logging and features that can be provided.
log4net | NLog | Serilog | |
Documentation | Has general documentation and samples | Well-documented and has a lot of samples | Well-documented and has a lot of samples and tutorials |
.NET Compatibility | .NET Framework 2.0 or higher .NET Core 1.0 or higher |
.NET Frameworks 3.5 – 4.8 .NET Core 1.0 or higher |
.NET Framework 4.5 or higher .NET Core 1.0 or higher |
Pass the entire object to logs | Simply passing an object as a parameter | Mark an object with @ |
Mark an object with @ |
Configuration | Need to customize configuration file to get a better logs view | No special configuration required for structured logging | No special configuration required for structured logging |
Complexity of implementation | Similar to default logging API, but need to customize the configuration file | Similar to default logging API, easy to implement, but no hints if implementation was unsuccessful and it doesn’t work | Similar to default logging API, easy to implement |
As you can see, all of these three .NET logging frameworks are similar, and it is not a big issue to switch to any of them, because they have similar statements, and can be easily installed and used. Also, we can use any of these frameworks to implement structured logging in your application. All of them provide similar features.
But if we need to make some decisions and select only one, I would recommend trying Serilog because of modern API, easy setting up, maintaining, and simple structured logging support from inside the box. By the way, it is very well documented and easy to use, all in all. However, as all of them are pretty similar, you can try to use each of them without any difficulty and make your own decision.