開くのに時間がかかる Project ファイルの問題

翻訳元: The Case of the Slow Project File Opens (英語)

"Case of the Unexplained..." (原因不明の...の問題) プレゼンテーションをご覧になったことがあれば、パフォーマンスの問題、問題のある動作、クラッシュ、およびハングの根本的な原因を突き止められる強力なトラブルシューティング ツールとして、スレッド スタックをどれくらい重視しているかご存じだと思います (先月の TechEd Europe でも、このシリーズのプレゼンテーションを行いました。こちらは、オンデマンドでご覧いただけます。この TechEd のプレゼンテーションでは、スタックについて簡単に説明しました)。なぜこれほど重視しているのかと言うと、多くの場合、プロセスの動作は、プロセスで読み込むコードの影響を受けるからです。プロセスで使用する DLL のように明示的な場合もあれば、拡張機能をホストするプロセスのように暗黙的な場合もあります。このブログ記事では、スタックによるトラブルシューティングが成功した別の事例を紹介します。また、短時間のトラブルシューティングで、迅速に解決へと導く手掛かりを見つける方法も説明します。

問題が発覚したのは、ネットワーク共有ある Microsoft Project のファイルを開くのに最大で 1 分かかり、ファイルを開こうとすると 10 回に約 1 回の割合でエラーが発生するというユーザーからの報告を受けて、顧客であるネットワーク管理者から Microsoft サポートに問い合わせがあったときのことです。

図: Microsoft Project エラー メッセージ

管理者は問題を検証し、ネットワークの設定とファイル サーバーにアクセスするときの待ち時間を確認しましたが、問題の原因は特定できませんでした。この問題を担当した Microsoft サポート エンジニアは、Process Monitor や Network Monitor を使用して、開くのに時間がかかるファイルのトレースをキャプチャするよう管理者に依頼しました。しばらくしてログを受け取ると、エンジニアはログ ファイルを開き、Project のプロセスで実行された操作のみが含まれるようにするフィルターを設定し、開くのに時間がかかるファイルの共有場所 (\\DBG.ADS.COM\LON-USERS-U) を参照したパスのみが含まれるようにするフィルターを設定しました。Process Monitor の [Tools] (ツール) メニューから [File Summary] (ファイルの概要) ダイアログを開くと、共有のファイルにアクセスする操作でかかった、問題を検証するうえで重要な時間が [File Time] (ファイルの時間) 列に表示されます。

図: ファイルの概要画面

トレースに含まれるパスから、ユーザー プロファイルがファイル サーバーに格納されていることが原因で、Project を起動すると、プロファイルの AppData サブディレクトリにアクセスが集中していたことが判明しました。多数のユーザーが、フォルダー リダイレクトによってプロファイルを同じサーバーに格納し、AppData に格納されているデータを使用する同じようなアプリケーションを実行した場合、少なくともこのような多少の遅延が発生する原因となるのは間違いありません。AppData ディレクトリにリダイレクトするとパフォーマンスの問題が発生することはよく知られているので、サポート エンジニアは、このことに基づいて、まず次のように提案しました。移動ユーザー プロファイルを、AppData ディレクトリにリダイレクトせず、ログオンとログオフ時にのみ AppData ディレクトリと同期する構成にするようにと。詳細については、マイクロソフトのブログ記事 (英語) にあるガイダンスの下記抜粋を参照してください。

AppData\Roaming フォルダーに関する考慮事項
AppData フォルダーをリダイレクトすると、アプリケーションによってはネットワーク経由でフォルダーにアクセスするため、パフォーマンスの問題が発生することがあります。このような場合、次のグループ ポリシー設定を構成し、ログオンとログオフ時にのみ AppData\Roaming フォルダーを同期して、ユーザーがログオンしている間はローカル キャッシュを使用するようにすることをお勧めします。この設定はログオンとログオフ時の処理速度に影響することがありますが、ネットワーク待ち時間が原因でアプリケーションが動作しなくなることはないので、ユーザー エクスペリエンスが向上する可能性があります。

ユーザーの構成\管理用テンプレート\システム\ユーザー プロファイル\ログオン\ログオフ時にのみ同期するネットワーク ディレクトリ

アプリケーションで引き続き問題が発生する場合は、フォルダー リダイレクトから AppData を除外することを検討する必要があります。除外した場合に生じるデメリットは、ログオンとログオフにかかる時間が長くなる可能性があることです。

次に、エンジニアは、Project で Global.MPT などのファイルへのトラフィックがすべて管理されているのか、アドインで管理されているのかを確認するため、トレースを検証しました。検証を行うには、スタック トレースは必要不可欠です。[File Summary] (ファイルの概要) ダイアログに表示された入出力時間の大半を占めている Global.MPT ファイルへのアクセスのみ表示するようにフィルターを設定すると、このファイルが複数回開かれて読み取られていたことがわかりました。まず、小規模でランダムな読み取りが長期にわたって 5 ~ 6 回行われていることを確認しました。

図: トレースの検証

また、これらの操作のスタックから、Project で読み取りが管理されていることがわかりました。

図: イベント プロパティ

大規模でキャッシュされていない一連の読み取りが行われていることも確認されました。最初に確認した小規模な読み取りはキャッシュされていたので、初回の読み取りでデータをローカルにキャッシュした後、ネットワーク アクセスは発生しませんが、キャッシュされていない読み取りでは、毎回サーバーにアクセスするため、パフォーマンスに影響を与える可能性が高くなります。

図: トレースをさらに検証

さらに悪いことに、このシーケンスはトレース内で 6 回確認されました。このことは、各シーケンスの初回の読み取りのみが表示されるようにフィルターを設定するとわかります。

図: トレースをフィルター設定

これらの読み取りのスタックから、読み取りはサード パーティ製のドライバーによって行われていたことが判明しました。これは、マイクロソフトのパブリック シンボル サーバーからシンボルを取得するように構成したスタック トレース ダイアログに、シンボルの情報が表示されていないことから判断できます。

図: フィルター結果を更に検証

さらに、同じスタックのスタック フレーム上部にある情報から、Project でファイルが開かれるコンテキストで、読み取りのシーケンスが実行されたことがわかりました。これは、オンラインのウイルス検出プログラムでよく見られる動作です。

図: 詳細から特定

案の定、スタック ダイアログで SRTSP64.SYS ファイルが表示されている行をダブル クリックすると、Project で特定のパラメーターが含まれるファイルを開くたびに、オンラインのウイルス検出を繰り返し実行していたのが、Symantec AutoProtect であったことが判明しました。

図: 原因を特定

通常、管理者は、ファイル サーバーでウイルス対策ソフトウェアを構成しています。そのため、クライアント側でスキャンを行っても重複するだけなので、クライアントはサーバー上にあるファイルを参照する際にファイルをスキャンする必要はありません。このことから、サポート エンジニアは、クライアントに展開しているウイルス対策ソフトウェアの除外フィルターで、ユーザー プロファイルをホストしているファイル共有を設定することをネットワーク管理者に推奨しました。

15 分もかからないうちに、エンジニアは分析結果と推奨事項をまとめて、顧客に送信しました。Network Monitor のトレースは、Process Monitor のトレースで見られた事象を確認するために使用したに過ぎません。ネットワーク管理者は、提案事項の実装に取り組み、数日後には、以前ユーザーによって報告された、ファイルの読み込みに時間がかかるという問題やエラーが発生しないことが確認されました。これでまた Process Monitor とスレッド スタックによって 1 つ問題が解決されました。

ページのトップへ

共有

ブログにコピー: ([Ctrl] + [C] でコピーしてください)