Journalisation avancée avec LoggerMessage dans ASP.NET CoreHigh-performance logging with LoggerMessage in ASP.NET Core

Par Luke LathamBy Luke Latham

Les fonctionnalités LoggerMessage créent des délégués pouvant être mis en cache qui nécessitent moins d’allocations d’objet et de charge de calcul par rapport aux méthodes d’extension de journaliseur, telles que LogInformation et LogDebug.LoggerMessage features create cacheable delegates that require fewer object allocations and reduced computational overhead compared to logger extension methods, such as LogInformation and LogDebug. Pour les scénarios de journalisation hautes performances, utilisez le modèle LoggerMessage.For high-performance logging scenarios, use the LoggerMessage pattern.

LoggerMessage procure les avantages suivants en termes de performances par rapport aux méthodes d’extension de journaliseur :LoggerMessage provides the following performance advantages over Logger extension methods:

  • Les méthodes d’extension de journaliseur nécessitent la conversion (« boxing ») de types de valeur, tels que int, en object.Logger extension methods require "boxing" (converting) value types, such as int, into object. Utilisant des champs Action statiques et des méthodes d’extension avec des paramètres fortement typés, le modèle LoggerMessage évite le boxing.The LoggerMessage pattern avoids boxing by using static Action fields and extension methods with strongly-typed parameters.
  • Les méthodes d’extension de journaliseur doivent analyser le modèle de message (chaîne de format nommé) chaque fois qu’un message de journal est écrit.Logger extension methods must parse the message template (named format string) every time a log message is written. LoggerMessage requiert l’analyse d’un modèle une seule fois quand le message est défini.LoggerMessage only requires parsing a template once when the message is defined.

Affichez ou téléchargez l’exemple de code (procédure de téléchargement)View or download sample code (how to download)

L’exemple d’application illustre les fonctionnalités LoggerMessage avec un système de suivi de citations de base.The sample app demonstrates LoggerMessage features with a basic quote tracking system. L’application ajoute et supprime des citations à l’aide d’une base de données en mémoire.The app adds and deletes quotes using an in-memory database. À mesure que ces opérations se produisent, des messages de journal sont générés à l’aide du modèle LoggerMessage.As these operations occur, log messages are generated using the LoggerMessage pattern.

LoggerMessage.DefineLoggerMessage.Define

Define(LogLevel, EventId, String) crée un délégué Action pour la journalisation d’un message.Define(LogLevel, EventId, String) creates an Action delegate for logging a message. Les surcharges Define permettent de passer jusqu’à six paramètres de type à une chaîne de format nommée (modèle).Define overloads permit passing up to six type parameters to a named format string (template).

La chaîne fournie à la méthode Define est un modèle et non pas une chaîne interpolée.The string provided to the Define method is a template and not an interpolated string. Les espaces réservés sont remplis dans l’ordre dans lequel les types sont spécifiés.Placeholders are filled in the order that the types are specified. Les noms d’espace réservé dans le modèle doivent être descriptifs et cohérents d’un modèle à l’autre.Placeholder names in the template should be descriptive and consistent across templates. Ils servent de noms de propriété dans les données de journal structurées.They serve as property names within structured log data. Nous vous recommandons d’utiliser la casse Pascal pour les noms d’espace réservé.We recommend Pascal casing for placeholder names. Par exemple, {Count}, {FirstName}.For example, {Count}, {FirstName}.

Chaque message de journal est une Action contenue dans un champ statique créé par LoggerMessage.Define.Each log message is an Action held in a static field created by LoggerMessage.Define. Par exemple, l’exemple d’application crée un champ afin de décrire un message de journal pour une demande GET pour la page Index (Internal/LoggerExtensions.cs) :For example, the sample app creates a field to describe a log message for a GET request for the Index page (Internal/LoggerExtensions.cs):

private static readonly Action<ILogger, Exception> _indexPageRequested;

Pour l’Action, spécifiez :For the Action, specify:

  • Le niveau du journalThe log level.
  • Un identificateur d’événement unique (EventId) avec le nom de la méthode d’extension statiqueA unique event identifier (EventId) with the name of the static extension method.
  • Le modèle de message (chaîne de format nommée)The message template (named format string).

Une demande pour la page Index de l’exemple d’application définit :A request for the Index page of the sample app sets the:

  • Le niveau de journal sur InformationLog level to Information.
  • L’ID d’événement sur 1 avec le nom de la méthode IndexPageRequestedEvent id to 1 with the name of the IndexPageRequested method.
  • Le modèle de message (chaîne de format nommée) sur une chaîneMessage template (named format string) to a string.
_indexPageRequested = LoggerMessage.Define(
    LogLevel.Information, 
    new EventId(1, nameof(IndexPageRequested)), 
    "GET request for Index page");

Des magasins de journalisation structurée peuvent utiliser le nom d’événement quand il est fourni avec l’ID d’événement pour enrichir la journalisation.Structured logging stores may use the event name when it's supplied with the event id to enrich logging. Par exemple, Serilog utilise le nom d’événement.For example, Serilog uses the event name.

L’Action est appelée par le biais d’une méthode d’extension fortement typée.The Action is invoked through a strongly-typed extension method. La méthode IndexPageRequested journalise un message pour une demande GET pour la page Index dans l’exemple d’application :The IndexPageRequested method logs a message for an Index page GET request in the sample app:

public static void IndexPageRequested(this ILogger logger)
{
    _indexPageRequested(logger, null);
}

IndexPageRequested est appelé sur le journaliseur dans la méthode OnGetAsync dans Pages/Index.cshtml.cs :IndexPageRequested is called on the logger in the OnGetAsync method in Pages/Index.cshtml.cs:

public async Task OnGetAsync()
{
    _logger.IndexPageRequested();

    Quotes = await _db.Quotes.AsNoTracking().ToListAsync();
}

Examinez la sortie de la console de l’application :Inspect the app's console output:

info: LoggerMessageSample.Pages.IndexModel[1]
      => RequestId:0HL90M6E7PHK4:00000001 RequestPath:/ => /Index
      GET request for Index page

Pour passer des paramètres à un message de journal, définissez jusqu’à six types au moment de la création du champ statique.To pass parameters to a log message, define up to six types when creating the static field. L’exemple d’application journalise une chaîne au moment de l’ajout d’une citation en définissant un type string pour le champ Action :The sample app logs a string when adding a quote by defining a string type for the Action field:

private static readonly Action<ILogger, string, Exception> _quoteAdded;

Le modèle de message de journal du délégué reçoit ses valeurs d’espace réservé des types fournis.The delegate's log message template receives its placeholder values from the types provided. L’exemple d’application définit un délégué pour l’ajout d’une citation, où le paramètre Quote est de type string :The sample app defines a delegate for adding a quote where the quote parameter is a string:

_quoteAdded = LoggerMessage.Define<string>(
    LogLevel.Information, 
    new EventId(2, nameof(QuoteAdded)), 
    "Quote added (Quote = '{Quote}')");

La méthode d’extension statique pour l’ajout d’une citation, QuoteAdded, reçoit la valeur d’argument quote et la passe au délégué Action :The static extension method for adding a quote, QuoteAdded, receives the quote argument value and passes it to the Action delegate:

public static void QuoteAdded(this ILogger logger, string quote)
{
    _quoteAdded(logger, quote, null);
}

Dans le modèle de page de la page Index (Pages/Index.cshtml.cs), QuoteAdded est appelé pour journaliser le message :In the Index page's page model (Pages/Index.cshtml.cs), QuoteAdded is called to log the message:

public async Task<IActionResult> OnPostAddQuoteAsync()
{
    _db.Quotes.Add(Quote);
    await _db.SaveChangesAsync();

    _logger.QuoteAdded(Quote.Text);

    return RedirectToPage();
}

Examinez la sortie de la console de l’application :Inspect the app's console output:

info: LoggerMessageSample.Pages.IndexModel[2]
      => RequestId:0HL90M6E7PHK5:0000000A RequestPath:/ => /Index
      Quote added (Quote = 'You can avoid reality, but you cannot avoid the 
          consequences of avoiding reality. - Ayn Rand')

L’exemple d’application implémente un modèle try–catch pour la suppression de citations.The sample app implements a try–catch pattern for quote deletion. Un message d’information est journalisé chaque fois qu’une opération de suppression réussit.An informational message is logged for a successful delete operation. Un message d’erreur est journalisé chaque fois qu’une opération de suppression donne lieu à la levée d’une exception.An error message is logged for a delete operation when an exception is thrown. Le message de journal lié à l’échec d’une opération de suppression inclut la trace des exceptions (Internal/LoggerExtensions.cs) :The log message for the unsuccessful delete operation includes the exception stack trace (Internal/LoggerExtensions.cs):

private static readonly Action<ILogger, string, int, Exception> _quoteDeleted;
private static readonly Action<ILogger, int, Exception> _quoteDeleteFailed;
_quoteDeleted = LoggerMessage.Define<string, int>(
    LogLevel.Information, 
    new EventId(4, nameof(QuoteDeleted)), 
    "Quote deleted (Quote = '{Quote}' Id = {Id})");

_quoteDeleteFailed = LoggerMessage.Define<int>(
    LogLevel.Error, 
    new EventId(5, nameof(QuoteDeleteFailed)), 
    "Quote delete failed (Id = {Id})");

Notez la manière dont l’exception est passée au délégué dans QuoteDeleteFailed :Note how the exception is passed to the delegate in QuoteDeleteFailed:

public static void QuoteDeleted(this ILogger logger, string quote, int id)
{
    _quoteDeleted(logger, quote, id, null);
}

public static void QuoteDeleteFailed(this ILogger logger, int id, Exception ex)
{
    _quoteDeleteFailed(logger, id, ex);
}

Dans le modèle de page pour la page Index, la réussite de la suppression d’une citation se traduit par l’appel de la méthode QuoteDeleted sur le journaliseur.In the page model for the Index page, a successful quote deletion calls the QuoteDeleted method on the logger. Quand une citation à supprimer n’est pas trouvée, une ArgumentNullException est levée.When a quote isn't found for deletion, an ArgumentNullException is thrown. L’exception est interceptée par l’instruction try–catch et journalisée par le biais de l’appel de la méthode QuoteDeleteFailed sur le journaliseur dans le bloc catch (Pages/Index.cshtml.cs) :The exception is trapped by the try–catch statement and logged by calling the QuoteDeleteFailed method on the logger in the catch block (Pages/Index.cshtml.cs):

public async Task<IActionResult> OnPostDeleteQuoteAsync(int id)
{
    var quote = await _db.Quotes.FindAsync(id);

    // DO NOT use this approach in production code!
    // You should check quote to see if it's null before removing 
    // it and saving changes to the database. A try-catch is used 
    // here for demonstration purposes of LoggerMessage features.
    try
    {
        _db.Quotes.Remove(quote);
        await _db.SaveChangesAsync();

        _logger.QuoteDeleted(quote.Text, id);
    }
    catch (ArgumentNullException ex)
    {
        _logger.QuoteDeleteFailed(id, ex);
    }

    return RedirectToPage();
}

Quand une citation est correctement supprimée, voici à quoi ressemble la sortie de la console de l’application :When a quote is successfully deleted, inspect the app's console output:

info: LoggerMessageSample.Pages.IndexModel[4]
      => RequestId:0HL90M6E7PHK5:00000016 RequestPath:/ => /Index
      Quote deleted (Quote = 'You can avoid reality, but you cannot avoid the 
          consequences of avoiding reality. - Ayn Rand' Id = 1)

Quand la suppression d’une citation échoue, voici à quoi ressemble la sortie de la console de l’application.When quote deletion fails, inspect the app's console output. Notez que l’exception est incluse dans le message de journal :Note that the exception is included in the log message:

fail: LoggerMessageSample.Pages.IndexModel[5]
      => RequestId:0HL90M6E7PHK5:00000010 RequestPath:/ => /Index
      Quote delete failed (Id = 999)
System.ArgumentNullException: Value cannot be null.
Parameter name: entity
   at Microsoft.EntityFrameworkCore.Utilities.Check.NotNull[T]
       (T value, String parameterName)
   at Microsoft.EntityFrameworkCore.DbContext.Remove[TEntity](TEntity entity)
   at Microsoft.EntityFrameworkCore.Internal.InternalDbSet`1.Remove(TEntity entity)
   at LoggerMessageSample.Pages.IndexModel.<OnPostDeleteQuoteAsync>d__14.MoveNext() 
      in <PATH>\sample\Pages\Index.cshtml.cs:line 87

LoggerMessage.DefineScopeLoggerMessage.DefineScope

DefineScope(String) crée un délégué Func<TResult> pour la définition d’une étendue de journal.DefineScope(String) creates a Func<TResult> delegate for defining a log scope. Les surcharges DefineScope permettent de passer jusqu’à trois paramètres de type à une chaîne de format nommée (modèle).DefineScope overloads permit passing up to three type parameters to a named format string (template).

Comme c’est le cas avec la méthode Define, la chaîne fournie à la méthode DefineScope est un modèle et non pas une chaîne interpolée.As is the case with the Define method, the string provided to the DefineScope method is a template and not an interpolated string. Les espaces réservés sont remplis dans l’ordre dans lequel les types sont spécifiés.Placeholders are filled in the order that the types are specified. Les noms d’espace réservé dans le modèle doivent être descriptifs et cohérents d’un modèle à l’autre.Placeholder names in the template should be descriptive and consistent across templates. Ils servent de noms de propriété dans les données de journal structurées.They serve as property names within structured log data. Nous vous recommandons d’utiliser la casse Pascal pour les noms d’espace réservé.We recommend Pascal casing for placeholder names. Par exemple, {Count}, {FirstName}.For example, {Count}, {FirstName}.

Définissez une étendue de journal à appliquer à une série de messages de journal à l’aide de la méthode DefineScope.Define a log scope to apply to a series of log messages using the DefineScope method.

L’exemple d’application a un bouton Clear All (Effacer tout) pour supprimer toutes les citations de la base de données.The sample app has a Clear All button for deleting all of the quotes in the database. Les citations sont supprimées une par une.The quotes are deleted by removing them one at a time. Chaque fois qu’une citation est supprimée, la méthode QuoteDeleted est appelée sur le journaliseur.Each time a quote is deleted, the QuoteDeleted method is called on the logger. Une étendue de journal est ajoutée à ces messages de journal.A log scope is added to these log messages.

Activez IncludeScopes dans la section du journaliseur de console d’appsettings.json :Enable IncludeScopes in the console logger section of appsettings.json:

{
  "Logging": {
    "Console": {
      "IncludeScopes": true
    },
    "LogLevel": {
      "Default": "Warning"
    }
  },
  "AllowedHosts": "*"
}

Pour créer une étendue de journal, ajoutez un champ destiné à contenir un délégué Func<TResult> pour l’étendue.To create a log scope, add a field to hold a Func<TResult> delegate for the scope. L’exemple d’application crée un champ intitulé _allQuotesDeletedScope (Internal/LoggerExtensions.cs) :The sample app creates a field called _allQuotesDeletedScope (Internal/LoggerExtensions.cs):

private static Func<ILogger, int, IDisposable> _allQuotesDeletedScope;

Utilisez DefineScope pour créer le délégué.Use DefineScope to create the delegate. Vous pouvez spécifier jusqu’à trois types à utiliser comme arguments de modèle quand le délégué est appelé.Up to three types can be specified for use as template arguments when the delegate is invoked. L’exemple d’application utilise un modèle de message qui inclut le nombre de citations supprimées (un type int) :The sample app uses a message template that includes the number of deleted quotes (an int type):

_allQuotesDeletedScope = 
    LoggerMessage.DefineScope<int>("All quotes deleted (Count = {Count})");

Fournissez une méthode d’extension statique pour le message de journal.Provide a static extension method for the log message. Incluez tous les paramètres de type pour les propriétés nommées qui s’affichent dans le modèle de message.Include any type parameters for named properties that appear in the message template. L’exemple d’application prend un count de citations à supprimer et retourne _allQuotesDeletedScope :The sample app takes in a count of quotes to delete and returns _allQuotesDeletedScope:

public static IDisposable AllQuotesDeletedScope(
    this ILogger logger, int count)
{
    return _allQuotesDeletedScope(logger, count);
}

L’étendue inclut les appels d’extension de journalisation dans un bloc using :The scope wraps the logging extension calls in a using block:

public async Task<IActionResult> OnPostDeleteAllQuotesAsync()
{
    var quoteCount = await _db.Quotes.CountAsync();

    using (_logger.AllQuotesDeletedScope(quoteCount))
    {
        foreach (Quote quote in _db.Quotes)
        {
            _db.Quotes.Remove(quote);

            _logger.QuoteDeleted(quote.Text, quote.Id);
        }
        await _db.SaveChangesAsync();
    }

    return RedirectToPage();
}

Examinez les messages de journal dans la sortie de la console de l’application.Inspect the log messages in the app's console output. Le résultat suivant montre trois citations supprimées, message d’étendue de journal compris :The following result shows three quotes deleted with the log scope message included:

info: LoggerMessageSample.Pages.IndexModel[4]
      => RequestId:0HL90M6E7PHK5:0000002E RequestPath:/ => /Index => 
          All quotes deleted (Count = 3)
      Quote deleted (Quote = 'Quote 1' Id = 2)
info: LoggerMessageSample.Pages.IndexModel[4]
      => RequestId:0HL90M6E7PHK5:0000002E RequestPath:/ => /Index => 
          All quotes deleted (Count = 3)
      Quote deleted (Quote = 'Quote 2' Id = 3)
info: LoggerMessageSample.Pages.IndexModel[4]
      => RequestId:0HL90M6E7PHK5:0000002E RequestPath:/ => /Index => 
          All quotes deleted (Count = 3)
      Quote deleted (Quote = 'Quote 3' Id = 4)

Ressources supplémentairesAdditional resources