NLog.Web.AspNetCore – make sure you add error message for logging exception

I’ve been using NLog for quite some time already, and it was a natural choice to use it in the ASP.NET Core projects as well. I’ve configured the logger using this tutorial and everything seemed to be working fine. Unfortunately, after some time we’ve noticed that for some reasons some of the errors are not logged. We’ve taken a deeper look at our code base and we’ve found couple logs being written as follows

This piece of code works perfectly fine with ASP.NET Core console logger but it seems it doesn’t for NLog.
We double checked that with following piece of code

And as you can see in the picture below, no errors have been reported

Changing the error message to any message (even the one containing only white spaces)

fixed the problem.

That looks like a bug for me, so I will create a PR with the fix and see if that will make its way to the “master”

As usual, the source code for this post can be found on my GitHub

NLog.Web.AspNetCore – make sure you add error message for logging exception

ASP.NET Core – tracking flow of requests with NLog

1. Introduction

A while ago I wrote an article about using MappedDiagnosticsLogicalContext for tracking request flow in your application. As we are moving our project to ASP.NET Core, I wanted to keep that functionality in place. Unfortunately, MDLC layout renderer is not available in that framework anymore(when targeting .NET Core). Luckily, there are two other renderers which can be used as a replacement:

  • aspnet-traceidentifier
  • aspnet-item

2. Configuring NLog

Before I dig into details of layout renderers mentioned above, we have to configure ASP.NET Core to use NLog as a logger. First of all, we need to grab NLog.Web.AspNetCore NuGet package. Once the package is installed we have to manually add NLog.config to the project (the file won’t be added automatically by NuGet installer). The next step is to configure NLog with our config, then configure NLogWeb and finally register NLog in LoggingFactory. All of these steps should be done in Startup class.

The final step required for NLog to work is to register HttpContextAccessor in IoC container of your choice. If you use the build one, you can do it like that

3. Using aspnet-traceidentifier renderer

Aspnet-traceidentifier layout renderer allows you to obtain value of TraceIdentifier property from current HttpContext. TraceIdentifier is basically unique id which identifies the request. The renderer can be used as follows

From now on (without any additional configuration) every log entry logged (once HttpContext is created), will contain TraceIdentifier.

4. Using aspnet-item renderer

If for some reasons we don’t like to use TraceIdentifier as our CorrelationId, we can leverage aspnet-item renderer, which basically allows you to read data from HttpContext.Items collection. However in that case, we are responsible for providing and storing unique identifier of request in HttpContext.Items. Fortunately it is pretty straightforward to do with custom middleware.

Of course we have to also use this middleware in our application so we have to add following line

in configure method of our Startup class. Having all the pieces in place, now we can append CorrelationId read from HttpContext.Items to our log entries with following configuration

From now on, CorrelationId will be automatically added to our log entries

6. It works in multithreading scenarios

If you take a closer look at logs presented above, you will see that both of the renderers can log proper CorrelationId/TraceId regardless of the thread from which the logger was called. This is possible thanks to implementation of HttpContextAccessor which uses AsyncLocal under the hood, which allows you to persist data across threads.

Source code for this post can be found here

ASP.NET Core – tracking flow of requests with NLog

NLog – tracking flow of requests using MappedDiagnosticsLogicalContext

1. Problem

Everyone who has ever had to analyze logs from production environment knows, that quite often it is not an easy task. Usually application flow is deduced by log entries matched by thread id, which is problematic when you deal with multithreading scenarios. Say for example we have following piece of code

Default log file usually looks like that

Having multiple simultaneous Index requests, makes it almost impossible to figure out which log entry is part of which call. Fortunately with NLog it is possible to solve this problem without too much of a hassle.

2. Proposed solution

The whole idea is to leverage MappedDiagnosticsLogicalContext “storage” to keep some unique identifier of request for entire call. Note, that this identifier will be accessible also from other threads created from within given call. In order to set unique request id (also known as correlation id) I will use custom HttpModule. The very first implementation looks like that

Once the HttpModule is ready it is necessary to register it in web.config.

From now on, every request goes through LogginHttpModule and proper correlationId is set in MappedDiagnosticsLogicalContext.
As we want to have correlationId included in log files it is necessary to modify Nlog.config. In my case it looks like that

Note that we can access our correlationId variable via ${mdlc:item=correlationid}
Log file after the changes looks like that

This is almost perfect, however for some reasons correlationId is lost in EndRequest event handler. I am not sure if this is bug in NLog (I’ve posted question in Nlog’s github) or it is by design, however there is easy workaround for that. We can store our correlationId in HttpContext.Items collection and reassign it to MappedDiagnosticsLogicalContext in EndRequest event handler.

After these changes our log file finally looks OK

Source code for this post can be found here

NLog – tracking flow of requests using MappedDiagnosticsLogicalContext