次の方法で共有

データ ポイント

  • [アーティクル]

Entity Framework でのデータベース アクティビティのプロファイリング

Julie Lerman

コード サンプルのダウンロード

Julie Lerman先月のコラム (msdn.microsoft.com/magazine/gg309181) では、Entity Framework と SQL Azure のパフォーマンスのプロファイリングについて説明しました。今月は、クエリのプロファイリングという種類の異なるプロファイリングについて見ていきます。この種のプロファイリングでは、Entity Framework でのクエリやその他のデータ アクセス アクティビティに応答してデータベースで実行されるクエリやコマンドを確認します。

Entity Framework には、挿入、更新、削除だけでなく、もう 1 つの優れた機能として、データベース クエリを実行するためのコマンドを生成する機能があります。この機能は多くの開発者に非常に大きなメリットをもたらします。ただし、オブジェクト リレーショナル マッピング (ORM) ツールによって生成される SQL の品質と、専門家が記述する SQL の品質の違いについては、常に議論が交わされます (ここでは、こうした議論については触れないでおきましょう)。大部分において、生成される SQL はかなり優れています。特に、LINQ to Entities または Entity SQL のクエリ式に対してどの程度工夫を凝らすかではなく、汎用的な方法で動的に作成しなければならない点を考慮すれば、生成される SQL の品質は納得できるものです。

Entity Framework 4 で生成されるコマンドの品質が向上したことには多くの注目を集めましたが、それでも、データベースで何が行われているかに注意を払うことは重要です。生成されるストア クエリの品質は、全体から見ればほんの一部にすぎません。データベースの実行時間を引き延ばしたり、データベースとのやり取りの回数を異常に多くしたりするコードを記述しているかもしれません。アプリケーションのプロファイリングを行うときは、このような点に注意することも重要です。

Entity Framework がリリースされてから最初の数年間は、SQL Server Profiler などのデータベース プロファイリング ツール以外に使用できるものはありませんでした。SQL Server Profiler は有効なツールですが、見やすい形式で結果を表示するには多くの構成とマイニングが必要です。ここからは、こうしたデータベース プロファイリング ツールよりも優れている、Entity Framework のクエリ プロファイリングのさまざまなオプションを紹介していきます。

Entity Framework の ObjectContext.ToTraceString メソッド

Entity Framework API (3.5 および 4) には、ToTraceString という実行時にクエリを調べる 1 つのメソッドがあります。このメソッドは便利ですが、データベースに対して行われる呼び出しに関して一部しか情報を提供しません。ToTraceString は ObjectQuery のメソッドであるため、LINQ to Entities クエリを記述する場合は、クエリを ObjectQuery にキャストしてから ToTraceString メソッドを呼び出す必要があります。次に例を示します。

var query = from c in context.Customers where c.CustomerID == 3 select c;
var objectQuery=query as System.Data.Objects.ObjectQuery;
Console.WriteLine(objectQuery.ToTraceString());

このコードからは、次の文字列が出力されます。

SELECT
[Extent1].[CustomerID] AS [CustomerID],
[Extent1].[Title] AS [Title],
[Extent1].[FirstName] AS [FirstName],
[Extent1].[MiddleName] AS [MiddleName],
[Extent1].[LastName] AS [LastName],
[Extent1].[Suffix] AS [Suffix],
[Extent1].[CompanyName] AS [CompanyName],
[Extent1].[SalesPerson] AS [SalesPerson],
[Extent1].[EmailAddress] AS [EmailAddress],
[Extent1].[Phone] AS [Phone],
[Extent1].[ModifiedDate] AS [ModifiedDate],
[Extent1].[TimeStamp] AS [TimeStamp]
FROM [SalesLT].[Customer] AS [Extent1]
WHERE 3 = [Extent1].[CustomerID]

このコード サンプルではクエリを実行していません。また、ToTraceString メソッドでもクエリは実行されません。ToTraceString メソッドに起因して、System.Data.SqlClient データベース プロバイダーの支援を受ける Entity Framework によってクエリが処理 (ストア クエリに変換) されますが、データベースでそのクエリが強制的に実行されることはありません。

ToTraceString メソッドは、明示的に定義されたクエリでのみに使用できます。そのため、Load メソッドによる遅延読み込みの結果として実行されるクエリを、ToTraceString メソッドを使用して確認することはできません。また、挿入、更新、削除、ストアド プロシージャの実行などのアクティビティを調べることもできません。

最後に重要な点として、デバッガー ビジュアライザーを作成するなどしても、ToTraceString メソッドの結果をデバッグ処理に渡すことは容易ではありません。これを行うには、ObjectQuery がシリアル化可能にする必要がありますが、それは不可能です。

Visual Studio 2010 IntelliTrace によるプロファイリング

IntelliTrace は Visual Studio 2010 Ultimate には付属していますが、それ以外のエディションには付属していません。IntelliTrace は、Entity Framework によってトリガーされるデータベース アクティビティなどのアクティビティをキャプチャしますが、コマンドと共に送信されたパラメーター値は表示しません。

以下のタスクを実行するとし、そのコードを示します。

  1. 10 人の顧客のクエリを実行する
  2. 最初に返された顧客の注文の遅延読み込みを行う
  3. 遅延読み込みを無効にする
  4. 2 番目に返された顧客の注文を明示的に読み込む
  5. 顧客を変更する
  6. SaveChanges メソッドを使ってデータベースに変更を送信する
  7. Entity Data Model でストアド プロシージャにマップしている関数を実行する
var query = from c in context.Customers select c;
var custList = query.Take(10).ToList();

Customer custFirst = custList[0];
int orderCount = custFirst.Orders.Count; 

context.ContextOptions.LazyLoadingEnabled=false;
Customer custSecond = custList[1];
custSecond.Orders.Load(); 

custSecond.ModifiedDate = DateTime.Now;
context.SaveChanges(); 

ObjectResult<PartialOrderDetails> orders= 
  context.GetCustomerOrdersForId(custList[2].CustomerID);

このコードを実行すると、データベースのストアド プロシージャに対して、3 つの SELECT ステートメント、1 つの UPDATE ステートメント、および 1 つの Execute コマンドが実行されます。

図 1 に示す IntelliTrace のスクリーンショットを見てください。上記の 5 つのコマンドがすべて表示されています。

image: A Series of Database Commands Displayed in the Visual Studio IntelliTrace Display

図 1 Visual Studio IntelliTrace 画面に表示される一連のデータベース コマンド

しかし、これらの項目の 1 つを展開すると、コマンドは表示されますが、パラメーターは表示されません (図 2 参照)。

image: A Detailed Select Statement Collected by the Visual Studio 2010 IntelliTrace Feature

図 2 Visual Studio 2010 IntelliTrace 機能によって収集された Select ステートメントの詳細情報

このため、パラメーターを含むデータベース アクティビティを確認する場合は、なんらかの外部プロファイラーを使用する必要があります。

MSDN コード ギャラリーの EFTracingProvider

Jarek Kowalski は、マイクロソフトの Entity Framework チームに所属していたときに EFTracingProvider を作成しました。EFTracingProvider には、Microsoft .NET Framework 3.5 用と .NET Framework 4 用のバージョンがそれぞれあります。

EFTracingProvider を使用するには、AWEntities という ObjectContext クラスのラッパーを作成し、この AWEntities を適切な箇所で使用する必要があります。この拡張クラスには、コンテキストのアクティビティをログに記録するために使用できるトレース メソッド (Log など) が用意されています。EFTracingProvider のダウンロードには、必須のクラス ラッパーの例も付属しています。また、このコラムのダウンロード (code.msdn.microsoft.com/mag201012DataPoints、英語) にも、関連コードを用意しています。また、アプリケーションの構成ファイルに 2 つの DbProviderFactories 設定を追加する必要があります。以上の準備を行うと、拡張コンテキストのインスタンスを作成し、ログ記録を開始できます。

ログ イベントをキャプチャするテキスト ファイルを作成し、TracingProvider.Log メソッドを使用してすべてのアクティビティをログ記録する例を以下に示します。

using (TextWriter logFile = File.CreateText("sqllogfile.txt"))
{
  using (var context = new ExtendedAWEntities())
  {
    context.Log = logFile;
    var query = from c in context.Customers select c;
    var custList = query.Take(10).ToList();
  }
  Console.WriteLine(File.ReadAllText("sqllogfile.txt"));
}

TracingProvider ラッパーと ExtendedAWEntities コンテキスト クラスを使用して、前述の IntelliTrace の例と同じコード セットを再実行します。

5 つのデータベース コマンドがすべてログに記録され、各コマンドが関連パラメーターと共に記録されます。

例として、遅延読み込みの結果として送信されるコマンドを図 3 に示します。ここでは、EntityKeyValue1 パラメーターの値がコマンドがリストされた後に示されています。

図 3 EFTracingProvider によってキャプチャされたコマンド

  SELECT
  [Extent1].[SalesOrderID] AS [SalesOrderID],
  [Extent1].[OrderDate] AS [OrderDate],
  [Extent1].[DueDate] AS [DueDate],
  [Extent1].[OnlineOrderFlag] AS [OnlineOrderFlag],
  [Extent1].[SalesOrderNumber] AS [SalesOrderNumber],
  [Extent1].[PurchaseOrderNumber] AS [PurchaseOrderNumber],
  [Extent1].[AccountNumber] AS [AccountNumber],
  [Extent1].[CustomerID] AS [CustomerID],
  [Extent1].[BillToAddressID] AS [BillToAddressID],
  [Extent1].[CreditCardApprovalCode] AS [CreditCardApprovalCode],
  [Extent1].[SubTotal] AS [SubTotal],
  [Extent1].[Comment] AS [Comment],
  [Extent1].[ModifiedDate] AS [ModifiedDate],
  [Extent1].[ShipDate] AS [ShipDate]
  FROM [SalesLT].[SalesOrderHeader] AS [Extent1]
  WHERE [Extent1].[CustomerID] = @EntityKeyValue1
  -- EntityKeyValue1 (dbtype=Int32, size=0, direction=Input) = 1

EFTracingProvider は実装が簡単で、Entity Framework コードによって生成されるすべてのデータベース コマンドが、未加工のテキストとして提供されます。また、このコンテキストの CommandExecuting、CommandFinished、および CommandFailed というトレース イベントをサブスクライブすることもできます。これにより、未加工の DbCommand が実行される直前および直後にその DbCommand にアクセスできるため、他の詳細を分析またはログ記録できます。

EFTracingProvider は、MSDN コード ギャラリー (code.msdn.microsoft.com/EFProviderWrappers、英語) から無償でダウンロードできます。その際、EFCachingProvider、およびこれらの機能をすべて調査できる EFProviderWrapperDemo というサンプル ソリューションも一緒にダウンロードできます。

サード パーティ製プロファイラー

とはいえ、EFTracingProvider のログ ファイルの未加工のテキストでは物足りません。EFTracingProvider のログ ファイルのコードを応用したり学習したりすることができます。しかし、このような応用や学習を行ってくれるツールを利用することもできます。Entity Framework のクエリのプロファイリングを行う 2 つのサード パーティ製ツールとして、Hibernating Rhinos の Entity Framework Profiler と Huagati の Huagati Query Profiler があります。

また、LINQPad というツールもありますが、これはアプリケーションの外部でクエリ式をテストすることに注目し、実行中の式の SQL を表示します。LINQPad はさまざまなプロバイダーに対して LINQ を記述することになる開発者には欠かせないツールですが、アプリケーションによって生成されるクエリのプロファイリングを行うことはできないため、ここではこれ以上説明しません。

Entity Framework Profiler (EF Prof) は、Hibernating Rhinos UberProf プロファイラー ファミリに含まれています (hibernatingrhinos.com/products/UberProf、英語)。この他にも nHibernate プロファイラー、Hibernate プロファイラー、および LINQ to SQL プロファイラーがあります。もう 1 つ LLBLGen Pro プロファイラーがありますが、このコラムの執筆時点ではベータ版です。EF Prof では、他の UberProf ツールから派生される既存の知的財産が、EFTracingProvider から集めたいくつかのアイデアと統合されます。最も単純な例としては、1 行のコードをアプリケーションに追加し、アプリケーションと EF Prof のエンジンとの対話を可能にして、結果を EF Prof クライアント アプリケーションに報告します。このコードを以下に示します。

HibernatingRhinos.Profiler.  
    Appender.EntityFramework.
    EntityFrameworkProfiler.Initialize

データベース アクティビティは、ObjectContext インスタンスによってグループ化されます。図 4 には、2 つの ObjectContext インスタンスが表示されています。これは、コード サンプルを 2 回実行したためです。

image: The EF Prof Query Profiler UI

図 4 EF Prof Query Profiler の UI

また、図 4 では、選択したコンテキスト インスタンスのそれぞれのデータベース呼び出しのプレビューが右側に表示されています。UPDATE コマンドの後に SELECT ステートメントが追加で呼び出されています。実のところ、これは SaveChanges メソッドと共に送信されるコマンドの一部です。ここでは、Entity Framework によって、Customer 行の更新された TimeStamp フィールドが Customer インスタンスに返されることが確認されます。

UI の SQL ステートメントが強調表示されているため、画面下部にその完全な SQL と、値 (この場合は 5) が @EntityKeyValue1 というパラメーターとして渡されたことが示されています。

また、EF Prof では、クエリの結果として生成される行、およびデータベース クエリ プランも表示できます。図 5 に示されている [Stack Trace] (スタック トレース) タブでは、アプリケーションによって特定のコマンドが実行される経緯を確認し、Visual Studio のそのコード行に直接移動することができます。

image: The EF Prof Stack Trace Lets You Jump to the Code that Executed the Selected Database Command

図 5 選択したデータベース コマンドを実行したコードに移動できる EF Prof の [Stack Trace] (スタック トレース) タブ

EF Prof では、Entity Framework でのアプリケーションのアクティビティをすべてキャプチャすることができ、キャプチャしたアクティビティをクエリ プラン ビューなどの優れたビューや、操作しやすい UI にも表示して、実行中のコードにリンクします。EF Prof の標準ライセンスは305 ドルですが、複数のライセンスと 1 つのサブスクリプション プランを購入すると割引があります。EF Prof はいずれかの Entity Framework のデータ プロバイダーと連携するため、対象は SQL Server に限定されません。.NET Framework Version 3.5 および 4 に対応しています。

Huagati Query Profiler (旧称 L2S Profiler) は、Entity Framework 4 のサポートを追加するように 11 月に更新されました。Huagati Query Profiler を使用して LINQ to SQL および LLBLGen Pro のプロファイリングを行うこともできますが、現在は SQL Server とのみ連携します。

Query Profiler の実装に必要な作業は、アプリケーションからプロファイラーのアセンブリ (Huagati.EFProfiler.dll) を参照し、部分クラスの ObjectContext クラスに 2 つの新しいコンストラクターとその他いくつかロジックを追加する程度です。図 6 に、AWEntities クラスに対して作成した部分クラスを示します。

図 6 Huagati Query Profiler で使用する部分クラス

string profilerOutput =
      System.IO.Path.Combine(System.Environment.GetFolderPath(
        Environment.SpecialFolder.Personal),
      @"EFProfiler\Samples");
    _profiler=new HuagatiEFProfiler.EFProfiler(this, profilerOutput, null, 
      HuagatiEFProfiler.ExecutionPlanMode.Actual, false);
   _profiler.LogError += EFProfiler_LogError;
  }
}

EFProfiler.GetConnection メソッドは、データベースにフックしてアクティビティを追跡します。EFProfiler のインスタンスを作成する際に使用できるさまざまな設定の詳細については、Huagati Web サイトを参照してください。

Huagati Query Profiler は、データを収集し、指定されたフォルダー内のファイルに出力します。その後、プロファイラーの Log Explorer でそのファイルを開くことができます (図 7 参照)。

image: The Huagati Entity Framework Query Profiler UI

図 7 Huagati の Entity Framework Query Profiler の UI

図 7 に示すように、5 つのデータベース要求がすべて収集されています。Update コマンドは SELECT コマンドと組み合わされて、TimeStamp を返します。これがまさに、コマンドがデータベースに送信されるしくみです。

図 7 の Log Explorer には、SQL Server SQL Profiler データの関連行が表示されます。EF Prof と同様、クエリをパラメーターと共に表示し、[Stack] (スタック) ビューでアプリケーションの関連コード行にリンクして、実行プランとクエリに関する統計情報をいくつか表示することができます。

各コンテキスト インスタンスのデータベース アクティビティは個別のログ ファイルに格納されるため、Log Explorer には一度に 1 つのコマンド セットしか表示されません。[Settings] (設定) タブでは、異常な動作状況 (注意または警告に値する実行時間の長い処理など) を強調し、警告を色分け表示します。

Huagati Query Profiler の UI は EF Prof の UI ほど優れているわけではないため、(アプリケーションの各 ObjectContext にロジックを追加して) やや慎重にコードを調べる必要があります。ただし、コンポーネントは配布可能です。つまり、クライアントの環境で実行しているアプリケーションのプロファイラー情報を収集できます。また、Huagati Query Profiler には EF Prof ほど多くの分析オプションはありません。しかし、Standard の店頭表示価格は 20 ドルで、Professional でも 40 ドル (3 つのプロファイラーをすべて含みます) なので、多くの開発者にこうした違い以上の価値をもたらします。Huagati の Entity Framework Query Profiler は、今回の調査時点ではまだベータ版であったこと、および Entity Framework をサポートするいずれかの使用可能な ADO.NET データ プロバイダーで機能する EF Prof の機能とは異なり SQL Server でしか機能しない点に留意してください。

Huagati の Entity Framework のサポートの概要については、tinyurl.com/26cfful (英語) を参照してください。このブログ記事の最後に、ベータ版 1.31 のダウンロード リンクが掲載されています。

仕事に適したツール

仕事に適したツールを使用することが重要だと強く信じています。他にも優れたツールを使用できるのに、Visual Studio 2010 の機能にこだわるのはもったいないことです。今月のコラムでは、Entity Framework API と Visual Studio 2010 に組み込まれている数々のツール、未加工のデータを提供する拡張機能、およびデータ収集だけでなく表示も行う 2 つのサード パーティ製ツールについて説明しました。前述のどの方法を選択しても、たとえ単に SQL Server Profiler を使用する場合でも、アプリケーションのプロファイリングを行うときにデータベースを軽く見てはいけません。

Julie Lerman は、バーモント ヒルズ在住の Microsoft MVP、.NET の指導者、およびコンサルタントです。世界中のユーザー グループやカンファレンスで、データ アクセスなどの Microsoft .NET トピックについてプレゼンテーションを行っています。彼女のブログは thedatafarm.com/blog (英語) で、彼女が執筆した『Programming Entity Framework』(O'Reilly Media、2010 年) は絶賛を浴びました。彼女には Twitter.com (julielermanvt、英語) から連絡できます。

この記事のレビューに協力してくれた技術スタッフの Jarek Kowalski に心より感謝いたします。