Logging in ASP .NET Core 3.1

By Shahed C on March 24, 2020

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.

Previous post:

NetLearner on GitHub:

In this Article:

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.

Logging providers in ASP .NET Core 3.1

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 ConsoleDebug, 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
VS2019 Output panel showing debug messages
Windows Event Viewer showing log data

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:

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

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:

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:

  1. Instead of ILogger<classname> we are now passing in an ILoggerFactory type as the logger.
  2. 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
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) elmahNLog 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:

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

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

References

7 thoughts on “Logging in ASP .NET Core 3.1

  1. Pingback: The Morning Brew - Chris Alcock » The Morning Brew #2960

  2. Pingback: Dew Drop – March 25, 2020 (#3161) | Morning Dew

  3. Pingback: March 30, 2020 Weekly Update on Microsoft Integration Platform & Azure iPaaS - BizTalkGurus

  4. Pingback: Production Tips for ASP .NET Core 3.1 Web Apps | Wake Up And Code!

  5. Pingback: Middleware in ASP .NET Core 3.1 | Wake Up And Code!

  6. Greg K

    I have exactly what you posted and nothing gets posted to EventLog unless I have the following line:
    logging.AddFilter(level => level >= LogLevel.Information);

    Any ideas?

    Reply
    1. Shahed C Post author

      Which URL are you going to, when you’re looking for log entries?

      Here’s what I’m doing without any further code changes.
      1. Open NetLearnerApp solution in VS2019.
      2. Run NetLearner.Portal web app
      3. Go to /Workhorse page, e.g. https://localhost:44306/Workhorse
      (your port number may vary)
      4. Open Event Viewer and look under Windows Logs | Application.
      (you may have to refresh your view)
      5. Look for Information entries with log entries like “Step 1 Kicked Off.”, “Step 1 in process…”, “Step 1 completed!” and so on…

      Reply

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.