windbg - ASP.NET MVC Web Application (.NET Framework) 응용 프로그램의 덤프 분석 시 요령
ASP.NET Web Application (.NET Framework) 응용 프로그램을 MVC 유형으로 기본 예제를 하나 만들어 windbg로 분석하는 과정 중에 나오는 것들을 정리해 보겠습니다.
우선, 개발자 입장에서 (MVC) 웹 사이트의 소스 코드 구조는 이렇게 나옵니다.
/Controllers/HomeController.cs
Indxe()
About()
Contact()
/Views/Home
/About.cshtml
/Contact.cshtml
/Index.cshtml
그리고 이것을 빌드하면 WebApplication1.dll DLL 파일 하나에 해당 웹 프로젝트의 모든 소스코드 컴파일 결과물이 포함됩니다. 이후, WebApplication1.dll을 디컴파일해 보면 개발자가 작성한 (HomeController.cs 등의) Controller 코드는 모두 (특별히 변경하지 않았다면) "Controllers" 네임스페이스 하위에서 찾을 수 있습니다.
WebApplication1.Controllers
HomeController
About()
Contact()
Index()
반면 cshtml 파일의 경우에는 다소 특별한데요, 개발자가 ASP.NET Web App을 개발한 다음, publish를 하게 되면 기본적으로 다음과 같은 식으로 결과물이 나옵니다.
/ (루트 디렉터리)
[bin]
[Content]
favicon.ico
Global.asax
[Scripts]
[Views] // cshtml 파일이 놓인 디렉터리
Web.config
따라서 운영 중인 서버에서 디버깅을 하는 중이라면 WebApp의 배포 디렉터리에서 cshtml 파일의 원본을 찾을 수 있습니다. 하지만, 프로세스의 덤프 파일에서는 저 원본 내용을 찾을 수 없습니다.
왜냐하면, ASP.NET 엔진은 런타임 시에 cshtml 파일을 pre-compile 시켜 DLL로 만들어 놓은 다음 사용하기 때문에 덤프 파일 내에는 어떠한 cshtml 파일의 내용도 찾을 수 없습니다. (물론, 운 좋게 ASP.NET 엔진이 컴파일을 위해 string 변수에 담은 파일 내용을 GC되기 전에 찾을 수 있다면 가능할 수도 있습니다.)
ASP.NET 엔진은 cshtml 파일에 대한 요청이 오면 그 순간 cshtml 파일을 pre-compile 시켜 DLL 파일로 만들어 놓습니다. 그리고 그 결과물은 호스팅 중인 서버의 "%WINDIR%\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files" 경로에 cache합니다.
물론, 메모리 덤프를 뜬 경우에는 그 DLL들이 모두 덤프 파일에 담기게 됩니다.
그렇다면 혹시 덤프에 포함된 그 pre-compiled 시킨 DLL을 디컴파일하면 cshtml 파일의 내용을 볼 수 있을까요? 아쉽게도 cshtml 파일의 원본은 확인할 수 없습니다. lm 명령어로 DLL 목록을 볼 때 "App_Web_[...hash...].dll" 유형의 이름을 갖는 것들이 바로 cshtml 파일의 내용을 포함하고 있는 DLL인데요,
0:000> lm
start end module name
...[생략]...
00000233`4b3e0000 00000233`4b3e8000 App_Web_esgmt44v (deferred)
00000233`4b3f0000 00000233`4b3fa000 App_Web_bauo0udd (deferred)
...[생략]...
파일명의 나머지 부분이 여러 가지 조건을 기반으로 한 hash로 이뤄지기 때문에 어떤 cshtml 파일인지 파일명만으로는 판단할 수 없습니다. 결국 일일이 decompiler로 열어봐야 하는데, 이것도 매우 번거로운 일이므로 Reflection을 이용해 검색을 할 수 있는 유틸리티를 만들어 사용하는 것이 좋을 것입니다.
참고로, About.cshtml 파일의 컴파일 결과물을 보면 다음과 같이 나오는데요, (일일이 열어본 결과 App_Web_esgmt44v.dll에 있었습니다.)
using System;
using System.Runtime.CompilerServices;
using System.Web.Mvc;
using Microsoft.CSharp.RuntimeBinder;
namespace ASP
{
// Token: 0x02000004 RID: 4
[Dynamic(new bool[]
{
false,
true
})]
public class _Page_Views_Home_About_cshtml : WebViewPage<object>
{
// Token: 0x17000002 RID: 2
// (get) Token: 0x06000009 RID: 9 RVA: 0x00002300 File Offset: 0x00000500
protected global_asax ApplicationInstance
{
get
{
return (global_asax)this.Context.ApplicationInstance;
}
}
// Token: 0x0600000A RID: 10 RVA: 0x00002324 File Offset: 0x00000524
public override void Execute()
{
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__0 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__0 = CallSite<Func<CallSite, object, string, object>>.Create(Binder.SetMember(CSharpBinderFlags.None, "Title", typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null),
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.UseCompileTimeType | CSharpArgumentInfoFlags.Constant, null)
}));
}
_Page_Views_Home_About_cshtml.<>o__3.<>p__0.Target(_Page_Views_Home_About_cshtml.<>o__3.<>p__0, base.ViewBag, "About");
this.WriteLiteral("\r\n<main");
this.WriteLiteral(" aria-labelledby=\"title\"");
this.WriteLiteral(">\r\n <h2");
this.WriteLiteral(" id=\"title\"");
this.WriteLiteral(">");
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__2 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__2 = CallSite<Action<CallSite, _Page_Views_Home_About_cshtml, object>>.Create(Binder.InvokeMember(CSharpBinderFlags.InvokeSimpleName | CSharpBinderFlags.ResultDiscarded, "Write", null, typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.UseCompileTimeType, null),
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null)
}));
}
Action<CallSite, _Page_Views_Home_About_cshtml, object> target = _Page_Views_Home_About_cshtml.<>o__3.<>p__2.Target;
CallSite <>p__ = _Page_Views_Home_About_cshtml.<>o__3.<>p__2;
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__1 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__1 = CallSite<Func<CallSite, object, object>>.Create(Binder.GetMember(CSharpBinderFlags.None, "Title", typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null)
}));
}
target(<>p__, this, _Page_Views_Home_About_cshtml.<>o__3.<>p__1.Target(_Page_Views_Home_About_cshtml.<>o__3.<>p__1, base.ViewBag));
this.WriteLiteral(".</h2>\r\n <h3>");
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__4 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__4 = CallSite<Action<CallSite, _Page_Views_Home_About_cshtml, object>>.Create(Binder.InvokeMember(CSharpBinderFlags.InvokeSimpleName | CSharpBinderFlags.ResultDiscarded, "Write", null, typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.UseCompileTimeType, null),
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null)
}));
}
Action<CallSite, _Page_Views_Home_About_cshtml, object> target2 = _Page_Views_Home_About_cshtml.<>o__3.<>p__4.Target;
CallSite <>p__2 = _Page_Views_Home_About_cshtml.<>o__3.<>p__4;
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__3 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__3 = CallSite<Func<CallSite, object, object>>.Create(Binder.GetMember(CSharpBinderFlags.None, "Message", typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null)
}));
}
target2(<>p__2, this, _Page_Views_Home_About_cshtml.<>o__3.<>p__3.Target(_Page_Views_Home_About_cshtml.<>o__3.<>p__3, base.ViewBag));
this.WriteLiteral("</h3>\r\n\r\n <p>Use this area to provide additional information.</p>\r\n</main>");
}
}
}
cshtml 원본에서는 ViewBag.Title = "About" 코드 한 줄이,
@{
ViewBag.Title = "About";
}
<main aria-labelledby="title">
<h2 id="title">@ViewBag.Title.</h2>
<h3>@ViewBag.Message</h3>
<p>Use this area to provide additional information.</p>
</main>
다음과 같이
dynamic 유형으로 변환돼 복잡하게 디컴파일이 됩니다.
if (_Page_Views_Home_About_cshtml.<>o__3.<>p__0 == null)
{
_Page_Views_Home_About_cshtml.<>o__3.<>p__0 = CallSite<Func<CallSite, object, string, object>>.Create(Binder.SetMember(CSharpBinderFlags.None, "Title", typeof(_Page_Views_Home_About_cshtml), new CSharpArgumentInfo[]
{
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.None, null),
CSharpArgumentInfo.Create(CSharpArgumentInfoFlags.UseCompileTimeType | CSharpArgumentInfoFlags.Constant, null)
}));
}
_Page_Views_Home_About_cshtml.<>o__3.<>p__0.Target(_Page_Views_Home_About_cshtml.<>o__3.<>p__0, base.ViewBag, "About");
그러니까, 저런 코드 조각들이 나오면 중간에 @{...} 코드 블록으로 인해 추가된 것으로 인지할 수 있습니다. 현실적인 기준으로, 저 코드를 통해 뭔가 원인 추적을 하는 것은 그다지 도움이 되지 않을 것입니다.
따라서 디버깅 측면에서 봤을 때, cshtml 파일에 코드를 넣어두기보다는 기왕이면 Controller 측에 넣어두는 것이 더 좋습니다.
자, 그럼 Controller 측의 코드로 다시 돌아가 예를 들기 위해 일부러 지연 코드를 넣어두고,
public ActionResult Index()
{
Thread.Sleep(1000 * 60);
return View();
}
실제로 실행된 프로세스의 덤프를
Debug Analysis로 분석해 보면 이런 결과가 나옵니다.
HttpContext Report
HttpContext Timeout Completed RunningSince ThreadId ReturnCode Verb RequestPath+QueryString
24b41371328 110 Sec Yes --- 200 GET /
24c813713c8 110 Sec Yes --- 200 GET /Home/About
24d81804348 110 Sec Yes --- 200 GET /Home/Contact
24d8188a608 110 Sec No 11 Sec 52 200 GET /
저기서, Completed가 Yes인 것들은 이미 HTTP 요청이 완료된 상태로 단지 GC Heap에 HttpContext 인스턴스가 아직 (수거되지 않고) 남아 있어 보여주는 것에 불과합니다.
따라서 실제로 의미가 있는 것은 현재 수행 중인 HttpContext == 24d8188a608, ThreadId == 52 항목을 살펴볼 필요가 있는데요, Windbg에서 52번 스레드로 이동해 call stack을 확인할 수 있으므로,
// 사실, callstack 마저도 기본적으로 Debug Analysis에서 제공해 줍니다.
0:000> ~52s
ntdll!NtDelayExecution+0x14:
00007ffa`cee307b4 c3 ret
0:052> !clrstack
OS Thread Id: 0xd2ac (52)
Child SP IP Call Site
0000005753d7d138 00007ffacee307b4 [HelperMethodFrame: 0000005753d7d138] System.Threading.Thread.SleepInternal(Int32)
0000005753d7d230 00007ffaa603b0bb System.Threading.Thread.Sleep(Int32) [f:\dd\ndp\clr\src\BCL\system\threading\thread.cs @ 725]
0000005753d7d260 00007ffa523e70d7 WebApplication1.Controllers.HomeController.Index() [c:\temp\webapp\WebApplication1\WebApplication1\Controllers\HomeController.cs @ 14]
0000005753d7d2a0 00007ffa525100d7 DynamicClass.lambda_method(System.Runtime.CompilerServices.Closure, System.Web.Mvc.ControllerBase, System.Object[])
0000005753d7d2d0 00007ffa523e68e3 System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(System.Web.Mvc.ControllerContext, System.Web.Mvc.ActionDescriptor, System.Collections.Generic.IDictionary`2<System.String,System.Object>)
...[생략]...
0000005753d7e700 00007ff987baee84 System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr, IntPtr, IntPtr, Int32)
0000005753d7e740 00007ff9882615e3 DomainNeutralILStubClass.IL_STUB_ReversePInvoke(Int64, Int64, Int64, Int32)
0000005753d7e908 00007ffab16dfef3 [ContextTransitionFrame: 0000005753d7e908]
문제 분석에 도움이 될 수 있습니다. 아울러, HttpContext 개체 자체도 덤프해 볼 수 있는데요,
0:052> !do 24d8188a608
Name: System.Web.HttpContext
MethodTable: 00007ff98788fdd8
EEClass: 00007ff9879564e0
Size: 424(0x1a8) bytes
File: C:\WINDOWS\Microsoft.Net\assembly\GAC_64\System.Web\v4.0_4.0.0.0__b03f5f7f11d50a3a\System.Web.dll
Fields:
MT Field Offset Type VT Attr Value Name
00007ff98788f5d0 4000334 8 ...IHttpAsyncHandler 0 instance 0000000000000000 _asyncAppHandler
00007ff987886be0 4000335 160 System.Int32 1 instance 0 _asyncPreloadModeFlags
00007ffaa5adc638 4000336 170 System.Boolean 1 instance 1 _asyncPreloadModeFlagsSet
00007ff98788de70 4000337 10 ...b.HttpApplication 0 instance 0000024b41373de0 _appInstance
00007ff98788f638 4000338 18 ....Web.IHttpHandler 0 instance 0000024d8188ddc0 _handler
00007ff98788fef0 4000339 20 ...m.Web.HttpRequest 0 instance 0000024d8188a7c8 _request
00007ff98788ff98 400033a 28 ....Web.HttpResponse 0 instance 0000024d8188a950 _response
...[생략]...
개인적인 경험으로는 딱히 의미 있었던 적은 없었습니다. (종종 특별하게는, 가령 HttpContext.Items에 넣어둔 데이터를 확인하는 게 필요하다면!)
참고로, 시간 되시면 이 글도 한번 읽어보시고. ^^
Debugging Script: Dumping out current and recent ASP.NET Requests
; https://www.tessferrandez.com/blog/2007/09/12/debugging-script-dumping-out-current-and-recent-aspnet-requests.html
다른 경우로, 예외 발생 상황을 볼까요? 테스트를 위해 관련 코드를 추가하고,
public ActionResult Index()
{
try
{
throw new InvalidCastException("[Index] test exception");
} catch { }
return View();
}
public ActionResult About()
{
ViewBag.Message = "Your application description page.";
throw new InvalidCastException("[About] test exception");
return View();
}
우선, About을 방문해서 발생하는 예외라면 ASP.NET의 경우 기본적으로 Event Viewer에서 호출 스택까지도 자세하게 남겨주므로,
Event code: 3005
...[생략]...
Event detail code: 0
Application information:
Application domain: /LM/W3SVC/2/ROOT-1-133717210099867290
Trust level: Full
Application Virtual Path: /
Application Path: C:\temp\webapp\WebApplication1\WebApplication1\
Machine name: KEVIN10
Process information:
Process ID: 13400
Process name: w3wp.exe
Account name: IIS APPPOOL\tempweb
Exception information:
Exception type: InvalidCastException
Exception message: [About] test exception
at WebApplication1.Controllers.HomeController.About() in c:\temp\webapp\WebApplication1\WebApplication1\Controllers\HomeController.cs:line 26
at lambda_method(Closure , ControllerBase , Object[] )
at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary`2 parameters)
...[생략]...
Request information:
Request URL: http://localhost:8030/Home/About
Request path: /Home/About
User host address: ::1
User:
Is authenticated: False
Authentication Type:
Thread account name: IIS APPPOOL\tempweb
Thread information:
Thread ID: 10
Thread account name: IIS APPPOOL\tempweb
Is impersonating: False
Stack trace: at WebApplication1.Controllers.HomeController.About() in c:\temp\webapp\WebApplication1\WebApplication1\Controllers\HomeController.cs:line 26
at lambda_method(Closure , ControllerBase , Object[] )
at System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(ControllerContext controllerContext, ActionDescriptor actionDescriptor, IDictionary`2 parameters)
...[생략]...
그나마 쉽게 분석이 가능합니다. 문제는, 예외를 먹는 Index에서의 경우입니다. 이럴 때는 방문을 해도 Event Viewer에도 남지 않는데요, 만약 저 결과로 인해 사용자가 원하는 화면이 나오지 않는 경우 그 원인을 추적하기가 매우 힘든 상황이 됩니다. 이럴 때는, procdump를 이용해 볼 수 있는데요,
try/catch로 조용히 사라진 예외를 파악하고 싶다면?
; https://www.sysnet.pe.kr/2/0/10965
따라서 다음과 같이 실행해 두고,
// 관리자 권한으로 실행
// w3wp.exe의 pid == 13400인 경우,
C:\Windows\System32> procdump -e 1 -f "" 13400
...[생략]...
예외를 먹는 페이지를 방문하면 그 순간 화면에 다음과 같은 출력이 나옵니다.
[16:06:39] Exception: E0434F4D.System.InvalidCastException ("[Index] test exception")
그럼, Ctrl+C 키를 눌러 procdump를 종료하고 위에서 얻은 예외 타입으로 덤프를 뜨도록 다음과 같이 다시 실행합니다.
// 관리자 권한으로 실행
// w3wp.exe의 pid == 13400인 경우,
C:\Windows\System32> procdump -ma -e 1 -f System.InvalidCastException 13400
...[생략]...
이후 문제가 되는 페이지를 방문하면 예외가 발생하는 그 순간 덤프가 남겨지고, 그 덤프를 통해 문제의 원인을 추적할 수 있습니다.
0:043> !clrstack
OS Thread Id: 0x3974 (43)
Child SP IP Call Site
000000684e67da78 00007ffacee301b4 [HelperMethodFrame: 000000684e67da78]
000000684e67db60 00007ffa523e711e WebApplication1.Controllers.HomeController.Index() [c:\temp\webapp\WebApplication1\WebApplication1\Controllers\HomeController.cs @ 16]
000000684e67dbd0 00007ffa525100d7 DynamicClass.lambda_method(System.Runtime.CompilerServices.Closure, System.Web.Mvc.ControllerBase, System.Object[])
000000684e67dc00 00007ffa523e68e3 System.Web.Mvc.ControllerActionInvoker.InvokeActionMethod(System.Web.Mvc.ControllerContext, System.Web.Mvc.ActionDescriptor, System.Collections.Generic.IDictionary`2<System.String,System.Object>)
...[생략]...
물론, 이 모든 것들은
Remote Debugging이 허용되는 상황이라면 덤프 없이 라이브 디버깅을 하는 것이 훨씬 문제 분석을 쉽게 할 수 있습니다. ^^
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]