Geração de origem de log em tempo de compilação

Artigo
06/21/2024

O .NET 6 apresenta o tipo LoggerMessageAttribute. Esse atributo faz parte do namespace Microsoft.Extensions.Logging e, quando usado, gera a origem de APIs de log de alto desempenho. O suporte ao log de geração de origem foi criado para fornecer uma solução de log altamente utilizável e de alto desempenho para aplicativos modernos do .NET. O código-fonte gerado automaticamente conta com a interface ILogger em conjunto com a funcionalidade LoggerMessage.Define.

O gerador de origem é disparado quando LoggerMessageAttribute é usado em métodos de log partial. Quando disparado, pode gerar automaticamente a implementação dos métodos partial que está decorando ou produzir diagnósticos em tempo de compilação com dicas sobre o uso adequado. Normalmente, a solução de log em tempo de compilação é consideravelmente mais rápida em tempo de execução do que as abordagens de log existentes. Ela faz isso eliminando a conversão boxing, alocações temporárias e cópias até o limite.

Uso básico

Para usar o LoggerMessageAttribute, a classe de consumo e o método precisam ser partial. O gerador de código é disparado em tempo de compilação e gera uma implementação do método partial.

public static partial class Log
{
    [LoggerMessage(
        EventId = 0,
        Level = LogLevel.Critical,
        Message = "Could not open socket to `{HostName}`")]
    public static partial void CouldNotOpenSocket(
        ILogger logger, string hostName);
}

No exemplo anterior, o método de log é static e o nível de log é especificado na definição de atributo. Ao usar o atributo em um contexto estático, a instância ILogger é necessária como um parâmetro ou modifica a definição para usar a palavra-chave this para definir o método como um método de extensão.

public static partial class Log
{
    [LoggerMessage(
        EventId = 0,
        Level = LogLevel.Critical,
        Message = "Could not open socket to `{HostName}`")]
    public static partial void CouldNotOpenSocket(
        this ILogger logger, string hostName);
}

Você também pode optar por usar o atributo em um contexto não estático. Considere o exemplo a seguir, em que o método de log é declarado como método de instância. Nesse contexto, o método de log obtém o agente acessando um campo ILogger na classe de contenção.

public partial class InstanceLoggingExample
{
    private readonly ILogger _logger;

    public InstanceLoggingExample(ILogger logger)
    {
        _logger = logger;
    }

    [LoggerMessage(
        EventId = 0,
        Level = LogLevel.Critical,
        Message = "Could not open socket to `{HostName}`")]
    public partial void CouldNotOpenSocket(string hostName);
}

A partir do .NET 9, o método de registro em log também pode obter o agente de um parâmetro de construtor primário ILogger na classe que o contém.

public partial class InstanceLoggingExample(ILogger logger)
{
    [LoggerMessage(
        EventId = 0,
        Level = LogLevel.Critical,
        Message = "Could not open socket to `{HostName}`")]
    public partial void CouldNotOpenSocket(string hostName);
}

Se houver um campo ILogger e um parâmetro de construtor primário, o método de registro em log obterá o agente do campo.

Às vezes, o nível de log precisa ser dinâmico, em vez de estaticamente integrado ao código. Você pode fazer isso omitindo o nível de log do atributo e, em vez disso, exigindo que ele seja um parâmetro para o método de log.

public static partial class Log
{
    [LoggerMessage(
        EventId = 0,
        Message = "Could not open socket to `{HostName}`")]
    public static partial void CouldNotOpenSocket(
        ILogger logger,
        LogLevel level, /* Dynamic log level as parameter, rather than defined in attribute. */
        string hostName);
}

Você pode omitir a mensagem de log e o String.Empty será fornecido para a mensagem. O estado conterá os argumentos, formatados como pares chave-valor.

using System.Text.Json;
using Microsoft.Extensions.Logging;

using ILoggerFactory loggerFactory = LoggerFactory.Create(
    builder =>
    builder.AddJsonConsole(
        options =>
        options.JsonWriterOptions = new JsonWriterOptions()
        {
            Indented = true
        }));

ILogger<SampleObject> logger = loggerFactory.CreateLogger<SampleObject>();
logger.PlaceOfResidence(logLevel: LogLevel.Information, name: "Liana", city: "Seattle");

readonly file record struct SampleObject { }

public static partial class Log
{
    [LoggerMessage(EventId = 23, Message = "{Name} lives in {City}.")]
    public static partial void PlaceOfResidence(
        this ILogger logger,
        LogLevel logLevel,
        string name,
        string city);
}

Considere o exemplo de saída de log ao usar o formatador JsonConsole.

{
  "EventId": 23,
  "LogLevel": "Information",
  "Category": "\u003CProgram\u003EF...9CB42__SampleObject",
  "Message": "Liana lives in Seattle.",
  "State": {
    "Message": "Liana lives in Seattle.",
    "name": "Liana",
    "city": "Seattle",
    "{OriginalFormat}": "{Name} lives in {City}."
  }
}

Restrições do método de log

Ao usar o LoggerMessageAttribute nos métodos de log, algumas restrições devem ser seguidas:

Os métodos de log devem ser partial e retornar void.
Os nomes do método de log não devem começar com um sublinhado.
Os nomes de parâmetro dos métodos de log não devem começar com um sublinhado.
Os métodos de log podem não ser definidos em um tipo aninhado.
Os métodos de log não podem ser genéricos
Se um método de log for static, a instância ILogger será exigida como parâmetro.

O modelo de geração de código depende de o código ser compilado com compilador moderno do C# versão 9 ou posterior. O compilador do C# 9.0 ficou disponível com o .NET 5. Para atualizar para um compilador moderno do C#, edite o arquivo de projeto para ser direcionado ao C# 9.0.

<PropertyGroup>
  <LangVersion>9.0</LangVersion>
</PropertyGroup>

Para obter mais informações, confira Controle de versão da linguagem C#.

Anatomia do método de log

A assinatura ILogger.Log aceita o LogLevel e, opcionalmente, um Exception, conforme mostrado abaixo.

public interface ILogger
{
    void Log<TState>(
        Microsoft.Extensions.Logging.LogLevel logLevel,
        Microsoft.Extensions.Logging.EventId eventId,
        TState state,
        System.Exception? exception,
        Func<TState, System.Exception?, string> formatter);
}

Como regra geral, a primeira instância de ILogger, LogLevel e Exception é tratada de maneira especial na assinatura do método de log do gerador de origem. As instâncias subsequentes são tratadas como parâmetros normais para o modelo de mensagem:

// This is a valid attribute usage
[LoggerMessage(
    EventId = 110, Level = LogLevel.Debug, Message = "M1 {Ex3} {Ex2}")]
public static partial void ValidLogMethod(
    ILogger logger,
    Exception ex,
    Exception ex2,
    Exception ex3);

// This causes a warning
[LoggerMessage(
    EventId = 0, Level = LogLevel.Debug, Message = "M1 {Ex} {Ex2}")]
public static partial void WarningLogMethod(
    ILogger logger,
    Exception ex,
    Exception ex2);

Importante

Os avisos emitidos fornecem detalhes sobre o uso correto do LoggerMessageAttribute. No exemplo anterior, o WarningLogMethod relatará um DiagnosticSeverity.Warning de SYSLIB0025.

Don't include a template for `ex` in the logging message since it is implicitly taken care of.

Suporte ao nome do modelo que não diferencia maiúsculas de minúsculas

O gerador faz uma comparação que não diferencia maiúsculas de minúsculas entre itens no modelo de mensagem e nomes de argumento na mensagem de log. Isso significa que quando ILogger enumera o estado, o argumento é selecionado pelo modelo de mensagem, o que pode tornar os logs mais agradáveis de consumir:

public partial class LoggingExample
{
    private readonly ILogger _logger;

    public LoggingExample(ILogger logger)
    {
        _logger = logger;
    }

    [LoggerMessage(
        EventId = 10,
        Level = LogLevel.Information,
        Message = "Welcome to {City} {Province}!")]
    public partial void LogMethodSupportsPascalCasingOfNames(
        string city, string province);

    public void TestLogging()
    {
        LogMethodSupportsPascalCasingOfNames("Vancouver", "BC");
    }
}

Considere o exemplo de saída de log ao usar o formatador JsonConsole:

{
  "EventId": 13,
  "LogLevel": "Information",
  "Category": "LoggingExample",
  "Message": "Welcome to Vancouver BC!",
  "State": {
    "Message": "Welcome to Vancouver BC!",
    "City": "Vancouver",
    "Province": "BC",
    "{OriginalFormat}": "Welcome to {City} {Province}!"
  }
}

Ordem de parâmetro indeterminada

Não há restrições sobre a ordenação de parâmetros do método de log. Um desenvolvedor pode definir o ILogger como o último parâmetro, embora possa parecer um pouco estranho.

[LoggerMessage(
    EventId = 110,
    Level = LogLevel.Debug,
    Message = "M1 {Ex3} {Ex2}")]
static partial void LogMethod(
    Exception ex,
    Exception ex2,
    Exception ex3,
    ILogger logger);

Dica

Não é necessário que a ordem dos parâmetros em um método de log corresponda à ordem dos espaços reservados do modelo. Em vez disso, espera-se que os nomes de espaço reservado no modelo correspondam aos parâmetros. Considere a saída de JsonConsole a seguir e a ordem dos erros.

{
  "EventId": 110,
  "LogLevel": "Debug",
  "Category": "ConsoleApp.Program",
  "Message": "M1 System.Exception: Third time's the charm. System.Exception: This is the second error.",
  "State": {
    "Message": "M1 System.Exception: Third time's the charm. System.Exception: This is the second error.",
    "ex2": "System.Exception: This is the second error.",
    "ex3": "System.Exception: Third time's the charm.",
    "{OriginalFormat}": "M1 {Ex3} {Ex2}"
  }
}

Outros exemplos de log

Os exemplos a seguir demonstram como recuperar o nome do evento, definir o nível de log dinamicamente e formatar os parâmetros de log. Os métodos de log são:

LogWithCustomEventName: recupere o nome do evento por meio do atributo LoggerMessage.
LogWithDynamicLogLevel: defina o nível de log dinamicamente para permitir que isso seja feito com base na entrada de configuração.
UsingFormatSpecifier: use especificadores de formato para formatar os parâmetros de log.

public partial class LoggingSample
{
    private readonly ILogger _logger;

    public LoggingSample(ILogger logger)
    {
        _logger = logger;
    }

    [LoggerMessage(
        EventId = 20,
        Level = LogLevel.Critical,
        Message = "Value is {Value:E}")]
    public static partial void UsingFormatSpecifier(
        ILogger logger, double value);

    [LoggerMessage(
        EventId = 9,
        Level = LogLevel.Trace,
        Message = "Fixed message",
        EventName = "CustomEventName")]
    public partial void LogWithCustomEventName();

    [LoggerMessage(
        EventId = 10,
        Message = "Welcome to {City} {Province}!")]
    public partial void LogWithDynamicLogLevel(
        string city, LogLevel level, string province);

    public void TestLogging()
    {
        LogWithCustomEventName();

        LogWithDynamicLogLevel("Vancouver", LogLevel.Warning, "BC");
        LogWithDynamicLogLevel("Vancouver", LogLevel.Information, "BC");

        UsingFormatSpecifier(logger, 12345.6789);
    }
}

Considere o exemplo de saída de log ao usar o formatador SimpleConsole:

trce: LoggingExample[9]
      Fixed message
warn: LoggingExample[10]
      Welcome to Vancouver BC!
info: LoggingExample[10]
      Welcome to Vancouver BC!
crit: LoggingExample[20]
      Value is 1.234568E+004

Considere o exemplo de saída de log ao usar o formatador JsonConsole:

{
  "EventId": 9,
  "LogLevel": "Trace",
  "Category": "LoggingExample",
  "Message": "Fixed message",
  "State": {
    "Message": "Fixed message",
    "{OriginalFormat}": "Fixed message"
  }
}
{
  "EventId": 10,
  "LogLevel": "Warning",
  "Category": "LoggingExample",
  "Message": "Welcome to Vancouver BC!",
  "State": {
    "Message": "Welcome to Vancouver BC!",
    "city": "Vancouver",
    "province": "BC",
    "{OriginalFormat}": "Welcome to {City} {Province}!"
  }
}
{
  "EventId": 10,
  "LogLevel": "Information",
  "Category": "LoggingExample",
  "Message": "Welcome to Vancouver BC!",
  "State": {
    "Message": "Welcome to Vancouver BC!",
    "city": "Vancouver",
    "province": "BC",
    "{OriginalFormat}": "Welcome to {City} {Province}!"
  }
}
{
  "EventId": 20,
  "LogLevel": "Critical",
  "Category": "LoggingExample",
  "Message": "Value is 1.234568E+004",
  "State": {
    "Message": "Value is 1.234568E+004",
    "value": 12345.6789,
    "{OriginalFormat}": "Value is {Value:E}"
  }
}

Resumo

Com o advento dos geradores de origem do C#, gravar APIs de log de alto desempenho ficou muito mais fácil. O uso da abordagem do gerador de origem tem vários benefícios importantes:

Permite que a estrutura de log seja preservada e habilita a sintaxe de formato exato exigida pelos Modelos de Mensagem.
Permite fornecer nomes alternativos para os espaços reservados do modelo e usar especificadores de formato.
Permite a passagem de todos os dados originais conforme apresentados, sem complicações em relação à maneira como são armazenados antes do processamento (além de criar um string).
Fornece diagnósticos específicos do log, emite avisos para IDs do evento duplicadas.

Além disso, existem benefícios no uso manual de LoggerMessage.Define:

Sintaxe mais curta e mais simples: uso de atributo declarativo, em vez da codificação padrão.
Experiência guiada do desenvolvedor: o gerador fornece avisos para ajudar os desenvolvedores a fazer a coisa certa.
Suporte para um número arbitrário de parâmetros de log. LoggerMessage.Define permite no máximo seis.
Suporte para nível de log dinâmico. Não é possível com o LoggerMessage.Define isolado.

Compartilhar via