システム プロセスの CPU スパイクの問題

私のブログ記事や他の執筆物からおそらく皆さんもお気付きのとおり、私は使用しているシステムで行われていることを正確に知ることが好きです。私は、あるプロセスが CPU を独占し、メモリ負担を発生させたりディスクに打撃を与えたりしているかどうかを知りたいと思っています。私の用心さは、コンピューターをスムーズに動作させるのに役立つだけでなく、Windows やサードパーティのコードにおけるパフォーマンスや信頼性に関する問題を見つけるのに役立つこともあります。

私が状況の把握に使用する主な方法は、ログオン時に自動的に実行されるように Process Explorer を構成するというものです。私は、新しいコンピューターを構成するたびに、自分のプロファイルのスタート ディレクトリに、/t (最小化) スイッチを指定した Process Explorer へのショートカットを追加します。Process Explorer は、CPU 動作レベルの小さな履歴ビューを示すトレイ アイコン以外は非表示で実行されます。システム プロセスおよび自分自身のプロセスに関する詳細な情報にアクセスする必要があるので、Vista では /e オプションも指定します。このオプションを指定すると、ログオン時に UAC プロンプトが表示され、このプロンプトで Process Explorer の管理者権限を付与することができます。

Process Explorer のトレイ アイコン (ユーザー モード (アプリケーション) の CPU 使用率に関しては緑、カーネル モード (オペレーティング システムとドライバー) の CPU 使用率に関しては赤で表示されます) で CPU スパイクに目を光らせていたところ、過去数か月間でいくつかのアプリケーション バグを特定しました。この記事では、私が Process Explorer と Kernrate というもう 1 つのツールをどのように使用して、サードパーティ製のドライバーに関する問題を特定し、ベンダーに問題を修正してもらうところまでこぎつけたかについて説明します。

私は、数か月前に新しいノート PC を手に入れてから間もなくして、システムの動作が遅く感じられるときがあることに気付きました。Process Explorer のトレイ アイコンで赤い CPU 動作のミニグラフが表示されたことで、私の直感は裏付けられました。アイコンをポイントすると、最も多くの CPU を消費しているプロセスの名前をレポートするヒントが開きます。今回は、次の図が示すように、システム プロセスがこのようなプロセスであるとレポートされました。

図 1

私が問題に気付いたうちの最初の数回は、問題は間もなく解決されたので、トラブルシューティングを行うチャンスはありませんでした。しかし、Process Explorer の [System Information] ダイアログ ボックスを開くと、次のように、CPU スパイクが著しいことはわかりました。

図 2

システム プロセスは、他のプロセスと違って実行可能なイメージをホストしないので、特別なプロセスです。システム プロセスは、デバイス ドライバー スレッド、およびメモリ マネージャー、キャッシュ マネージャー、および他のサブシステムのオペレーティング システム スレッドをホストするためだけに存在します。 これらのスレッドは完全にカーネル モードで実行されます。Process Explorer のグラフでシステム プロセスの CPU 使用率が赤で表示されるのはこのためです。

私はサードパーティ製のデバイス ドライバーが問題の原因ではないかと考えたので、調査の最初のステップは CPU を使用しているスレッドを特定することでした。うまくいけば、これで問題の原因がわかると思われました。私は、ネットワークを切り替えるたびに用心深く問題の兆しを探し、最初に兆しを見つけたときは跳び上がりました。Process Explorer では、プロセス内で実行されているスレッドが [Process Properties] ダイアログ ボックスの [Threads] ページに表示されるので、次に CPU スパイクに気付いたとき、私は [System] プロセスをダブルクリックし、[Threads] ページに切り替えました (下図参照)。

図 3

各スレッドの開始アドレス (start address) の "ntkrnlpa.exe" というプレフィックスは、CPU 使用率に基づいて並べ替えた場合にオペレーティング システム スレッドとして上部に表示されるものを示していました (Ntkrnlpa.exe は、4 GB を超えるメモリを処理する必要のある実行メモリ保護やサーバー システムを持たない 32 ビット クライアント システムに読み込まれるカーネルのバージョンです)。マイクロソフトのパブリック シンボル サーバーからオペレーティング システム イメージのシンボルを取得するように以前に Process Explorer を構成したので、スレッド一覧には、スレッド開始関数の名前も表示されました。最もアクティブなスレッドは ExpWorkerThread 関数内で開始されました。つまり、こうしたスレッドは、システムやデバイス ドライバーの代わりに処理を実行するワーカー スレッドだということです。システムやドライバーは、メモリ リソースを消費する専用のスレッドを作成するのではなく、オペレーティング システムのワーカー スレッド (英語) の共有プールに処理を放り込むことができます。

残念ながら、CPU 使用率の原因がワーカー スレッドだとわかっても、根本原因の解決や特定にはまったく近づきませんでした。ワーカー スレッドが呼び出している関数をぜひとも知る必要がありました。関数は、スレッドが代わりに処理を実行しているデバイス ドライバーやオペレーティング システムのコンポーネントの内部にあるからです。スレッドの実行の内部を確認する 1 つの方法は、Process Explorer でそのスレッドのスタックを確認することです。スタックは関数呼び出しを格納するメモリ領域です。Process Explorer では、スレッドを選択して [Stack] をクリックするか、スレッドをダブルクリックすると、スレッドのスタックが表示されます。ただし、Vista では、システム プロセス内のスレッドのスタックを確認しようとすると、次のエラーが表示されます。

図 4

Vista では、システム プロセスは "保護されているプロセス" と呼ばれる特別な種類のプロセスで、このプロセスのスレッドやメモリにアクセスすることはできません。保護されているプロセスは、デジタル著作権管理 (DRM) をサポートし、高解像度コンテンツのプロバイダーが、管理ユーザーが DRM はく奪ツールを使用してプロセス内にアクセスしキーを読み取る危険性を軽減した状態でコンテンツ暗号化キーを格納できるようにするために導入されました。

このアプローチが失敗したので、ワーカー スレッドが何を行っているかを確認する別の方法を見つける必要がありました。私は、マイクロソフトが提供する無償でダウンロードできるコマンドライン プロファイル ツールの KernRate (英語) をこれに使用することにしました。KernRate では、ユーザー モード プロセスとカーネル モード スレッドをプロファイルすることができます。KernRate では、Windows NT の最初のリリースで導入されたサンプル ベースのプロファイル機能が使用されます。このプロファイル機能では、プロファイル期間タイマーが作動するときに CPU が実行されている場所を示す一意のアドレスが記録されます。プロファイルのキャプチャを停止すると、Kernrate は、カーネルから情報を取得し、読み込まれた該当するデバイス ドライバーにアドレスをマップします。また、シンボル エンジンを使用して関数の名前をレポートすることさえできます。

トレースによってデバイス ドライバーが特定されたらシンボルは不要なので、引数を渡さずに Kernrate を実行しました。Vista 用の正式にサポートされているバージョンの Kernrate は存在しませんが、Windows XP 用のバージョンである Kernrate_i386_XP.exe は 32 ビットの Vista 上で機能します (最近リリースされた xperf (英語) ツールを使用して同様のプロファイルを実行することもできます。xperf を実行するには Vista または Windows Server 2008 が必要ですが、xperf は 64 ビット バージョンで機能します)。高い CPU 使用率の下でプロファイルを実行し、Ctrl キーを押しながら C キーを押して次のようにコンソール ウィンドウに結果を出力します。

図 5

最初のヒットはカーネル内でしたが、2 番目は b57nd60x という見覚えのないドライバーでした。ほとんどのドライバー ファイルは %systemroot%\system32\drivers ディレクトリにあるので、エクスプローラーでこのフォルダーを開いてファイルのプロパティを確認することもできましたが、私は Process Explorer を開いていたので、ドライバーのベンダーとバージョンをより簡単に確認する方法は、システム プロセスの DLL ビューを開くことでした。DLL ビューでは、ユーザー モード プロセスのアドレス空間にマップされた DLL やファイルが表示されますが、システム プロセスの場合は、システムに読み込まれたカーネル モジュール (ドライバーを含む) が表示されます。DLL ビューから、当該のドライバーはノート PC の NIC 用のもので、Broadcom によって提供されたものであり、バージョン 10.10 であることがわかりました。

図 6

Broadcom 製のドライバーが CPU 使用率の原因だとわかったので、次のステップは、使用できる新しいバージョンがあるかどうかを確認することでした。使用しているシステム向けの Dell のダウンロード ページにアクセスしてみましたが、何も見つかりませんでした。自分が気付いたことは既知の問題ではないのかもしれないと考えた私は、Broadcom に知らせることにしました。マイクロソフトのハードウェア エコシステム チームの窓口を使用して Broadcom 製のドライバーのセールスマンを見つけ、現象と私が行った調査の詳細な説明を記載した電子メールをこのセールスマンに送りました。セールスマンは私の電子メールをドライバー開発者に転送してくれました。ドライバー開発者は原因がわかっていないことを認め、数日以内に、ドライバー内のどの関数がスパイク中にアクティブだったかを彼らに知らせる Kernrate プロファイルをキャプチャできるように、デバッグ バージョンのドライバーをシンボルと共に送ってくれました。問題は数日後に再び発生したので、私は、関数情報を含む Kernrate の出力を送り返しました。

開発者は、特定のクエリを処理する際にドライバーが効率的に PCIe バスと連携していなかったことが私のトレースから明らかになったこと、および問題は私のハードウェア構成によって悪化していたように思われることを説明してくれました。開発者は、試用するための新しいドライバーを提供してくれました。私は、問題が発生しないかどうか数週間注意深くノート PC を監視した後で、問題が解決したと思われることを確認しました。更新されたドライバーはまだ Dell のサポート サイトで公開されていませんが、近いうちに公開されるでしょう。これでまた 1 つ問題が解決されました。今回は、Process Explorer、Kernrate、そして親切な Broadcom のドライバー開発者のおかげです。

こうしたトラブルシューティングのブログ記事を気に入ってくださった方には、私が TechEd/ITforum で行った "Case of the Unexplained…" (英語) (原因不明の…の問題) セッションの Web キャストも楽しんでいただけるでしょう。この 75 分間の Web キャストには、今回の記事で詳しく書いた例、それ以外の例、およびまだ文書化していない例を含む現実世界のトラブルシューティング例がたくさん詰まっています。セッションの最後に、私は、セッションを聞いてくださった方々に、各自のトラブルシューティングのサクセス ストーリーに関するスクリーンショット、ログ ファイル、および説明を送ってくださるように頼みました。そして、送っていただいた方にはお礼にサイン入りの『Windows Internals (英語)』をお送りすることを約束しました。この申し出はまだ有効なので、ぜひ調査内容を文書化してお送りください。お送りいただければ、無料の書籍を進呈いたします。既にいくつもの優れた例が寄せられており、次回のブログ記事はゲスト (Web キャストを見て、Web サーバーの問題を解決するのに Process Monitor を使用した方) による記事になる予定です。

最後になりましたが、私の講演を生でご覧になりたい方は、6 月にオーランドで開催される TechEd US/IT Pro (英語) にぜひお越しください。ここでは、私は "The Case of the Unexplained…" (原因不明の…の問題)、"Windows Server 2008 Kernel Advances" (Windows Server 2008 カーネルの強化点)、および "Windows Security Boundaries" (Windows セキュリティ境界) という講演をします。そこで皆さんにお会いできることを楽しみにしています。