성태의 닷넷 이야기
홈 주인
모아 놓은 자료
프로그래밍
질문/답변
사용자 관리
사용자
메뉴
아티클
외부 아티클
유용한 코드
온라인 기능
MathJax 입력기
최근 덧글
[정성태] How can I tell whether two programs...
[정성태] The case of the fail-fast crashes c...
[정성태] Creating Docker multi-arch images f...
[정성태] BinaryFormatter removed from .NET 9...
[정성태] Extending the Windows Shell Progres...
[우광현] 와..... 범위를 잡았으니 클라이언트가 해당 범위를 확인해본다...
[정성태] 딱히, 그것 이상으로 더 설명할 내용이 없습니다. 동적 포...
[정성태] If Windows 3.11 required a 32-bit p...
[정성태] What is a hard error, and what make...
[괴물신인] 질문작성자인데 이 글을 이제봤네요 ㄷㄷ 이 글처럼 타입별로 인...
글쓰기
제목
이름
암호
전자우편
HTML
홈페이지
유형
제니퍼 .NET
닷넷
COM 개체 관련
스크립트
VC++
VS.NET IDE
Windows
Team Foundation Server
디버깅 기술
오류 유형
개발 환경 구성
웹
기타
Linux
Java
DDK
Math
Phone
Graphics
사물인터넷
부모글 보이기/감추기
내용
<div style='display: inline'> <h1 style='font-family: Malgun Gothic, Consolas; font-size: 20pt; color: #006699; text-align: center; font-weight: bold'>실제 사례를 통해 Debug Diagnostics 도구가 생성한 닷넷 웹 응용 프로그램의 성능 장애 보고서 설명</h1> <p> 최근에 고객사 덤프 분석을 하면서 의외로 "Debug Diagnostic" 도구의 결과물에 대해 너무 어렵다는 선입견을 보게 되었습니다.<br /> <br /> <pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' > DebugDiag 1.1을 사용한 덤프 분석 ; <a target='tab' href='http://www.sysnet.pe.kr/2/0/1026'>http://www.sysnet.pe.kr/2/0/1026</a> Debug Diagnostic Tool v2 Update 3 ; <a target='tab' href='https://www.microsoft.com/en-us/download/details.aspx?id=58210'>https://www.microsoft.com/en-us/download/details.aspx?id=58210</a> </pre> <br /> 그런데, 실제로 사용해서 찬찬히 뜯어 보시면 충분히 일반적으로 인식할 수 있는 수준입니다. 여러분의 이해를 돕기 위해 이 글의 첨부 파일에 DebugDiag가 분석을 완료한 mht 출력 파일을 하나 올렸으니 그걸 보면서 설명해 보겠습니다. (실제 장애가 발생한 시점에 뜬 고객사 사례인데, 단지 메서드 등을 모두 TestWebApp이라든가 하는 식의 이름으로 바꾼 것입니다.)<br /> <br /> <pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' > dotnet_2_CrashHangAnalysis.mht ; <a target='tab' href='http://www.sysnet.pe.kr/bbs/DownloadAttachment.aspx?fid=1513&boardid=331301885'>http://www.sysnet.pe.kr/bbs/DownloadAttachment.aspx?fid=1513&boardid=331301885</a> </pre> <br /> 위의 파일을 열어서 보면 초기에 다음과 같은 내용을 볼 수 있습니다.<br /> <br /> <img onclick='toggle_img(this)' class='imgView' alt='windbg_es_hang_1.png' src='/SysWebRes/bbs/windbg_es_hang_1.png' /><br /> <br /> 딱 봐도 문제가 있는 듯하죠? ^^ 어쨌든 메시지를 보면 610개의 스레드가 "System.Threading.Monitor.Wait"로 대기하고 있음을 알려주고 있습니다. 나열된 번호는 대기 중인 Thread의 ID 목록입니다.<br /> <br /> 그리고 내용을 좀 더 내려 보면 "Thread Report"가 나오고 그중에서 같은 thread call stack을 가진 것들만 연속으로 함께 나열된 후 해당 사실을 다음과 같이 알려줍니다.<br /> <br /> <img alt='windbg_es_hang_2.png' src='/SysWebRes/bbs/windbg_es_hang_2.png' /><br /> <br /> <pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' > <span style='color: blue; font-weight: bold'>311 Threads (46% of all threads) have this same call stack.</span> Note: Grouping of identical threads can be disabled in the 'Preferences' tab of the Analysis Options </pre> <br /> 위의 메시지에 따라 이후 311개의 스레드가 같은 스레드 call stack을 갖고 있지만 개별 스레드마다 생성 시간 등은 다르므로 다음과 같이 그런 정보들만 다시 나열하고,<br /> <br /> <pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' > 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 ...[생략]... </pre> <br /> 311개 스레드 정보의 마지막에 해당하는 (dotnet_2_CrashHangAnalysis.mht의 경우 664번) 스레드가 나올 때 어떤 call stack을 동일하게 갖고 있는지 비로소 보여주게 됩니다.<br /> <br /> <img onclick='toggle_img(this)' class='imgView' alt='windbg_es_hang_3.png' src='/SysWebRes/bbs/windbg_es_hang_3.png' /><br /> <br /> 이 정도면 그냥 눈에 들어오죠? 위의 내용을 보면 가장 상단은 "System.Threading.ManualResetEventSlim.Wait"이지만 약간만 내려가도 ElasticSearch 관련 호출이 나오는 것에서 결국 ElasticSearch 호출로 인해, 즉 ElasticSearch 서버가 정상적으로 호출을 처리해주지 못해 311개의 스레드가 대기 중이라는 것을 알 수 있습니다.<br /> <br /> 이후의 Thread 분석 결과도 유사합니다. 처음 보고에서 610개의 스레드가 blocking 상태였는데 그중 311개는 위와 같은 상태이고, 다른 300개 정도의 스레드도 중간에 호출되는 업무 메서드가 달라서 callstack이 다른 것일 뿐 결국 상단에는 Elasticsearch.Net.HttpConnection.Request가 자리 잡고 있습니다.<br /> <br /> <hr style='width: 50%' /><br /> <br /> 어떠신가요? 덤프 분석이 (windbg로 하려면 어려운 듯하지만) Debug Diagnostics로 기본적인 분석 결과만 돌려봐도 응용 프로그램의 성능 문제를 파악하는 데 그다지 어려움이 없습니다.<br /> <br /> 따라서 앞으로는 문제가 발생했을 때, 무작정 iisreset 또는 recycle을 하지 말고 그전에 덤프 파일을 생성해 둘 것을 권장합니다. ^^<br /> </p><br /> <br /><hr /><span style='color: Maroon'>[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]</span> </div>
첨부파일
스팸 방지용 인증 번호
2427
(왼쪽의 숫자를 입력해야 합니다.)