Jednoduché protokolování

Článek
09/12/2023

Tip

Ukázku tohoto článku si můžete stáhnout z GitHubu.

Jednoduché protokolování Entity Framework Core (EF Core) lze použít k snadnému získání protokolů při vývoji a ladění aplikací. Tato forma protokolování vyžaduje minimální konfiguraci a žádné další balíčky NuGet.

Tip

EF Core se také integruje s Microsoft.Extensions.Logging, která vyžaduje více konfigurace, ale často je vhodnější pro protokolování v produkčních aplikacích.

Konfigurace

K protokolům EF Core je možné přistupovat z libovolného typu aplikace prostřednictvím LogTo při konfiguraci instance DbContextu. Tato konfigurace se běžně provádí přepsáním DbContext.OnConfiguring. Příklad:

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

Alternativně LogTo lze volat jako součást AddDbContext nebo při vytváření DbContextOptions instance pro předání konstruktoru DbContext .

Tip

OnConfiguring je stále volána, když AddDbContext je použit nebo DbContextOptions instance je předán DbContext konstruktoru. Díky tomu je ideálním místem pro použití konfigurace kontextu bez ohledu na to, jak je dbContext vytvořen.

Směrování protokolů

Protokolování do konzoly

LogTo vyžaduje delegáta Action<T> , který přijímá řetězec. EF Core zavolá tohoto delegáta s řetězcem pro každou vygenerovanou zprávu protokolu. Pak je na delegátu, aby něco udělal s danou zprávou.

Metoda Console.WriteLine se často používá pro tohoto delegáta, jak je znázorněno výše. Výsledkem je zápis každé zprávy protokolu do konzoly.

Protokolování do okna ladění

Debug.WriteLine lze použít k odeslání výstupu do okna Ladění v sadě Visual Studio nebo v jiných prostředích IDE. V tomto případě je nutné použít syntaxi lambda, protože Debug třída je zkompilována z buildů vydaných verzí. Příklad:

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

Protokolování do souboru

Zápis do souboru vyžaduje vytvoření nebo podobného StreamWriter souboru. Metodu WriteLine pak můžete použít jako v dalších příkladech výše. Nezapomeňte zajistit, aby se soubor zavřel čistě tak, že zapisovač vyřazuje při odstranění kontextu. Příklad:

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

Tip

Zvažte použití microsoft.Extensions.Logging pro protokolování do souborů v produkčních aplikacích.

Získání podrobných zpráv

Citlivá data

Ef Core ve výchozím nastavení nebude obsahovat hodnoty žádných dat ve zprávách výjimek. Důvodem je to, že taková data mohou být důvěrná a mohou být odhalena v produkčním použití, pokud není zpracována výjimka.

Znalost hodnot dat, zejména pro klíče, ale může být při ladění velmi užitečná. To lze povolit v EF Core voláním EnableSensitiveDataLogging(). Příklad:

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

Podrobné výjimky dotazů

Z důvodů výkonu EF Core nezabalí každé volání pro čtení hodnoty od zprostředkovatele databáze v bloku try-catch. To ale někdy vede k výjimkám, které je obtížné diagnostikovat, zejména v případě, že databáze vrátí hodnotu NULL, pokud model nepovoluje.

Zapnutí EnableDetailedErrors způsobí, že EF zavede tyto bloky try-catch a poskytne tak podrobnější chyby. Příklad:

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

Filtrování

Úrovně protokolů

Každá zpráva protokolu EF Core je přiřazena k úrovni definované výčtem LogLevel . Ve výchozím nastavení zahrnuje jednoduché protokolování EF Core všechny zprávy na Debug úrovni nebo vyšší. LogTo může být předána vyšší minimální úroveň, aby se vyfiltrily některé zprávy. Předáním výsledků je například Information minimální sada protokolů omezených na přístup k databázi a některé zprávy o úklidu.

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

Konkrétní zprávy

Každé zprávě protokolu je přiřazeno EventId. K těmto ID lze přistupovat z CoreEventId třídy nebo RelationalEventId třídy pro relační zprávy. Zprostředkovatel databáze může mít také ID specifická pro zprostředkovatele v podobné třídě. Například SqlServerEventId pro poskytovatele SQL Serveru.

LogTo lze nakonfigurovat tak, aby protokolovaly pouze zprávy přidružené k jednomu nebo více ID událostí. Pokud například chcete protokolovat pouze zprávy pro inicializaci nebo vyřazení kontextu:

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

Kategorie zpráv

Každá zpráva protokolu se přiřadí k pojmenované hierarchické kategorii protokolovacího nástroje. Kategorie:

Kategorie	Zprávy
Microsoft.EntityFrameworkCore	Všechny zprávy EF Core
Microsoft.EntityFrameworkCore.Database	Všechny interakce databáze
Microsoft.EntityFrameworkCore.Database. Připojení ion	Použití připojení k databázi
Microsoft.EntityFrameworkCore.Database.Command	Použití databázového příkazu
Microsoft.EntityFrameworkCore.Database.Transaction	Použití databázové transakce
Microsoft.EntityFrameworkCore.Update	Ukládání entit s výjimkou interakcí s databází
Microsoft.EntityFrameworkCore.Model	Všechny interakce modelu a metadat
Microsoft.EntityFrameworkCore.Model.Validation	Ověření modelu
Microsoft.EntityFrameworkCore.Query	Dotazy s výjimkou interakcí s databází
Microsoft.EntityFrameworkCore.Infrastructure	Obecné události, například vytváření kontextu
Microsoft.EntityFrameworkCore.Scaffolding	Zpětná analýza databáze
Microsoft.EntityFrameworkCore.Migrations	Migrace
Microsoft.EntityFrameworkCore.ChangeTracking	Interakce sledování změn

LogTo lze nakonfigurovat tak, aby protokolovaly pouze zprávy z jedné nebo více kategorií. Pokud například chcete protokolovat pouze databázové interakce:

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

Všimněte si, že DbLoggerCategory třída poskytuje hierarchické rozhraní API pro vyhledání kategorie a zabraňuje nutnosti pevně zakódovat řetězce.

Vzhledem k tomu, že kategorie jsou hierarchické, bude toto použití Database kategorie obsahovat všechny zprávy pro podkategorie Database.Connection, Database.Commanda Database.Transaction.

Vlastní filtry

LogTo umožňuje použít vlastní filtr pro případy, kdy žádná z výše uvedených možností filtrování nestačí. Pokud například chcete protokolovat jakoukoli zprávu na úrovni Information nebo vyšší, a také zprávy pro otevření a zavření připojení:

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

Tip

Filtrování pomocí vlastních filtrů nebo použití některé z dalších možností zobrazených zde je efektivnější než filtrování v delegátu LogTo . Důvodem je to, že pokud filtr určuje, že zpráva by neměla být protokolována, zpráva protokolu se ani nevytvořila.

Konfigurace pro konkrétní zprávy

Rozhraní EF Core ConfigureWarnings API umožňuje aplikacím změnit, co se stane, když dojde k určité události. Můžete ho použít k:

Změna úrovně protokolu, na které se událost protokoluje
Přeskočení protokolování události celkem
Vyvolání výjimky při výskytu události

Změna úrovně protokolu pro událost

Předchozí příklad použil vlastní filtr k protokolování každé zprávy LogLevel.Information a také dvě události definované pro LogLevel.Debug. Totéž lze dosáhnout změnou úrovně protokolu dvou Debug událostí na 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);

Potlačení protokolování události

Podobně může být jednotlivá událost potlačena z protokolování. To je užitečné zejména pro ignorování upozornění, které bylo zkontrolováno a srozumitelné. Příklad:

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

Vyvolání události

Nakonec je možné ef Core nakonfigurovat tak, aby se pro danou událost vyhodila. To je užitečné zejména při změně upozornění na chybu. (To byl původní účel ConfigureWarnings metody, tedy název.) Příklad:

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

Obsah a formátování zpráv

Výchozí obsah z LogTo je naformátovaný napříč více řádky. První řádek obsahuje metadata zpráv:

Jako LogLevel předpona čtyř znaků
Místní časové razítko formátované pro aktuální jazykovou verzi
Ve EventId formuláři, který lze zkopírovat nebo vložit, aby získal člena z CoreEventId nebo jedné z dalších EventId tříd, plus nezpracovaná hodnota ID
Kategorie události, jak je popsáno výše.

Příklad:

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.

Tento obsah lze přizpůsobit předáním hodnot z DbContextLoggerOptions, jak je znázorněno v následujících částech.

Tip

Zvažte použití microsoft.Extensions.Logging pro větší kontrolu nad formátováním protokolu.

Použití času UTC

Ve výchozím nastavení jsou časová razítka navržená pro místní spotřebu při ladění. Místo toho používejte DbContextLoggerOptions.DefaultWithUtcTime časová razítka UTC nezávislá na jazykové verzi, ale ponechejte všechno ostatní stejné. Příklad:

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

Výsledkem tohoto příkladu je následující formátování protokolu:

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.

Protokolování s jedním řádkem

Někdy je užitečné získat přesně jeden řádek pro každou zprávu protokolu. To může povolit DbContextLoggerOptions.SingleLine. Příklad:

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

Výsledkem tohoto příkladu je následující formátování protokolu:

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.

Další možnosti obsahu

Další příznaky lze DbContextLoggerOptions použít k oříznutí množství metadat zahrnutých v protokolu. To může být užitečné ve spojení s jednořádkovým protokolováním. Příklad:

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

Výsledkem tohoto příkladu je následující formátování protokolu:

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.

Přechod z EF6

Jednoduché protokolování EF Core se liší od Database.Log EF6 dvěma důležitými způsoby:

Zprávy protokolu nejsou omezeny pouze na interakce databáze.
Protokolování musí být nakonfigurované v době inicializace kontextu.

U prvního rozdílu lze filtrování popsané výše použít k omezení toho, které zprávy se protokolují.

Druhým rozdílem je úmyslná změna ke zlepšení výkonu tím, že negeneruje zprávy protokolu, pokud nejsou potřeba. Přesto je ale možné získat podobné chování jako EF6 vytvořením Log vlastnosti ve vaší DbContext a jeho následném použití pouze v případě, že byla nastavena. Příklad:

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

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

Sdílet prostřednictvím

Jednoduché protokolování

Konfigurace

Směrování protokolů

Protokolování do konzoly

Protokolování do okna ladění

Protokolování do souboru

Získání podrobných zpráv

Citlivá data

Podrobné výjimky dotazů

Filtrování

Úrovně protokolů

Konkrétní zprávy

Kategorie zpráv

Vlastní filtry

Konfigurace pro konkrétní zprávy

Změna úrovně protokolu pro událost

Potlačení protokolování události

Vyvolání události

Obsah a formátování zpráv

Použití času UTC

Protokolování s jedním řádkem

Další možnosti obsahu

Přechod z EF6

Další materiály