基調講演のデモで発生した遅延の問題

数週間前、私は 5,000 人以上の参加者が集まる Microsoft の TechEd US コンファレンスの基調講演 (英語) に初めて参加しました。Windows 担当上級副社長である Bill Veghte が基調講演を行い、Windows 7 のユーザーを重視した機能をひととおり紹介し、Windows Server 担当ゼネラル マネージャーである Iain McDonald が Hyper-V と Windows Server 2008 R2 の新機能を披露しました。私は、Windows 7 と Microsoft Desktop Optimization Pack (MDOP) の IT プロフェッショナル向け強化機能のデモを実演しました。

BitLocker To Go のグループ ポリシー設定、PowerShell v2 のリモート処理機能、PowerShell のグループ ポリシー オブジェクトのスクリプト処理機能、Microsoft Enterprise Desktop Virtualization (MEDV) などの機能のほか、App-V、移動ユーザー プロファイル、フォルダー リダイレクトを使用してダウンタイムを最小限に抑えた PC の交換方法などを紹介しました。私が強調したのは、IT プロフェッショナルが Windows Vista アプリケーション用に開発してきたアプリケーション互換性修正プログラム (shim と呼ばれる) が Windows 7 でも動作するようにあらゆる努力をしてきたという点です。Windows 7 の新機能である AppLocker のデモも披露しました。この機能を利用すると、IT プロフェッショナルはエンタープライズ デスクトップ上で実行可能なソフトウェアを柔軟なルールで制限できます。

基調講演までの数週間、私は基調講演の IT プロフェッショナル向けの部分を担当する Jason Leznek と協力して、紹介する機能を選定し、デモを作成しました。台本のリハーサルを行い、デモを調整してスムーズに進行するように編成し、自分に割り当てられた時間内に収まるように内容を整え、新しいテクノロジのメリットを強調したナレーションに切り替えました。アプリケーションの互換性のデモでは、マイクロソフト社内で使用している Stock Viewer というサンプル プログラムを使用することにしました。このプログラムは、意図的に Windows Vista や Windows 7 との互換性がない設計がなされており、新しいオペレーティング システムによるサポートがなければ実行不可能な基幹業務ソフトウェアの見本として使用されています。このデモでは、Windows 7 上で Stock Viewer を起動すると非互換性が原因でトレンド レポート機能に障害が発生して、不明瞭なエラー メッセージが表示されるのを示すつもりでした。

図 1

続いて、Windows Vista 上でアプリケーションを正しく動作させることができるアプリケーション互換性 shim を展開して、アプリケーションが正常に動作することを示しました。

さらに、AppLocker のルール作成ウィザードを使って、発行者やバージョンに基づいたデジタル署名ソフトウェアの実行許可を簡単に設定できることを説明したいと考えていました。当初は、アプリケーションの互換性のデモの次に AppLocker を紹介し、企業で広く使用されているアプリケーションの Adobe Acrobat Reader を実行可能にする方法を示す予定でした。リハーサルを何度か行ううちに流れが少しぎこちないことに気付いたので、Stock Viewer の実行ファイルに対してデジタル署名を行い、AppLocker のデモを shim のデモの前に行うことを提案しました。こうすれば、2 つのデモを通して、AppLocker のルールを使用して Stock Viewer の実行を許可できることと、アプリケーションを正しく実行するのに shim が役立つことを示すことができます。

私はオフィスに戻って、Sysinternals 署名証明書を使用して Stock Viewer に署名し、Jason に送信しました。数時間後、彼から、デモ システムのどこかに異常があり、以前はすぐに起動していた Stock Viewer が起動に 1 分以上もかかるようになったというメールが届きました。TechEd は目前に迫っており、デモの内容を確定しなければならなかったので、彼はパニック状態になっていました。私は以前に、.NET では、デジタル署名されたアセンブリを読み込むときに Authenticode 署名のチェックが行われると聞いたことがあったので、これが関係しているのではないかとまず疑いました。Jason に Process Monitor のトレースをキャプチャするように依頼すると、数分後には彼から電子メールでトレースが送られてきました。

このログを開いて、まず最初に StockViewer.exe の最初の処理を見つけ、右クリックしてクイック フィルターを設定して、表示対象を StockViewer.exe のイベントに絞り込みました。

図 2

次に、最初の項目のタイムスタンプ (2:27:20) と、最後の項目のタイムスタンプ (2:28:32) を確認しました。Jason が言っていた 1 分の遅れと関係がありそうでした。トレースをスクロールすると、暗号化 (crypto) のレジストリ キーやファイル システム ディレクトリへの参照が多く、また TCP/IP 設定への参照も含まれていました。そのうちタイムスタンプの間隔が大きい箇所がどこか 1 つはあるはずだと考え、ログの内容を先頭から順にチェックし、2:27:22 から次のタイムスタンプまで 10 秒ほど間隔が空いているのを突き止めました。

図 3 [拡大図]

この直前の操作は Rasadhlp.dll (ネットワーク関連の DLL) への参照で、さらに少し遡ると Winsock レジストリ キーへの参照が多数行われていました。10 秒間の遅延の直後には crypto レジストリ キーへのアクセスが行われています。システムがインターネットに接続されていないため、ネットワークのタイムアウトまでの約 10 秒間、アプリケーションは待機状態になっていたようです。さらに見ていくと、12 秒間間隔が空いている箇所が見つかりました。

図 4 [拡大図]

ここでも、前後にネットワーク関連のアクティビティや crypto 関連のアクティビティが発生していました。その次の個所も 12 秒間で、同じような状況で発生していました。

図 5 [拡大図]

その後にも、いくつか似たような形でタイムスタンプの間隔が空いているのが見つかりました。いずれの場合も直前に HKCU\Software\Microsoft\Windows\CurrentVersion\Internet Settings\Connections への参照が行われていたので、表示対象をそのパスと RegOpenKey に絞り込むと、思ったとおり、きっかり 12 秒間隔で処理が 6 回行われていました。

図 6 [拡大図]

合計すると 12 × 6 = 72 秒で、Jason が言っていた "1 分以上" の遅れと合致します。次に、ネットワークへのアクセスが繰り返される原因が署名の検証処理であることを確認するために、さまざまなイベントのスタックを選択し、Ctrl を押しながら K キーを押してスタックのプロパティ ダイアログ ボックスを開いて、スタックを調べました。インターネット接続の設定に関連するイベントのスタックを調べると、crypto が原因であることがわかりました。

図 7

最後に、最初の疑いを確かめるために、これらのチェックが .NET によって行われているのかどうかを確認しました。もう一度ログをチェックすると、トレースに、Stock Viewer が .NET アプリケーションであることを確認するイベントがあるのを発見しました。

図 8 [拡大図]

最初の方の crypto レジストリ キーを参照するイベントの一部のスタックを調べると、何度もインターネットへのアクセスを試みていたのは、.NET ランタイムであり、ファイルのデジタル署名をチェックする Windows 関数 WinVerifyTrust (英語) の呼び出しを実行していたのがその原因であったことがわかりました。

図 9

起動が遅くなった原因が、.NET による Stockviewer.exe の署名のチェックおよび署名証明書の有効性のチェックであることがわかったので、この処理を省略する方法を Web で検索しました。基調講演で使うコンピューターは、講演中はインターネットには接続されないことがわかっていたからです。同様の経験をした人の記事を読んでいるうちに、このサポート技術情報の記事を見つけました。

図 10 [拡大図]

私たちが経験したのとまったく同じ現象について説明したこの記事の中で、.NET 2.0 (トレース時に Stock Viewer がアクセスしていた .NET DLL のパスから、Stock Viewer が使用していることが判明した .NET のバージョン) は、アセンブリのデジタル署名の強制的なチェックを無効にする方法をサポートしていることが指摘されています。この方法では、実行可能ファイルが存在するディレクトリに、実行可能ファイルの名前に ".config" という拡張子を追加した名前 (例: StockViewer.exe.config) を持つ構成ファイルを作成し、その内容として次の XML を記述します。

<?xml version="1.0" encoding="utf-8"?>
<configuration> 
      <runtime> 
              <generatePublisherEvidence enabled="false"/> 
      </runtime> 
</configuration>

Jason から電子メールを受信してから約 15 分後、私は自分の導き出した結論をメールに記し、構成ファイルを添付して返信しました。それからすぐに、遅延が解消されたことを確認した、この短時間で問題と解決策を特定するとはまったく驚きだ、という返信が Jason から届きました。彼には魔法のように見えたのかもしれませんが、私はただ、基本的な Process Monitor によるトラブルシューティングの手法と Web を活用して問題を解決しただけです。言うまでもありませんが、順序の変更によって、AppLocker からアプリケーションの互換性へとスムーズにデモを進行することができました。

公開: 2009 年 5 月 26 日火曜日 7: 30 AM 投稿者: markrussinovich (英語)