知っておくと便利な「Visual Studio 2012」によるドライバのトラブルシューティング：Windows 8 デバイスドライバ開発入門（2）（2/3 ページ）

» 2013年10月10日 10時00分 公開
[橋口友美（サイエンスパーク），MONOist]
前のページへ 1|2|3 次のページへ

3．トレースログ

　おそらく本稿を読んでいる方の多くが、アプリケーション開発経験者であると思います。アプリケーションを開発する際、保守機能としてDebug Build版にログを仕込むことが多いと思いますが、ドライバにも同様の機能が存在します。

　ログを出力したい箇所でKdPrint関数を呼び出すと、Checked Build版のみログ出力が可能となります。Free Build版には影響しません。

　ドライバのログは、BSOD以外の問題（デバイスを認識しない、デバイスとのデータ通信に失敗する……など）の発生時に、「どこでエラーが発生したか」「どのようなシーケンスで処理を行っていたか」を記録に残す意味でとても重要です。しかし、ログを大量に出力すると、ドライバのパフォーマンスに影響を及ぼし、タイミングが変わってしまいエラーが再現しなくなるという問題も起こり得ます。

　筆者にも以下のような経験があります。

  1. 客先から「ドライバ周りで問題が発生した！」と連絡が入る（先方でしか再現しない）
  2. すぐに、Checked Build版ドライバ（ログ出力用）を先方に送り、現象が再現したときのログを取得してほしいと依頼
  3. 客先で試してもらったところ、ドライバのログが大量に出過ぎて現象が再現しない
  4. 再度、ログを減らしたChecked Build版ドライバ（ログ出力用）を先方に送り、ログを取得してほしいともう一度依頼
  5. やはり、ログ出力によってタイミングが変わったせいで現象が再現しない……
  6. これ以上ログを減らすとシーケンスが分からなくなると焦り始める……
  7. 客先もイライラしはじめ、さらに焦り出す……
  8. 結局、再現環境一式を送ってもらうことになる

　こんな悩みを解決するのが、「ETW（Event Tracing for Windows）」と呼ばれるイベントトレース機能です。ETWを使用してログを取得するメリットは以下の通りです（Checked Build版ドライバを動かして、ログを取得する場合と比較して記述しています）。

（1）ドライバのパフォーマンスにほぼ影響しない
　Checked Build版ドライバを動かしてログを取得する場合、出力するログの量によってはドライバのパフォーマンスが悪くなり、PCの動作が重くなるケースがあります。例えば、データ通信エラーの解析のために、送受信データを全て出力する際、これが顕著になります。一方、ETWを使用してログを取得した場合、多少のタイミングのズレはありますが「PCの動作が重い」と感じるほどではありません。

（2）Releaseビルド版でもトレースログが表示される
　通常客先に納品するドライバはFree Build版のドライバです。Free Build版では“パフォーマンスに影響が出る”という理由から、ログ出力機能を無効にしておくことが多いのですが、ETWでは（1）で説明したように“パフォーマンスへの影響が少ない”というメリットがあります。そのため、Free Build版のドライバにもログ出力機能を追加でき、客先で何か問題が起きた場合でも、Checked Build版のドライバに差し替えてもらう必要がなくなるため、エンドユーザーの負担も軽減されます。

（3）エンドユーザーにログが見えない
　ETWのトレースログは、バイナリ形式で保存されます。そのため、一般的なテキストエディタでログファイルを開くことはできません。Checked Build版のドライバのように、出力したログを見て、ドライバの関数名などが分かってしまうこともありません。

（4）ログ取得のために、追加でアプリケーションをインストールする必要がない
　ETWのトレースログの取得開始／停止は、コマンドプロンプトから実行可能です。そのため、特別なツールをインストールする必要がありません。

（5）ダンプファイルからログの取り出しが可能
　トレースログ取得中にBSODが発生した場合でも、ダンプファイルからトレースログを取り出すことが可能です。そのため、BSOD発生時に、どのようなシーケンスで処理が行われたかについての情報も得られます。

　それでは、次にトレースログを有効にする手順を説明します。

3．1．イベントトレース機能を利用するための事前準備（実装）

　イベントトレース機能を有効にするためには、以下の事前準備が必要となります。

  1. GUIDとトレースフラグを定義
  2. ヘッダファイルと.tmhファイルをインクルード
  3. WPPプリプロセッサを追加
  4. トレースの初期化処理を追加
  5. トレースのクリーンアップ処理を追加
  6. トレースログ出力関数の呼び出し

1．GUIDとトレースフラグを定義
　まず、Visual Studio 2012上のGUID作成ツールにて、トレースログを識別するためのGUIDを取得します。Visual Studio 2012でドライバプロジェクトを開き、メニューの［ツール］―［GUIDの作成］を選択すると、以下のGUID作成ダイアログが表示されます。

GUIDの作成 図4　GUIDの作成

　取得後に、任意のヘッダファイルでGUIDとトレースフラグを定義します。

コード

　以下に、ヘッダファイルのサンプルを記述します。このままコピーして使用可能ですが、“KMDFSampleDriverTraceGuid, (C5D3D42C,739C,4070,A80B,7BFCE1809134)”の部分は変更してください。ちなみに、一番下の“// begin_wpp config”の部分も必要です。

// trace.h
// Define the tracing flags.
#define WPP_CONTROL_GUIDS                                                   \
    WPP_DEFINE_CONTROL_GUID(                                                \
        KMDFSampleDriverTraceGuid, (C5D3D42C,739C,4070,A80B,7BFCE1809134),  \
        WPP_DEFINE_BIT(TRACE_FLAG1)                                         \
        WPP_DEFINE_BIT(TRACE_FLAG2)                                         \
        WPP_DEFINE_BIT(TRACE_FLAG3)                                         \
        )
#define WPP_FLAG_LEVEL_LOGGER(flag, level)                                  \
    WPP_LEVEL_LOGGER(flag)
#define WPP_FLAG_LEVEL_ENABLED(flag, level)                                 \
    (WPP_LEVEL_ENABLED(flag) &&                                             \
     WPP_CONTROL(WPP_BIT_ ## flag).Level >= level)
#define WPP_LEVEL_FLAGS_LOGGER(lvl,flags) \
    WPP_LEVEL_LOGGER(flags)
               
#define WPP_LEVEL_FLAGS_ENABLED(lvl, flags) \
    (WPP_LEVEL_ENABLED(flags) && WPP_CONTROL(WPP_BIT_ ## flags).Level >= lvl)
// This comment block is scanned by the trace preprocessor to define our
// Trace function.
// begin_wpp config
// FUNC Trace{FLAG=MYDRIVER_ALL_INFO}(LEVEL, MSG, ...);
// FUNC TraceEvents(LEVEL, FLAGS, MSG, ...);
// end_wpp
//

2．ヘッダファイルと.tmhファイルをインクルード
　トレースログを出力する.cファイルごとに、1．で編集したヘッダファイル（trace.h）と、.cファイルと同名の.tmhファイル（注2）をインクルードします。

注2：.tmhファイル（Trace Message Header）は、トレース用のコードのビルドに必要な宣言や定義が入ったヘッダファイルで、ビルド時に自動生成される。



3．WPPプリプロセッサを追加
　この項目は、ドライバプロジェクトのプロパティから設定します。Visual Studio 2012でドライバプロジェクトを開き、メニューの［プロジェクト］―［XXXのプロパティ］でプロパティダイアログを表示させ、［構成プロパティ］―［Wpp Tracing］のツリーから以下の設定を行います。

  • ［General］― Run Wpp Tracing ⇒ ［はい］
  • ［Function and Macro Options］― Trace Kernel-Mode Components ⇒ ［はい］
  • ［File Options］― Scan Configuration Data ⇒ trace.h

WPPプリプロセッサを追加 図5　WPPプリプロセッサを追加

4．トレースの初期化処理を追加
　ドライバのエントリポイント（DriverEntry関数）にイベントトレースの初期化処理を追加します。初期化処理は以下のように記述します。

WPP_INIT_TRACING( DriverObject, RegistryPath);

5．トレースのクリーンアップ処理を追加
　ドライバのアンロード処理の部分にイベントトレースのクリーンアップ処理を追加します。クリーンアップ処理は以下のように記述します。

WPP_CLEANUP(pDevObj);

6．トレースログ出力関数の呼び出し
　トレースログを出力するには、先ほどのヘッダファイル（trace.h）で定義したTraceEvents関数を、トレースログを出力させたい位置に追加します。TraceEvents関数の呼び出しフォーマットは以下の通りです。

TraceEvents(LEVEL, FLAG, MSG,…);


TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_FLAG0, "%!FUNC! Entry");
入力例

　TraceEvents関数の第1引数の“TRACE_LEVEL_INFORMATION”は、「トレースレベル」と呼ばれるもので、ログの重要度を指定します。トレースレベルは、Windowsの標準ヘッダファイル（evntrace.h）内で定義されているため、自分で定義する必要はありません。以下が定義の内容です。

#define TRACE_LEVEL_NONE        0   // Tracing is not on
#define TRACE_LEVEL_CRITICAL    1   // Abnormal exit or termination
#define TRACE_LEVEL_FATAL       1   // Deprecated name for Abnormal exit or termination
#define TRACE_LEVEL_ERROR       2   // Severe errors that need logging
#define TRACE_LEVEL_WARNING     3   // Warnings such as allocation failure
#define TRACE_LEVEL_INFORMATION 4   // Includes non-error cases(e.g.,Entry-Exit)
#define TRACE_LEVEL_VERBOSE     5   // Detailed traces from intermediate steps
#define TRACE_LEVEL_RESERVED6   6
#define TRACE_LEVEL_RESERVED7   7
#define TRACE_LEVEL_RESERVED8   8
#define TRACE_LEVEL_RESERVED9   9

　以上で事前準備完了です。少々面倒に感じるかもしれませんが、一度行えばその後は6．を追加していくだけです。

　次に、実際にトレースログを出力させてみましょう。ドライバをインストール後、コマンドプロンプトから簡単に実行できます。

前のページへ 1|2|3 次のページへ

Copyright © ITmedia, Inc. All Rights Reserved.