(C# ASP.NET Core) Logging in ASP.NET Core

Logging helps in troubleshooting, it helps in audit, it helps in getting signals of an imminent application crash. This topic explains the terminology of a log message, and also explains how to configure an application for logging, and also how to observe a sequence of log messages.
(Rev. 30-Sep-2022)

Categories | About |     |  

Parveen,

Structure of a Log Message

Let me first explain the terminology associated with a log message.

Consider this snapshot of a log message generated by an application.

  
dbug: Microsoft.AspNetCore.Hosting.Diagnostics[21]
      Loaded hosting startup assembly Microsoft....

  

This dbug: is the log level. A log level indicates the severity of a log message. There are five levels of severity - Trace, Debug, Information, Warning, Error and Critical. This is the increasing order.

In this example, dbug: is an abbreviation for the log level of Debug. Hence, this message has a log level of Debug.

The next item in a log message is Category. By convention, a category is the fully-qualified name of the class that generates that log message.

The category in our message is the fully qualified name of the class Diagnostics.

You can also see a number, 21, in brackets. This number is the EventId of the message. A software developer can define and document any numerics for an event id. It is just a convenient tag for providing additional documentation on a log message.

An un-specified EventId has a value of zero.

The second line is the Log Message, which is a readable information about the log message.

Video Explanation

Please watch the following youtube video:

Log Levels

Now I will discuss the various shades of log levels. I am calling them shades because the decision to classify a message in two adjacent levels gets subjective and judgemental sometimes.

Trace is used to provide the most detailed log. It can contain sensitive data as well. It is disabled in a production scenario.

Debug is used to provide data for debugging. It is disabled in a production scenario, because it tends to get bulky.

Information is used to track the general flow of an application.

Warning is for un-expected events. But these events or conditions do not cause the application to fail. This log demands attention and further analysis from the developer team.

Error is for failure in a current action. These could be as a result of exceptions that do not cause application wide failure. An example is a failed database update.

Critical is for logs of extreme importance that require immediate attention. For example, on a disk going out of space.

None is not a level of severity, but it is often used in configuration for disabling the output of any log.

The appSettings.json Files

Logging can be configured through configuration files, in a json based format.

Visual Studio maintains configuration files in the root directory of your project. These files are a very convenient means for configuring the rules of logging.

Default logging is easily configured with a file called appSettings.json.

Additonal files like appSettings.Development.json, appSettings.Production.json can be used to over-ride the settings for specific environments.

Let us double-click and open our appSettings.json file.

Have a look at the section called Logging. This section is used for specifying the minimum levels of log output.

The default minimum log level is specified through the property called "default". This means that for all the categories (i.e., classes), log messages will be output only if the level is "information" or higher.

Notice that there is a specific property called Microsoft.AspNetCore. This property works as a wild card Microsoft.AspNetCore*. This means that all classes whose full path starts with Micsrosoft.AspNetCore are included, and hence the log level of Debug applies to all namespaces and classes within the Microsoft.AspNetCore namespace.

This setting will over-ride the default level.


// appSettings.json file 

{
  
  "DetailedErrors": true,

  "Logging": {

    "LogLevel": {

      "Default": "Information",
      "Microsoft.AspNetCore": "Debug"

    }
  }
}

How to Output a Log Message

The following is from a project in Visual Studio 2022, .NET 6 or later

Next let us see how to output a log message.

We have created a simple ASP.NET Core project of just one page called Index. This project has been created using Visual Studio 2022, the default version for which is .NET 6. You can download this project from the downloads linked to this tutorial.

Double-click to open the IndexModel class.

We shall write various types of log messages in the OnGet function of the IndexModel class.

public class IndexModel : PageModel
{

  private readonly ILogger<IndexModel> _logger;

  // dependency injection 
  public IndexModel(ILogger<IndexModel> logger)
  {

    _logger = logger;

  }

  public void OnGet()
  {

    // information log 
    _logger.LogInformation("OnGet called for Information");

    // error log 
    _logger.LogError("OnGet called for Error");

    // force an exception 
    // to demonstrate an exception based 
    // log 
    try
    {

      throw new Exception("a test exception");

    }

    catch (Exception ex)
    {

      _logger.LogInformation(ex, "OnGet Exception");

    }

    // a log with a numeric event id 
    EventId ev = new EventId(200, "My Event");

    _logger.LogInformation(ev, "OnGet event based log");

    _logger.LogTrace("OnGet trace based log");

  }

}

The first step is to obtain a ready-made instance of an ILogger through the constructor of this class. This instance is immediately cached as a readonly reference called _logger.

You might wonder at this magic. This "magic" is actually a well-known design pattern called Dependency Injection; Let me briefly explain how it works.

The first few lines of our Program.cs file make various behind-the-scenes calls to configure a default logger for our project. It adds a logger service to the DI Container. This configuration forms the basis of the constructor based Dependency Injection that we have seen here. The relevant constructor overloads are made available by the ASP.NET Core engine. For details of the DI pattern please refer the msdn documentation, but I will re-visit this topic later as well, during the database connectivity tutorials.

So, at the end of the day we have with us an ILogger specialized for the name of our IndexModel class. This name will be used as the Category of a message.

Come to the OnGet method. Here we have added various types of statements to showcase the various commonly used flavors of log messages.

Firstly we can output a log level of Information by using the built-in function called LogInformation.

Just after this I will show how to see these messages. But let me first explain the various ways of generating log messages.

In the second statement you can see a message of the log level Error.

Then, we have simulated the throw of an exception. A try block has been used to generate an exception. The entire excpetion can be logged by using an overload of the LogInformation method. Infact, overloads exist for each such method.

The next log message uses a yet another overload to add a numeric event id to a log message.

And, in the end we have added a log message of the level Trace.

Set the Log Level

Let us set the minimum log level for our project.

Our project runs in the development mode. So we can edit the appSettings.Development file.

// appSettings.Development.json 

{
  "DetailedErrors": true,

  "Logging": {

    "LogLevel": {

      "Default": "Warning",

      "Microsoft.AspNetCore": "Error",

 // minimum level is Information,  
 // Trace log will not appear 
      "MyRazorApp.Pages.IndexModel": "Information" 

    }
  }
}

As you can see that we have set the default level for our IndexModel class to Information, so log messages will appear only for levels of Information, Warning, Error and Critical.

Notice that the last message of Trace will not appear because its level is below that of Information.

Watching the Log Messages

Run the app in Debug mode, and allow it to settle.

Now, come to visual studio and open the Output window. You can see a dropdown called "Show output from". Select "Project - ASP.NET Core Web Server".

This window is a dump of all the log messages generated by your application.


info: MyRazorApp.Pages.IndexModel[0]
      OnGet called for Information

fail: MyRazorApp.Pages.IndexModel[0]
      OnGet called for Error

info: MyRazorApp.Pages.IndexModel[0]
      OnGet Exception
      System.Exception: a test exception
         at MyRazorApp.Pages.IndexModel.OnGet() :line 27

info: MyRazorApp.Pages.IndexModel[200]
      OnGet event based log

Observe that the log messages correspond to the various statements that we wrote in the OnGet method. They appear in the same sequential order.

The first log is from the first LogInformation call, the next is of the LogError call, then we can see the log corresponding to the exception in the catch method, and the last log is of the event number 200.

We also verify that there is no log corresponding to Trace, because it is below the minimum level of Information.

Next let us modify the settings to lower the minimum log level for our class to Trace.

// appSettings.Development.json 

{
  "DetailedErrors": true,

  "Logging": {

    "LogLevel": {

      "Default": "Warning",

      "Microsoft.AspNetCore": "Error",

 // level lowered to Trace 
      "MyRazorApp.Pages.IndexModel": "Trace"

    }
  }
}

Run the app again.

Open the output window and we can verify that the trace log message also appears now!

Logging is a complex topic. There are third-party providers that enable us to log the output to files, databases, and cloud also. Please refer the documentation on msdn for more details - Thanks!


This Blog Post/Article "(C# ASP.NET Core) Logging in ASP.NET Core" by Parveen is licensed under a Creative Commons Attribution-NonCommercial-ShareAlike 4.0 International License.