極端なシステム遅延の問題

数週間前に、私の妻が、Windows Vista デスクトップが入力やマウス クリックに反応しないと私に文句を言ってきたことがありました。「お客様第一」です。私はすぐに妻のシステムの前に座り、トラブルシューティングを開始しました。完全にハングアップはしていないものの、極端に遅くなっています。たとえば、マウスを動かして [スタート] メニューを押すと、約 30 秒後に [スタート] メニューが表示されるといった具合です。私は、何かが CPU を独占していることを疑いました。そのままログオフするか、再起動すれば、簡単に問題を解決できたでしょう。と同時に、問題の根本を突き止めて対処しなれば、彼女は近いうちに再び、私というテクニカル サポート サービスを呼ぶことになるだろうとも思いました。とにかく、こうしたトラブルシューティングに手をこまねいているようでは、私の面子が立ちません。本格的に調べてみることにしました。

私はまず Process Explorer を実行して、CPU を消費しているのはどのプロセスなのかを調べることにしました。数分間かかってやっと立ちあがった Process Explorer には、1 つではなく 2 つのプロセスが表示されていました。Iexplore.exe と Dllhost.exe、それぞれが CPU を 50% ずつ消費しているのです。Iexplore は Internet Explorer (IE) ですが、私は IE 自体に問題はなく、ブラウザー ヘルパー オブジェクト (BHO) や ActiveX コントロール、あるいは IE に読み込まれたその他のプラグインが悪さをしているのではと考えました。同じく、プロセス外 COM サーバー DLL のホスト プロセスである Dllhost.exe も、それ自体ではなく、ホスト プロセスに読み込まれた COM サーバーに問題があると考えました。2 つのプロセスとも、詳しく調査する必要がありそうです。まずは IE から取りかかることにしました。

作業に必要な CPU ヘッドルームを確保するため、Process Explorer で Dllhost プロセスを停止しました。右クリックしてプロセス コンテキスト メニューを表示し、[Suspend] をクリックします。

図 1

これによって Dllhost プロセスが停止します。ここで予想どおり、CPU の 50% が開放されました。妻のコンピューターはデュアルコア システムです。このため、使用可能な CPU サイクルの 100% を消費するには、1 つのプロセス内にある 2 つのスレッドが、それぞれ 1 つのコアを独占することになります。私の経験では、CPU が固まる不具合のほとんどは、1 つのスレッドによって発生していました。

コードは、プロセスではなくスレッドによって実行されます。私は IE のプロセス内でどのようなスレッドが実行されているのか確認することにしました。Process Explorer 内の Iexplore.exe をダブルクリックして、プロセスのプロパティを示すダイアログ ボックスを表示し、[Threads] ページに移動します。スレッドがいくつか実行されており、その中に CPU を占有しているスレッドがありました。

図 2

私はこれまでの経験から、Ieframe.dll が IE の一部であることを知っていましたが、念のため確認しようと思い、このプロパティ ダイアログの [Threads] タブにあるモジュール ボタンをクリックして、Shell プロパティのダイアログ ボックスを表示し、[Details] ページに移動しました。

図 3

表示されている説明に、このスレッドの役割を特定する手がかりはありませんでした。そこで、2つめの手がかりである、スレッドの開始関数に着目しました。Process Explorer で、マイクロソフトのシンボル サーバーから Windows イメージのシンボルを取得するよう設定しているため ([Options]、[Configure Symbols] の順にクリック)、Process Explorer には各スレッドの実行を開始する関数が表示されます。スレッドを開始させる DLL または関数さえわかれば、スレッドの目的や、問題を引き起こす原因となっているソフトウェアを探り当てることができる場合があります。ここでは、このスレッドは CTablWindow::_TabWindowThreadProc という関数で開始されています。この名称から、この関数が、1 つのタブのメイン スレッドを開始させる関数であることがわかりますが、それだけではここまで大量のメモリを消費する理由はわかりません。さらに詳しく調べ、このスレッドが実行された場所を確認する必要がありそうです。

スレッドの目的を確認するには、[Threads] リストにあるスレッドをダブルクリックして、[Thread Stack] ダイアログを表示します。ここにはスレッド スタック関連の関数が表示されます。スタックとは、要するに「実行の履歴」のことです。スタックでは、呼び出された関数が呼び出し元の関数の上に来るような形でリスト化されており、リストの最上位は、Process Explorer によるスタックの確認時点で最後に実行された関数、となります。リストをスクロールして、サードパーティの DLL または Microsoft IE プラグインを参照したフレームを探します。バグが混入している可能性は、IE 自体のコードよりもこれらの方が高いと推測されます。思ったとおり、有名なサードパーティの ActiveX コントロールである Adobe Flash を参照するフレームが見つかりました。

図 4

別のコンポーネントが CPU 時間の大半を占有していたときに Flash が実行されていたというわけではないことを確認するため、このスタックのダイアログを閉じて開く操作を数回行いましたが、常に Flash への参照が発生していました。

問題の原因がソフトウェアにあると思ったときは、まず、ベンダーの Web サイトにアクセスして、ソフトウェアが最新であるかどうかを確かめます。今回も、Process Explorer の DLL ビューを表示して Flash.ocx のバージョンを確認した後、Adobe のサイトでダウンロード可能な最新の Flash バージョンを確認しました。Flash.ocx は最新のバージョンでした。

私はこれで完全に行き詰まってしまいました。Flash にバグがあるのか、Flash アプリケーションにバグがあるのかもわからず、この問題が再発しないという確信もありませんでした。私はタブを 1 つずつ閉じて Flash コンテンツをホスティングしているサイトを特定することも試みましたが、タブを閉じた後もすべてのスレッドが実行されていました。

この時点で私に残された選択肢は、Flash をアンインストールして妻に Flash なしの Web エクスペリエンスで我慢してもらう、あるいは、IE を終了させてこの異常な CPU 占有率をひとまず解決し、この問題が再び起こらないことを祈るだけでした。私は後者を選んだため、この問題は現在も続いています。この調査以降、同様の Flash の動作は、妻のシステムでも私のシステムでも発生しています。Flash のバグが原因だった場合に最新バージョンを入手できるよう、私は Adobe サイトを欠かさずチェックし続けています。少なくとも CPU 占有率が異常に高くなる原因はわかりましたがが、調査からもっと有意義な結論を導き出せなかったことは非常に残念です。

では、気を取り直して、次に Dllhost の問題に取りかかります。Process Explorer では、ホスティング プロセスに読み込まれた 1 つまたは複数のコンポーネントがツールチップで一覧表示されます。ホスティング プロセスの例としては、Svchost.exe (Windows サービスのホスト プロセス)、Rundll32 (コントロール パネル アプレットのホスティング プロセス)、Taskeng.exe (Windows Vista および Windows Server 2008 上のスケジュールされたタスクのホスティング プロセス)、そして Dllhost.exe などがあります。私はマウスを Dllhost.exe の上に動かし、Dllhost.exe が実行する COM サーバーを確認しました。

図 5

ここでは、サムネイル キャッシュの COM サーバーが実行されています。この COM サーバーのジョブは、画像ファイルやメディア ファイルのエクスプローラー用のサムネイルを作成することです。これは Windows の一部であるため、やはりここでもプロセスを詳しく調べ、より多くの手がかりを探す必要があります。先ほど停止した Dllhost プロセスを再開して、プロセスのプロパティ ページの [Threads] を確認します。

図 6

今回は、CPU を占有しているスレッドは、Quartz.dll の ObjectThread 関数で開始されていることがわかります。私はそのプロパティを調べ、これが別の Windows DLL の DirectShow Runtime であることを確認しました。汎用関数の名前が使用されています。

図 7

次に、ダブルクリックしてスレッド スタックを確認しました。

図 8

先頭のフレームのいくつかでは、User32.dll および Ntdll.dll というコア Windows システム DLL 内で、4 ～ 7 番目のフレームは、サードパーティーのコンポーネント Sonicmp4demux.ax (".ax" は、一般に DirectShow フィルターに使用される拡張子) 内で発生しています。これらのフレームの関数名は同じですが、何を指すかはわかりません。これは、マイクロソフトのシンボル サーバーは、Windows に含まれるソフトウェアのシンボル以外は格納しないためです。その他のスナップ ショットをいくつか作成した後、CPU を浪費しているのがこのコードだということが判明しました。

問題の原因を突き止めたら次にすべきことは、新しいバージョンの確認です。しかしその前に、この DLL がどのソフトウェアに関連付けられているのかを確かめなければなりません。そしてそれは予想以上に困難でした。DLL ビューを表示し、バージョン情報を詳しく調べましたが、説明からは何もわかりませんでした。

図 9

[スタート] メニューのフォルダーや [プログラムの追加と削除] 一覧の項目には、「Sonic」と名前が付いたものは見当たりません。そこで私は、「Sonic」を "Bing する" ことにしました (この言葉、早く辞書に載らないかなと思っているのですが)。Bing で検索したところ、「Sonic」は Roxio 社の CD/DVD 作成ソフトウェア スイートの一部であることがわかりました。[スタート] メニューを確認したところ、確かに Roxio 用のフォルダーがあります。

図 10

この Roxio ソフトウェアを実行してバージョン番号を確認したところ、Creator アプリケーションには最新のアップデートを確認する機能が組み込まれていることがわかりました。早速実行しましたが、適用可能なアップデートはありませんでした。

図 11

念のため Roxio の Web サイトを確認したところ、より新しいバージョンが提供されていることがわかりました。Web ページの情報によれば、新しいバージョンにアップデート可能なことが通知されなかった理由は、このアップデートには新機能がなんら含まれていないことが理由のようです。

図 12 [拡大図]

ともあれ、私はこのアップデートをダウンロードしました。サイズが 640 MB と大きく、インストールするまでに 15 分もかかってしまいました。インストールした後、最新のファイルに更新されていることを確認するため、Sonicmp4demux.ax のバージョンをチェックしました。バージョン番号は「1.4.402.60802」で、私が DLL ビューで見たのとまったく同じでした。ファイルの作成日も 2 年前でした。

図 13

Roxio ソフトウェアをアンインストールして問題の再発を防ぐということもできましたが、この DVD 作成機能を手放したくはありませんでした。Roxio 固有の画像形式のサムネイル表示がされなくなったって、いっこうにかまいません。というより、エクスプローラーでそんなものを見たことがあるかどうかさえ覚えていません。そこで、Sonic のデマルチプレクサーだけを無効化することが可能か試すことにしました。レジストリで DLL の名前を検索すれば、DLL が登録された場所が必ず見つかるはずですが、これはちょっと強引な方法です。それに間接的な参照関係や複数の参照関係が存在した場合、サムネイル表示の生成以外の機能も無効化されてしまったり、Windows の他の機能が壊れてしまうかもしれません。

こんな状況にぴったりのツールが Process Monitor でした。この問題がいつ再発するかは、私にはわかりません。数日ですぐ再発するやもしれません。それを気にも留めずそのままにして、使用可能な仮想メモリやディスク スペースを占有させっぱなしにはしたくありませんでした。私は [Options] メニューの [History Depth] で、Process Monitor が直近の 100 万件のイベントだけを保持するよう設定しました。

図 14

また、[Include] フィルターには C:\Windows\System32\Dllhost.exe というパスを設定して、Process Monitor を最小化し、妻を呼び戻してマシンの前に座らせました。

次の日、仕事から帰ってきた私はコンピューターの前に座り、Process Explorer を確認しました。すると、Dllhost.exe が実行中で、CPU の 50% を占有していました。私はこれはデュアルコア システムが原因だと考えました。この問題は定期的に発生するのです。しかしそれを気にさせないだけの CPU パワーが残るため、妻は気付いていないのでしょう。マルチコア プロセッサ導入のメリットは、こんなところにもあるようです。Process Monitor を前面に表示すると、確認された Dllhost の処理が 114,000 件にも達しています。これは、1 つひとつ見ていくにはあまりに多すぎる量です。私は「sonicmp4」で検索し、トレースの終わり近くで、レジストリ クエリ内に参照を見つけました。

図 15

このクエリは、このデマルチプレクサー用に、COM オブジェクトを登録するものです。この COM オブジェクトはサードパーティ DLL であるため、COM クラス ID (CLSID) は Windows にハードコーディングされていません。このため私は、トレースの先頭のエントリから、この CLSID の先頭文字「A7DD215」を検索しました。さきほど見つかった参照よりも何千件か手前で、検索がヒットしました。

図 16

この CLSID は、別の COM オブジェクトのレジストリ キー名として使用されていました。上位の CLSID を "Bing" したところ (もう慣れましたか?)、このレジストリ キーに DirectShow (英語) フィルターが登録されることを説明している MSDN サポート技術情報の記事が見つかりました (https://msdn.microsoft.com/en-us/library/ms787560(VS.85).aspx (英語))。私はこのクエリのスタックを調べて、Dllhost がここから読み込みを行なっている理由がこれであることを確認しました。

図 17

ここで初めて、Sonic フィルターの登録キーの名前を変更して使用されないようにすれば良いことが確信できました。私はこのようなトラブルシューティングの際、レジストリ キーは削除しません。削除によって重要な機能が無効化されたり、その他の障害が発生しないようにするためです。トレースから、ある AVI ファイルが原因で、サムネイルのキャッシュ生成機能が Sonic デマルチプレクサーを読み込んでしまっていることがわかりました。Sonic デマルチプレクサーは、Windows 自体で処理することが可能なフォーマットなため、今後も続けて使用できるはずだと考えました。Dllhost を終了して、登録キーの名前を変更した後、フォルダーを開いてサムネイルを削除しました。何か機能が正常に動かなくなってしまったりしていないことを確認しました。それから Roxio を使用して AVI ファイルをいくつか DVD に保存しました。これも問題なくできました。すべて問題を解決できました。

妻がまたシステムを使えるようになりました。Flash に絡む問題については解決できませんでしたが、少なくとも原因は判明しており、後はアップデートで改善されることを望むだけでした。さらに重要なことは、Dllhost に関する問題が解決されたことで、Flash で万が一再び問題が発生しても、妻は続けてシステムを利用することができ、私に苦情を投げかけてくることもなくなるでしょう。これもすべて Process Explorer と Process Monitor のおかげです。公開:

2008 年 9 月 24 日水曜日 11:08 AM 投稿者: markrussinovich (英語)