Shahed Chowdhuri @ Microsoft for .NET

Posted on Mar 24, 2020 • Originally published at wakeupandcode.com on Mar 24, 2020

Logging in ASP .NET Core 3.1

#webdev #csharp #dotnet

This is the twelfth of a new series of posts on ASP .NET Core 3.1 for 2020. In this series, we’ll cover 26 topics over a span of 26 weeks from January through June 2020, titled ASP .NET Core A-Z! To differentiate from the 2019 series, the 2020 series will mostly focus on a growing single codebase (NetLearner!) instead of new unrelated code snippets week.

Key Vault for ASP .NET Core 3.1 Web Apps

NetLearner on GitHub :

Repository: https://github.com/shahedc/NetLearnerApp
v0.12-alpha release: https://github.com/shahedc/NetLearnerApp/releases/tag/v0.12-alpha

L is for Logging in ASP .NET Core

You could write a fully functional ASP .NET Core web application without any logging. But in the real world, you should use some form of logging. This blog post provides an overview of how you can use the built-in logging functionality in ASP .NET Core web apps. While we won’t go deep into 3rd-party logging solutions such as Serilog in this article, you should definitely consider a robust semantic/structured logging solution for your projects.

Log Messages

The simplest log message includes a call to the extension method ILogger.Log() by passing on a LogLevel and a text string. Instead of passing in a LogLevel, you could also call a specific Log method such as LogInformation () for a specific LogLevel. Both examples are shown below:

_**// Log() method with LogLevel passed in**_ \_logger. **Log** (LogLevel.Information, "some text");// _**Specific LogXX() method, e.g. LogInformation()**_\_logger. **LogInformation** ("some text");

LogLevel values include Trace, Debug, Information, Warning, Error, Critical and None. These are all available from the namespace Microsoft.Extensions.Logging. For a more structured logging experience, you should also pass in meaningful variables/objects following the templated message string, as all the Log methods take in a set of parameters defined as “params object[] args”.

public static void **Log** ( this ILogger **logger** , LogLevel **logLevel** , string **message** , **params object[] args**);

This allows you to pass those values to specific logging providers, along with the message itself. It’s up to each logging provider on how those values are captured/stored, which you can also configure further. You can then query your log store for specific entries by searching for those arguments. In your code, this could look something like this:

\_logger. **LogInformation** ("some text for id: { **someUsefulId** }", **someUsefulId** );

Even better, you can add your own EventId for each log entry. You can facilitate this by defining your own set of integers, and then passing an int value to represent an EventId. The EventId type is a struct that includes an implicit operator, so it essentially calls its own constructor with whatever int value you provide.

\_logger. **LogInformation** (someEventId, "some text for id: { **someUsefulId** }", **someUsefulId** );

In the NetLearner.Portal project, we can see the use of a specific integer value for each EventId, as shown below:

_ **// Step X: kick off something here** _\_logger. **LogInformation** (LoggingEvents. **Step1KickedOff** , "Step {stepId} Kicked Off.", stepId);_ **// Step X: continue processing here** _\_logger. **LogInformation** (LoggingEvents. **Step1InProcess** , "Step {stepId} in process...", stepId);_ **// Step X: wrap it up** _\_logger. **LogInformation** (LoggingEvents. **Step1Completed** , "Step {stepId} completed!", stepId);

The integer values can be whatever you want them to be. An example is shown below:

public class **LoggingEvents** { public const int **ProcessStarted** = 1000; public const int **Step1KickedOff** = 1001; public const int **Step1InProcess** = 1002; public const int **Step1Completed** = 1003; ...}

Logging Providers

The default template-generated web apps include a call to CreateDefaultBuilder () in Program.cs, which automatically adds the Console and Debug providers. As of ASP.NET Core 2.2, the EventSource provider is also automatically added by the default builder. When on Windows, the EventLog provider is also included.

 public static IHostBuilder **CreateHostBuilder** (string[] args) => Host. **CreateDefaultBuilder** (args) .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup<Startup>(); });

NOTE : As mentioned in an earlier post in this blog series, the now-deprecated Web Host Builder has been replaced by the Generic Host Builder with the release of .NET Core 3.0.

If you wish to add your own set of logging providers, you can expand the call to CreateDefaultBuilder(), clear the default providers, and then add your own. The built-in providers now include Console , Debug, EventLog, TraceSource and EventSource.

public static IHostBuilder **CreateHostBuilder** ( string[] args) => Host. **CreateDefaultBuilder** (args) .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup<Startup>(); }) . **ConfigureLogging** (logging => { _ **// clear default logging providers** _ logging. **ClearProviders** (); _ **// add built-in providers manually, as needed** _ logging. **AddConsole** (); logging. **AddDebug** (); logging. **AddEventLog** (); logging. **AddEventSourceLogger** (); logging. **AddTraceSource** (sourceSwitchName); });

The screenshots below show the log results viewable in Visual Studio’s Debug Window and in the Windows 10 Event Viewer. Note that the EventId’s integer values (that we had defined) are stored in the EventId field as numeric value in the Windows Event Viewer log entries.

VS2019 Output panel showing debug messages

For the Event Log provider, you’ll also have to add the following NuGet package and corresponding using statement:

Microsoft.Extensions.Logging. **EventLog**

For the Trace Source provider, a “source switch” can be used to determine if a trace should be propagated or ignored. For more information on the Trace Source provider and the Source Switch it uses check out the official docs at:

SourceSwitch Class (System.Diagnostics): https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.sourceswitch?view=netcore-3.1

For more information on adding logging providers and further customization, check out the official docs at:

Add Providers section of Logging in ASP.NET Core : https://docs.microsoft.com/en-us/aspnet/core/fundamentals/logging#add-providers

JSON Configuration

One way to configure each Logging Provider is to use your appsettings.json file. Depending on your environment, you could start with appsettings.Development.json or App Secrets in development, and then use environment variables, Azure Key Vault in other environments. You may refer to earlier blog posts from 2018 and 2019 for more information on the following:

Your Web App Secrets in ASP .NET Core: https://wakeupandcode.com/your-web-app-secrets-in-asp-net-core/
Key Vault for ASP .NET Core Web Apps: https://wakeupandcode.com/key-vault-for-asp-net-core-3-1-web-apps/

In your local JSON config file, your configuration uses the following syntax:

{ " **Logging**": { " **LogLevel**": { **"Default":**"Debug", **"Category1":**"Information", **"Category2":**"Warning" }, **"SpecificProvider":** { **"ProviderProperty":** true } }}

The configuration for LogLevel sets one or more categories, including the Default category when no category is specified. Additional categories (e.g. System, Microsoft or any custom category) may be set to one of the aforementioned LogLevel values.

The LogLevel block can be followed by one or more provider-specific blocks (e.g. Console ) to set its properties, e.g. IncludeScopes. Such an example is shown below.

{ " **Logging**": { " **LogLevel**": { **"Default":**"Debug", **"System":**"Information", **"Microsoft":**"Information" }, **"Console":** { **"IncludeScopes":** true } }}

To set logging filters in code, you can use the AddFilter () method for specific providers or all providers in your Program.cs file. The following syntax can be used to add filters for your logs.

  .ConfigureLogging(logging => logging. **AddFilter** ("_ **Category1** _", LogLevel._ **Level1** _) . **AddFilter** <_ **SomeProvider** _>("_ **Category2** _", LogLevel._ **Level2** _));

In the above sample, the following placeholders can be replaced with:

_ CategoryX _: System, Microsoft, custom categories
LogLevel._ LevelX _: Trace, Debug, Information, Warning, Error, Critical, None
_ SomeProvider _: Debug, Console, other providers

To set the EventLog level explicitly, add a section for “EventLog” with the default minimum “LogLevel” of your choice. This is useful for Windows Event Logs, because the Windows Event Logs are logged for Warning level or higher, by default.

{ " **Logging**": { " **LogLevel**": { " **Default**": "Debug" }, " **EventLog**": { " **LogLevel**": { " **Default**": "Information" } } } }

Log Categories

To set a category when logging an entry, you may set the string value when creating a logger. If you don’t set a value explicitly, the fully-qualified namespace + class name is used. In the WorkhorseModel class seen in The NetLearner.Portal project, the log results seen in the Debug window started with:

NetLearner.Portal.Pages.WorkhorseModel

This is the category name created using the class name passed to the constructor in WorkhorseModel as shown below:

private readonly ILogger \_logger; public **WorkhorseModel** (ILogger< **WorkhorseModel** > logger){ \_logger = logger;}

If you wanted to set this value yourself, you could change the code to the following:

private readonly ILogger \_logger; public **WorkhorseModel** ( **WorkhorseModel** logger){ \_logger = logger. **CreateLogger** ("NetLearner.Portal.Pages.WorkhorseModel");}

The end results will be the same. However, you may notice that there are a couple of differences here:

Instead of ILogger <classname> we are now passing in an ILoggerFactory type as the logger.
Instead of just assigning the injected logger to the private _logger variable, we are now calling the factory method CreateLogger() with the desired string value to set the category name.

Exceptions in Logs

In addition to EventId values and Category Names, you may also capture Exception information in your application logs. The various Log extensions provide an easy way to pass an exception by passing the Exception object itself.

try { _ **// try something here** _ **throw new Exception();**} catch (Exception **someException** ){ \_logger.LogError(eventId, **someException** , "Trying step {stepId}", stepId); _ **// continue handling exception** _}

Checking the Event Viewer, we may see a message as shown below. The LogLevel is shown as “Error” because we used the LogError () extension method in the above code, which is forcing an Exception to be thrown. The details of the Exception is displayed in the log as well.

Windows Event Viewer showing error log entry

Structured Logging with Serilog

At the very beginning, I mentioned the possibilities of structured logging with 3rd-party providers. There are many solutions that work with ASP .NET Core, including (but not limited to) elmah, NLog and Serilog. Here, we will take a brief look at Serilog.

Similar to the built-in logging provider described throughout this article, you should include variables to assign template properties in all log messages, e.g.

Log.Information("This is a message for { **someVariable** }", **someVariable** );

To make use of Serilog, you’ll have to perform the following steps:

grab the appropriate NuGet packages: Serilog, Hosting, various Sinks, e,g, Console
use the Serilog namespace, e.g. using Serilog
create a new LoggerConfiguration() in your Main() method
call UseSerilog() when creating your Host Builder
write log entries using methods from the Log static class.

For more information on Serilog, check out the following resources: