Compartilhar via


Registro em log simples

Dica

É possível baixar o exemplo deste artigo no GitHub.

O registro em log simples do EF Core (Entity Framework Core) pode ser usado para obter facilmente logs durante o desenvolvimento e a depuração de aplicativos. Essa forma de registro em log requer configuração mínima e não utiliza pacotes NuGet adicionais.

Dica

O EF Core também se integra ao Microsoft.Extensions.Logging, que exige configuração adicional, mas é geralmente mais adequado para registros em log em aplicativos de produção.

Configuração

Os registros em log do EF Core podem ser acessados ​​de qualquer tipo de aplicativo por meio do uso de LogTo ao configurar uma instância de DbContext. Essa configuração geralmente é feita em uma substituição de DbContext.OnConfiguring. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(Console.WriteLine);

Como alternativa, LogTo pode ser chamado como parte de AddDbContext ou ao criar uma instância DbContextOptions para transmissão ao construtor DbContext.

Dica

OnConfiguring ainda é chamado quando AddDbContext é usado ou ao transmitir uma instância DbContextOptions para o construtor do DbContext. Isso o torna o local ideal para aplicar a configuração de contexto, independentemente de como o DbContext é construído.

Direcionar os logs

Registros em log no console

LogTo requer um delegado Action<T> que aceita uma cadeia de caracteres. O EF Core chamará esse delegado com uma cadeia de caracteres para cada mensagem de log gerada. Em seguida, cabe ao delegado fazer algo com a mensagem fornecida.

O método Console.WriteLine geralmente é usado para esse delegado, conforme mostrado acima. Isso resulta na gravação de cada mensagem de log no console.

Registros em log na janela de depuração

Debug.WriteLine pode ser usado a fim de enviar a saída para a janela “Depuração” no Visual Studio ou em outros IDEs. A sintaxe Lambda deve ser usada nesse caso porque a classe Debug é compilada com base em builds de versão. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(message => Debug.WriteLine(message));

Registrando em log em um arquivo

A gravação em um arquivo requer a criação de um StreamWriter ou algo semelhante para o arquivo. Em seguida, o método WriteLine pode ser usado como nos outros exemplos acima. Lembre-se de verificar se o arquivo é fechado de maneira limpa descartando o gravador quando o contexto for descartado. Por exemplo:

private readonly StreamWriter _logStream = new StreamWriter("mylog.txt", append: true);

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(_logStream.WriteLine);

public override void Dispose()
{
    base.Dispose();
    _logStream.Dispose();
}

public override async ValueTask DisposeAsync()
{
    await base.DisposeAsync();
    await _logStream.DisposeAsync();
}

Dica

Considere usar o Microsoft.Extensions.Logging com registros em log para arquivos em aplicativos de produção.

Obter mensagens detalhadas

Dados Confidenciais

Por padrão, o EF Core não inclui os valores de nenhum dado em mensagens de exceção. Isso ocorre porque esses dados podem ser confidenciais e podem ser revelados no uso de produção caso uma exceção não seja tratada.

No entanto, conhecer os valores de dados, especialmente para chaves, pode ser muito útil na depuração. Isso pode ser habilitado no EF Core chamando EnableSensitiveDataLogging(). Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine)
        .EnableSensitiveDataLogging();

Exceções de consulta detalhadas

Por motivos de desempenho, o EF Core não encapsula cada chamada para ler um valor do provedor de banco de dados em um bloco try-catch. No entanto, isso frequentemente resulta em exceções difíceis de diagnosticar, especialmente quando o banco de dados retorna um NULL quando não há permissão do modelo.

Ativar EnableDetailedErrors fará com que o EF introduza esses blocos try-catch e forneça erros mais detalhados. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine)
        .EnableDetailedErrors();

Filtragem

Níveis de log

Cada mensagem de log do EF Core é atribuída a um nível definido pela enumeração LogLevel. Por padrão, o registro em log simples do EF Core inclui todas as mensagens no nível Debug ou superior. É possível transmitir um nível mínimo mais alto ao LogTo para filtrar algumas mensagens. Por exemplo, transmitir Information resulta em um conjunto mínimo de logs limitados ao acesso ao banco de dados e a algumas mensagens de limpeza.

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(Console.WriteLine, LogLevel.Information);

Mensagens específicas

Cada mensagem de log recebe um EventId. Essas IDs podem ser acessadas na classe CoreEventId ou na classe RelationalEventId para mensagens específicas relacionais. Um provedor de banco de dados também pode ter IDs específicas de provedor em uma classe semelhante. Por exemplo, SqlServerEventId para o provedor SQL Server.

LogTo pode ser configurado para registrar apenas as mensagens associadas a uma ou mais IDs de evento. Por exemplo, para registrar somente mensagens relativas ao contexto que está sendo inicializado ou descartado:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine, new[] { CoreEventId.ContextDisposed, CoreEventId.ContextInitialized });

Categorias de mensagem

Cada mensagem de log é atribuída a uma categoria de agente hierárquica nomeada. As categorias são:

Categoria Mensagens
Microsoft.EntityFrameworkCore Todas as mensagens do EF Core
Microsoft.EntityFrameworkCore.Database Todas as interações de banco de dados
Microsoft.EntityFrameworkCore.Database.Connection Usos de uma conexão de banco de dados
Microsoft.EntityFrameworkCore.Database.Command Usos de um comando de banco de dados
Microsoft.EntityFrameworkCore.Database.Transaction Usos de uma transação de banco de dados
Microsoft.EntityFrameworkCore.Update Salvar entidades, exceto interações de banco de dados
Microsoft.EntityFrameworkCore.Model Todas as interações de modelo e metadados
Microsoft.EntityFrameworkCore.Model.Validation Validação de modelo
Microsoft.EntityFrameworkCore.Query Consultas, exceto interações de banco de dados
Microsoft.EntityFrameworkCore.Infrastructure Eventos gerais, como a criação de contexto
Microsoft.EntityFrameworkCore.Scaffolding Engenharia reversa de banco de dados
Microsoft.EntityFrameworkCore.Migrations Migrações
Microsoft.EntityFrameworkCore.ChangeTracking Interações de acompanhamento de alterações

LogTo pode ser configurado para registrar somente as mensagens associadas a uma ou mais categorias. Por exemplo, para registrar somente interações de banco de dados, faça o seguinte:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine, new[] { DbLoggerCategory.Database.Name });

Observe que a classe DbLoggerCategory fornece uma API hierárquica para localizar uma categoria e evita a necessidade de embutir cadeias de caracteres no código.

Como as categorias são hierárquicas, este exemplo usando a categoria Database incluirá todas as mensagens para as subcategorias Database.Connection, Database.Command e Database.Transaction.

Filtros personalizados

O LogTo permite que um filtro personalizado seja usado para casos em que nenhuma das opções de filtragem acima são suficientes. Por exemplo, para registrar qualquer mensagem no nível Information ou superior, bem como mensagens para estabelecer e encerrar uma conexão, faça o seguinte:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(
            Console.WriteLine,
            (eventId, logLevel) => logLevel >= LogLevel.Information
                                   || eventId == RelationalEventId.ConnectionOpened
                                   || eventId == RelationalEventId.ConnectionClosed);

Dica

A filtragem usando filtros personalizados ou qualquer uma das outras opções mostradas aqui é mais eficiente do que a filtragem no delegado LogTo. Isso ocorre porque, se o filtro determinar que a mensagem de log não deve ser registrada, ela nem sequer será criada.

Configuração para mensagens específicas

A API ConfigureWarnings do EF Core permite que os aplicativos alterem o que acontece quando um evento específico é encontrado. Isso pode ser usado para o seguinte:

  • Alterar o nível de log em que o evento é registrado
  • Ignorar completamente o registro do evento
  • Lançar uma exceção quando o evento ocorrer

Alterar o nível de log de um evento

O exemplo anterior usou um filtro personalizado para registrar todas as mensagens em LogLevel.Information, bem como dois eventos definidos para LogLevel.Debug. O mesmo pode ser feito alterando o nível de log dos dois eventos Debug para Information:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .ConfigureWarnings(
            b => b.Log(
                (RelationalEventId.ConnectionOpened, LogLevel.Information),
                (RelationalEventId.ConnectionClosed, LogLevel.Information)))
        .LogTo(Console.WriteLine, LogLevel.Information);

Suprimir o registro em log de um evento

De maneira semelhante, um evento individual pode ser suprimido do registro em log. Isso é particularmente útil para ignorar um aviso que foi revisado e compreendido. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .ConfigureWarnings(b => b.Ignore(CoreEventId.DetachedLazyLoadingWarning))
        .LogTo(Console.WriteLine);

Lançamento para um evento

Finalmente, o EF Core pode ser configurado para ser lançado para um determinado evento. Isso é particularmente útil para transformar um aviso em um erro. (Na verdade, esse era o propósito original do método ConfigureWarnings, por isso o nome.) Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .ConfigureWarnings(b => b.Throw(RelationalEventId.MultipleCollectionIncludeWarning))
        .LogTo(Console.WriteLine);

Conteúdo e formatação da mensagem

O conteúdo padrão de LogTo é formatado em diversas linhas. A primeira contém os metadados da mensagem:

  • O LogLevel como um prefixo de quatro caracteres
  • Um carimbo de data/hora local, formatado para a cultura atual
  • O EventId no formulário que pode ser copiado/colado para obter o membro de CoreEventId ou de uma das outras classes EventId, além do valor bruto da ID
  • A categoria de evento, conforme descrito acima.

Por exemplo:

info: 10/6/2020 10:52:45.581 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      CREATE TABLE "Blogs" (
          "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,
          "Name" INTEGER NOT NULL
      );
dbug: 10/6/2020 10:52:45.582 RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committing transaction.
dbug: 10/6/2020 10:52:45.585 RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committed transaction.

Esse conteúdo pode ser personalizado transmitindo os valores de DbContextLoggerOptions, conforme mostrado nas seções a seguir.

Dica

Considere usar o Microsoft.Extensions.Logging para obter mais controle sobre a formatação de log.

Mostrar o horário UTC

Por padrão, os carimbos de data/hora são projetados para consumo local durante a depuração. Use DbContextLoggerOptions.DefaultWithUtcTime para adotar carimbos de data/hora UTC independentes da cultura, mas mantenha todo o restante igual. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(
        Console.WriteLine,
        LogLevel.Debug,
        DbContextLoggerOptions.DefaultWithUtcTime);

Este exemplo resulta na seguinte formatação de log:

info: 2020-10-06T17:55:39.0333701Z RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      CREATE TABLE "Blogs" (
          "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,
          "Name" INTEGER NOT NULL
      );
dbug: 2020-10-06T17:55:39.0333892Z RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committing transaction.
dbug: 2020-10-06T17:55:39.0351684Z RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction)
      Committed transaction.

Registro em log de linha única

Às vezes, é útil obter exatamente uma linha por mensagem de log. Isso pode ser habilitado usando DbContextLoggerOptions.SingleLine. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(
        Console.WriteLine,
        LogLevel.Debug,
        DbContextLoggerOptions.DefaultWithLocalTime | DbContextLoggerOptions.SingleLine);

Este exemplo resulta na seguinte formatação de log:

info: 10/6/2020 10:52:45.723 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) -> Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']CREATE TABLE "Blogs" (    "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,    "Name" INTEGER NOT NULL);
dbug: 10/6/2020 10:52:45.723 RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction) -> Committing transaction.
dbug: 10/6/2020 10:52:45.725 RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction) -> Committed transaction.

Outras opções de conteúdo

Outros sinalizadores em DbContextLoggerOptions podem ser usados para reduzir a quantidade de metadados incluídos no log. Isso pode ser útil quando usado com o registro em log de linha única. Por exemplo:

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(
        Console.WriteLine,
        LogLevel.Debug,
        DbContextLoggerOptions.UtcTime | DbContextLoggerOptions.SingleLine);

Este exemplo resulta na seguinte formatação de log:

2020-10-06T17:52:45.7320362Z -> Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']CREATE TABLE "Blogs" (    "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,    "Name" INTEGER NOT NULL);
2020-10-06T17:52:45.7320531Z -> Committing transaction.
2020-10-06T17:52:45.7339441Z -> Committed transaction.

Migração do EF6

O registro em log simples do EF Core difere do Database.Log no EF6 de duas maneiras importantes:

  • As mensagens de log não estão limitadas apenas a interações de banco de dados
  • O registro em log deve ser configurado no momento da inicialização do contexto

A primeira diferença é que a filtragem descrita acima pode ser usada a fim de limitar quais mensagens são registradas.

A segunda diferença é uma alteração intencional que melhora o desempenho, não gerando mensagens de log quando elas não são necessárias. No entanto, ainda é possível obter um comportamento semelhante ao do EF6 criando uma propriedade Log no DbContext e, em seguida, usando-a somente quando ela estiver definida. Por exemplo:

public Action<string> Log { get; set; }

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(s => Log?.Invoke(s));