Thursday, June 1, 2017

Filtering log entries in ASP.NET ILoggerFactory logs

By Steve Endow

UPDATE: Before reading further, a note that I ended up not using the standard Microsoft ASP.NET Core logging.  I don't recall the details, but I suspect I gave up on trying to get it to work the way I wanted.  After researching other logging options, I chose Serilog, which is apparently used by some well known ASP.NET Core developers and has a lot of features.  It isn't perfect and has its own quirks, but I've successfully implemented Serilog on two ASP.NET Core web API projects, and it has worked great.

I have two new projects that require web service APIs, so rather than actually use a tried and true tool that I am familiar with to develop these new projects, I am plunging into the dark depths of ASP.NET Core.

If you've played with ASP.NET Core, you may have noticed that Microsoft has decided that everything you have learned previously about developing web apps and web services should be discarded, making all of your prior knowledge and experience worthless.  And if you choose to venture in to new world of ASP.NET Core, you will be rewarded by not knowing how to do anything.   At all.  Awesome, can't wait!

One of those things that you'll likely need to re-learn from scratch is logging.  ASP.NET Core has a native logging framework, so rather than write your own or use a third party logging package, you can now use a built-in logger.  This sounds good, right?

Not so fast.  At this point, I have come to understand that nothing is easy or obvious with ASP.NET Core.

This article provides a basic overview showing how to perform logging in ASP.NET Core.

One thing it doesn't clearly explain is that if you want to have your logs capture Information level entries, it will quickly be filled with hundreds of entries from the ASP.NET Core engine / web server itself.  You will literally be unable to find your application entries in the log file if you log at the Information level.

So the article helpfully points out that ILoggerFactory supports filtering, allowing you to specify that you only want warnings or errors from the Microsoft tools/products, while logging Information or even Debug messages from your application.

You just add this .WithFilter section to your startup.cs Configure method:

loggerFactory .WithFilter(new FilterLoggerSettings { { "Microsoft", LogLevel.Warning }, { "System", LogLevel.Warning }, { "ToDoApi", LogLevel.Debug } })

Cool, that looks easy enough.

Except after I add that to my code, I see the red squigglies of doom:

Visual Studio 2017 is indicating that it doesn't recognize FilterLoggerSettings. At all.

Based on my experience with VS 2017 so far, it seems that it has lost the ability (that existed in VS 2015) to identify missing NuGet packages.  If you already have a NuGet package installed, it can detect that you need to add a using statement to your class, but if you don't have the NuGet package installed, it can't help you.  Hopefully this functionality is added back to VS 2017 in a service pack.

After many Google searches, I finally found this StackOverflow thread, and hidden in one of the post comments, someone helpfully notes that the WithFilter extension requires a separate NuGet package, Microsoft.Extensions.Logging.Filter.  If you didn't know that, you'd spend 15 minutes of frustration, like I did, wondering why the very simple Microsoft code sample doesn't work.

Once you add the Microsoft.Extensions.Logging.Filter NuGet package to your project, Visual Studio will recognize both WithFilter and FilterLoggerSettings.

And here is my log file with an Information and Warning message, but no ASP.NET Core messages.

And several wasted hours later, I am now able to read my log file and actually work on the real project code.

Best of luck with ASP.NET Core.  You'll need it.

You can also find him on Twitter, YouTube, and Google+


albissweet said...

Very helpful post but still not working for me :(
I think the problem is in "AddFile()" method.
What parameters did you pass it?
Thank you in advance.

Steve Endow said...

Hi albissweet,

I don't remember why, but it looks like I gave up on the default Microsoft logging and switched to Serilog instead.

I've now used Serilog on a second project, and it has worked fine. It has a few quirks, but has a lot of functionality.