×
Back to book

Log handling with C#Bot

This article will cover the logger strategy used for C#Bot and covers the third parties libraries which are being used.

Please note that no logging is currently output to file system.

Logging libraries

Currently, C#Bot uses the built-in library Microsoft.Extensions.Logging for logging.

Logging strategy

Logging configuration files

To provide more options to configure the logging, C#Bot currently uses two configuration files for the logging functionality, appsettings.xml & appsettings.Development.xml.

appsettings.xml

The apsetting.xml file contains the configuration settings used in the production environment, and the following xml snippet shows how to set the default logging level to "Warning".

<logging>
    <LogLevel>
        <Default>Warning</Default>
    </LogLevel>
</logging>

There are no protected regions in this file. Some will be added in a future version. For now, any changes to this file will be lost if you build your project again. To get around this, backup your appsetting.xml on production (or beta) and change it manually as needed when you deploy your app.

The file can be located at serverside/src/appsettings.xml.

appsettings.Development.xml

The appsettings.Development.xml file contains the configuration settings used in the development environment, and the following snippet shows how different logging levels are set.

<logging>
    <LogLevel>
        <!-- % protected region % [Configure log levels] off begin -->
        <Default>Information</Default>
        <System>Information</System>
        <Microsoft>Information</Microsoft>
        <!-- % protected region % [Configure log levels] end -->
    </LogLevel>
</logging>

The file can be located at serverside/src/appsettings.Development.xml.

To change these configurations, you need to turn on the protected region in this file and change them to the required level.

Configuration

There are many ways to add logging configurations.
Currently, logging configuration in C#Bot is in the Logging section of appsettings files. The following example shows the contents of a typical appsettings.Development.xml file:

<logging>
    <LogLevel>
        <!-- % protected region % [Configure log levels] on begin -->
        <Default>Debug</Default>
        <System>Information</System>
        <Microsoft>Information</Microsoft>
        <!-- % protected region % [Configure log levels] end -->
    </LogLevel>
</logging>

The Logging property can have LogLevel. The LogLevel property specifies the minimum level to log for selected categories. In the example, System and Microsoft categories log at Information level, and all others log at Debug level.

For information on implementing configuration providers, see Configuration in ASP.NET Core.

Log levels

Every log specifies a LogLevel value. The log level indicates the severity or importance. For example, you might write an Information log when a method ends normally and a Warning log when a method returns a 404 Not Found status code.

The following code creates Information and Warning logs:

public IActionResult GetById(string id)
{
    _logger.LogInformation(LoggingEvents.GetItem, "Getting item {Id}", id);
    var item = _todoRepository.Find(id);
    if (item == null)
    {
        _logger.LogWarning(LoggingEvents.GetItemNotFound, "GetById({Id}) NOT FOUND", id);
        return NotFound();
    }
    return new ObjectResult(item);
}

In the preceding code, the first parameter is the Log event ID. The second parameter is a message template with placeholders for argument values provided by the remaining method parameters. The method parameters are explained in the message template section later in this article.

Log methods that include the level in the method name (for example, LogInformation and LogWarning) are extension methods for ILogger. These methods call a Log method that takes a LogLevel parameter. You can call the Log method directly rather than one of these extension methods, but the syntax is relatively complicated. For more information, see ILogger and the logger extensions source code.

ASP.NET Core defines the following log levels, ordered here from lowest to highest severity.

  • Trace = 0
    For information that's typically valuable only for debugging. These messages may contain sensitive application data and so shouldn't be enabled in a production environment. Disabled by default.

  • Debug = 1
    For information that may be useful in development and debugging. Example: Entering method Configure with flag set to true. Enable Debug level logs in production only when troubleshooting, due to the high volume of logs.

  • Information = 2
    For tracking the general flow of the app. These logs typically have some long-term value. Example: Request received for path /api/todo

  • Warning = 3
    For abnormal or unexpected events in the app flow. These may include errors or other conditions that don't cause the app to stop but might need to be investigated. Handled exceptions are a common place to use the Warning log level. Example: FileNotFoundException for file quotes.txt.

  • Error = 4
    For errors and exceptions that cannot be handled. These messages indicate a failure in the current activity or operation (such as the current HTTP request), not an app-wide failure. Example log message: Cannot insert record due to duplicate key violation.

  • Critical = 5
    For failures that require immediate attention. Examples: data loss scenarios, out of disk space.

Use the log level to control how much log output is written to a particular storage medium or display window. For example:

In Production

Logging at the Trace through Information levels produces a high-volume of detailed log messages. To control costs and not exceed data storage limits, log Trace through Information level messages to a high-volume, low-cost data store.

Logging at Warning through Critical levels typically produces fewer, smaller log messages. Therefore, costs and storage limits usually aren't a concern, which results in greater flexibility of data store choice.

In Development

Log Warning through Critical messages to the console.

Add Trace through Information messages when troubleshooting.

The Log filtering section later in this article explains how to control which log levels a provider handles.

Example of writing logs in your code

public class AccountController : Controller
{
    ...
    private readonly ILogger<AccountController> _logger;
    public AccountController(
        ...
        ILogger<AccountController> logger)
    {
        _logger = logger;
    }
    ...
    [HttpGet("example")]
    [AllowAnonymous]
    public async Task<IActionResult> ExampleAction()
    {
        try
        {
            ...
        }
        catch (Exception e)
        {
            _logger.LogError(e.ToString());
        }
        ...
    }
}

To see console logging output, open a command prompt in the project folder and run the following command:

dotnet run

Example of console logs

info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET http://localhost:62555/api/todo/0
dbug: Microsoft.AspNetCore.Routing.Tree.TreeRouter[1]
      Request successfully matched the route with name 'GetTodo' and template 'api/Todo/{id}'.
dbug: Microsoft.AspNetCore.Mvc.Internal.ActionSelector[2]
      Action 'TodoApi.Controllers.TodoController.Update (TodoApi)' with id '089d59b6-92ec-472d-b552-cc613dfd625d' did not match the constraint 'Microsoft.AspNetCore.Mvc.Internal.HttpMethodActionConstraint'
dbug: Microsoft.AspNetCore.Mvc.Internal.ActionSelector[2]
      Action 'TodoApi.Controllers.TodoController.Delete (TodoApi)' with id 'f3476abe-4bd9-4ad3-9261-3ead09607366' did not match the constraint 'Microsoft.AspNetCore.Mvc.Internal.HttpMethodActionConstraint'
dbug: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action TodoApi.Controllers.TodoController.GetById (TodoApi)
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method TodoApi.Controllers.TodoController.GetById (TodoApi) with arguments (0) - ModelState is Valid
info: TodoApi.Controllers.TodoController[1002]
      Getting item 0
warn: TodoApi.Controllers.TodoController[4000]
      GetById(0) NOT FOUND
dbug: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action method TodoApi.Controllers.TodoController.GetById (TodoApi), returned result Microsoft.AspNetCore.Mvc.NotFoundResult.
info: Microsoft.AspNetCore.Mvc.StatusCodeResult[1]
      Executing HttpStatusCodeResult, setting HTTP status code 404
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action TodoApi.Controllers.TodoController.GetById (TodoApi) in 0.8788ms
dbug: Microsoft.AspNetCore.Server.Kestrel[9]
      Connection id "0HL6L7NEFF2QD" completed keep alive response.
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 2.7286ms 404