Compartilhar via

Registro em log simples

Dica

Você pode baixar o exemplo deste artigo no GitHub.

O registro simplificado do EF Core (Entity Framework Core) pode ser utilizado para obter facilmente logs durante o desenvolvimento e depuração de aplicativos. Essa forma de registro em log requer configuração mínima e nenhum pacote NuGet adicional.

Dica

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

Configuração

Os logs do EF Core podem ser acessados de qualquer tipo de aplicativo por meio do uso de LogToao configurar uma instância 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 DbContextOptions instância para passar para o DbContext construtor.

Dica

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

Direcionando os logs

Fazer logon no console

LogTo requer um Action<T> delegado 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 Console.WriteLine método geralmente é usado para esse delegado, conforme mostrado acima. Isso resulta em cada mensagem de log sendo gravada no console.

Gravar no log da janela de depuração

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

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

Fazer logon em um arquivo

Gravar em um arquivo requer a criação de um StreamWriter ou semelhante para o arquivo. O método WriteLine pode então ser usado como nos outros exemplos acima. Lembre-se de garantir que o arquivo seja fechado de forma 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 Microsoft.Extensions.Logging para fazer logon em arquivos em aplicativos de produção.

Obtendo mensagens detalhadas

Dados sensíveis

Por padrão, o EF Core não incluirá os valores de nenhum dado em mensagens de exceção. Isso ocorre porque esses dados podem ser confidenciais e podem ser revelados no ambiente de produção se uma exceção não for tratada.

No entanto, conhecer valores de dados, especialmente para chaves, pode ser muito útil durante a 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 às vezes resulta em exceções difíceis de diagnosticar, especialmente quando o banco de dados retorna um NULL quando não é permitido pelo modelo.

Ativar EnableDetailedErrors fará com que o EF introduza esses blocos try-catch e assim, forneça mensagens de erro mais detalhadas. 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 LogLevel enumeração. Por padrão, o log simples do EF Core inclui todas as mensagens no Debug nível ou acima. LogTo pode ser passado um nível mínimo mais alto para filtrar algumas mensagens. Por exemplo, passar Information resulta em um conjunto mínimo de logs limitados ao acesso ao banco de dados e algumas mensagens de manutenção.

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

Mensagens específicas

Cada mensagem de log é atribuída a um EventId. Essas IDs podem ser acessadas da CoreEventId classe ou da RelationalEventId classe para mensagens específicas relacionais. Um provedor de banco de dados também pode ter IDs específicas do provedor em uma classe semelhante. Por exemplo, SqlServerEventId para o provedor do 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 para o 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árquico 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 Salvamento de entidades, exceto interações com 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, excluindo 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 Alterar interações de controle

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

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

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

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

Filtros personalizados

LogTo permite que um filtro personalizado seja usado para casos em que nenhuma das opções de filtragem acima é suficiente. Por exemplo, para registrar qualquer mensagem no nível Information ou acima, bem como mensagens para abrir e fechar uma conexão:

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

Dica

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

Configuração para mensagens específicas

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

  • Alterar o nível de log no qual o evento é registrado
  • Ignorar o registro em log do evento inteiramente
  • Gerar uma exceção quando o evento ocorrer

Alterando o nível de log para um evento

O exemplo anterior usou um filtro personalizado para registrar todas as mensagens em log, LogLevel.Information bem como dois eventos definidos para LogLevel.Debug. O mesmo pode ser alcançado alterando o nível de log dos dois Debug eventos 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

Da mesma forma, 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);

Organizar um evento

Por fim, o EF Core pode ser configurado para lançar um determinado evento. Isso é particularmente útil para alterar um aviso em um erro. (Na verdade, essa era a finalidade original do ConfigureWarnings método, daí o nome.) Por exemplo:

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

Conteúdo da mensagem e formatação

O conteúdo padrão do LogTo é formatado em várias linhas. A primeira linha contém metadados de mensagem:

  • O LogLevel como um prefixo de quatro caracteres
  • Um carimbo de data e hora local, formatado para a cultura atual
  • Na forma EventId que pode ser copiada/colada para obter o membro de CoreEventId ou de uma das outras classes EventId, além do valor bruto do 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 passando valores de DbContextLoggerOptions, conforme mostrado nas seções a seguir.

Dica

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

Usando a hora UTC

Por padrão, os marcadores de tempo são projetados para consumo local durante a depuração. Use DbContextLoggerOptions.DefaultWithUtcTime para usar carimbos de data/hora UTC independentes da cultura, mas mantenha tudo 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 por 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 DbContextLoggerOptions podem ser usados para reduzir a quantidade de metadados incluídos no log. Isso pode ser útil em conjunto 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.

Mudança do EF6

O log simples do EF Core se diferencia 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

Para a primeira diferença, a filtragem descrita acima pode ser usada para limitar quais mensagens são registradas.

A segunda diferença é uma alteração intencional para melhorar 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 EF6 criando uma Log propriedade em seu DbContext e, em seguida, usando-a somente quando ela tiver sido definida. Por exemplo:

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

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