Visual Studio 2015

  • [アーティクル]

IntelliTrace を使用して迅速に問題を診断する

Angelos Petropoulos

普段、デバッグする際のワークフローについて考えてみてください。問題の根本原因を特定できるまで延々と、ブレークポイントを設定し、問題再現のためのテスト ステップを繰り返していませんか。IntelliTrace を使用すると、デバッグ対象のアプリケーションを実行しながらデバッグ履歴情報を記録できるようになります。そのため、この果てしない反復作業から抜け出すことができます。問題再現のためのテスト ステップを 1 回実行した後は、デバッグ履歴を確認するだけで、根本原因を特定できます。

IntelliTrace は、Visual Studio 2015 Enterprise のデバッガーを拡張する、デバッグ履歴テクノロジの集合です。Visual Studio の外部で使用できるスタンドアロン コンポーネントもあります。IntelliTrace を使用すると、関心のあるイベントを調べながらアプリケーションの実行を記録できます。関心のあるイベントが発生すると、アプリケーションを実行したまま呼び出し履歴とローカル変数が自動的に記録されます。[Tools] (ツール) メニューの [Options] (オプション) をクリックすると表示される [IntelliTrace] ノードの [IntelliTrace Events] (IntelliTrace イベント) ノードを使用すれば、IntelliTrace によって "関心がある" と判断されたイベントを制御できます。

IntelliTrace は、タイムライン (イベントの概要) と各イベントの詳細を表示した表で、アプリケーションの実行履歴を示します。また、Visual Studio デバッガーを拡張して統合することで、デバッグ履歴データにアクセスできるようにもします。そのため、開発者は収集したイベントの呼び出し履歴やローカル変数を時間をさかのぼって確認できます。

Visual Studio 2015 で、IntelliTrace は診断ツール ウィンドウに表示されるようになりました。診断ツール ウィンドウには、IntelliTrace 以外に、CPU 使用率ツールとメモリ使用量ツールも表示されます。開発中のプロジェクトの種類とデバッグ構成がサポートされている場合 (最新情報については、aka.ms/diagtoolswindow (英語) を参照してください)、Visual Studio 2015 でデバッグを開始すると診断ツール ウィンドウが表示されます (F5 キーを押すことも、手動で [Debug] (デバッグ) メニューの [Show Diagnostic Tools] (診断ツールを表示) をクリックして任意のタイミングでウィンドウを開くこともできます)。デバッグ履歴をアクティブにすると、図 1 のような画面が表示されます。

IntelliTrace のデバッグ履歴
図 1 IntelliTrace のデバッグ履歴

UI を探る

IntelliTrace UI の各コンポーネントと、その目的や機能を紹介しましょう。

デバッガー イベント: デバッガー イベント詳細の表 (図 2 参照) には、IntelliTrace で収集したイベントが表形式で表示されます。表に表示される列は、左から順に次のとおりです。

  1. デバッガーに現在情報が表示されているイベントのポインター。現在の命令ポインターの位置を示す黄色い矢印が、1 行だけに表示されます。アクティブにしている履歴イベントを示すピンクの矢印が、いずれか 1 行に表示されることもあります。
  2. [デバッガー イベント] のタイムラインに表示されているイベントを示すためのアイコン。
  3. イベントの簡単な説明。
  4. デバッグ セッションを開始してからイベントを収集するまでに経過した秒数。
  5. イベントの期間 (注: すべてのイベントに期間があるわけではありません)。
  6. イベントを生成したスレッドの ID と名前 (注: すべてのイベントがスレッドに関連付けられているわけではありません)。

デバッガー イベントの表
図 2 デバッガー イベントの表

リスト内のイベントをクリックして展開し、[Activate Historical Debugging] (デバッグ履歴のアクティブ化) をクリックすると、選択したイベントが記録されている時点にデバッガーを設定できます。

カテゴリ フィルター コントロール: 収集中のイベント カテゴリを表示または非表示にします。特定のカテゴリに絞り込む必要がある場合、または関心のないカテゴリがある場合は、この機能を使用すると各カテゴリの表示と非表示を簡単に切り換えることができます。一覧で現在選択できるカテゴリには、ADO.NET、ASP.NET、コンソール、データバインディング、デバッガー、環境変数、例外、ファイル、ジェスチャ、遅延初期化、出力、レジストリ、サービス モデル、スレッド、トレース、ユーザー プロンプト、XAML などがあります。

スレッド フィルター コントロール: 生成元のスレッドごとに、イベントを表示または非表示にします。特定のスレッドのみを診断する場合、または特定のスレッドの実行には問題がないと思われる場合に使用します。

[Show Events from External Code] (外部コードから生成されたイベントの表示) ボタン: IntelliTrace ではデバッガーの "マイ コードのみ" 設定が優先されます。つまり既定では、関係ない情報を減らすために、非ユーザー コードから生成されたイベントは表示されません。[Show Events from External Code] (外部コードから生成されたイベントの表示) ボタンをクリックすると、デバッガーの設定が無効になり、外部コードから生成されたイベントが表示されます。ほとんどの場合、このボタンをクリックすると出力が詳細になります。

[デバッガー イベント] のタイムライン: IntelliTrace で収集したイベントのグラフィック表示です。このタイムラインには、デバッガー イベント詳細の表と同じ情報が、異なる観点から表示されます。タイムラインを使用すると、概要を把握でき、デバッガー イベント詳細の表で掘り下げる領域を特定して選択することができます。特定の時間範囲を選択することで、デバッガー イベント詳細の表に表示されている情報にフィルターを適用できます。

ルーラー: タイムラインの上には、各イベントが発生した時点を示すルーラーが表示されます。また、クリックしてドラッグすることで、特定の時間範囲を選択できます。時間範囲を選択することで、デバッガー イベント詳細の表にフィルターを適用できます。

Break Events (中断イベント) トラック: 中断に関連するイベントが発生するたびに、発生したイベントをこのタイムライン トラックに表示します。中断イベントには、ブレークポイントの到達、ステップの完了、[Break All] (すべて中断) のクリック、Debugger.Break の呼び出し、ハンドルされない例外による実行中断などがあります。Break Events (中断イベント) トラックは、プログラムの実行中に他のトラックのイベントが発生した時点を特定しやすくする、マスター タイムライン トラックと言えます (ブレークポイントとステップでアプリケーションの実行を制御するため)。Break Events (中断イベント) トラックのイベントをクリックすると、デバッガー イベント詳細の表のイベントに時間フィルターが適用されます。このように、あるコード行をステップ オーバーしたときに発生したイベント、または F5 キーを押してからブレークポイントに達するまでの間に発生したイベントだけが表示されるように、簡単にフィルターを適用できます。

Output Events (出力イベント) トラック: 出力ウィンドウに表示されるメッセージに対応するイベントを表示します。このトラックに表示されるイベント カテゴリには、スローされた例外、プログラム出力 (または Console.WriteLine)、読み込まれたモジュール、アンロードされたモジュール、スレッドの終了、プロセスの終了などがあります。これによって、標準的なデバッグ出力メッセージをデバッガーの他の履歴情報に関連付けることができます。

IntelliTrace イベント トラック: IntelliTrace で収集した、その他のイベント カテゴリを表示します。表示されるイベント カテゴリには、ADO.NET、ASP.NET、コンソール、データ バインディング、環境変数、ファイル、ジェスチャ、遅延初期化、レジストリ、サービス モデル、スレッド、トレース、ユーザー プロンプト、XAML などがあります。

診断ツール ツール バー: [Zoom In] (ズームイン) ボタンと [Zoom Out] (ズームアウト) ボタンに加えて、[Reset View] (表示のリセット) ボタンが表示されます。[Reset View] (表示のリセット) ボタンをクリックすると、[デバッガー イベント] のタイムラインが既定のズーム レベルに戻り、時間範囲の選択が解除されます。つまり、収集したデータがすべて表示されます。[Select Tools] (ツールの選択) ボックスをクリックすると、IntelliTrace と共に診断ツール ウィンドウに表示するツールを選択できます。

同時に複数の診断ツールを実行できます。診断ツール ウィンドウには、メモリ使用量ツール、CPU 使用率ツール、および IntelliTrace ツールをすべて同時にホストできます。そのため、アプリケーションの動作の全体像を把握できます。たとえば、図 3 は、ASP.NET アプリケーションの起動時に発生する一連のモジュール読み込みイベントによって、メモリ使用量と CPU 使用率が増加するようすを示しています。

アプリケーションの動作とパフォーマンスを表示している診断ツール ウィンドウ
図 3 アプリケーションの動作とパフォーマンスを表示している診断ツール ウィンドウ

実際のバグを IntelliTrace で修正する

ここからは、Visual Studio 2015 Enterprise の IntelliTrace ライブ デバッグ機能を使用して、実際のバグを修正する方法を説明していきましょう。デバッグ対象のアプリケーションは、CodeProject で公開されている SocialClub という名前の Windows フォーム アプリケーションです。

このアプリケーションは、社交クラブのメンバーのデータベースを管理するアプリケーションです。修正するバグは、メンバー登録後に検索が正常に動作しなくなるというバグです。このバグを再現するために、SocialClub を起動して新しいメンバーを 1 人登録します。次に、"すべて取得" 検索を実行すると、正常であれば登録済みの全メンバーが返されるはずです。予期する検索結果は 1 件だけですが、実際には 2 件の結果が返されます (図 4 参照)。2 つ目の検索結果は予期しない結果なので、この検索結果を修正する必要があります。

予期しないレコードが含まれている "すべて取得" 検索の結果
図 4 予期しないレコードが含まれている "すべて取得" 検索の結果

バグを修正するには、次に何をすればよいでしょうか。この時点で立てた仮説は、"すべて取得" 検索機能に問題があるか、新しいメンバーの登録プロセスに問題があることです。SocialClub には、具体的な検索条件を指定できる別の検索モードがあるので、この検索モードを使用して、"すべて取得" 検索で返された予期しないレコード (指定されていないデータや Unknown 値が含まれているレコード) を検索します。

考えられるシナリオは、次のとおりです。検索結果がまったく返されない場合、予期しないレコードはおそらくデータベースに存在していないので、"すべて取得" 検索機能に問題があります。Occupation と MaritalStatus の値が Unknown のレコードが検索結果として返された場合は、本来の件数よりも多くのレコードがデータベースに入力されるメンバー登録機能におそらく問題があります。

そこで、Occupation と MaritalStatus の条件値にそれぞれ Unknown を指定して検索すると、検索結果が 1 件だけ返されます。このレコードは、Occupation の値を Engineer に、MaritalStatus の値を Married に指定して、正常に登録したレコードです。これは奇妙なことです。しかも残念なことに、この結果を基にしてバグの根本原因にそれ以上近づくことはできません。ブレークポイントを設定し、新しいメンバーを登録して、そのレコードを検索する作業を何回も繰り返すことに時間を費やす代わりに、IntelliTrace を使用するとこの調査をどれほど円滑に進められるかについてを説明しましょう。

IntelliTrace で収集したイベントを確認する必要がありますが、デバッガーがアプリケーションの実行を中断するまで (つまりブレークポイントに達するまで)、IntelliTrace イベントは更新されません。特に関心のあるブレークポイントはないので、Visual Studio のツール バーにある [Break All] (すべて中断) をクリックします。これで SocialClub がブレーク状態になり、すべてのスレッドが中断されます。IntelliTrace で収集したデータが、診断ツール ウィンドウのタイムラインと詳細表示の表の両方に表示されます。

デバッグを開始してからこの時点までに、SocialClub で実行した操作はかなりの量に上ります。ログインし、新しいメンバーを登録し、"すべて取得" 機能で検索し、具体的な条件を指定して検索しました。しかし、関心のあるイベントは、[Register] (登録) のクリックに対する直接の結果として発生したイベントだけです。そのようなイベントだけが表示されるようにフィルターを適用するには、[デバッガー イベント] のタイムラインに表示されている各イベントをポイントして、[Register] をクリックした時点を見つけます。次に、一連のイベントをドラッグして選択します。時点を選択してから詳細表示の表を参照すると、表示されているうちで ([Break All] (すべてを中断) のクリックを除いた) 直近のイベントが、2 つの INSERT ステートメントであるとわかります (図 5 参照)。

選択した時間範囲のイベントが表示されるようにフィルターを適用した詳細表示の表
図 5 選択した時間範囲のイベントが表示されるようにフィルターを適用した詳細表示の表

表示されているイベントのいずれかをクリックすると、複数行に展開されて、実行された SQL ステートメント全体が表示されます。2 つの INSERT ステートメントが発生しているのがわかり、2 つ目の INSERT ステートメントでは、NULL 値を含む無効なレコードを挿入しています。2 つの SQL ステートメントは以下のとおりです。

Execute Reader "insert [dbo].[ClubMembers]([Name], [DateOfBirth],
  [Occupation], [Salary], [MaritalStatus], [HealthStatus], [NumberOfChildren],
  [ExpirationDate])values (@0, @1, @2, @3, @4, @5, @6, @7)
  select [Id] from [dbo].[ClubMembers] where @@ROWCOUNT > 0 and [Id] =
  scope_identity()"
Execute Reader "insert [dbo].[ClubMembers]([Name], [DateOfBirth],
  [Occupation], [Salary], [MaritalStatus], [HealthStatus], [NumberOfChildren],
  [ExpirationDate])values (null, @0, @1, null, @2, @3, null, @4) select [Id] from
  [dbo].[ClubMembers] where @@ROWCOUNT > 0 and [Id] = scope_identity()"

INSERT ステートメントの後の SELECT ステートメントは無視してかまいません。これは、挿入したレコードの ID を Entity Framework で取得する処理です。次に検討する点は、[Register] (登録) ボタンを 1 回クリックすると 2 つの SQL ステートメントが実行されるのはなぜかという疑問です。IntelliTrace を使用すれば、この疑問にはすぐに答えが出ます。各イベントのデバッグ履歴をアクティブにし (図 6 参照)、それぞれに対応する呼び出し履歴を呼び出し履歴ウィンドウで確認します。

最初の INSERT ステートメント (2 つの INSERT ステートメントのうち) のデバッグ履歴のアクティブ化
図 6 最初の INSERT ステートメント (2 つの INSERT ステートメントのうち) のデバッグ履歴のアクティブ化

最初の INSERT ステートメントの呼び出し履歴は、次のとおりです。

John.SocialClub.Data.dll!John.SocialClub.Data.Service.ClubMemberService.Create(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.Membership.Manage.RegisterMember()
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.Membership.Manage.Register_Click(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Program.Main()

レコードが無効な 2 つ目の INSERT ステートメントの呼び出し履歴は、次のとおりです。

John.SocialClub.Data.dll!John.SocialClub.Data.Service.ClubMemberService.Create(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.Membership.Manage.RegisterMember()
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.Membership.Manage.btnRegister_MouseClick(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Program.Main()

各フレームをクリックすると、対応するコード行を参照できます。2 つの呼び出し履歴を調べると、Register_Click(…) と btnRegister_MouseClick(…) という 2 つのイベント ハンドラーで同一のボタン クリックをサブスクライブしてることがわかります。この 2 つのイベント ハンドラーのコードを読むと、最初のイベント ハンドラーは新しいメンバーを登録するたびにフォームのフィールドをリセットするので、データベースにレコードが正しく挿入されているとすぐに推論できます。しかし、2 つ目のイベント ハンドラーは空白のフィールドと NULL フィールドを含むレコードを挿入しています。このように、[Break All] (すべて中断) を使用して迅速にバグを発見し、続いて IntelliTrace を使用して問題を引き起こしているコードを特定することができました。

IntelliTrace イベントでは発見できないバグに対処する

現時点では、IntelliTrace を利用するとデバッグ方法を強化できることに興奮する一方で、バグの根本原因を特定する手掛かりとなる関心のあるイベントを IntelliTrace で記録できない場合はどうすればよいのだろうと考えている方もいらっしゃるでしょう。原因を特定できる見込みはないのでしょうか。いいえ、そんなことはありません。既に述べたように、[Tools] (ツール) メニューの [Options] (オプション) をクリックすると表示される [IntelliTrace] ノードの [IntelliTrace Events] (IntelliTrace イベント) ノードを使用すれば、どの IntelliTrace イベントを有効にするか制御できます。すべてのイベントが既定で有効なわけではありません。しかし、すべてのイベントを有効にしても、一部の厄介なバグに対しては必ずしも十分な対策とは言えません。

こうした難しい問題については、IntelliTrace を構成して、イベントだけでなく各メソッド呼び出しとそのパラメーターも記録することができます。[Tools] (ツール) メニューの [Options] (オプション) をクリックすると表示される [IntelliTrace] ノードで、[IntelliTrace events and call information] (Intellitrace イベントと呼び出し情報) ボックスをクリックするだけです。これは強力なデバッグ機能ですが、実行時のコストが生じます。この設定を有効にすると、IntelliTrace ですべてのメソッド呼び出しを取得して記録するので、アプリケーションのパフォーマンスに影響します。そのため、既定ではメソッド呼び出しを収集しません。IntelliTrace の設定で開発者が有効化を選択する必要があります。

メソッド呼び出しの情報を表示して確認する方法は、2 つあります。1 つ目の方法では、デバッガー イベント詳細の表の [Calls] (呼び出し) ビューを使用できます。このビューには、記録されたすべての呼び出しが表示されます ([Calls] (呼び出し) ビューの詳細については、aka.ms/itracecalls (英語) を参照してください)。もう 1 つの方法は、イベントのデバッグ履歴をアクティブにし、テキスト エディターの IntelliTrace コントロールを使用して、アプリケーションの実行を前後に移動することです。IntelliTrace コントロールは、コードと命令ポインターのような機能です。そのため、IntelliTrace を使用するとすべてのライブ デバッグ シナリオに対応できます。

開発者のコンピューターで再現できないバグに対処する

このようなバグに対処するには、IntelliTrace による "非ライブ デバッグ"が便利です。ここまでの説明では、デバッグしている問題の再現に必要な手順がわかっていることを前提としていました。しかし、常に手順がわかっているとは限りません。特に難しくて時間がかかるバグの例としては、再現のための正確な手順がわからないバグを挙げられます。IntelliTrace を使用すると、運用環境でもテスト環境でもアプリケーションの実行を記録できるため、この厄介な "再現できない" シナリオをなくすことができます。バグを再現できたら、開発用コンピューターでバグをデバッグできます。そのためには、この記事で解説してきた診断ツール ウィンドウを使用して、収集した情報を調査します。

IntelliTrace には、Visual Studio を接続できない他の環境に配置できる、スタンドアロン コレクターもあります。インストール処理を実行しないので、管理者の抵抗を受ける心配は不要です。ターゲット環境にコレクターをコピーできるかどうかかどうかだけが問題です。コレクターでは、アプリケーションの実行が .itrace ファイルに記録されます。開発者はこのファイルを開発コンピューターに転送して Visual Studio で開くことができます。このシナリオは、デバッグ中にアプリケーションの実行を制御できないので、"非ライブ デバッグ" と呼ばれます。IntelliTrace スタンドアロン コレクターの使用法に関する最新情報については、aka.ms/itracecollector (英語) を参照してください。

まとめ

IntelliTrace が刷新され、診断ツール ウィンドウに統合されたことで、魅力的な可能性が開けました。こうした新機能や、その他の診断関連機能に関する最新情報については、aka.ms/DiagnosticsBlog (英語) を参照してください。

Angelos Petropoulos は、Visual Studio チームのシニア プログラム マネージャーを務めています。オブジェクト指向ソフトウェア エンジニアリングの修士号を取得した後は、英国で IT コンサルタントとして働きました。その後、米国に移住した後で、Visual Studio の診断ツール チームに加わりました。現在は、IntelliTrace に関するプロジェクト マネージャーを務めています。

この記事のレビューに協力してくれたマイクロソフト技術スタッフの Andrew Hall、Daniel Moth、Dan Taylor、および Charles Willis に心より感謝いたします。