IIS Crash/Hang Agent & IIS Dump でのトラブルシューティング
ちょっと昔のツールで IIS Crash/Hang Agent & IIS Dump というのがありました。
IIS 5 (Windows 2000) とか IIS 5.1 (Windows XP) とか IIS 6.0 (Windows Server 2003) で利用可能なツールです。
最新の環境 IIS 7.x には対応していません。また IIS 6 上では Debug Diagnostic Tool というのが新しく開発されたので、 IIS Crash/Hang Agent のほうは使われなくなっていました。
ところが、最近「ハングアップを検出した時にカスタムのコマンドを叩きたい」という要望に対応するツールを検討していたところ、 簡単に使えそうなツールとして IIS Crash/Hang Agent が挙がりました。
ここでは、IIS Crash/Hang Agent を使ってハングアップを検出して、ログを取得。さらにカスタムコマンドを実行する方法を紹介します。
IIS Crash/Hang Agent & IIS Dump の入手とインストール
IIS Crash/Hang Agent & IIS Dump は MS のダウンロードセンターから入手可能です。
IIS Crash/Hang Agent & IIS Dump
http://www.microsoft.com/download/en/details.aspx?displaylang=en&id=1200
インストールプログラムを実行すると、IIS (W3SVC サービス) の再起動が促されます。再起動後、クラッシュハングエージェントの ISAPI フィルタが設定されます。
この ISAPI フィルタはサイトレベルではなくシステムレベルです。また、IIS6 ではリクエストをうけてからアプリケーションプールの ワーカープロセスが起動するので優先度 = 不明などになってますが正常です。リクエストを受けた後は優先度 "高" になります。
なお、ISAPI フィルタについては ISAPI フィルタ概要 を参考にしてください。
クラッシュハングエージェントによる IIS の監視が行われているときには、_IISCHAgent.exe が実行します。
IIS Crash/Hang Agent の設定
さて、インストールディレクトリはつぎのようになっています。
この中に設定ファイルがはいってます。ハングについてはデフォルトでモニター対象外なので、設定ファイルを変更します。
ハングアップの検出を有効にする
IISCHAgent.ini を書き換えます。
[HangAgent] Enable=1 ;LogLocation=%SystemDrive%\iisdebugtools\logs MaxLogFiles=10 WriteLog=1 RequestTimeLimit=15 ActionCommand=C:\Temp\test.cmd MaxActionsAllowed=10
ここで、ハング検出時に C:\Temp\test.cmd ファイルを実行するようにしています。 test.cmd は次の内容です。
C:\IISDebugTools\iisdump.exe ...
... の部分に好きなコマンドを書けば OK です。
ハングアップ検出時にはつぎのようにログが採取されるはずです。
実際の監視を開始する前に次のようなコードでハングアップを発生させて、ログが取得できることを確認しておくと良いでしょう。
hang.aspx
<%@ Page Language="C#" AutoEventWireup="true" CodeFile="hang.aspx.cs" Inherits="hang" %>
<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN"
"http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml" >
<head runat="server">
<title>Untitled Page</title>
</head>
<body>
<form id="form1" runat="server">
<div>
<asp:Button ID="Button1"
runat="server"
OnClick="Button1_Click"
Text="Button"
/></div>
</form>
</body>
</html>
コードビハインド hang.aspx.cs はこんなです。単に Sleep してます。
using System;
using System.Data;
using System.Configuration;
using System.Collections;
using System.Web;
using System.Web.Security;
using System.Web.UI;
using System.Web.UI.WebControls;
using System.Web.UI.WebControls.WebParts;
using System.Web.UI.HtmlControls;
public partial class hang : System.Web.UI.Page
{
protected void Button1_Click(object sender, EventArgs e)
{
System.Threading.Thread.Sleep(120 * 1000);
}
}
これでログが採取できない場合は、ワーカープロセスの ID を System にするなどしてみてください。
簡単なダンプ解析
ログを取得してもログの見方がわからないと意味が全くありませんので、上のテストコード hang.aspx を用いて試しに取得したメモリダンプの 見方を簡単に紹介します。
最初にシステム環境変数 _NT_SYMBOL_PATH を作成します。
名前: _NT_SYMBOL_PATH
値: SRV*C:\websymbols*http://msdl.microsoft.com/download/symbols
次に Debugging Tools for Windows をインストールします。私は C:\Debuggers フォルダにインストールしました。
SOS.dll を .NET Framework のシステムフォルダから C:\Debuggers にコピーします。 ダンプを取得した環境と同じバージョンの SOS.dll を利用します。
デバッガ (WinDbg や cdb) でダンプファイルを開きます。
CLR のスタックは次のように見えます。
0:000> !sos.threads
ThreadCount: 7
UnstartedThread: 0
BackgroundThread: 7
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
PreEmptive GC Alloc Lock
ID OSID ThreadOBJ State GC Context Domain Count APT Exception
1 1 13cc 00174a38 a808220 Enabled 05a19560:05a1b008 001a5430 1 MTA (Threadpool Completion Port)
7 2 8e4 0017af78 b220 Enabled 00000000:00000000 0016b950 0 MTA (Finalizer)
8 3 17d4 00191e00 80a220 Enabled 00000000:00000000 0016b950 0 MTA (Threadpool Completion Port)
9 4 14b4 001a4f10 1220 Enabled 00000000:00000000 0016b950 0 Ukn
10 5 c10 001e35d8 180b220 Enabled 05a085c0:05a08fe8 0016b950 0 MTA (Threadpool Worker)
11 6 1764 00242468 180b220 Enabled 05a06944:05a06fe8 0016b950 0 MTA (Threadpool Worker)
13 7 900 0024ab18 880b220 Enabled 01a53e30:01a55008 0016b950 0 MTA (Threadpool Completion Port)
0:000> ~1s
eax=00000000 ebx=00000000 ecx=00000004 edx=058c0000 esi=00000000 edi=00aff370
eip=7c90e514 esp=00aff340 ebp=00aff398 iopl=0 nv up ei pl nz na po nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00200202
ntdll!KiFastSystemCallRet:
7c90e514 c3 ret
0:001> !clrstack
OS Thread Id: 0x13cc (1)
ESP EIP
00aff480 7c90e514 [HelperMethodFrame: 00aff480] System.Threading.Thread.SleepInternal(Int32)
00aff4d4 79299275 System.Threading.Thread.Sleep(Int32)
00aff4d8 0fc50835 hang.Button1_Click(System.Object, System.EventArgs)
00aff4ec 6679a6a8 System.Web.UI.WebControls.Button.OnClick(System.EventArgs)
00aff504 6679a50f System.Web.UI.WebControls.Button.RaisePostBackEvent(System.String)
00aff51c 6679a74b System.Web.UI.WebControls.Button.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(System.String)
00aff524 66095d5e System.Web.UI.Page.RaisePostBackEvent(System.Web.UI.IPostBackEventHandler, System.String)
00aff530 66095cb5 System.Web.UI.Page.RaisePostBackEvent(System.Collections.Specialized.NameValueCollection)
00aff544 660a7ede System.Web.UI.Page.ProcessRequestMain(Boolean, Boolean)
00aff69c 660a7764 System.Web.UI.Page.ProcessRequest(Boolean, Boolean)
00aff6d4 660a7691 System.Web.UI.Page.ProcessRequest()
00aff70c 660a7626 System.Web.UI.Page.ProcessRequestWithNoAssert(System.Web.HttpContext)
00aff718 660a7602 System.Web.UI.Page.ProcessRequest(System.Web.HttpContext)
00aff72c 0fc502fe ASP.hang_aspx.ProcessRequest(System.Web.HttpContext)
00aff73c 660adad6 System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
00aff770 6608132c System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
00aff7b0 6608c5c3 System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(System.Exception)
00aff800 660808ac System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
00aff81c 66083e1c System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
00aff850 66083ac3 System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
00aff860 66082c5c System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)
00aff864 79faca4d [InlinedCallFrame: 00aff864]
00affaa8 79faca4d [GCFrame: 00affaa8]
00affc04 79faca4d [ComMethodFrame: 00affc04]
確かに Button1_Click から Sleep が呼ばれていることが分かりますね？ このようにして、何がハングアップの原因となっているかわかります。
ハングアップが発生した時に「あれが原因かな？」「これじゃないか？」などと妙な推測をして問題を切り抜けようとする人は多いものです。 しかし、闇雲にあれこれ試すのではなく、こうしたダンプファイルを確認して、ちゃんと実際に何が起きているかチェックすることができるようになれば、 問題はたいていの場合速やかに片付きます。