パフォーマンスの診断

このセクションでは、EF アプリケーションでパフォーマンスの問題を検出する方法と、問題のある領域が特定されてからそれらをさらに分析して根本問題を特定する方法について説明します。 結論を急ぐ前に問題を慎重に診断して調査し、問題の根本がどこにあるかを想定しないようにすることが重要です。

ログ記録を使用した低速データベース コマンドの特定

1 日の終わりに、EF ではデータベースに対して実行されるコマンドを準備して実行します。リレーショナル データベースを使用する場合、これは ADO.NET データベース API を介して SQL ステートメントを実行することを意味します。 特定のクエリに時間がかかりすぎる場合 (たとえば、インデックスが欠落しているために) は、コマンド実行ログを調べ、実際にかかる時間を確認することでこれを検出できます。

EF を使用すると、単純なログ記録または Microsoft.Extensions.Logging を使用して、コマンドの実行時間を非常に簡単に取り込むことができます。

シンプルなログ

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    optionsBuilder
        .UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=Blogging;Trusted_Connection=True;ConnectRetryCount=0")
        .LogTo(Console.WriteLine, LogLevel.Information);
}

Microsoft.Extensions.Logging

private static ILoggerFactory ContextLoggerFactory
    => LoggerFactory.Create(b => b.AddConsole().AddFilter("", LogLevel.Information));

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    optionsBuilder
        .UseSqlServer(@"Server=(localdb)\mssqllocaldb;Database=Blogging;Trusted_Connection=True;ConnectRetryCount=0")
        .UseLoggerFactory(ContextLoggerFactory);
}

ログ記録レベルが LogLevel.Information に設定されている場合、EF では、時間がかかったコマンドの実行ごとにログ メッセージを出力します。

info: 06/12/2020 09:12:36.117 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (4ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [b].[Id], [b].[Name]
      FROM [Blogs] AS [b]
      WHERE [b].[Name] = N'foo'

上記のコマンドでは 4 ミリ秒かかりました。 特定のコマンドに予想以上の時間がかかる場合は、パフォーマンス問題の考えられる原因を見つけ、それに集中して、実行速度が遅い理由を把握できます。 コマンド ログ記録では、予期しないデータベース ラウンドトリップが行われるケースも明らかにすることができます。これにより、1 つだけ必要な場合に複数のコマンドとして表示されます。

警告

通常、コマンド実行ログ記録を運用環境で有効にしたままにすることは適切でありません。 ログ記録自体がアプリケーションの速度を低下させ、サーバーのディスクをいっぱいにする可能性がある膨大なログ ファイルがすぐに作成される場合があります。 アプリケーションを慎重に監視しながら、データを収集するか、あるいは運用前システムでログ記録データを取り込む場合は、短期間だけログオンし続けることをお勧めします。

データベース コマンドと LINQ クエリの関連付け

コマンド実行ログ記録に関する問題の 1 つは、SQL クエリと LINQ クエリを関連付けるのが難しい場合があるということです。EF によって実行される SQL コマンドは、生成元の LINQ クエリとは非常に異なって見える場合があります。 この問題の解決に役立つように、EF のクエリ タグ機能を使用できます。これにより、小さな識別コメントを SQL クエリに挿入できます。

var myLocation = new Point(1, 2);
var nearestPeople = (from f in context.People.TagWith("This is my spatial query!")
                     orderby f.Location.Distance(myLocation) descending
                     select f).Take(5).ToList();

タグはログに表示されます。

-- This is my spatial query!

SELECT TOP(@__p_1) [p].[Id], [p].[Location]
FROM [People] AS [p]
ORDER BY [p].[Location].STDistance(@__myLocation_0) DESC

多くの場合、この方法でアプリケーションの主なクエリにタグを付け、コマンド実行ログをより迅速に読み取れるようにする価値があります。

パフォーマンス データを取り込むためのその他のインターフェイス

EF のログ記録機能には、コマンド実行時間を取り込むためのさまざまな代替手段があります。これはより強力な場合があります。 一般的に、データベースには独自のトレースおよびパフォーマンス分析ツールが備えられています。これにより、通常は単純な実行時間だけでなく、より豊富なデータベース固有の情報が提供されます。実際のセットアップ、機能および使用法は、データベースによって大きく異なります。

たとえば、SQL Server Management Studio は、SQL Server インスタンスに接続し、有用な管理およびパフォーマンス情報を提供できる強力なクライアントです。 詳細についてはこのセクションでは説明しませんが、説明する価値のある 2 つの機能として、(最もコストがかかるクエリを含む) サーバー アクティビティのライブ ダッシュボードを提供する アクティビティ モニターと、正確なニーズに合わせて調整できる任意のデータ キャプチャ セッションを定義できる拡張イベント (XEvent) 機能があります。 監視に関する SQL Server ドキュメントで、これらの機能や他の機能に関する詳細を説明しています。

パフォーマンス データを取り込むためのもう 1 つの方法は、DiagnosticSource インターフェイスを介して EF またはデータベース ドライバーによって自動的に出力された情報を収集してから、そのデータを分析するか、ダッシュボードに表示することです。 Azure を使用する場合、Azure Application Insights により、そのようなすぐに利用できる強力な監視機能が提供され、Web 要求の処理速度の分析にデータベースのパフォーマンスとクエリの実行時間が統合されます。 これについて詳しくは、Application Insights のパフォーマンスについてのチュートリアルに関するページと、Azure SQL 分析に関するページを参照してください。

クエリ実行プランの調査

最適化を必要とする問題のあるクエリを特定したら、次の手順では通常、クエリの ''実行プラン'' を分析します。 データベースでは、SQL ステートメントを受け取ると、一般的にそのプランをどのように実行するかを計画します。これには、定義されているインデックス、テーブルに存在するデータの量などに基づく複雑な意思決定が必要になる場合があります (ちなみに、最適なパフォーマンスを得るには通常、プラン自体をサーバーにキャッシュする必要があります)。 リレーショナル データベースでは一般的に、ユーザーがクエリ プランを表示する方法と、クエリのさままざまな部分に対して計算された見積もりが提供されます。これは、クエリを改善する上で非常に貴重です。

SQL Server で作業を開始する場合は、クエリ実行プランに関するドキュメントを参照してください。 一般的な分析ワークフローでは、SQL Server Management Studio を使用し、上記のいずれかの方法で特定された低速クエリの SQL を貼り付け、グラフィカル実行プランを生成します。

実行プランは最初は複雑に見えるかもしれませんが、少し時間をかけてよく理解する価値があります。 特に、プランの各ノードに関連付けられているコストに注意し、さまざまなノードでインデックスがどのように使用される (または使用されない) かを特定することが重要です。

上記の情報は SQL Server に固有のものですが、他のデータベースでも一般的に同様の視覚化を使用する同じ種類のツールが提供されます。

重要

データベースでは、データベース内の実際のデータに応じてさまざまなクエリ プランが生成される場合があります。 たとえば、テーブルに含まれている行がほんのわずかである場合、データベースでは、そのテーブルでインデックスを使用するのではなく、代わりにフル テーブル スキャンを実行するように選択できます。 テスト データベースでクエリ プランを分析する場合は、必ず運用システムに似たデータが含まれるようにしてください。

イベント カウンター

上記のセクションでは、コマンドに関する情報を取得する方法と、これらのコマンドをデータベースで実行する方法に重点を置きました。 それに加え、EF では、EF 自体の内部で起こっていること、およびアプリケーションでどのように使用されるかに関するより詳細な情報を提供する一連の ''イベント カウンター'' が公開されます。 これらのカウンターは、特定のパフォーマンスの問題やパフォーマンスの異常を診断するのに非常に役立つ場合があります。たとえば、一定の再コンパイルの原因となるクエリ キャッシュの問題や未処理の DbContext リークなどです。

詳細については、EF のイベント カウンターの専用ページを参照してください。

EF Core を使用するベンチマークの実行

1 日の終わりに、クエリを記述または実行する特定の方法が別の方法よりも速いかどうかを知る必要がある場合があります。 答えを想定したり推測したりしないことが重要です。簡単なベンチマークをまとめて答えを得るのは非常に簡単です。 ベンチマークを作成する場合は、よく知られている BenchmarkDotNet ライブラリを使用することを強くお勧めします。このライブラリでは、ユーザーが独自のベンチマークを作成しようとするときにはまる多くの落とし穴に対処します。たとえば、いくつかのウォームアップ イテレーションを実行したか、 ベンチマークで実際に実行されるイテレーションはいくつか、またその理由は何かなどです。 それでは EF Core を使用するベンチマークがどのようなものかを確認しましょう。

ヒント

以下のソースの完全なベンチマーク プロジェクトについては、こちらを参照してください。 それをコピーし、独自のベンチマークのテンプレートとして使用することお勧めします。

単純なベンチマーク シナリオとして、データベース内のすべてのブログの平均ランクを計算する次のさまざまな方法を比較しましょう。

• すべてのエンティティを読み込み、個々のランクを合計して、平均を計算する。
• 上記と同じだが、非追跡クエリのみを使用する。 ID 解決が実行されず、変更追跡のためにエディターのスナップショットが作成されないので、この方が速いはずです。
• ランクのみを投影して、Blog エンティティ インスタンス全体をまったく読み込まないようにする。 これにより、Blog エンティティ型の他の不要な列を転送する必要がなくなります。
• クエリの一部にすることで、データベースで平均を計算する。 すべてがデータベースで計算され、結果だけがクライアントに戻されるので、これが最も速い方法であるはずです。

BenchmarkDotNet を使用して、単体テストと同じように単純なメソッドとしてベンチマークされるコードを記述します。BenchmarkDotNet では自動的に各メソッドを実行して十分な数のイテレーションを行い、それにかかる時間と割り当てられるメモリの量を確実に測定します。 次にさまざまなメソッドを示します (完全なベンチマーク コードについては、こちらを参照してください)。

エンティティを読み込む

[Benchmark]
public double LoadEntities()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var blog in ctx.Blogs)
    {
        sum += blog.Rating;
        count++;
    }

    return (double)sum / count;
}

追跡なしで、エンティティを読み込む

[Benchmark]
public double LoadEntitiesNoTracking()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var blog in ctx.Blogs.AsNoTracking())
    {
        sum += blog.Rating;
        count++;
    }

    return (double)sum / count;
}

ランクのみを投影する

[Benchmark]
public double ProjectOnlyRanking()
{
    var sum = 0;
    var count = 0;
    using var ctx = new BloggingContext();
    foreach (var rating in ctx.Blogs.Select(b => b.Rating))
    {
        sum += rating;
        count++;
    }

    return (double)sum / count;
}

データベースで計算する

[Benchmark(Baseline = true)]
public double CalculateInDatabase()
{
    using var ctx = new BloggingContext();
    return ctx.Blogs.Average(b => b.Rating);
}

BenchmarkDotNet によって出力された結果を以下に示します。

メソッド	平均	エラー	StdDev	Median	比率	RatioSD	Gen 0	Gen 1	Gen 2	Allocated
LoadEntities	2,860.4 us	54.31 us	93.68 us	2,844.5 us	4.55	0.33	210.9375	70.3125	-	1309.56 KB
LoadEntitiesNoTracking	1,353.0 us	21.26 us	18.85 us	1,355.6 us	2.10	0.14	87.8906	3.9063	-	540.09 KB
ProjectOnlyRanking	910.9 us	20.91 us	61.65 us	892.9 us	1.46	0.14	41.0156	0.9766	-	252.08 KB
CalculateInDatabase	627.1 us	14.58 us	42.54 us	626.4 us	1.00	0.00	4.8828	-	-	33.27 KB

Note

メソッドにより、そのメソッド内のコンテキストがインスタンス化されて破棄されるため、これらの操作はベンチマークに対してカウントされます。しかし、厳密に言えば、これらはクエリ プロセスの一部ではありません。 これは、目標が 2 つの代替手段を互いに比較することである場合は問題ないはずです (コンテキストのインスタンス化と破棄が同じであるため)。これにより、操作全体をより総体的に測定できます。

BenchmarkDotNet の制限の 1 つは、指定したメソッドの単純なシングルスレッド パフォーマンスが測定されるため、同時実行シナリオのベンチマークには適していないことです。

重要

ベンチマークを行う場合は、必ずデータベース内のデータが運用データと似たものになるようにしてください。そうしないと、ベンチマークの結果が運用環境の実際のパフォーマンスを表さない可能性があります。