I’m currently investigating how we port a large ASP.NET application to ASP.NET Core, and one of the things I had to figure out this morning was how to include information about the logged-in user in our logs.
The most important value to collect is the username, but I also need to be able to collect other information from the session at some point.
In the original ASP.NET app we did some slightly questionable HttpContext.Current access inside the logging providers, which I didn’t love.
In ASP.NET Core however, I can combine the use of the middleware system with NLog to add this information to my logs in a much better/easier way.
Adding NLog to my App
To add NLog to my ASP.NET Core app, I just followed the basic instructions at https://github.com/NLog/NLog/wiki/Getting-started-with-ASP.NET-Core-2 to get up and going (that guide tells you what you need to put in your Program and Startup classes to wire everything up).
I then updated the default HomeController to write a log message in the index page:
public class HomeController : Controller | |
{ | |
public ILogger<HomeController> Logger { get; } | |
public HomeController(ILogger<HomeController> logger) | |
{ | |
Logger = logger; | |
} | |
public IActionResult Index() | |
{ | |
Logger.LogInformation("User loaded the home page"); | |
return View(); | |
} | |
// and the rest.. | |
} |
So when I launch my app, I get my log messages out (this is just the basic ASP.NET Core site template):

Adding our Username to Log Events
First up, I’m just going to add an extremely basic action to my HomeController that will sign me in with a test user (I’ve already set up the Startup class configuration to add cookie authentication):
public async Task<IActionResult> SignMeIn() | |
{ | |
// Just do a real basic login. | |
var claims = new List<Claim> | |
{ | |
new Claim(ClaimTypes.Name, "ajevans"), | |
new Claim("FullName", "Alistair Evans"), | |
new Claim(ClaimTypes.Role, "Administrator"), | |
}; | |
var claimsIdentity = new ClaimsIdentity(claims, "AuthCookie"); | |
await HttpContext.SignInAsync( | |
"AuthCookie", | |
new ClaimsPrincipal(claimsIdentity)); | |
Logger.LogInformation("Signed in {user}", claimsIdentity.Name); | |
return RedirectToAction(nameof(Index)); | |
} |
Now we can do the middleware changes (this is the important bit). In the Startup
class’ Configure
method, we have an additional Use
method:
public void Configure(IApplicationBuilder app) | |
{ | |
app.UseStaticFiles(); | |
app.UseCookiePolicy(); | |
app.UseAuthentication(); | |
app.Use(async (ctxt, next) => | |
{ | |
if(ctxt.User == null) | |
{ | |
// Not logged in, so nothing to do. | |
await next(); | |
} | |
else | |
{ | |
// Set a scoped value in the NLog context, then call the next | |
// middleware. | |
var userName = ctxt.User.Identity.Name; | |
using (MappedDiagnosticsLogicalContext.SetScoped("userName", userName)) | |
{ | |
await next(); | |
} | |
} | |
}); | |
app.UseMvc(routes => | |
{ | |
routes.MapRoute( | |
name: "default", | |
template: "{controller=Home}/{action=Index}/{id?}"); | |
}); | |
} |
The MappedDiagnosticsLogicalContext class is an NLog class that lets you provide values that are scoped to the current async context. These values are attached to every log event raised inside the using block. The call to next()
inside our using
means that the entirety of the middleware pipeline (from that point onwards) has the userName
property attached to it.
Displaying the Username in the Log
The last part of this is to update our nlog.config to display the username.
To do this, we use the MDLC Layout Renderer to pull the userName
property out of the log event, by adding ${mdlc:userName}
inside our layout:
<!-- the targets to write to --> | |
<targets> | |
<!-- write logs to file --> | |
<target xsi:type="File" name="allfile" fileName="c:\temp\nlog-all-${shortdate}.log" | |
layout="${longdate} | ${uppercase:${level:padding=5}} | ${mdlc:userName} | ${logger} | ${message} ${exception:format=tostring}" /> | |
<!-- another file log, only own logs. Uses some ASP.NET core renderers --> | |
<target xsi:type="File" name="ownFile-web" fileName="c:\temp\nlog-own-${shortdate}.log" | |
layout="${longdate} | ${uppercase:${level:padding=5}} | ${mdlc:userName} | ${logger} | ${message} ${exception:format=tostring} | url: ${aspnet-request-url} | action: ${aspnet-mvc-action}" /> | |
</targets> |
Now, if we start the application, and log in, we get our username in each log event!
2019-09-07 10:40:15.4822 | DEBUG | | Main.Program | Starting Application | url: | action: | |
2019-09-07 10:40:18.5081 | INFO | | Main.Controllers.HomeController | Home page | url: https://localhost/ | action: Index | |
2019-09-07 10:40:40.3932 | INFO | | Main.Controllers.HomeController | Signed in ajevans | url: https://localhost/Home/SignMeIn | action: SignMeIn | |
2019-09-07 10:40:40.4028 | INFO | ajevans | Main.Controllers.HomeController | Home page | url: https://localhost/ | action: Index | |
2019-09-07 10:40:58.8799 | INFO | ajevans | Main.Controllers.HomeController | Home page | url: https://localhost/ | action: Index | |
2019-09-07 10:41:05.0707 | INFO | ajevans | Main.Controllers.HomeController | Home page | url: https://localhost/ | action: Index |
The real bonus of assigning the username inside the middleware though is that the extra detail gets added to the internal Microsoft.* logs as well:
2019-09-07 10:41:05.0707 | INFO | | Microsoft.AspNetCore.Hosting.Internal.WebHost | Request starting HTTP/1.1 GET https://localhost:5001/ | |
2019-09-07 10:41:05.0707 | INFO | ajevans | Microsoft.AspNetCore.Routing.EndpointMiddleware | Executing endpoint 'Main.Controllers.HomeController.Index (Main)' | |
2019-09-07 10:41:05.0707 | INFO | ajevans | Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker | Route matched with {action = "Index", controller = "Home"}. Executing controller action with signature Microsoft.AspNetCore.Mvc.IActionResult Index() on controller Main.Controllers.HomeController (Main). | |
2019-09-07 10:41:05.0707 | INFO | ajevans | Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker | Executing action method Main.Controllers.HomeController.Index (Main) - Validation state: Valid | |
2019-09-07 10:41:05.0707 | INFO | ajevans | Main.Controllers.HomeController | Home page | |
2019-09-07 10:41:05.0779 | INFO | ajevans | Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker | Executed action method Main.Controllers.HomeController.Index (Main), returned result Microsoft.AspNetCore.Mvc.ViewResult in 5.3381ms. | |
2019-09-07 10:41:05.0779 | INFO | ajevans | Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor | Executing ViewResult, running view Index. | |
2019-09-07 10:41:05.0779 | INFO | ajevans | Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor | Executed ViewResult - view Index executed in 1.978ms. | |
2019-09-07 10:41:05.0779 | INFO | ajevans | Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker | Executed action Main.Controllers.HomeController.Index (Main) in 8.4146ms | |
2019-09-07 10:41:05.0779 | INFO | ajevans | Microsoft.AspNetCore.Routing.EndpointMiddleware | Executed endpoint 'Main.Controllers.HomeController.Index (Main)' | |
2019-09-07 10:41:05.0779 | INFO | | Microsoft.AspNetCore.Hosting.Internal.WebHost | Request finished in 10.42ms 200 text/html; charset=utf-8 | |
2019-09-07 10:41:05.1352 | INFO | | Microsoft.AspNetCore.Hosting.Internal.WebHost | Request starting HTTP/1.1 GET https://localhost:5001/favicon.ico | |
2019-09-07 10:41:05.1679 | INFO | | Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware | Sending file. Request path: '/favicon.ico'. Physical path: 'D:\AzureDevOps\ISA-Prototyping\Main\wwwroot\favicon.ico' | |
2019-09-07 10:41:05.1685 | INFO | | Microsoft.AspNetCore.Hosting.Internal.WebHost | Request finished in 33.3657ms 200 image/x-icon |
You’ll notice that not all the log messages have a username value. Why is that?
The reason is that those log messages come from middleware that occurs earlier in the pipeline than our middleware that assigns the username, so those log events won’t contain that property.
In conclusion…
So, you’ve seen here how to use the NLog MappedDiagnosticsLogicalContext class and ASP.NET Core middleware to add extra information to all the log messages for each request. Don’t forget that you can add as much information to the log as you need, for example you could pull some user session state value out of the Session and add that too.