IIS 6.0에서 교착 상태 덤프 파일 분석 (OrphanWorkerProcess)

IIS 6.0 에서는 재생이나 오류가 발생하는 경우 해당 응용프로그램 풀을 재생하는 기능을 지원합니다.

그럴때 정상적인 종료가 되지 못할경우 오류이벤트가 발생하게 되나, 일반적으로 크게 문제가 되지는 않지만 일부 웹사이트에서는 장애를 일으키는 경우가 있습니다.

특히나, 기본설정값으로 IIS 6.0 에서는 오류가 급증할경우 코어를 보호하기 위해서 해당 응용프로그램풀을 아예 중지를 시켜 버립니다.

이벤트로그를 유심히 살펴봐야 하는데요., 주로 다음과 같은 이벤트가 발생하게 됩니다.



이때 고아프로세스 형태로 재생을 시도하게 되며, 새로운 요청은 별도의 새로운 작업자프로세스에서 처리하게 됩니다. 고아프로세스는 해당 프로세스가 완전 종료하기 전의 상태입니다.

이 프로세스에는 재생전 요청이나 처리가 되지 못한 요청이 저장되어 있는데, 이를 분석하면 원인을 제공하는 요청이나 처리를 어느정도 파악할수 있습니다.

이때, 디버거를 통해서 해당 프로세스의 크래시 덤프를 떠서 분석을 할수 있는데요,. 덤프를 자동으로 뜰수 있게끔 IIS 6.0 에서는 고아프로세스가 종료할 때 특정 작업을 할수 있는 옵션을 제공합니다.


1. 덤프파일 생성을 위한 설정

다음과 같이 메타베이스에 값을 설정하면 됩니다.

adsutil.vbs SET W3SVC/AppPools/DefaultAppPool/OrphanWorkerProcess TRUE
adsutil.vbs SET W3SVC/AppPools/DefaultAppPool/OrphanActionExe "F:\Debug\debug.cmd"
adsutil.vbs SET W3SVC/AppPools/DefaultAppPool/OrphanActionParams "%1%"

debug.cmd 배치파일

@if "%_echo%"=="" echo off
setlocal
    set TIMESTAMP=%DATE:~-9%_%TIME%
set TIMESTAMP=%TIMESTAMP:/=_%
set TIMESTAMP=%TIMESTAMP::=_%
set TIMESTAMP=%TIMESTAMP:.=_%
set TIMESTAMP=%TIMESTAMP: =_%
set FILENAME=F:\Debug\crash_%TIMESTAMP%.dmp
set LOG=F:\Debug\log.txt
set COMMAND="C:\Program Files\Debugging Tools for Windows"\cdb.exe -c ".dump /o /mhf %FILENAME%;q" -p %1

echo %COMMAND% > %LOG%
%COMMAND%

endlocal

물론 덤프를 뜰수 있도록 사전에 디버거를 설치해 놓아야 하겠죠..^^

OrphanActionExe: %SystemRoot%\System32\CScript.exe
OrphanActionParams: C:\debuggers\adplus.vbs -quiet -hang -p %1%

위와 같이 디버거툴에 내장된 Adplus.vbs 스크립트를 이용해서도 덤프파일을 생성할수 있습니다.

2. 덤프파일 분석

생성된 덤프파일 분석은 이미 설치한 디버거툴을 통해서 분석을 할수 있습니다. 최근에 배포되고 있는  Windbg 툴을 이용해도 좋습니다.

다운로드: http://www.microsoft.com/whdc/devtools/debugging/default.mspx

그런데 이툴은 심볼을 자동 다운로드를 지원하지 않하서, 해당 덤프를 분석해도 별 도움이 되지 않는 아주 간단한 로그만 볼수가 있습니다.

이 툴보다는, 최근에 새로이 배포하는 Debug Diagnostic Tool v1.1 를 권장합니다. 이 툴은 특히 IIS 에 관련된 프로세스 덤프 및 분석, 그리고 관련 심볼을 자동다운로드 하여 분석해 줍니다.

다운로드: http://www.microsoft.com/downloads/details.aspx?familyid=28BD5941-C458-46F1-B24D-F60151D875A3&mg_id=10110&displaylang=en

관련 심볼을 통해서 분석하므로, 아주 상세한 분석을 보여줍니다.



요약에는 WinSock 관련된 문제라고 하는데요. 해당 쓰레드의 상세를 보면, 다음과 같습니다.

실제, 1013 이벤트 에서는 덤프에서 분석이 가능한 데이터가 그리 많지 않습니다.

주로 효과적인 덤프분석은 웹서버에서 루프같은 CPU 로드가 100% 이거나, 메모리 누수같은 메모리 급증이 나타날때 재생되거나 또는 해당 시점에서 직접 덤프를 뜨는 것이 아주 좋습니다.

그럴 경우 다음과 같이 실제 문제가 되는 코드까지도 알수 있습니다.

POST request for   /www/body/A.asp
Request alive for   00:32:47
QueryString   PageName=PageUpload&theAct=upload&overWrite=true
Request mapped to   D:\service\serverinfo.pe.kr\www\body\A.asp
ASP Application   /LM/W3SVC/792638948/Root
ASP Template   D:\SERVICE\serverinfo.pe.kr\WWW\BODY\A.ASP

StreamUpload   sA.CopyTo sB, intEnd - intInfoEnd - 4   D:\SERVICE\serverinfo.pe.kr\WWW\BODY\A.ASP   1697
PageUpload   StreamUpload()   D:\SERVICE\serverinfo.pe.kr\WWW\BODY\A.ASP   1577
Global Scope   PageUpload()   D:\SERVICE\serverinfo.pe.kr\WWW\BODY\A.ASP   192

좀더 상세한 분석은, 각자 운영하는 서버별로 상황이 다르므로 디버거툴을 이용해서 분석해 보시기를 바랍니다. 또한  추가로 다음문서를 더 참고해 보시기 바랍니다.

ASP.NET 교착 상태에 있는 이벤트 ID 1003
http://support.microsoft.com/?kbid=325947

ASP.NET 응용 프로그램에서 웹 서비스를 요청하면 경합, 성능 저하 및 교착 상태가 발생한다
http://support.microsoft.com/kb/821268/ko


08-iis-debug-0.png
08-iis-debug-1.png
08-iis-debug-3.gif
08-iis-debug-4.gif