Compartir vía

Registro de alto rendimiento en .NET

Para escenarios de registro de alto rendimiento en .NET 6 y versiones posteriores, utilice el LoggerMessageAttribute con la generación de código en tiempo de compilación. Este enfoque proporciona el mejor rendimiento al eliminar el boxing, las asignaciones temporales y el análisis de plantillas de mensajes en tiempo de ejecución.

El registro generado por el origen proporciona las siguientes ventajas de rendimiento sobre los métodos de extensión del registrador, como LogInformation y LogDebug:

  • Elimina el boxing: Los métodos de extensión del logger requieren el "boxing" (conversión) de tipos de valor, como int, en object. El registro generado por el origen evita el boxing mediante el uso de parámetros de tipos fuertes.
  • Analiza plantillas en tiempo de compilación: Los métodos de extensión del registrador deben analizar la plantilla de mensaje (cadena de formato con nombre) cada vez que se escribe un mensaje de registro. El registro generado por el origen del código analiza las plantillas una vez en tiempo de compilación.
  • Reduce las asignaciones: El generador de origen crea código optimizado que minimiza las asignaciones de objetos y el uso temporal de memoria.

La aplicación de ejemplo muestra características de registro de alto rendimiento con un servicio de trabajo de procesamiento de colas prioritario. La aplicación procesa los elementos de trabajo en orden de prioridad. A medida que se producen estas operaciones, los mensajes de registro se generan mediante el registro generado por el origen.

Sugerencia

Todo el código fuente del ejemplo de registro está disponible en el Explorador de ejemplos para su descarga. Para obtener más información, consulte Explorar ejemplos de código: registro en .NET.

Definición de mensajes del registrador de registros con generación de código fuente

Para crear mensajes de registro de alto rendimiento en .NET 6 y versiones posteriores, defina partial los métodos decorados con LoggerMessageAttribute. El generador de origen crea la implementación en tiempo de compilación.

Método de registro básico

Para un mensaje de registro simple, defina un método parcial con el atributo que especifica el identificador de evento, el nivel de registro y la plantilla de mensaje:

public static partial class Log
{
    [LoggerMessage(
        EventId = 13,
        Level = LogLevel.Critical,
        Message = "Epic failure processing item!")]
    public static partial void FailedToProcessWorkItem(
        ILogger logger, Exception ex);
}

La plantilla de mensaje utiliza marcadores de posición que se rellenan con parámetros del método. Los nombres de marcador de posición deben ser descriptivos y coherentes en todas las plantillas. Sirven como nombres de propiedad dentro de los datos de registro estructurados. Se recomienda Pascal casing para los nombres de marcador de posición. Por ejemplo, {Item}, {DateTime}.

Llame al método de registro desde su código. Por ejemplo, cuando se produce una excepción durante el procesamiento de elementos de trabajo:

try
{
    // Process work item.
}
catch (Exception ex)
{
    Log.FailedToProcessWorkItem(logger, ex);
}

Este código genera resultados de consola como:

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.

Registro con parámetros

Para pasar parámetros a un mensaje de registro, agréguelos como parámetros de método. Los nombres de parámetro coinciden con los marcadores de posición de la plantilla de mensaje:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Llame al método con los valores de registrador y parámetro:

var workItem = queue.Dequeue();
Log.PriorityItemProcessed(logger, workItem);

Este código genera resultados de consola como:

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

Los almacenes de registro estructurado pueden usar el nombre del evento cuando se suministra junto con el ID de evento para enriquecer el registro. Por ejemplo, Serilog usa el nombre del evento.

Definición del ámbito del mensaje del logger con la generación de código fuente

Puede definir ámbitos de registro para encapsular una serie de mensajes de registro con contexto adicional. Con el registro autogenerado, se combinan los métodos LoggerMessageAttribute con el método estándar ILogger.BeginScope.

Habilite IncludeScopes en la sección de registro de consola de appsettings.json:

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

Cree métodos de registro generados a partir del origen y envolverlos en un ámbito mediante BeginScope:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Utiliza el método de registro dentro de un contexto en tu código de aplicación.

using (_logger.BeginScope("Processing scope, started at: {DateTime}", DateTime.Now))
{
    Log.PriorityItemProcessed(_logger, workItem);
}

Inspeccione los mensajes de registro en la salida de la consola de la aplicación. El resultado siguiente muestra el orden de prioridad de los mensajes de registro con el mensaje de ámbito de registro incluido:

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'

Enfoque heredado: LoggerMessage.Define (para .NET Framework y .NET Core 3.1)

Antes de que se introdujera el registro generado por código fuente en .NET 6, el enfoque recomendado para el registro de alto rendimiento era usar el método LoggerMessage.Define para crear delegados que se pueden almacenar en caché. Aunque este enfoque sigue siendo compatible con versiones anteriores, el nuevo código debe usar el registro generado por el código fuente con LoggerMessageAttribute en su lugar.

La LoggerMessage clase expone la funcionalidad para crear delegados almacenables en caché que requieren menos asignaciones de objetos y una sobrecarga computacional reducida en comparación con los métodos de extensión de registrador, como LogInformation y LogDebug. LoggerMessage proporciona las siguientes ventajas de rendimiento sobre los métodos de extensión del registrador:

  • Los métodos de extensión del registrador requieren la conversión boxing de tipos de valor, como int, en object. El patrón LoggerMessage impide la conversión boxing mediante métodos de extensión y campos Action estáticos con parámetros fuertemente tipados.
  • Los métodos de extensión del registrador deben analizar la plantilla de mensaje (cadena de formato con nombre) cada vez que se escribe un mensaje de registro. LoggerMessage solo necesita analizar una vez una plantilla cuando se define el mensaje.

Nota:

Si mantiene código que usa LoggerMessage.Define, considere la posibilidad de migrar al registro generado por el origen. En el caso de las aplicaciones de .NET Framework o .NET Core 3.1, siga usando LoggerMessage.Define.

Definición de un mensaje de registrador

Use Define(LogLevel, EventId, String) para crear un Action delegado para registrar un mensaje. Define Las sobrecargas permiten pasar hasta seis parámetros de tipo a una cadena de formato nombrada (plantilla).

La cadena proporcionada al Define método es una plantilla y no una cadena interpolada. Los marcadores de posición se rellenan en el orden en que se especifican los tipos. Los nombres de marcador de posición en la plantilla deben ser descriptivos y coherentes en todas las plantillas. Sirven como nombres de propiedad dentro de los datos de registro estructurados. Se recomienda el uso de mayúsculas y minúsculas pascales para los nombres de marcador de posición. Por ejemplo, {Item}, {DateTime}.

Cada mensaje de registro es un Action que se encuentra en un campo estático creado por LoggerMessage.Define. Por ejemplo, la aplicación de ejemplo crea un campo para describir un mensaje de registro para el procesamiento de elementos de trabajo:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

Para el Action, especifique:

  • El nivel de registro.
  • Identificador de evento único (EventId) con el nombre del método de extensión estática.
  • Plantilla de mensaje (cadena de formato con nombre).

A medida que los elementos de trabajo se quitan de la cola para su procesamiento, la aplicación de servicio de trabajo establece lo siguiente:

  • Nivel de registro en LogLevel.Critical.
  • ID de evento es 13 con el nombre del método FailedToProcessWorkItem.
  • Plantilla de mensaje (cadena de formato con nombre) en una cadena.
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

El LoggerMessage.Define método se usa para configurar y definir un Action delegado, que representa un mensaje de registro.

El almacenamiento estructurado de registros puede usar el nombre del evento cuando se proporciona junto con el ID del evento para mejorar los registros. Por ejemplo, Serilog usa el nombre del evento.

Action se invoca a través de un método de extensión fuertemente tipado. El PriorityItemProcessed método registra un mensaje cada vez que se procesa un elemento de trabajo. FailedToProcessWorkItem se llama si y cuando se produzca una excepción.

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);
        }
    }
}

Inspeccione la salida de la consola de la aplicación:

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

Para pasar parámetros a un mensaje de registro, defina hasta seis tipos al crear el campo estático. La aplicación de ejemplo registra los detalles del elemento de trabajo al procesar elementos definiendo un WorkItem tipo para el Action campo:

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

La plantilla de mensaje de registro del delegado recibe sus valores de marcador de posición de los tipos proporcionados. La aplicación de ejemplo define un delegado para agregar un elemento de trabajo donde el parámetro item es un WorkItem:

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

El método de extensión estática para registrar que se está procesando un elemento de trabajo, PriorityItemProcessed, recibe el valor del argumento del elemento de trabajo y lo pasa al Action delegado:

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

En el método del servicio de trabajadores ExecuteAsync, se llama a PriorityItemProcessed para registrar el mensaje:

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);
        }
    }
}

Inspeccione la salida de la consola de la aplicación:

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

Optimizaciones protegidas en el nivel de los registros

Puede optimizar el rendimiento comprobando el LogLevel con ILogger.IsEnabled(LogLevel) antes de invocar el método correspondiente Log*. Cuando el registro de actividad no está configurado para el dado LogLevel, no se llama a ILogger.Log. Además, se evita el boxing de tipo de valor y una asignación de object[] (para representar los parámetros).

Para obtener más información, consulte:

Consulte también

  • Last updated on