Registrazione a prestazioni elevate in .NET
La classe LoggerMessage espone le funzionalità atte a creare delegati inseribili nella cache che richiedono un numero minore di allocazioni di oggetti e riducono il sovraccarico di calcolo 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 seguenti vantaggi in termini di 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, inobject. 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. Il LoggerMessageAttribute offre supporto per la registrazione di generazione dell'origine progettato per offrire una soluzione di registrazione altamente utilizzabile e ad alte prestazioni per le applicazioni .NET moderne. Per altre informazioni, vedere Generazione dell'origine di registrazione in fase di compilazione (nozioni fondamentali su .NET).
L'app di esempio illustra le funzionalità LoggerMessage con un servizio prioritario di lavoro di elaborazione della coda. L'app elabora gli elementi di lavoro in ordine di priorità. Durante l'esecuzione di queste operazioni, i messaggi del log vengono generati usando LoggerMessage.
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.
Definizione di un messaggio logger
Usare Define(LogLevel, EventId, String) per creare un delegato Action per la registrazione di un messaggio. Gli overload Define permettono il passaggio di un massimo di sei parametri di tipo in una stringa di formato denominata (modello).
La stringa specificata nel metodo Define è un modello e non una stringa interpolata. I segnaposto vengono inseriti nell'ordine in cui sono specificati i tipi. I nomi dei segnaposto nel modello devono essere descrittivi e coerenti tra i modelli. Vengono usati come nomi di proprietà all'interno dei dati di log strutturati. Per i nomi dei segnaposto è consigliabile usare la convenzione Pascal. Ad esempio, {Item}, {DateTime}.
Ogni messaggio di log è un elemento Action 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 Action, specificare:
- Il livello del log.
- Un identificatore di evento univoco (EventId) con il nome del metodo di estensione statico.
- Il modello di messaggio (stringa di formato denominata).
Man mano che gli elementi di lavoro vengono rimossi dalla coda per l'elaborazione, l'app del servizio di lavoro imposta:
- Il livello del log su LogLevel.Critical.
- L'ID evento su
13con il nome del metodoFailedToProcessWorkItem. - Il modello di messaggio (stringa di formato denominata) su una stringa.
s_failedToProcessWorkItem = LoggerMessage.Define(
LogLevel.Critical,
new EventId(13, nameof(FailedToProcessWorkItem)),
"Epic failure processing item!");
Il metodo LoggerMessage.Define viene usato per configurare e definire un delegato Action, che rappresenta un messaggio di log.
Negli archivi di log strutturati è possibile che venga usato il nome evento quando viene specificato con l'ID evento per arricchire la registrazione. Ad esempio, Serilog usa il nome evento.
Action viene richiamato attraverso un metodo di estensione fortemente tipizzato. Il metodo PriorityItemProcessed 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 i parametri in un messaggio di log, definire un massimo di 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 tipo WorkItem per il campo Action:
private static readonly Action<ILogger, WorkItem, Exception> s_processingPriorityItem;
Il modello di messaggio di log del delegato riceve i valori dei segnaposto dai tipi specificati. 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 di lavoro e lo passa al delegato Action:
public static void PriorityItemProcessed(
this ILogger logger, WorkItem workItem) =>
s_processingPriorityItem(logger, workItem, default!);
Nel metodo ExecuteAsync del servizio di lavoro PriorityItemProcessed viene chiamato 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'
Definizione dell'ambito del messaggio del logger
Il metodo DefineScope(String) crea un delegato Func<TResult> per definire un ambito del log. Gli overload DefineScope permettono il passaggio di un massimo di sei parametri di tipo in una stringa di formato denominata (modello).
Come avviene per il metodo Define, la stringa specificata nel metodo DefineScope è un modello e non una stringa interpolata. I segnaposto vengono inseriti nell'ordine in cui sono specificati i tipi. I nomi dei segnaposto nel modello devono essere descrittivi e coerenti tra i modelli. Vengono usati come nomi di proprietà all'interno dei dati di log strutturati. Per i nomi dei segnaposto è consigliabile usare la convenzione Pascal. Ad esempio, {Item}, {DateTime}.
Definire un ambito del log da applicare a una serie di messaggi di log usando il metodo DefineScope. Abilitare IncludeScopes nella sezione del logger di 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 per inserire un delegato Func<TResult> per l'ambito. L'app di esempio crea un campo denominato s_processingWorkScope (Internal/LoggerExtensions.cs):
private static readonly Func<ILogger, DateTime, IDisposable?> s_processingWorkScope;
Usare DefineScope per creare il delegato. È possibile specificare un massimo di sei tipi da usare come argomenti di modello quando viene richiamato il delegato. L'app di esempio utilizza 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 i parametri di tipo per le proprietà denominate visualizzate nel modello di messaggio. L'app di esempio accetta un valore DateTime per la registrazione di un timestamp personalizzato e restituisce _processingWorkScope:
public static IDisposable? ProcessingWorkScope(
this ILogger logger, DateTime time) =>
s_processingWorkScope(logger, time);
L'ambito esegue il wrapping delle 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 una chiamata al metodo corrispondente Log*. Quando la registrazione non è configurata per l'oggetto specificato LogLevel, le istruzioni seguenti sono vere:
- ILogger.Log non viene chiamato.
- Viene evitata un'allocazione di
object[]che rappresenta i parametri. - Viene evitato il boxing del tipo valore.
Per altre informazioni:
