USB Event Tracing for Windows 7

--- UPDATE 2010/07/09 ---

2010/06/24 に Network Monitor v3.4 がリリースされました。これに伴い、USBHUB / USBPORT の Parser ファイルはデフォルトで組み込まれることになり、Codeplex より Parser をダウンロードし、手動で追加する必要がなくなりました。ご確認いただければ幸いです。

--------------------------------

こんにちは、K里です。

今回は、Windows 7 で対応された USB イベントトレースログについてご紹介します。こちらの機能は、各 USB クラスにおけるデバイスドライバを開発されていたり、システム全体の評価を行う時に USB 周りで何か問題が発生した場合のトラブルシューティングする必要のある方が対象となります。USB イベントトレースログは、ETW (Event Tracing for Windows) 機能を使用し、対象モジュールを Checked Build 版に置き換えることなくトレースログを採取します。また、採取したログファイル (etl ファイル) は、Network Monitor を使用して解析することが可能です。なお、USB トレースログの各情報を解析するためには、USB に関する仕様について包括的に理解しておくことが前提となります。

 

トレース対象モジュール:

Windows 7 で登録されているトレースプロバイダーは、以下の 2 つになります。

 

Ø Microsoft-Windows-USB-USBHUB - GUID: {7426A56B-E2D5-4B30-BDEF-B31815C1A74A}

Ø Microsoft-Windows-USB-USBPORT - GUID: {C88A4EF5-D048-4013-9408-E04B7DB2814A}

 

Microsoft-Windows-USB-USBPORT は、ポートドライバ (USBPORT.SYS) だけでなく、USB ホストコントローラーに対応するミニポートドライバ (USBEHCI.SYS, USBUHCI.SYS, USBOHCI.SYS) も含みます。Windows 7 での USB ドライバスタックは、以下のような構成となり、特に USBHUB と USBPORT は重要な役割を担います。

 

usbstack

 

ログ採取:

ログを採取するためのツールとしては、OS に含まれる logman、SDK に含まれる WPT (XPerf)、WDK に含まれる tracelog などがあります。今回はてっとり早く使用できる logman で説明したいと思います。なお、XPerf ですと、USB イベントログの他にもパフォーマンスに特化したイベントを同時に採取することが可能ですので、検証内容に応じて使い分けると便利です。Xperf については以前ご紹介しました記事を参照いただければ幸いです。ここでは、システム稼働時、システム状態遷移時の採取方法と OS 再起動時の採取方法をご紹介します。

 

1) システム稼働時、システム状態遷移時(スリープ、休止状態、ハイブリッドスリープへの遷移ならびに復帰) の採取方法

下記コマンド実行後、USB のテストを行い、任意のタイミングでトレースを停止します。たとえば、スリープ遷移時のログ採取の場合には、一旦スリープに遷移し、再度復帰した後にトレースを停止します。

> Logman start Usbtrace -p Microsoft-Windows-USB-USBPORT -o usbtrace.etl -ets -nb 128 640 -bs 128

> Logman update Usbtrace -p Microsoft-Windows-USB-USBHUB -ets

 

--- USB デバイスのテストを実施 ---

 

> Logman stop Usbtrace -ets

-ets: コマンドを保存またはスケジュールしないで、直接イベント トレース セッションに送信します

-nb <最小値> <最大値>: イベント トレース セッションの最小バッファー数と最大バッファー数です

-bs <値>: イベント トレースセッション バッファーサイズ(KB) です

logman /? で各オプションのヘルプを表示することができます

 

2) OS 再起動時の採取方法

Boot 時のログを採取する場合には、AutoLogger を使用します。セッション名に“autosession\” を追加することで自動的に設定がなされます。下記コマンド実行後、システムを再起動します。

> Logman create trace "autosession\Usbtrace" -p Microsoft-Windows-USB-USBPORT -o usbtrace.etl

> Logman update "autosession\Usbtrace" -p Microsoft-Windows-USB-USBHUB

 

以下のコマンドを実行してトレースを停止し (stop)、今後上記セッションが必要なければ削除します (delete)。

> Logman stop Usbtrace

> Logman delete "autosession\Usbtrace"

 

ログ解析:

解析には、Network Monitor v3.3Network Monitor Parsers v3.4 を使用しますのでダウンロードし、インストールします。USBHUB/USBPORT 用の解析ファイル (Parser) は、現在 Netmon に含まれていないため、Codeplex から v3.4 の Parser を追加する必要があります。インストールが完了したら、Network Monitor を起動し、以下の通り Parser の設定を行います。Codeplex は、マイクロソフトが運営する開発者支援用のポータルサイトです。

 

1. [Tool] メニュー -> [Options] をクリックします

2. [Parser] タブの Windows を選択し、”Stubs” をクリックします

3. Set 情報が Full になっていることを確認し、OK を押下します

 

netmonoption

 

それでは、トラブルシューティングの例として文末 Appendix のサイトで公開されている etl ファイルを使ってログを見てみましょう。[File] メニュー -> [Open] -> [Capture] をクリックし、etl ファイルを選択します。Frame Summary 画面にトレースログの解析結果が表示されます。おそらくは、ログが大量に出力されており、どこから解析を進めればよいのか困惑するかもしれません。その場合には、フィルタを用いてまずは、USBHUB もしくは USBPORT で何らかの問題が発生していないかを確認します。Display Filter 画面に以下のフィルタコードを設定し、Apply ボタンを押すと、Frame Summary 画面のログがフィルタされます。この場合のログでは、Create Device でエラーが発生していることが分かります。また、Frame Details 画面では、各ログに含まれるデータを確認することができ、Create Device は、STATUS_UNSUCCESSFUL (0xC0000001) となっていることが分かります。

 

netmontrace

 

いかがでしたでしょうか。詳細な説明については、下記ホワイトペーパーに記載されておりますのでご参照ください。

ではまた。

 

Appendix

Windows 用 USB Event Tracing

https://www.microsoft.com/japan/whdc/connect/usb/Event-Tracing.mspx