Microsoft MVP성태의 닷넷 이야기
글쓴 사람
홈페이지
첨부 파일

실제 사례를 통해 Debug Diagnostics 도구가 생성한 닷넷 웹 응용 프로그램의 성능 장애 보고서 설명

최근에 고객사 덤프 분석을 하면서 의외로 "Debug Diagnostic" 도구의 결과물에 대해 너무 어렵다는 선입견을 보게 되었습니다.

DebugDiag 1.1을 사용한 덤프 분석
; https://www.sysnet.pe.kr/2/0/1026

Debug Diagnostic Tool v2 Update 3
; https://www.microsoft.com/en-us/download/details.aspx?id=58210

그런데, 실제로 사용해서 찬찬히 뜯어 보시면 충분히 일반적으로 인식할 수 있는 수준입니다. 여러분의 이해를 돕기 위해 이 글의 첨부 파일에 DebugDiag가 분석을 완료한 mht 출력 파일을 하나 올렸으니 그걸 보면서 설명해 보겠습니다. (실제 장애가 발생한 시점에 뜬 고객사 사례인데, 단지 메서드 등을 모두 TestWebApp이라든가 하는 식의 이름으로 바꾼 것입니다.)

dotnet_2_CrashHangAnalysis.mht
; https://www.sysnet.pe.kr/bbs/DownloadAttachment.aspx?fid=1513&boardid=331301885

위의 파일을 열어서 보면 초기에 다음과 같은 내용을 볼 수 있습니다.

windbg_es_hang_1.png

딱 봐도 문제가 있는 듯하죠? ^^ 어쨌든 메시지를 보면 610개의 스레드가 "System.Threading.Monitor.Wait"로 대기하고 있음을 알려주고 있습니다. 나열된 번호는 대기 중인 Thread의 ID 목록입니다.

그리고 내용을 좀 더 내려 보면 "Thread Report"가 나오고 그중에서 같은 thread call stack을 가진 것들만 연속으로 함께 나열된 후 해당 사실을 다음과 같이 알려줍니다.

windbg_es_hang_2.png

311 Threads (46% of all threads) have this same call stack.
Note: Grouping of identical threads can be disabled in the 'Preferences' tab of the Analysis Options

위의 메시지에 따라 이후 311개의 스레드가 같은 스레드 call stack을 갖고 있지만 개별 스레드마다 생성 시간 등은 다르므로 다음과 같이 그런 정보들만 다시 나열하고,

Thread 48 - System ID 18376

    Entry point   coreclr!Thread::intermediateThreadProc 
    Create time   2018-05-23 오후 10:04:41 
    Time spent in user mode   0 Days 00:00:46.531 
    Time spent in kernel mode   0 Days 00:00:00.953 

    This thread is waiting in System.Threading.Monitor.Wait


Thread 49 - System ID 32492

    Entry point   coreclr!Thread::intermediateThreadProc 
    Create time   2018-05-23 오후 10:07:13 
    Time spent in user mode   0 Days 00:00:39.625 
    Time spent in kernel mode   0 Days 00:00:01.015 

    This thread is waiting in System.Threading.Monitor.Wait

...[생략]...

311개 스레드 정보의 마지막에 해당하는 (dotnet_2_CrashHangAnalysis.mht의 경우 664번) 스레드가 나올 때 어떤 call stack을 동일하게 갖고 있는지 비로소 보여주게 됩니다.

windbg_es_hang_3.png

이 정도면 그냥 눈에 들어오죠? 위의 내용을 보면 가장 상단은 "System.Threading.ManualResetEventSlim.Wait"이지만 약간만 내려가도 ElasticSearch 관련 호출이 나오는 것에서 결국 ElasticSearch 호출로 인해, 즉 ElasticSearch 서버가 정상적으로 호출을 처리해주지 못해 311개의 스레드가 대기 중이라는 것을 알 수 있습니다.

이후의 Thread 분석 결과도 유사합니다. 처음 보고에서 610개의 스레드가 blocking 상태였는데 그중 311개는 위와 같은 상태이고, 다른 300개 정도의 스레드도 중간에 호출되는 업무 메서드가 달라서 callstack이 다른 것일 뿐 결국 상단에는 Elasticsearch.Net.HttpConnection.Request가 자리 잡고 있습니다.




어떠신가요? 덤프 분석이 (windbg로 하려면 어려운 듯하지만) Debug Diagnostics로 기본적인 분석 결과만 돌려봐도 응용 프로그램의 성능 문제를 파악하는 데 그다지 어려움이 없습니다.

따라서 앞으로는 문제가 발생했을 때, 무작정 iisreset 또는 recycle을 하지 말고 그전에 덤프 파일을 생성해 둘 것을 권장합니다. ^^




[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]





[최초 등록일: ]
[최종 수정일: 11/28/2019 ]

Creative Commons License
이 저작물은 크리에이티브 커먼즈 코리아 저작자표시-비영리-변경금지 2.0 대한민국 라이센스에 따라 이용하실 수 있습니다.
by SeongTae Jeong, mailto:techsharer@outlook.com

비밀번호

댓글 쓴 사람
 



2019-12-12 11시57분
[이광표] 부장님.. 덤프관련 내용 서치하다 글보고 댓글 남깁니다. 항시 도움 주셔서 감사합니다.
[손님]

1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...
NoWriterDateCnt.TitleFile(s)
12055정성태11/17/2019492개발 환경 구성: 463. Visual Studio의 Ctrl + Alt + M, 1 (Memory 1) 등의 단축키가 동작하지 않는 경우
12054정성태11/15/2019919.NET Framework: 869. C# - 일부러 GC Heap을 깨뜨려 GC 수행 시 비정상 종료시키는 예제
12053정성태11/15/2019556Windows: 164. 윈도우 10 - 명령행 창(cmd.exe) 속성에 (DotumChe, GulimChe, GungsuhChe 등의) 한글 폰트가 없는 경우
12052정성태11/15/2019497오류 유형: 578. Azure - 일정(schedule)에 등록한 runbook이 1년 후 실행이 안 되는 문제(Reason - The key used is expired.)
12051정성태12/2/20191172개발 환경 구성: 462. 시작하자마자 비정상 종료하는 프로세스의 메모리 덤프 - procdump [1]
12050정성태11/14/2019739Windows: 163. AcLayers의 API 후킹과 FaultTolerantHeap
12049정성태11/13/2019558.NET Framework: 868. (닷넷 프로세스를 대상으로) 디버거 방식이 아닌 CLR Profiler를 이용해 procdump.exe 기능 구현
12048정성태11/12/2019758Windows: 163. GUID 이름의 볼륨에 해당하는 파티션을 찾는 방법
12047정성태11/12/20191239Windows: 163. 안전하게 eject시킨 USB 장치를 물리적인 재연결 없이 다시 인식시키는 방법
12046정성태11/9/2019685오류 유형: 577. windbg - The call to LoadLibrary(...\sos.dll) failed, Win32 error 0n193
12045정성태10/27/2019558오류 유형: 576. mstest.exe 실행 시 "Visual Studio Enterprise is required to execute the test." 오류 - 두 번째 이야기
12044정성태10/27/2019703오류 유형: 575. mstest.exe - System.Resources.MissingSatelliteAssemblyException: The satellite assembly named "Microsoft.VisualStudio.ProductKeyDialog.resources.dll, ..."
12043정성태10/27/2019696오류 유형: 574. Windows 10 설치 시 오류 - 0xC1900101 - 0x4001E
12042정성태10/26/2019633오류 유형: 573. OneDrive 하위에 위치한 Documents, Desktop 폴더에 대한 권한 변경 시 "Unable to display current owner"
12041정성태10/23/2019505오류 유형: 572. mstest.exe - The load test results database could not be opened.
12040정성태10/23/2019866오류 유형: 571. Unhandled Exception: System.Net.Mail.SmtpException: Transaction failed. The server response was: 5.2.0 STOREDRV.Submission.Exception:SendAsDeniedException.MapiExceptionSendAsDenied
12039정성태10/22/2019655스크립트: 16. cmd.exe의 for 문에서는 ERRORLEVEL이 설정되지 않는 문제
12038정성태10/17/2019518오류 유형: 570. SQL Server 2019 RC1 - SQL Client Connectivity SDK 설치 오류
12037정성태10/15/2019829.NET Framework: 867. C# - Encoding.Default 값을 바꿀 수 있을까요?파일 다운로드1
12036정성태10/21/20191466.NET Framework: 866. C# - 고성능이 필요한 환경에서 GC가 발생하지 않는 네이티브 힙 사용파일 다운로드1
12035정성태10/13/2019697개발 환경 구성: 461. C# 8.0의 #nulable 관련 특성을 .NET Framework 프로젝트에서 사용하는 방법파일 다운로드1
12034정성태1/31/2020973개발 환경 구성: 460. .NET Core 환경에서 (프로젝트가 아닌) C# 코드 파일을 입력으로 컴파일하는 방법 [1]
12033정성태10/11/20191390개발 환경 구성: 459. .NET Framework 프로젝트에서 C# 8.0 컴파일러를 사용하는 방법
12032정성태11/25/2019854.NET Framework: 865. .NET Core 2.2/3.0 웹 프로젝트를 IIS에서 호스팅(Inproc, out-of-proc)하는 방법 - AspNetCoreModuleV2 소개
12031정성태10/7/2019545오류 유형: 569. Azure Site Extension 업그레이드 시 "System.IO.IOException: There is not enough space on the disk" 예외 발생
12030정성태11/12/20192247.NET Framework: 864. .NET Conf 2019 Korea - "닷넷 17년의 변화 정리 및 닷넷 코어 3.0" 발표 자료 [1]파일 다운로드1
1  2  3  4  5  6  7  8  [9]  10  11  12  13  14  15  ...