.NET Core, Entity Framework CoreでSQLログを出力する


はじめに

.NET Core の Entity Framework Core で LINQ を使用してデータベースアクセスしていると、実際にはどのような SQL が発行されているのか気になることがあります。

Entity Framework Core には、いくつかの方法で SQL ログを出力することができますが、この記事ではコンソールアプリケーションでコンソールに出力する方法をご紹介します。

なお、環境は、Mac (macOS High Sierra 10.13.3) で .NET Core SDK 2.1.4、PostgreSQL 10.3 、Visual Studio Code になります。

データの準備

まず、PostgreSQLで以下の SQL を実行してデータを準備します。

CREATE DATABASE ConsoleTest;

CREATE TABLE Book (
  Id SERIAL PRIMARY KEY,
  Price int,
  Title text
);

INSERT INTO Book (Price, Title) values (2000,'おはようございますこんにちはこんばんは');
INSERT INTO Book (Price, Title) values (1000,'おはようございます');
INSERT INTO Book (Price, Title) values (500,'こんにちは');
INSERT INTO Book (Price, Title) values (800,'こんばんは');

データベース定義の取り込みについては、以下の記事をご確認ください。

必要なパッケージのインストール

Entity Framework Core でコンソールに SQL ログを出力するには、Microsoft.Extensions.Logging.Console パッケージを NuGet からインストール必要があります。ここでは以下のようにインストールします。

$ dotnet add package Microsoft.Extensions.Logging.Console

SQL ログ出力

データベースコンテキストクラスを、以下のように修正します。

using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Console;

//(中略)

    //(追加)
    public static readonly LoggerFactory MyLoggerFactory
        = new LoggerFactory(new[]
        {
            new ConsoleLoggerProvider((category, level)
                => category == DbLoggerCategory.Database.Command.Name
                && level == LogLevel.Information, true)
        });

    protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    {
        if (!optionsBuilder.IsConfigured)
        {
            optionsBuilder
                .UseLoggerFactory(MyLoggerFactory)  //追加
                .UseNpgsql("Server=localhost;Database=databasename;Username=username;Password=password;");
        }
    }

また、Program.cs の Main メソッドにデータベースにアクセスするコードを追加します。

    using (var db = new consoletestContext())
    {
        var books = db.Book.Where(m => m.Title.Contains("おはようございます"))
                            .OrderBy(m => m.Id)
                            .ToList();
        foreach (var book in books) {
            Console.WriteLine(book.Title);
        }
    }

では、アプリケーションをビルドして実行してみます。

$ dotnet build
$ dotnet run
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (21ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT "m"."id", "m"."price", "m"."title"
      FROM "book" AS "m"
      WHERE STRPOS("m"."title", 'おはようございます') > 0
      ORDER BY "m"."id"
おはようございますこんにちはこんばんは
おはようございます

SQL ログが問題なく出力されていますね。

実際には、余計な情報が出力されないようにフィルターをかけているのですが、そこは気にしなくてもよいかと思います。

ちなみに、検索文字列の「おはようございます」を「おはよう’;--ございます」 とすれば SQL インジェクションを引き起こせるかと思ったのですが、しっかりとエスケープ対策されていました。

おわりに

やり方さえ分かって込み入ったことをやらなければ、このように簡単に SQL ログを出力することができることが分かりました。

実際に、LINQ の SQL ログを出力したところ、データ抽出の処理を LINQ to Object で行っていることがあったりしたので、パフォーマンスがでないときなどに SQL ログを確認することは有効だと思います。

参考サイト