Einfache Protokollierung

Artikel
10/05/2023

Tipp

Sie können das Beispiel in diesem Artikel von GitHub herunterladen.

Die einfache Protokollierung von Entity Framework Core (EF Core) kann zum einfachen Abrufen von Protokollen während dem Entwickeln und Debuggen von Anwendungen verwendet werden. Diese Form der Protokollierung erfordert minimale Konfiguration und keine zusätzlichen NuGet-Pakete.

Tipp

EF Core ist auch in Microsoft.Extensions.Logging integriert, was mehr Konfiguration erfordert, aber oft besser für die Protokollierung in Produktionsanwendungen geeignet ist.

Konfiguration

Beim Konfigurieren einer DbContext-Instanz kann von jedem Anwendungstyp aus mithilfe von LogTo auf EF Core-Protokolle zugegriffen werden. Diese Konfiguration erfolgt in der Regel durch ein Überschreiben von DbContext.OnConfiguring. Beispiel:

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

Alternativ kann LogTo als Teil von AddDbContext aufgerufen werden, oder beim Erstellen einer DbContextOptions-Instanz, die an den DbContext-Konstruktor übergeben werden soll.

Tipp

OnConfiguring wird weiterhin aufgerufen, wenn AddDbContext verwendet wird oder eine DbContextOptions-Instanz an den DbContext-Konstruktor übergeben wird. Dadurch ist es der ideale Ort, um die Kontextkonfiguration anzuwenden, unabhängig davon, wie der DbContext konstruiert wird.

Lenkung der Protokolle

Protokollierung zur Konsole

LogTo erfordert einen Action<T>-Delegat, der eine Zeichenfolge akzeptiert. EF Core ruft diesen Delegat mit einer Zeichenfolge für jede generierte Protokollnachricht auf. Es liegt dann am Delegat, etwas mit der gegebenen Nachricht zu tun.

Die Console.WriteLine-Methode wird häufig für diesen Delegat verwendet, wie oben gezeigt. Dies führt dazu, dass jede Protokollnachricht zur Konsole geschrieben wird.

Protokollierung zum Debuggenfenster

Debug.WriteLine kann verwendet werden, um die Ausgabe an das Debuggenfenster in Visual Studio oder andere IDEs zu senden. Die Lambda-Syntax muss in diesem Fall verwendet werden, da die Debug-Klasse aus Releasebuilds kompiliert wird. Beispiel:

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

Protokollierung in einer Datei

Das Schreiben in eine Datei erfordert die Erstellung einer StreamWriter oder ähnlich für die Datei. Die WriteLine-Methode kann dann wie in den anderen Beispielen oben verwendet werden. Denken Sie daran, sicherzustellen, dass die Datei sauber geschlossen ist, indem Sie den Schreibvorgang löschen, wenn der Kontext verworfen wird. Beispiel:

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

Tipp

Erwägen Sie die Verwendung von Microsoft.Extensions.Logging für die Protokollierung zu Dateien in Produktionsanwendungen.

Abrufen detaillierter Nachrichten

Sensible Daten

Standardmäßig schließt EF Core die Werte von Daten in Ausnahmenachrichten nicht ein. Dies liegt daran, dass solche Daten vertraulich sein können und im Produktionsbetrieb offenbart werden können, wenn eine Ausnahme nicht behandelt wird.

Die Kenntnis von Datenwerten, insbesondere für Schlüssel, kann jedoch bei dem Debuggen sehr hilfreich sein. Dies kann in EF Core durch Aufrufen von EnableSensitiveDataLogging() aktiviert werden. Beispiel:

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

Detaillierte Abfrageausnahmen

Aus Leistungsgründen umschließt EF Core nicht jeden Aufruf, um einen Wert vom Datenbankanbieter in einem Try-Catch-Block zu lesen. Dies führt jedoch manchmal zu Ausnahmen, die schwer zu diagnostizieren sind, insbesondere dann, wenn die Datenbank einen NULL-Wert zurückgibt, obwohl das Modell dies nicht zulässt.

Das Aktivieren von EnableDetailedErrors führt dazu, dass EF diese Try-Catch-Blöcke einführt und dadurch detailliertere Fehler bereitstellt. Beispiel:

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

Filtern

Protokolliergrade

Jede EF Core-Protokollnachricht wird einer durch die LogLevel-Enumeration definierten Ebene zugewiesen. Standardmäßig enthält die einfache EF Core-Protokollierung jede Nachricht auf der Ebene Debug oder höher. LogTo kann eine höhere Mindestebene übergeben werden, um einige Nachrichten herauszufiltern. Beispiel: Das Übergeben von Information führt zu einem minimalen Satz von Protokollen, die auf den Datenbankzugriff und einige Verwaltungsmeldungen beschränkt sind.

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

Bestimmte Nachrichten

Jeder Protokollnachricht wird eine EventId zugewiesen. Auf diese IDs kann über die CoreEventId-Klasse oder die RelationalEventId-Klasse für spezifische relationale Nachrichten zugegriffen werden. Ein Datenbankanbieter verfügt möglicherweise auch über anbieterspezifische IDs in einer ähnlichen Klasse. Beispiel: SqlServerEventId für den SQL Server-Anbieter.

LogTo kann so konfiguriert werden, dass nur die Nachrichten protokolliert werden, die einer oder mehreren Ereignis-IDs zugeordnet sind. So protokollieren Sie beispielsweise nur Nachrichten für den Kontext, der initialisiert oder verworfen wird:

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

Meldungskategorien

Jede Protokollnachricht wird einer benannten hierarchischen Protokollierungskategorie zugewiesen. Die Kategorien lauten wie folgt:

Kategorie	Nachrichten
Microsoft.EntityFrameworkCore	Alle EF Core-Nachrichten
Microsoft.EntityFrameworkCore.Database	Alle Datenbankinteraktionen
Microsoft.EntityFrameworkCore.Database.Connection	Verwendungsmöglichkeiten einer Datenbankverbindung
Microsoft.EntityFrameworkCore.Database.Command	Verwendungsmöglichkeiten eines Datenbankbefehls
Microsoft.EntityFrameworkCore.Database.Transaction	Verwendungsmöglichkeiten einer Datenbanktransaktion
Microsoft.EntityFrameworkCore.Update	Speichern von Entitäten mit Ausnahme von Datenbankinteraktionen
Microsoft.EntityFrameworkCore.Model	Alle Modell- und Metadateninteraktionen
Microsoft.EntityFrameworkCore.Model.Validation	Modellvalidierung
Microsoft.EntityFrameworkCore.Query	Abfragen mit Ausnahme von Datenbankinteraktionen
Microsoft.EntityFrameworkCore.Infrastructure	Allgemeine Ereignisse, z. B. Kontexterstellung
Microsoft.EntityFrameworkCore.Scaffolding	Reverse-Engineering einer Datenbank
Microsoft.EntityFrameworkCore.Migrations	Migrationen
Microsoft.EntityFrameworkCore.ChangeTracking	Interaktionen zur Änderungsnachverfolgung

LogTo kann so konfiguriert werden, dass nur die Nachrichten aus einer oder mehreren Kategorien protokolliert werden. Um beispielsweise nur Datenbankinteraktionen zu protokollieren:

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

Beachten Sie, dass die DbLoggerCategory-Klasse eine hierarchische API zum Suchen einer Kategorie bereitstellt und die Notwendigkeit von hartcodierten Zeichenfolgen vermeidet.

Da Kategorien hierarchisch sind, enthält dieses Beispiel, in dem die Database-Kategorie verwendet wird, alle Nachrichten für die Unterkategorien Database.Connection, Database.Command und Database.Transaction.

Benutzerdefinierte Filter

LogTo ermöglicht die Verwendung eines benutzerdefinierten Filters für Fälle, in denen keine der oben genannten Filteroptionen ausreichend ist. Um beispielsweise Nachrichten auf Ebene Information oder höher sowie Nachrichten zum Öffnen und Schließen einer Verbindung zu protokollieren:

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

Tipp

Das Filtern mit benutzerdefinierten Filtern oder die Verwendung einer der hier gezeigten anderen Optionen ist effizienter als das Filtern im LogTo-Delegat. Denn wenn der Filter feststellt, dass die Nachricht nicht protokolliert werden soll, wird die Protokollnachricht gar nicht erst erstellt.

Konfiguration für bestimmte Nachrichten

Mit der EF Core-API ConfigureWarnings können Anwendungen ändern, was passiert, wenn ein bestimmtes Ereignis auftritt. Dies kann verwendet werden, um Folgendes zu tun:

Ändern der Protokollebene, auf der das Ereignis protokolliert wird
Vollständiges Überspringen der Protokollierung des Ereignisses
Auslösen einer Ausnahme, wenn das Ereignis auftritt

Ändern der Protokollebene für ein Ereignis

Im vorherigen Beispiel wurde ein benutzerdefinierter Filter verwendet, um jede Nachricht auf LogLevel.Information zu protokollieren sowie für zwei für LogLevel.Debug definierte Ereignisse. Das gleiche kann erreicht werden, indem die Protokollebene der beiden Debug-Ereignisse in Information geändert wird:

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

Unterdrücken der Protokollierung eines Ereignisses

Auf ähnliche Weise kann ein einzelnes Ereignis aus der Protokollierung ausgeschlossen werden. Dies ist besonders nützlich, um eine Warnung zu ignorieren, die überprüft und verstanden wurde. Beispiel:

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

Auslösen für ein Ereignis

Schließlich kann EF Core so konfiguriert werden, dass es für ein bestimmtes Ereignis auslöst. Dies ist besonders nützlich, um eine Warnung in einen Fehler zu ändern. (Tatsächlich war dies der ursprüngliche Zweck der ConfigureWarnings-Methode, daher der Name.) Zum Beispiel:

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

Nachrichteninhalte und Formatierung

Der Standardinhalt von LogTo wird über mehrere Zeilen formatiert. Die erste Zeile enthält Nachrichtenmetadaten:

Das LogLevel als ein Präfix mit vier Zeichen
Ein lokaler Zeitstempel, formatiert für die aktuelle Kultur
Das EventId im Format, das kopiert/eingefügt werden kann, um das Element von CoreEventId oder einer der anderen EventId-Klassen abzurufen, sowie den unformatierten ID-Wert
Die Ereigniskategorie, wie oben beschrieben.

Beispiel:

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.

Dieser Inhalt kann angepasst werden, indem Werte von DbContextLoggerOptions übergeben werden, wie in den folgenden Abschnitten gezeigt.

Tipp

Erwägen Sie die Verwendung von Microsoft.Extensions.Logging, um mehr Kontrolle über die Protokollformatierung zu haben.

Verwenden der UTC-Zeit

Standardmäßig sind Zeitstempel für den lokalen Verbrauch beim Debuggen vorgesehen. Verwenden Sie DbContextLoggerOptions.DefaultWithUtcTime, um stattdessen kulturunabhängige UTC-Zeitstempel zu verwenden, aber lassen Sie alles andere gleich. Beispiel:

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

Dieses Beispiel ergibt die folgende Protokollformatierung:

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.

Einzelzeilenprotokollierung

Manchmal ist es nützlich, nur genau eine Zeile pro Protokollnachricht abzurufen. Dies kann durch DbContextLoggerOptions.SingleLine ermöglicht werden. Beispiel:

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

Dieses Beispiel ergibt die folgende Protokollformatierung:

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.

Weitere Inhaltsoptionen

Andere Flags in DbContextLoggerOptions können verwendet werden, um die Menge der im Protokoll enthaltenen Metadaten zu kürzen. Dies kann in Verbindung mit der Einzelzeilenprotokollierung hilfreich sein. Beispiel:

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

Dieses Beispiel ergibt die folgende Protokollformatierung:

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.

Migrieren von EF6

Die einfache EF Core-Protokollierung unterscheidet sich von Database.Log in EF6 in zwei wichtigen Punkten:

Protokollmeldungen sind nicht nur auf Datenbankinteraktionen beschränkt
Die Protokollierung muss zur Kontextinitialisierungszeit konfiguriert werden

Der erste Unterschied besteht darin, dass die oben beschriebene Filterung verwendet werden kann, um einzuschränken, welche Nachrichten protokolliert werden.

Der zweite Unterschied ist eine absichtliche Änderung, um die Leistung zu verbessern, indem keine Protokollmeldungen generiert werden, wenn sie nicht benötigt werden. Es ist jedoch weiterhin möglich, ein ähnliches Verhalten wie in EF6 zu erreichen, indem eine Log-Eigenschaft für Ihre DbContext erstellt wird und dann nur verwendet wird, wenn sie festgelegt wurde. Beispiel:

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

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

Freigeben über

Einfache Protokollierung

Konfiguration

Lenkung der Protokolle

Protokollierung zur Konsole

Protokollierung zum Debuggenfenster

Protokollierung in einer Datei

Abrufen detaillierter Nachrichten

Sensible Daten

Detaillierte Abfrageausnahmen

Filtern

Protokolliergrade

Bestimmte Nachrichten

Meldungskategorien

Benutzerdefinierte Filter

Konfiguration für bestimmte Nachrichten

Ändern der Protokollebene für ein Ereignis

Unterdrücken der Protokollierung eines Ereignisses

Auslösen für ein Ereignis

Nachrichteninhalte und Formatierung

Verwenden der UTC-Zeit

Einzelzeilenprotokollierung

Weitere Inhaltsoptionen

Migrieren von EF6

Zusätzliche Ressourcen