単純なログ記録

Entity Framework Core (EF Core) の単純なログ記録を使用すると、アプリケーションの開発とデバッグ中にログを簡単に取得できます。 この形式のログ記録には最小限の構成が必要であり、追加の NuGet パッケージは必要ありません。

コンフィギュレーション

EF Core ログには、LogToするときにを使用して、任意の種類のアプリケーションからアクセスできます。 この構成は、通常、 DbContext.OnConfiguringのオーバーライドで行われます。 例えば次が挙げられます。

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

または、LogToは、AddDbContextの一部として、またはDbContextOptionsコンストラクターに渡すDbContext インスタンスを作成するときに呼び出すことができます。

ログの管理

コンソールへのログ記録

LogTo には、文字列を受け取る Action<T> デリゲートが必要です。 EF Core は、生成されたログ メッセージごとに文字列を使用してこのデリゲートを呼び出します。 その後、指定されたメッセージを使用して何かを行うのはデリゲートに任されます。

Console.WriteLine メソッドは、上に示すように、このデリゲートによく使用されます。 これにより、各ログ メッセージがコンソールに書き込まれます。

デバッグ ウィンドウへのログ記録

Debug.WriteLine は、Visual Studio またはその他の IDE のデバッグ ウィンドウに出力を送信するために使用できます。 クラスはリリース ビルドからコンパイルされるため、この場合はDebugを使用する必要があります。 例えば次が挙げられます。

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

ファイルへのログ記録

ファイルに書き込むには、ファイルの StreamWriter または同様のファイルを作成する必要があります。 WriteLineメソッドは、上記の他の例のように使用できます。 コンテキストを破棄するときにライターも破棄して、ファイルが正常に閉じられるよう忘れずにしてください。 例えば次が挙げられます。

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

詳細なメッセージの取得

機微なデータ

既定では、EF Core は例外メッセージにデータの値を含めなくなります。 これは、このようなデータは機密である可能性があり、例外が処理されない場合は運用環境で明らかにされる可能性があるためです。

ただし、特にキーのデータ値を知ることは、デバッグ時に非常に役立ちます。 これを EF Core で有効にするには、 EnableSensitiveDataLogging()を呼び出します。 例えば次が挙げられます。

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

詳細なクエリ例外

パフォーマンス上の理由から、EF Core は、try-catch ブロック内のデータベース プロバイダーから値を読み取る各呼び出しをラップしません。 ただし、これは、特にデータベースがモデルで許可されていない場合に NULL を返す場合に、診断が困難な例外が発生することがあります。

EnableDetailedErrorsをオンにすると、EF がこれらの try-catch ブロックを導入し、より詳細なエラー情報を提供します。 例えば次が挙げられます。

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

フィルタリング

ログ レベル

すべての EF Core ログ メッセージは、 LogLevel 列挙型によって定義されたレベルに割り当てられます。 既定では、EF Core の単純なログ記録には、 Debug レベル以上のすべてのメッセージが含まれます。 LogTo は、一部のメッセージを除外するために、より高い最小レベルを渡すことができます。 たとえば、 Information を渡すと、データベース アクセスと一部のハウスキーピング メッセージに限定されるログの最小セットが得られます。

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

特定のメッセージ

すべてのログ メッセージには、 EventIdが割り当てられます。 これらの ID は、リレーショナル固有のメッセージの場合は、 CoreEventId クラスまたは RelationalEventId クラスからアクセスできます。 データベース プロバイダーは、同様のクラスにプロバイダー固有の ID を持つ場合もあります。 たとえば、SQL Server プロバイダーに関してSqlServerEventIdです。

LogTo は、1 つ以上のイベント ID に関連付けられているメッセージのみをログに記録するように構成できます。 たとえば、初期化または破棄されているコンテキストのメッセージのみをログに記録するには、次のようにします。

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

メッセージのカテゴリ

すべてのログ メッセージは、名前付き階層ロガー カテゴリに割り当てられます。 カテゴリは次のとおりです。

LogTo は、1 つ以上のカテゴリからのメッセージのみをログに記録するように構成できます。 たとえば、データベースの操作のみをログに記録するには、次のようにします。

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

DbLoggerCategory クラスには、カテゴリを検索するための階層型 API が用意されており、文字列をハードコーディングする必要がなくなります。

カテゴリは階層構造であるため、 Database カテゴリを使用するこの例には、サブカテゴリ Database.Connection、 Database.Command、および Database.Transactionのすべてのメッセージが含まれます。

カスタム フィルター

LogTo では、上記のフィルター処理オプションで十分でない場合にカスタム フィルターを使用できます。 たとえば、レベル Information 以上のメッセージと、接続を開いたり閉じたりするためのメッセージをログに記録するには、次のようにします。

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

特定のメッセージの構成

EF Core ConfigureWarnings API を使用すると、特定のイベントが発生した場合の動作をアプリケーションで変更できます。 これを使用すると、次のことができます。

• イベントがログに記録されるログ レベルを変更する
• イベントのログ記録をスキップする
• イベントが発生したときに例外をスローする

イベントのログ レベルの変更

前の例では、カスタム フィルターを使用して、 LogLevel.Information のすべてのメッセージと、 LogLevel.Debugに定義された 2 つのイベントをログに記録しました。 2 つの Debug イベントのログ レベルを 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);

イベントのログ記録を抑制する

同様に、個々のイベントをログ記録から抑制できます。 これは、確認および理解された警告を無視する場合に特に便利です。 例えば次が挙げられます。

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

イベントの開催

最後に、特定のイベントに対してスローするように EF Core を構成できます。 これは、警告をエラーに変更する場合に特に便利です。 実際、これはConfigureWarningsメソッドの本来の目的であるため、この名前が付けられています。例えば：

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

メッセージの内容と書式設定

LogToの既定のコンテンツは、複数行にわたって書式設定されます。 最初の行には、メッセージ メタデータが含まれています。

• 4 文字のプレフィックスとしてのLogLevel
• 現在のカルチャ用に書式設定されたローカル タイムスタンプ
• EventIdまたは他のCoreEventIdクラスのいずれかからメンバーを取得するためにコピー/貼り付けできるフォーム内のEventIdと、生の ID 値
• 上記のイベント カテゴリ。

例えば次が挙げられます。

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.

このコンテンツは、次のセクションに示すように、 DbContextLoggerOptionsから値を渡すことによってカスタマイズできます。

UTC 時刻の使用

既定では、タイムスタンプはデバッグ中にローカルで使用するように設計されています。 代わりに、 DbContextLoggerOptions.DefaultWithUtcTime を使用してカルチャに依存しない UTC タイムスタンプを使用しますが、それ以外はすべて同じにします。 例えば次が挙げられます。

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

この例では、次のログ形式になります。

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.

1 行のログ記録

ログ メッセージごとに正確に 1 行取得すると便利な場合があります。 これは、 DbContextLoggerOptions.SingleLineで有効にすることができます。 例えば次が挙げられます。

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

この例では、次のログ形式になります。

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.

その他のコンテンツ オプション

DbContextLoggerOptions内の他のフラグを使用して、ログに含まれるメタデータの量を減らすことができます。 これは、単一行ログと組み合わせて使用すると便利です。 例えば次が挙げられます。

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

この例では、次のログ形式になります。

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.

EF6 からの移行

EF Core の単純なログ記録は、EF6 の Database.Log と 2 つの重要な点で異なります。

• ログ メッセージはデータベース操作のみに限定されません
• コンテキストの初期化時にログ記録を構成する必要がある

最初の違いについては、上記のフィルター処理を使用して、ログに記録されるメッセージを制限できます。

2 つ目の違いは、ログ メッセージが不要な場合は生成しないことでパフォーマンスを向上させるための意図的な変更です。 ただし、LogにDbContext プロパティを作成し、設定されている場合にのみ使用することで、EF6 と同様の動作を引き続き取得できます。 例えば次が挙げられます。

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

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