シンプルなログ

[アーティクル]
08/24/2023

ヒント

この記事のサンプルは GitHub からダウンロードできます。

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

ヒント

EF Core は、Microsoft.Extensions.Logging とも統合します。これは必要な構成が多くなりますが、多くの場合、運用環境のアプリケーションでのログ記録に適しています。

構成

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

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

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

ヒント

AddDbContext が使用される場合も、または DbContextOptions インスタンスが DbContext コンストラクターに渡される場合も、OnConfiguring が呼び出されます。したがって、それは 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();
}

ヒント

運用環境のアプリケーションでのファイルへのログ記録には、Microsoft.Extensions.Logging を使用することを検討してください。

詳細なメッセージを取得する

機密データ

既定では、EF Core には例外メッセージ内のデータの値は含まれません。これは、そのようなデータは機密情報である可能性があるためで、例外が処理されない場合に運用環境で流出するおそれがあるためです。

ただし、特にキーについて、データ値を把握することは、デバッグ時に非常に役立ちます。これは、EnableSensitiveDataLogging() を呼び出すことによって EF Core 内で有効にすることができます。次に例を示します。

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

Filtering

ログレベル

すべての 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 });

メッセージの種類

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

カテゴリ	[メッセージ]
Microsoft.EntityFrameworkCore	すべての EF Core メッセージ
Microsoft.EntityFrameworkCore.Database	すべてのデータベース操作
Microsoft.EntityFrameworkCore.Database.Connection	データベース接続の使用
Microsoft.EntityFrameworkCore.Database.Command	データベースコマンドの使用
Microsoft.EntityFrameworkCore.Database.Transaction	データベーストランザクションの使用
Microsoft.EntityFrameworkCore.Update	エンティティの保存 (データベース操作を除く)
Microsoft.EntityFrameworkCore.Model	すべてのモデルとメタデータの相互作用
Microsoft.EntityFrameworkCore.Model.Validation	モデルの検証
Microsoft.EntityFrameworkCore.Query	クエリ (データベース操作を除く)
Microsoft.EntityFrameworkCore.Infrastructure	一般的なイベント (コンテキストの作成など)
Microsoft.EntityFrameworkCore.Scaffolding	データベースのリバースエンジニアリング
Microsoft.EntityFrameworkCore.Migrations	移行
Microsoft.EntityFrameworkCore.ChangeTracking	変更の追跡操作

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

ヒント

カスタムフィルターを使用するか、ここで示す他のオプションを使用したフィルター処理は、LogTo デリゲートでのフィルター処理よりも効率的です。これは、あるメッセージをログに記録すべきではないとフィルターで判断された場合、そのログメッセージは作成すらされないためです。

特定のメッセージの構成

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
現在のカルチャ用に書式設定されたローカルタイムスタンプ
CoreEventId または他の EventId クラスの 1 つからメンバーを取得するためにコピー/貼り付けできる形式の 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 から値を渡すことによってカスタマイズできます。

ヒント

ログの書式設定をさらに制御するには、Microsoft.Extensions.Logging の使用を検討してください。

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 行を取得するようにすると便利な場合があります。これは、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 つの重要な点で異なります。

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

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

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

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

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

シンプルなログ

構成

ログの出力指定

コンソールへのログの記録

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

ファイルへのログ記録

詳細なメッセージを取得する

機密データ

詳細なクエリの例外

Filtering

ログレベル

特定のメッセージ

メッセージの種類

カスタムフィルター

特定のメッセージの構成

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

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

イベントに対してスローする

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

UTC 時刻の使用

単一行のログ記録

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

EF6 からの移行

フィードバック

その他のリソース

シンプルなログ

構成

ログの出力指定

コンソールへのログの記録

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

ファイルへのログ記録

詳細なメッセージを取得する

機密データ

詳細なクエリの例外

Filtering

ログ レベル

特定のメッセージ

メッセージの種類

カスタム フィルター

特定のメッセージの構成

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

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

イベントに対してスローする

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

UTC 時刻の使用

単一行のログ記録

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

EF6 からの移行

フィードバック

その他のリソース

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

ログレベル

カスタムフィルター

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

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