Microsoft MVP성태의 닷넷 이야기
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일
 

Windbg - SOS 디버깅 사례 System.NullReferenceException 예외 추적

Release 모드로 빌드된 Windows Forms 응용 프로그램 실행 중 별다른 콜스택 정보 없이 예외가 발생했다면서 비정상 종료 메시지만 나오는 상황이었습니다.

메시지 창이 뜬 시점에 프로세스 풀 덤프를 남긴 후 windbg에서 살펴봤습니다.

CLR 2.0이었기 때문에 다음과 같이 sos를 로드하고,

0:000> .loadby sos mscorjit

예외 정보를 확인(!PrintException)하려 했지만,

0:000> !pe
There is no current managed exception on this thread

다른 스레드에서 발생한 듯싶군요. ^^ 그럼, !threads를 이용해 예외가 발생한 스레드를 확인해 보면 됩니다.

0:000> !threads
ThreadCount: 771
UnstartedThread: 0
BackgroundThread: 770
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
                                              PreEmptive                                                Lock
       ID OSID        ThreadOBJ     State   GC     GC Alloc Context                  Domain           Count APT Exception
   0    1 2544 0000000000694bb0      6020 Enabled  0000000003b10b90:0000000003b113c0 000000000068c370     0 STA
   2    2 1cac 00000000006a0630      b220 Enabled  0000000000000000:0000000000000000 000000000068c370     0 MTA (Finalizer)
   5    4  2e8 000000001b3ec740      b220 Enabled  0000000000000000:0000000000000000 000000000068c370     2 MTA System.NullReferenceException (0000000002a87b58)
   6    f 27bc 000000001b41f690   380b220 Enabled  0000000000000000:0000000000000000 000000000068c370     0 MTA (Threadpool Worker)

(Managed 환경 기준으로) 5번 스레드임을 알았으니 문맥 전환을 해주고 다시 예외 정보를 확인합니다.

0:000> ~5s
ntdll!NtWaitForSingleObject+0x14:
00007ff9`82ba6154 c3

0:005> !pe
Exception object: 0000000002a87b58
Exception type: System.NullReferenceException
Message: Object reference not set to an instance of an object.
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    000000001E2CE820 00007FF9128C862B MyTestEXE!MyTestEXE.SampleType.CallMyMethod(MyTestEXE.SampleType, System.Text.StringBuilder)+0x4cb
    000000001E2CEBB0 00007FF9128C335D MyTestEXE!MyTestEXE.MainForm.SecondThreadFunc(System.Object)+0x8ad
    000000001E2CEF10 00007FF96CEF2C8B mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x9b
    000000001E2CEF60 00007FF96D598C6D mscorlib_ni!System.Threading.ThreadHelper.ThreadStart(System.Object)+0x5d

물론, !clrstack 명령을 이용하셔도 됩니다.

0:005> !clrstack
OS Thread Id: 0x2e8 (5)
Child-SP         RetAddr          Call Site
000000001e2ce820 00007ff9128c335d MyTestEXE.SampleType.CallMyMethod(MyTestEXE.SampleType, System.Text.StringBuilder)
000000001e2cebb0 00007ff96cef2c8b MyTestEXE.MainForm.SecondThreadFunc(System.Object)
000000001e2cef10 00007ff96d598c6d System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000001e2cef60 00007ff972148f32 System.Threading.ThreadHelper.ThreadStart(System.Object)

그런데, 아쉽게도 소스 코드 위치를 알 수가 없습니다. 이런 경우 문제 추적을 위해 도움이 되는 방법이 해당 상황을 재현시켜 보는 것입니다. 즉, 메서드가 수행된 시점에 관련 객체들의 상태 정보와 메서드에 들어온 인자 값들의 상태 정보를 알아내면 높은 확률로 재현할 수 있는 환경을 마련할 수 있습니다. ^^

이를 위해 clrstack 명령에 -a 옵션을 주면 다음과 같이 인자 값(이 코드에서는 current와 log)과 객체(this)의 주소를 알아낼 수 있습니다.

0:005> !clrstack -a
OS Thread Id: 0x2e8 (5)
Child-SP         RetAddr          Call Site
000000001e2ce820 00007ff9128c335d MyTestEXE.SampleType.CallMyMethod(MyTestEXE.SampleType, System.Text.StringBuilder)
    PARAMETERS:
        this = 0x00000000029c63f0
        current = 0x00000000029f90a8
        log = 0x0000000002a87250
    LOCALS:
        0x000000001e2ce840 = 0x0000000000000000
        0x000000001e2ce848 = 0x0000000000000000
        0x000000001e2ce850 = 0x0000000000000000
        0x000000001e2ce858 = 0x0000000000000000
        0x000000001e2ce859 = 0x0000000000000001
        0x000000001e2ce860 = 0x0000000000000000
        0x000000001e2ce868 = 0x0000000000000000

...[이하 생략]...

첫 번째 인자인 "MyTestEXE.SampleType current" 값을 다음과 같이 확인할 수 있습니다.

0:005> !dumpobj 0x00000000029f90a8
Name: MyTestEXE.SampleType
MethodTable: 00007ff912768818
EEClass: 00007ff912894250
Size: 224(0xe0) bytes
 (D:\MyTestEXE\bin\debug\MyTestEXE.exe)
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff96d03f130  4000012       90         System.Int32  1 instance            51964 Position
00007ff96d037ec0  4000013        8        System.String  0 instance 00000000029f9188 RawData
00007ff96d025cb0  4000014       10      System.Object[]  0 instance 00000000029f9ef0 Lines
0000000000000000  4000015       18                       0 instance 00000000029f9fb8 Values
00007ff96d03f130  4000016       94         System.Int32  1 instance               70 Count
00007ff96d03f130  4000017       98         System.Int32  1 instance                0 Limit
00007ff96d037ec0  4000018       20        System.String  0 instance 000000000386aea8 MachineName
...[이하 생략]...

위의 출력은 SampleType 클래스의 멤버들을 "Value" 값과 함께 보여줍니다. 이 중에서 System.Int32와 같이 기본 자료형인 경우 "Value" 칼럼에 나온 값을 그대로 필드 값이라고 보면 됩니다. 반면 System.String, System.Object[]와 같은 참조형들은 Value에 대해 다시 한번 dumpobj를 호출해 그 객체의 내부 값을 확인해 봐야 합니다.

0:005> !dumpobj 000000000386aea8
Name: System.String
MethodTable: 00007ff96d037ec0
EEClass: 00007ff96cc3e560
Size: 46(0x2e) bytes
 (C:\WINDOWS\assembly\GAC_64\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll)
String: WIN2008X86
Fields:
              MT    Field   Offset                 Type VT     Attr            Value Name
00007ff96d03f130  4000096        8         System.Int32  1 instance               11 m_arrayLength
00007ff96d03f130  4000097        c         System.Int32  1 instance               10 m_stringLength
00007ff96d039908  4000098       10          System.Char  1 instance               57 m_firstChar
00007ff96d037ec0  4000099       20        System.String  0   shared           static Empty
                                 >> Domain:Value  000000000068c370:0000000002931308 <<
00007ff96d0397b8  400009a       28        System.Char[]  0   shared           static WhitespaceChars
                                 >> Domain:Value  000000000068c370:0000000002931b08 <<

위에서 보는 것처럼, MyTestEXE.SampleType의 MachineName 필드의 값은 "WIN2008X86"이었음을 알 수 있습니다.

운이 좋다면, 문제가 발생한 환경을 재현하는 데 성공할 것입니다. 이 방법은 간혹, CPU 100% 현상을 보일 때에도 유용하게 써먹을 수 있습니다. 같은 구간을 무한 반복해서 실행하는 코드의 경우, 해당 메서드의 수행 환경만 잘 살펴봐도 왜 그런 현상에 빠졌는지를 유추해 볼 수 있기 때문입니다.



이 외에, !pe 출력의 결과로 나온 offset 값을 통해 System.NullReferenceException 예외가 발생한 코드를 대략적으로 찾아낼 수도 있습니다.

0:005> !pe
Exception object: 0000000002a87b58
Exception type: System.NullReferenceException
Message: Object reference not set to an instance of an object.
InnerException: <none>
StackTrace (generated):
    SP               IP               Function
    000000001E2CE820 00007FF9128C862B MyTestEXE!MyTestEXE.SampleType.CallMyMethod(MyTestEXE.SampleType, System.Text.StringBuilder)+0x4cb
    000000001E2CEBB0 00007FF9128C335D MyTestEXE!MyTestEXE.MainForm.SecondThreadFunc(System.Object)+0x8ad
    000000001E2CEF10 00007FF96CEF2C8B mscorlib_ni!System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)+0x9b
    000000001E2CEF60 00007FF96D598C6D mscorlib_ni!System.Threading.ThreadHelper.ThreadStart(System.Object)+0x5d

이에 대해서는 예전 글에서 한번 설명한 적이 있습니다.

Windbg - 비정상 종료된 닷넷 프로그램의 StackTrace에서 보이는 offset 값 의미
; https://www.sysnet.pe.kr/2/0/1095

문제가 발생한 CallMyMethod의 jitted code address를 알아내고,

0:005> !name2ee MyTestEXE!MyTestEXE.SampleType.CallMyMethod
Module: 00007ff912762e38 (MyTestEXE.exe)
Token: 0x0000000006000008
MethodDesc: 00007ff9127687e8
Name: MyTestEXE.SampleType.CallMyMethod(MyTestEXE.SampleType, System.Text.StringBuilder)
JITTED Code Address: 00007ff9128c8160

그 값에 !pe 출력 결과에서 얻은 IP 주소(00007FF9128C862B)와 0x4cb 오프셋 값을 더한 위치(= 7FF9128C8AF6)를 계산하고, 그 위치를 JITTED Code Address 주소를 역어셈블한 코드에서 찾아내면 됩니다.





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







[최초 등록일: ]
[최종 수정일: 8/3/2021]

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

비밀번호

댓글 작성자
 




... 136  137  138  139  140  141  [142]  143  144  145  146  147  148  149  150  ...
NoWriterDateCnt.TitleFile(s)
1504정성태9/24/201330190.NET Framework: 387. UDP 브로드캐스팅을 이용해 서비스 측의 IP 주소를 구하는 방법 [1]파일 다운로드1
1503정성태9/21/201335365개발 환경 구성: 199. Visual Studio - github 연동 [7]
1502정성태9/21/201338957개발 환경 구성: 198. Visual Studio - git을 이용한 로컬 소스 컨트롤
1501정성태9/21/201346043개발 환경 구성: 197. Visual Studio를 위한 Git 환경 설정 [5]
1500정성태9/20/201345023.NET Framework: 386. C# 버전의 한글 형태소 분석기 [1]파일 다운로드1
1499정성태9/20/201321627개발 환경 구성: 196. Windows Azure - Cloud Service의 인스턴스 타입 변경하는 방법
1498정성태9/20/201327778Windows: 76. 윈도우 8.1 / 서버 2012 R2 마이그레이션 [5]
1497정성태9/20/201360032웹: 28. IE 11로 바꾼 후 발생하는 문제 정리
1496정성태9/20/201332336Windows: 75. 윈도우 8.1, 2012 R2 설치 후 원격 접속이 안 되는 문제
1495정성태9/20/201323469웹: 27. IE 11 - YBM Sisa.com에서 검색된 영단어의 발음 기호가 안 나오는 문제
1494정성태9/13/201333094.NET Framework: 385. Html Agility Pack 소개 - 웹 문서에서 텍스트만 분리하는 방법 [2]파일 다운로드1
1493정성태9/13/201334854.NET Framework: 384. WebClient.DownloadString 문자열 인코딩 문제
1492정성태9/13/201322295오류 유형: 186. The .NET assembly 'Microsoft.Vsa' could not be found.
1491정성태9/9/201325452.NET Framework: 383. RSAParameters의 ToXmlString과 ExportParameters의 결과 비교
1490정성태9/7/201360466기타: 34. 도서: 시작하세요! C# 프로그래밍: 기본 문법부터 실전 예제까지 [7]
1489정성태9/4/201344896오류 유형: 185. 오피스 워드 파일이 저장되지 않는 문제 [2]
1488정성태8/27/201329027.NET Framework: 382. WCF에서 DataSet을 binary encoding으로 직렬화하는 방법파일 다운로드1
1487정성태8/27/201331343개발 환경 구성: 195. 로컬 PC에서의 WCF 통신을 Fiddler로 보는 방법 [1]
1486정성태8/27/201328839.NET Framework: 381. SqlCommand를 이용해 Microsoft SQL 서버의 쿼리 실행 계획을 구하는 방법파일 다운로드1
1485정성태8/26/201332520.NET Framework: 380. 프로세스 스스로 풀 덤프 남기는 방법 [3]파일 다운로드1
1484정성태8/23/201326763제니퍼 .NET: 24. 제니퍼 닷넷 적용 사례 (4) - GZIP 인코딩으로 인한 성능 하락
1483정성태8/23/201326879.NET Framework: 379. System.IO.MemoryStream, ArraySegment&lt;T&gt; 의 효율적인 사용법 [1]
1482정성태8/23/201320335.NET Framework: 378. Java / C# - 정수의 부호 유무에 따른 16진수 문자열 변환
1481정성태8/22/201321172오류 유형: 184. PaaS 유형(Cloud Services)의 Azure VM에 연결할 때 계정 만료 에러가 발생하는 경우
1480정성태8/22/201337825개발 환경 구성: 194. 윈도우 서버의 80 포트에 대한 port forwarding 설정 방법파일 다운로드1
1479정성태8/14/201325160오류 유형: 183. IIS - 바인딩 추가 시 Object reference not set to an instance of an object 오류 [5]
... 136  137  138  139  140  141  [142]  143  144  145  146  147  148  149  150  ...