はじめに

運用時にデータベースへのクエリが遅延し、SlowQuery が検出された場合、どのように対応しますか？
もちろんクエリチューニングを行う必要があるので、まずは対象の SQL がどこで発行されたかを特定する必要がありますよね。
ただ、EFCore などの ORM を利用している場合は SQL はクエリビルダーによって動的に作成されるため、SQL を見ただけでは発行しているメソッドをすぐに特定できない場合があります。

このような場合、SQL 内に発行したメソッド名などをコメントとして含めてしまうと問題解決時に対象を特定しやすくなります。
EFCore ではこのような用途のため TagWith メソッドや EFCore 6.0 で追加された TagWithCallSite を利用する事ができます。

TagWith メソッド

EFCore では DataContext への拡張メソッドとして TagWith メソッドが 2.2 のタイミングで、呼び出しメソッドや行を表示してくれる TagWithCallSite メソッドが 6.0 のタイミングで追加されています。

双方とも、クエリの途中に呼び出せば SQL のコメント行として出力されます。TagWith も TagWithCallSite も複数回呼び出すと呼び出した分だけコメントが追加されますが、わかりにくくなるのである程度ルールを決めてタグをつけたほうが良いでしょう。

例えば次のような DbSet が DataContext に定義されていた場合

    public class Blog
    {
        public Blog(string blogName, string url)
        {
            BlogName = blogName;
            Url = url;
        }
        public int BlogId { get; set; }
        public string BlogName { get; set; }
        public string Url { get; set; }
    }
    public class BlogDbContext: DbContext
    {
        public DbSet<Blog> Blogs => Set<Blog>();
    }

クエリ発行時に次のようにタグをつけると、

Program.cs

        var query = _dbContext.Blogs
            .TagWith("ブログの取得")
            .TagWithCallSite()
            ;

        foreach (var b in await query.TagWith("全件取得").TagWithCallSite().ToListAsync())
        {
            _logger.LogInformation("Blog = {BlogName}", b.BlogName);
        }

        var from = 10;
        var to = 10;
        foreach (var b in query.TagWith($"ページネーション({from}件目から-{to}件目)").TagWithCallSite().OrderBy(b => b.BlogName).Skip(from).Take(to))
        {
            _logger.LogInformation("Blog = {BlogName}", b.BlogName);
        }

下記のような SQL が発行されます。タグをつけた部分が SQL のコメントとして出力されているのが分かりますね。

info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (50ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      -- ブログの取得
      -- File: C:\Users\*****\source\repos\ConsoleApp18\ConsoleApp18\Program.cs:70
      -- 全件取得
      -- File: C:\Users\*****\source\repos\ConsoleApp18\ConsoleApp18\Program.cs:73

      SELECT `b`.`BlogId`, `b`.`BlogName`, `b`.`Url`
      FROM `Blogs` AS `b`
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (23ms) [Parameters=[@__p_0='10'], CommandType='Text', CommandTimeout='30']
      -- ブログの取得
      -- File: C:\Users\*****\source\repos\ConsoleApp18\ConsoleApp18\Program.cs:70
      -- ページネーション(10件目から-10件目)
      -- File: C:\Users\*****\source\repos\ConsoleApp18\ConsoleApp18\Program.cs:80

      SELECT `b`.`BlogId`, `b`.`BlogName`, `b`.`Url`
      FROM `Blogs` AS `b`
      ORDER BY `b`.`BlogName`
      LIMIT @__p_0 OFFSET @__p_0

おわりに

実運用環境では、ユーザーの予期しない使われ方などで思ってもみない SQL が発行されたりします。
全てのクエリにタグをつけていくのはちょっと現実的ではありませんが、重要な箇所や複雑なクエリに予防的にタグをつけておくと後で助かるかもしれませんね。

TagWithとTagWithCallSiteでSQLを発行したメソッドを特定する

はじめに

TagWith メソッド

おわりに