EFCoreコードファーストが発行したSQLをログ出力する

EFCoreコードファーストから発行されたSQLをログファイルに残す、サンプルを作りしました。コードファーストのDBパフォーマンスを、インデクス追加で改善する際には必須だと思う。
今回は今流行りの Blazor Server をベースに作成していますが、Blazor Server 以外でも同じです。
ソースコードはGitHubで公開しています。

EFCoreコードファーストから発行されたSQLは、Microsoftのログレベルを debugにすると出力されますが、DbContextの OnConfiguringメソッドを overrideすることでも出力できます。
Microsoftのログレベルを debugにして、コードファーストが発行したSQLをログ出力すると、発行したSQL以外のログが大量に出力されてしまう為、DbContextの OnConfiguringメソッドを overrideして、コードファーストが発行したSQLをログ出力する実装方式がお勧めです。

DbContextの OnConfiguringメソッドを overrideして、コードファーストが発行したSQLをログ出力した場合。ログファイルサイズは 2KB。

Microsoftのログレベルを debugにして、コードファーストが発行したSQLをログ出力した場合。ログファイルサイズは 31KB。

ソースコード構成

Blazor Server でログを出力するをベースに、EFCoreコードファーストから発行されたSQLをログファイルへ出力する処理だけ、追加実装しています。
追加変更を加えたソースファイル。

ソースコード変更内容を解説

/WebApplication1.csproj

・SqlServerを操作する為の、Microsoft.EntityFrameworkCore.SqlServer Nugetパッケージを追加。


<Project Sdk="Microsoft.NET.Sdk.Web">

  <PropertyGroup>
    <TargetFramework>net5.0</TargetFramework>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="Microsoft.EntityFrameworkCore.SqlServer" Version="5.0.17" />
    <PackageReference Include="NLog" Version="4.7.13" />
    <PackageReference Include="NLog.Web.AspNetCore" Version="4.14.0" />
  </ItemGroup>

</Project>

</PropertyGroup>

</ItemGroup>

</Project>

/appsettings.Development.json

・SqlServerに接続する為の、接続文字列を追加。
　ローカルPCにインストールした SqlServerの TestDBへ、ID/PW認証で接続しています。


{
  "ConnectionStrings": {
    "DefaultConnection": "Data Source=localhost;Database=TestDB;User ID=testuser;Password=testpassword;Connect Timeout=30;Encrypt=False;TrustServerCertificate=False;ApplicationIntent=ReadWrite;MultiSubnetFailover=False"
  },
  "DetailedErrors": true,
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    }
  }
}

{

"ConnectionStrings": {

"DefaultConnection": "Data Source=localhost;Database=TestDB;User ID=testuser;Password=testpassword;Connect Timeout=30;Encrypt=False;TrustServerCertificate=False;ApplicationIntent=ReadWrite;MultiSubnetFailover=False"

"DetailedErrors": true,

"Logging": {

"LogLevel": {

"Default": "Information",

"Microsoft": "Warning",

"Microsoft.Hosting.Lifetime": "Information"

}

/Startup.cs

・各画面で、DbContextからコードファーストで SQLServerを操作できるようにする為、起動処理にコネクションストリングを使用して DbContextを初期化する処理を追加。

/Model/DB/TableA.cs

・SQLServer TestDB上のテストテーブルに対応する、Modelクラスを作成。


using System;
using System.Collections.Generic;
using System.ComponentModel.DataAnnotations.Schema;
using System.Linq;
using System.Threading.Tasks;


namespace WebApplication1.Model.DB
{
    [Table("TableA")]
    public class TableA
    {
        /// <summary>
        /// ID
        /// </summary>
        [Column("Id")]
        public long Id { get; set; }

        /// <summary>
        /// value
        /// </summary>
        [Column("value")]
        public string Value { get; set; }

    }
}

using System;

using System.Collections.Generic;

using System.ComponentModel.DataAnnotations.Schema;

using System.Linq;

using System.Threading.Tasks;

namespace WebApplication1.Model.DB

{

[Table("TableA")]

public class TableA

{

/// <summary>

/// ID

/// </summary>

[Column("Id")]

public long Id { get; set; }

/// <summary>

/// value

/// </summary>

[Column("value")]

public string Value { get; set; }

}

/Data/ApplicationDbContext.cs

・DbContextのクラスを作成。
・コンストラクタで、Loggerのインスタンスを作成。
・OnConfiguringをオーバライドして、コードファーストのログを、ログファイルへ出力する共通メソッドへ送っている。
・Modelクラスの DbSetを設けている。


using Microsoft.EntityFrameworkCore;
using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Text;
using WebApplication1.Helpers;
using WebApplication1.Model.DB;

namespace WebApplication1.Data
{
    public class ApplicationDbContext : DbContext
    {
        private readonly ILogger _Logger;

        /// <summary>
        /// コンストラクタ
        /// </summary>
        public ApplicationDbContext(DbContextOptions<ApplicationDbContext> options, ILoggerFactory loggerFactory)
            : base(options)
        {
            _Logger = loggerFactory.CreateLogger("DefaultDbContext");
        }

        /// <summary>
        /// 
        /// </summary>
        protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
        {
            // デバッグ実行時は、コードファーストが発行するSQLを、出力ウィンドウへも出力する。
            optionsBuilder.LogTo(msg => CodeFirstHelper.OutputCodeFirstLog(_Logger, msg));
        }

        public DbSet<TableA> DB_TableA { get; set; }

    }
}

using Microsoft.EntityFrameworkCore;

using Microsoft.Extensions.Logging;

using System;

using System.Collections.Generic;

using System.Text;

using WebApplication1.Helpers;

using WebApplication1.Model.DB;

namespace WebApplication1.Data

{

public class ApplicationDbContext : DbContext

{

private readonly ILogger _Logger;

/// <summary>

/// コンストラクタ

/// </summary>

public ApplicationDbContext(DbContextOptions<ApplicationDbContext> options, ILoggerFactory loggerFactory)

: base(options)

{

_Logger = loggerFactory.CreateLogger("DefaultDbContext");

}

/// <summary>

///

/// </summary>

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)

{

// デバッグ実行時は、コードファーストが発行するSQLを、出力ウィンドウへも出力する。

optionsBuilder.LogTo(msg => CodeFirstHelper.OutputCodeFirstLog(_Logger, msg));

}

public DbSet<TableA> DB_TableA { get; set; }

}

/Helpers/CodeFirstHelper.cs

・コードファイルのログの内、発行された SQLだけログファイルへ出力する共通メソッドを作成。
　static化することで高速化している。
・Debugレベルのログは、他製品のログが大量に出力される為、SQL実行ログ（ビジネスロジックのログ）は、Informationレベルで出力している。
・Debug実行時は、ログファイルだけではなく、Debug.WriteLineから Visual Studioの「出力」ウィンドウへ SQL実行ログが出力されるようにし、開発生産性を上げている。


using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Threading.Tasks;

namespace WebApplication1.Helpers
{
    /// <summary>
    /// 
    /// </summary>
    public static class CodeFirstHelper
    {
        /// <summary>
        /// EFCoreが出力するログの内、コードファーストが発行したSQLのみ、出力ウィンドウに残す。
        /// </summary>
        public static void OutputCodeFirstLog(ILogger _logger, string msg)
        {
            if (msg.IndexOf("Executing DbCommand") > -1)
            {
                Debug.WriteLine($"[Code First SQL]" + Environment.NewLine + msg);

                _logger.LogInformation($"[Code First SQL]" + Environment.NewLine + msg);
            }
        }

    }
}

using Microsoft.Extensions.Logging;

using System;

using System.Collections.Generic;

using System.Diagnostics;

using System.Linq;

using System.Threading.Tasks;

namespace WebApplication1.Helpers

{

/// <summary>

///

/// </summary>

public static class CodeFirstHelper

{

/// <summary>

/// EFCoreが出力するログの内、コードファーストが発行したSQLのみ、出力ウィンドウに残す。

/// </summary>

public static void OutputCodeFirstLog(ILogger _logger, string msg)

{

if (msg.IndexOf("Executing DbCommand") > -1)

{

Debug.WriteLine($"[Code First SQL]" + Environment.NewLine + msg);

_logger.LogInformation($"[Code First SQL]" + Environment.NewLine + msg);

}

/_Imports.razor

・各Razorページで、DbContextを使ったコードファースト処理を実装できるよう、共通部品に Usingを追加。


@using System.Net.Http
@using Microsoft.AspNetCore.Authorization
@using Microsoft.AspNetCore.Components.Authorization
@using Microsoft.AspNetCore.Components.Forms
@using Microsoft.AspNetCore.Components.Routing
@using Microsoft.AspNetCore.Components.Web
@using Microsoft.AspNetCore.Components.Web.Virtualization
@using Microsoft.Extensions.Logging
@using Microsoft.JSInterop
@using WebApplication1
@using WebApplication1.Data
@using WebApplication1.Model.DB
@using WebApplication1.Shared

@using System.Net.Http

@using Microsoft.AspNetCore.Authorization

@using Microsoft.AspNetCore.Components.Authorization

@using Microsoft.AspNetCore.Components.Forms

@using Microsoft.AspNetCore.Components.Routing

@using Microsoft.AspNetCore.Components.Web

@using Microsoft.AspNetCore.Components.Web.Virtualization

@using Microsoft.Extensions.Logging

@using Microsoft.JSInterop

@using WebApplication1

@using WebApplication1.Data

@using WebApplication1.Model.DB

@using WebApplication1.Shared

/Pages/Counter.razor

・Razorページにコードファースト処理を追加。


@page "/Counter"
@inject ILogger<Counter> _Logger
@inject ApplicationDbContext _DbContext

<h1>Counter</h1>

<p>Current count: @currentCount</p>

<button class="btn btn-primary" @onclick="IncrementCount">Click me</button>

@code {
    private int currentCount = 0;

    private void IncrementCount()
    {
        var tableAList = _DbContext.DB_TableA.Where(x => x.Id == 1).Select(x => x.Value).ToList();

        currentCount++;

        _Logger.LogDebug($"Debug level log write.{currentCount}");

        _Logger.LogInformation($"Information level log write.{currentCount}");

        _Logger.LogWarning($"Warning level log write.{currentCount}");

        _Logger.LogError($"Error level log write.{currentCount}");
    }
}

@page "/Counter"

@inject ILogger<Counter> _Logger

@inject ApplicationDbContext _DbContext

<h1>Counter</h1>

<p>Current count: @currentCount</p>

<button class="btn btn-primary" @onclick="IncrementCount">Click me</button>

@code {

private int currentCount = 0;

private void IncrementCount()

{

var tableAList = _DbContext.DB_TableA.Where(x => x.Id == 1).Select(x => x.Value).ToList();

currentCount++;

_Logger.LogDebug($"Debug level log write.{currentCount}");

_Logger.LogInformation($"Information level log write.{currentCount}");

_Logger.LogWarning($"Warning level log write.{currentCount}");

_Logger.LogError($"Error level log write.{currentCount}");

}