時間のかかるログオンの問題

翻訳元: The Case of the Slow Logons (英語)

トラブルシューティング事例が記載された電子メールは私の受信トレイに届き続けています。私は、解決不可能に思える問題で始まり、いくつかの手順の実行後に解決策または (多くの場合同じくらい有効な) 回避策で締めくくられる事例を多数受け取りました。私は数百のこのような事例を 400 枚を超える PowerPoint スライドに記録して蓄積し、ブログや、いくつもの主要な業界カンファレンスで行った "Case of the Unexplained" (原因不明の...の問題) 講演シリーズの題材として役立ててきました。

私はいつも新しい事例、ツールのあまり知られていない機能の使い方、およびユニークなトラブルシューティング技法を探していますので、今後もぜひこうした情報をお寄せください。今回は、Sysinternals の Process Monitor で正常に機能しているシステムと問題のあるシステムのログを比較する、および Sysinternals の PsExec を使用してログオン中の動作をキャプチャするという 2 つの役立つ技法に光を当てる非常に興味深い事例をご紹介します。

この事例は、大規模な会社のシステム管理者に、ログオンにかかる時間が 3 分を超えたという不満がエンドユーザーからいくつも寄せられたところから始まります。不満を寄せたユーザーはログオン後には何の問題にも直面しませんでしたが、遅延は当然いらだたしいものでした。しかし、同じソフトウェア構成でシステムを実行している他の多くのユーザーのところでは問題は発生しませんでした。共通点を探すため、管理者はネットワーク構成データベースに照会しました。そして、案の定、不満が寄せられたシステムはすべて Dell Precision 670 ワークステーションであることがわかりました。管理者は重要な手掛かりを得たと思いましたが、問題なく動作しているシステムの中には、これと同一と思われる 670 ワークステーションが含まれていることに気付きました。

より直接的に手掛かりを探すため、管理者は次に、遅延が発生したシステムのログオン プロセスを分析しようとしました。管理者は、ログオフしても無効にならず次のログオン時に有効であるように、PsExec を使用してローカル システム アカウント内で Process Explorer を実行しました。システムでは Windows XP が実行されていたので、管理者は次のようなコマンドラインを使用しました (Windows Vista およびそれ以上のバージョンでこれを行う方法については、このブログ記事の最後を参照)。

psexec -sid c:\sysint\procexp.exe

"-s" は、ローカル システム アカウント内でプロセスを起動するよう PsExec に指示し、"–i" は、プロセスのウィンドウが表示されるようにするためプロセスを対話型のデスクトップと接続するよう PsExec に指示し、"-d" は、プロセスが終了するのを待たずすぐに戻るよう PsExec に指示します。ユーザーの簡易切り替えが有効になっていてセッション 0 にログインしていない場合は、ログアウトするのではなく、ユーザーを切り替え、問題のあるアカウントにログインし、その後、PsExec を起動したセッションに切り替えてください。

続くログオンで、管理者は、会社独自のシステム一覧基幹業務 (LOB) アプリケーション である Lisa_client_7.0.0.0.exe が短時間 CPU を消費し、3 分間アイドル状態になってから終了し、その後、ログオン プロセスが通常どおり続行されることに気付きました (下図参照)。

図 1

図 1 [拡大図]

David Solomon (英語)外部サイトへは、Process Monitor が Filemon と Regmon に取って代わる前に、"疑問がある場合は Filemon と Regmon を実行してください" という名フレーズを生み出しました。このフレーズは、"Filemon と Regmon" の部分を "Process Monitor" に変えて "疑問がある場合は Process Monitor を実行してください" にすれば今でも通用します (私は徹底してこのアドバイスに従っています。娘が宿題について質問しに来たときにも Process Monitor を実行させているほどです)。この事例はこの理念の良い実践例です。一見、Process Monitor によってプロセス ハングの原因が明らかになるとは思えませんが、管理者は Process Monitor を使用することにしたからです。

Process Monitor を PsExec と共に起動し、ログオン トレースをキャプチャした後で、管理者は、キャプチャしたデータの先頭までスクロールし、分析を開始しました。Process Explorer で確認した内容から、Lisa_client プロセスが明らかに怪しいと思われたので、管理者はトレース行の 1 つでこのプロセス名を右クリックし、"Include" というクイック フィルターメニュー項目をクリックして、他のプロセスの動作に関連するエントリが表示されないようにしました (下図参照)。

図 2

図 2

Process Monitor でハングのトラブルシューティングを行う際は、まず、操作のタイム スタンプの差にハングの期間と一致するものがあるかどうかを確認する必要があります。"Duration" 列を追加し、通常すぐには完了しない操作 (ディレクトリ変更の通知など) をフィルターで除外して、時間がかかる操作を探すことができます。これは、操作間にあまり時間の差がない場合に役立ちます。プロセスは複数のスレッドを持ち、そのいくつかは、ハングを発生させているスレッドが休止している間に動作し続けるからです。

うれしい驚きできたが、管理者は、ちょうど 3 分前に発生しているだけでなく "IO DEVICE ERROR" という異常な結果コードを持つイベントをすぐに見つけることができました (下図参照)。

図 3

図 3 [拡大図]

Lisa_client プロセスは、C: ボリュームをホストしているディスクに対して SCSI パススルー コマンドを実行し、それが 3 分後にハードウェア エラーでタイムアウトしたようでした。管理者は、すぐにログオンできた 670 ワークステーションの 1 つではこのコマンドの実行結果はどうだったのだろうと思い、このようなワークステーションのトレースをキャプチャしました。そして、このようなワークステーションでは同じ操作にかかった時間が 1 ミリ秒未満であり、その操作は成功したことを知りました (下図参照)。

図 4

図 4 [拡大図]

この証拠は、670 ワークステーションの一部に搭載されていたディスクにハードウェアの問題があることをはっきり示していたので、管理者はすべての 670 ワークステーションからディスクの種類に関するデータを収集し、それを時間のかかるログオンのレポートと相互に関連付けました。そして、ログオンに時間のかかるシステムはすべて Seagate のディスクを搭載しており、それ以外のシステムは富士通のディスクを搭載していることに気付きました。

会社が独自の LOB アプリケーションによって発生している問題を回避するためだけにディスクを交換することがないのは明らかだったので、管理者は回避策を見つけ出す必要がありました。管理者は、Lisa_client の開発チームにこの問題について知らせました。そして、開発チームから、機能を失うことなくこのコマンドを削除することはできるが、この更新が内部のリリース プロセスを完了するには少なくとも数日間かかるという報告を受けました。一部のシステムで数日間システム情報が収集されないことはエンドユーザーの生産性ほど重要ではなかったので、管理者はひとまず、システム ディスクに照会しそれが Seagate モデルでなかった場合にのみ Lisa_client 起動する WMI ログオン スクリプトを記述しました。

管理者は、Process Monitor の助けを借りなくても、ディスクがハードウェア上の主な違いであることはおそらく突き止められたでしょうが、ディスクの交換を行うのではなく根本原因を特定してそれに対処することができたかどうかはわかりません。これも、Process Monitor の助けと洞察に満ちた探知作業によって解決された事例の 1 つです。

最後になりましたが、前述のとおり、Windows Vista、Windows Server 2008、およびそれ以上のバージョンでログオフとログオンを経ても有効であり続けるようにアプリケーションを構成するための手順をご紹介します。Windows XP 用にご紹介した PsExec コマンドは、より新しいバージョンのオペレーティング システムでは機能しません。Windows Vista にはセッション 0 分離が導入されているため、起動されたアプリケーションにログオン後にアクセスできるようにするには追加のコマンドがいくつか必要だからです。まず、管理者特権でのコマンド プロンプトで次の PsExec コマンドを使用して、セッション 0 でユーティリティを起動します。

psexec -sd -i 0 c:\sysint\procmon.exe

非表示のセッション 0 デスクトップでウィンドウを表示するプロセスが実行されていることを示す、"対話型サービス ダイアログの検出" というタイトルのウィンドウがタスク バーで点滅します。タスク バーのウィンドウをクリックして通知ダイアログを復元し、[メッセージを表示する] をクリックしてセッション 0 デスクトップに切り替えます (下図参照)。

図 5

起動したユーティリティがセッション 0 デスクトップに表示され、望ましい設定を使用してこのユーティリティを構成することができます (このユーティリティはローカル システム アカウント内で実行されているので、皆さん自身のアカウントの既定の設定はこのユーティリティには適用されません)。構成が完了したら、[戻る] をクリックしてメインのデスクトップに戻ります。これで、調査中の問題を再現するために、ログオフしてから再びオンすることができるようになりました。再びログオンしたら、セッション 0 デスクトップへの入り口が再び表示されるように、管理者特権でのコマンド プロンプトで次のコマンドを実行します。

net stop ui0detect 
net start ui0detect

セッション 0 デスクトップに戻ってキャプチャされた情報を確認し、ツールを閉じます。

最後に、このブログでは他にも多数のトラブルシューティング事例を取り上げており、こちら (英語) のブログ インデックスでそれを確認できることをお伝えしておきます。私が TechEd で行った "Case of the Unexplained" セッションを録画したものはこちら (英語) からご覧いただくことができます。また、今年の 6 月にニューオーリンズで開催される TechEd US (英語) では事例をすべて新しくしてこのセッションを行いますので、こちらにもぜひお越しください。

公開: 2010 年 1 月 13 日水曜日 3:06 AM 投稿者: markrussinovich (英語)

ページのトップへ

共有

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