Partager via


Journalisation simple

Conseil

Vous pouvez télécharger l’exemple de cet article à partir de GitHub.

La journalisation simple d’Entity Framework Core (EF Core) peut être utilisée pour obtenir facilement des journaux lors du développement et du débogage d’applications. Cette forme de journalisation nécessite une configuration minimale et aucun package NuGet supplémentaire.

Conseil

EF Core s’intègre également à Microsoft.Extensions.Logging, qui nécessite davantage de configuration, mais qui est souvent plus adapté à la journalisation dans les applications de production.

Configuration

Les journaux EF Core sont accessibles à partir de n’importe quel type d’application à l’aide de LogTo lors de la configuration d’une instance DbContext. Cette configuration est généralement effectuée en remplaçant DbContext.OnConfiguring. Par exemple :

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

Il est également possible d’appeler LogTo dans le cadre de AddDbContext ou lors de la création d’une instance DbContextOptions à transmettre au constructeur DbContext.

Conseil

OnConfiguring est toujours appelé lorsque AddDbContext est utilisé ou qu’une instance DbContextOptions est transmise au constructeur DbContext. C’est donc l’emplacement idéal pour appliquer la configuration du contexte, quel que soit le mode de construction du DbContext.

Direction des journaux

Journalisation vers la console

LogTo nécessite un délégué Action<T> qui accepte une chaîne. EF Core appellera ce délégué avec une chaîne pour chaque message de journal généré. Il incombe ensuite au délégué de faire quelque chose avec le message donné.

La méthode Console.WriteLine est souvent utilisée pour ce délégué, comme indiqué ci-dessus. Ainsi, chaque message de journal est écrit dans la console.

Journalisation dans la fenêtre de débogage

Debug.WriteLine peut être utilisé pour envoyer la sortie vers la fenêtre Débogage dans Visual Studio ou d’autres IDE. La syntaxe lambda doit être utilisée dans ce cas, car la classe Debug est compilée hors des builds de mise en production. Par exemple :

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

Journalisation dans un fichier

L’écriture dans un fichier nécessite la création d’un fichier StreamWriter ou similaire. La méthode WriteLine peut ensuite être utilisée comme dans les autres exemples ci-dessus. N’oubliez pas de vous assurer que le fichier est correctement fermé en supprimant l’enregistreur lorsque le contexte est supprimé. Par exemple :

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

Conseil

Envisagez d’utiliser Microsoft.Extensions.Logging pour la journalisation des fichiers dans les applications de production.

Obtention de messages détaillés

Données sensibles

Par défaut, EF Core n’inclura pas les valeurs des données dans les messages d’exception. Cela est dû au fait que ces données peuvent être confidentielles et qu’elles pourraient être révélées en production si une exception n’était pas gérée.

Toutefois, connaître les valeurs de données, en particulier celles des clés, peut s’avérer très utile lors du débogage. Cela peut être activé dans EF Core en appelant EnableSensitiveDataLogging(). Par exemple :

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

Exceptions de requête détaillées

Pour des raisons de performances, EF Core n’enveloppe pas chaque appel pour lire une valeur du fournisseur de la base de données dans un bloc try-catch. Toutefois, cela entraîne parfois des exceptions difficiles à diagnostiquer, notamment lorsque la base de données renvoie une valeur NULL alors que le modèle ne l’autorise pas.

En activant EnableDetailedErrors, EF introduira ces blocs try-catch et fournira ainsi des erreurs plus détaillées. Par exemple :

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

Filtrage

Niveaux de journal

Chaque message de journal EF Core est attribué à un niveau défini par l’énumération LogLevel. Par défaut, la journalisation simple EF Core inclut chaque message au niveau Debug ou supérieur. LogTo peut passer à un niveau minimum supérieur afin de filtrer certains messages. Par exemple, en passant Information au niveau minimum supérieur, on obtient un ensemble de journaux limités à l’accès à la base de données et à certains messages de gestion.

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

Messages spécifiques

Chaque message de journal est attribué à un EventId. Ces ID sont accessibles à partir de la classe CoreEventId ou de la classe RelationalEventId pour les messages relationnels spécifiques. Un fournisseur de base de données peut également avoir des ID spécifiques au fournisseur dans une classe similaire. Par exemple, SqlServerEventId pour le fournisseur SQL Server.

LogTo peut être configuré pour journaliser uniquement les messages associés à un ou plusieurs ID d’événement. Par exemple, pour journaliser uniquement les messages du contexte initialisé ou supprimé :

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

Catégories des messages

Chaque message de journal est attribué à une catégorie d’enregistreur d’événements hiérarchiquement nommée. Les catégories sont les suivantes :

Catégorie Messages
Microsoft.EntityFrameworkCore Tous les messages EF Core
Microsoft.EntityFrameworkCore.Database Toutes les interactions de la base de données
Microsoft.EntityFrameworkCore.Database.Connection Utilisations d’une connexion de base de données
Microsoft.EntityFrameworkCore.Database.Command Utilisations d’une commande de base de données
Microsoft.EntityFrameworkCore.Database.Transaction Utilisations d’une transaction de base de données
Microsoft.EntityFrameworkCore.Update Sauvegarde des entités, à l’exclusion des interactions de la base de données
Microsoft.EntityFrameworkCore.Model Toutes les interactions de modèle et de métadonnées
Microsoft.EntityFrameworkCore.Model.Validation Validation du modèle
Microsoft.EntityFrameworkCore.Query Requêtes, à l’exclusion des interactions de la base de données
Microsoft.EntityFrameworkCore.Infrastructure Événements généraux, tels que la création de contexte
Microsoft.EntityFrameworkCore.Scaffolding Ingénierie à rebours de la base de données
Microsoft.EntityFrameworkCore.Migrations Migrations
Microsoft.EntityFrameworkCore.ChangeTracking Interactions de suivi des modifications

LogTo peut être configuré pour journaliser uniquement les messages d’une ou plusieurs catégories. Par exemple, pour journaliser uniquement les interactions de la base de données :

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

Notez que la classe DbLoggerCategory fournit une API hiérarchique pour rechercher une catégorie et évite de devoir coder en dur des chaînes de caractères.

Étant donné que les catégories sont hiérarchiques, cet exemple utilisant la catégorie Database inclura tous les messages des sous-catégories Database.Connection, Database.Commandet Database.Transaction.

Filtres personnalisés

LogTo permet à un filtre personnalisé d’être utilisé dans les cas où aucune des options de filtrage ci-dessus n’est suffisante. Par exemple, pour journaliser un message au niveau Information ou supérieur, ainsi que des messages d’ouverture et de fermeture d’une connexion :

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

Conseil

Le filtrage à l’aide de filtres personnalisés ou de l’une des autres options présentées ici est plus efficace que le filtrage dans le délégué LogTo. Cela est dû au fait que si le filtre détermine que le message ne doit pas être journalisé, le message de journal n’est même pas créé.

Configuration pour des messages spécifiques

L’API EF Core ConfigureWarnings permet aux applications de modifier ce qui se passe lorsqu’un événement spécifique est rencontré. Cela peut être utilisé pour :

  • Modifier le niveau du journal auquel l’événement est journalisé
  • Ignorer complètement la journalisation de l’événement
  • Lever une exception lorsque l’événement se produit

Modification du niveau de journal d’un événement

L’exemple précédent a utilisé un filtre personnalisé pour journaliser tous les messages à LogLevel.Information ainsi que deux événements définis pour LogLevel.Debug. Le même résultat peut être obtenu en modifiant le niveau de journal des deux événements Debug en 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);

Supprimant la journalisation d’un événement

De la même façon, un événement individuel peut être supprimé de la journalisation. Cela est particulièrement utile pour ignorer un avertissement qui a été examiné et compris. Par exemple :

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

Lancer un événement

Enfin, EF Core peut être configuré pour lancer un événement donné. Cela est particulièrement utile pour changer un avertissement en erreur. (En effet, c’était l’objectif initial de la méthode ConfigureWarnings, d’où son nom.) Exemple :

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

Contenu et mise en forme des messages

Le contenu par défaut de LogTo est mis en forme sur plusieurs lignes. La première ligne contient des métadonnées de message :

  • Le LogLevel comme préfixe à quatre caractères
  • Un timestamp local, mis en forme pour la culture actuelle
  • Le EventId du formulaire qui peut être copié/collé pour obtenir le membre de CoreEventId ou de l’une des EventId autres classes, ainsi que la valeur brute de l’ID
  • La catégorie d’événement, comme décrit ci-dessus.

Par exemple :

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.

Ce contenu peut être personnalisé en transmettant des valeurs de DbContextLoggerOptions, comme indiqué dans les sections suivantes.

Conseil

Envisagez d’utiliser Microsoft.Extensions.Logging pour plus de contrôle sur la mise en forme du journal.

Utilisation de l’heure UTC

Par défaut, les timestamps sont conçus pour une utilisation locale lors du débogage. Utilisez DbContextLoggerOptions.DefaultWithUtcTime afin d’utiliser les timestamps UTC indépendants de la culture à la place, mais le reste doit rester inchangé. Par exemple :

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

Cet exemple se traduit par la mise en forme suivante du journal :

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.

Journalisation à ligne unique

Parfois, il est utile d’obtenir exactement une ligne par message de journal. Cela peut être activé par DbContextLoggerOptions.SingleLine. Par exemple :

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

Cet exemple se traduit par la mise en forme suivante du journal :

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.

Autres options de contenu

D’autres indicateurs dans DbContextLoggerOptions peuvent être utilisés pour réduire la quantité de métadonnées incluses dans le journal. Cela peut être utile en conjonction avec la journalisation à ligne unique. Par exemple :

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

Cet exemple se traduit par la mise en forme suivante du journal :

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.

Déplacement depuis EF6

La journalisation simple EF Core diffère de Database.Log dans EF6 de deux façons importantes :

  • Les messages de journal ne sont pas limités aux seules interactions de la base de données
  • La journalisation doit être configurée au moment de l’initialisation du contexte

Pour la première différence, le filtrage décrit ci-dessus peut être utilisé pour limiter les messages qui sont journalisés.

La deuxième différence est une modification intentionnelle visant à améliorer les performances en ne générant pas de messages de journal lorsqu’ils ne sont pas nécessaires. Toutefois, il est toujours possible d’obtenir un comportement similaire à celui d’EF6 en créant une propriété Log sur votre DbContext, puis en l’utilisant uniquement lorsqu’elle a été définie. Par exemple :

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

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