Condividi tramite

Registrazione ad alte prestazioni in .NET

La LoggerMessage classe espone la funzionalità per creare delegati memorizzabili nella cache che richiedono un minor numero di allocazioni di oggetti e un sovraccarico di calcolo ridotto rispetto ai metodi di estensione del logger, ad esempio LogInformation e LogDebug. Per gli scenari di registrazione a prestazioni elevate, usare LoggerMessage.

LoggerMessage offre i vantaggi seguenti per le prestazioni rispetto ai metodi di estensione del logger:

  • I metodi di estensione del logger richiedono una "conversione boxing" dei tipi di valori, ad esempio int, in object. LoggerMessage evita la conversione boxing usando campi Action statici e metodi di estensione con parametri fortemente tipizzati.
  • I metodi di estensione del logger devono analizzare il modello di messaggio (stringa di formato denominata) ogni volta che viene scritto un messaggio del log. Solo LoggerMessage richiede una sola analisi del modello durante la definizione del messaggio.

Importante

Anziché usare la classe LoggerMessage per creare log ad alte prestazioni, è possibile usare l'attributo LoggerMessage in .NET 6 e versioni successive. LoggerMessageAttribute offre supporto per il logging generato dalla sorgente, progettato per offrire una soluzione di logging moltò fruibile e ad alte prestazioni per le applicazioni .NET moderne. Per altre informazioni, vedere Generazione dei log in fase di compilazione (nozioni fondamentali su .NET).

L'app di esempio illustra le LoggerMessage funzionalità con un servizio di lavoro di elaborazione della coda con priorità. L'app elabora gli elementi di lavoro in ordine di priorità. Quando si verificano queste operazioni, i messaggi di log vengono generati usando il LoggerMessage modello .

Suggerimento

Tutto il codice sorgente di esempio di registrazione è disponibile nel browser Samples per il download. Per altre informazioni, vedere Esplorare gli esempi di codice: Registrazione in .NET.

Definire un messaggio di registro

Usare Define(LogLevel, EventId, String) per creare un Action delegato per la registrazione di un messaggio. Define Gli overload consentono di passare fino a sei parametri di tipo a una stringa di formato denominata (modello).

La stringa fornita al Define metodo è un modello e non una stringa interpolata. I segnaposto vengono riempiti secondo l'ordine in cui i tipi sono specificati. I nomi segnaposto nel modello devono essere descrittivi e coerenti tra i modelli. Fungono da nomi di proprietà all'interno di dati di log strutturati. Raccomandiamo l'uso del Pascal casing per i nomi segnaposto. Per esempio, {Item}, {DateTime}.

Ogni messaggio di log è un Action oggetto contenuto in un campo statico creato da LoggerMessage.Define. Ad esempio, l'app di esempio crea un campo per descrivere un messaggio di log per l'elaborazione degli elementi di lavoro:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

Per il Action, specificare:

  • Livello di registrazione.
  • Identificatore di evento univoco (EventId) con il nome del metodo di estensione statico.
  • Modello di messaggio (chiamato anche stringa di formato).

Man mano che gli elementi di lavoro vengono dequeuati per l'elaborazione, l'app del servizio di lavoro imposta:

  • Livello di log su LogLevel.Critical.
  • ID evento a 13 con il nome del metodo FailedToProcessWorkItem.
  • Conversione del modello di messaggio (stringa di formato denominato) in una stringa.
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

Il LoggerMessage.Define metodo viene usato per configurare e definire un Action delegato, che rappresenta un messaggio di log.

Gli archivi di registrazione strutturati possono utilizzare il nome dell'evento quando viene fornito con l'ID dell'evento per contribuire al processo di registrazione. Ad esempio, Serilog usa il nome dell'evento.

Viene Action richiamato tramite un metodo di estensione fortemente tipizzato. Il PriorityItemProcessed metodo registra un messaggio ogni volta che viene elaborato un elemento di lavoro. FailedToProcessWorkItem viene chiamato se e quando si verifica un'eccezione:

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Esaminare l'output della console dell'app:

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.
         at WorkerServiceOptions.Example.Worker.ExecuteAsync(CancellationToken stoppingToken) in
         ..\Worker.cs:line 27

Per passare parametri a un messaggio di log, definire fino a sei tipi durante la creazione del campo statico. L'app di esempio registra i dettagli dell'elemento di lavoro durante l'elaborazione degli elementi definendo un WorkItem tipo per il Action campo:

private static readonly Action<ILogger, WorkItem, Exception> s_processingPriorityItem;

Il modello di messaggio di log del delegato riceve i valori segnaposto dai tipi forniti. L'app di esempio definisce un delegato per l'aggiunta di un elemento di lavoro in cui il parametro dell'elemento è :WorkItem

s_processingPriorityItem = LoggerMessage.Define<WorkItem>(
    LogLevel.Information,
    new EventId(1, nameof(PriorityItemProcessed)),
    "Processing priority item: {Item}");

Il metodo di estensione statico per la registrazione dell'elaborazione di un elemento di lavoro, PriorityItemProcessed, riceve il valore dell'argomento dell'elemento Action di lavoro e lo passa al delegato:

public static void PriorityItemProcessed(
    this ILogger logger, WorkItem workItem) =>
    s_processingPriorityItem(logger, workItem, default!);

Nel metodo del servizio di lavoratore ExecuteAsync, viene chiamato PriorityItemProcessed per registrare il messaggio:

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Esaminare l'output della console dell'app:

info: WorkerServiceOptions.Example.Worker[1]
      Processing priority item: Priority-Extreme (50db062a-9732-4418-936d-110549ad79e4): 'Verify communications'

Definire l'ambito del messaggio del logger

Il metodo DefineScope(string) crea un Func<TResult> delegato per definire un ambito di log. DefineScope Gli overload consentono di passare fino a sei parametri di tipo a una stringa di formato denominata (modello).

Come accade con il Define metodo , la stringa fornita al DefineScope metodo è un modello e non una stringa interpolata. I segnaposto vengono riempiti secondo l'ordine in cui i tipi sono specificati. I nomi segnaposto nel modello devono essere descrittivi e coerenti tra i modelli. Fungono da nomi di proprietà all'interno di dati di log strutturati. Raccomandiamo l'uso del Pascal casing per i nomi segnaposto. Per esempio, {Item}, {DateTime}.

Definire un ambito di log da applicare a una serie di messaggi di log usando il DefineScope metodo . Abilitare IncludeScopes nella sezione del logger della console di appsettings.json:

{
    "Logging": {
        "Console": {
            "IncludeScopes": true
        },
        "LogLevel": {
            "Default": "Information",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information"
        }
    }
}

Per creare un ambito di log, aggiungere un campo che contenga un Func<TResult> delegato per l'ambito. L'app di esempio crea un campo denominato s_processingWorkScope (Interno/LoggerExtensions.cs):

private static readonly Func<ILogger, DateTime, IDisposable?> s_processingWorkScope;

Usare DefineScope per creare il delegato. È possibile specificare fino a sei tipi per l'uso come argomenti modello quando viene richiamato il delegato. L'app di esempio usa un modello di messaggio che include la data di inizio dell'elaborazione:

s_processingWorkScope =
    LoggerMessage.DefineScope<DateTime>(
        "Processing scope, started at: {DateTime}");

Specificare un metodo di estensione statico per il messaggio di log. Includere tutti i parametri di tipo per le proprietà denominate visualizzate nel modello di messaggio. L'app di esempio accetta un DateTime valore per un timestamp personalizzato per registrare e restituisce _processingWorkScope:

public static IDisposable? ProcessingWorkScope(
    this ILogger logger, DateTime time) =>
    s_processingWorkScope(logger, time);

L'ambito racchiude le chiamate di estensione di registrazione in un blocco using.

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

Esaminare i messaggi di log nell'output della console dell'app. Il risultato seguente mostra l'ordinamento prioritario dei messaggi di log con il messaggio di ambito del log incluso:

info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Extreme (7d153ef9-8894-4282-836a-8e5e38319fb3): 'Verify communications'
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\source\repos\dotnet-docs\docs\core\extensions\snippets\logging\worker-service-options
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-High (dbad6558-60cd-4eb1-8531-231e90081f62): 'Validate collection'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1eabe213-dc64-4e3a-9920-f67fe1dfb0f6): 'Propagate selections'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1142688d-d4dc-4f78-95c5-04ec01cbfac7): 'Enter pooling [contention]'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Low (e85e0c4d-0840-476e-b8b0-22505c08e913): 'Health check network'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (07571363-d559-4e72-bc33-cd8398348786): 'Ping weather service'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (2bf74f2f-0198-4831-8138-03368e60bd6b): 'Set process state'
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...

Ottimizzazioni sorvegliate a livello di log

È possibile eseguire un'altra ottimizzazione delle prestazioni controllando LogLevel con ILogger.IsEnabled(LogLevel) prima di effettuare una chiamata al metodo corrispondente Log*. Quando il log non è configurato per il LogLevel specificato, le seguenti affermazioni sono vere:

  • ILogger.Log non viene chiamato.
  • Viene evitata un'allocazione di object[] che rappresenta i parametri.
  • Il boxing del tipo valore viene evitato.

Per altre informazioni:

Vedere anche

  • Last updated on