'전체 글'에 해당되는 글 202건

  1. 2007.06.29 [WinDbg 분석] BugCheck 0x50
WinDbg 디버깅2007. 6. 29. 00:45
반응형

덤프파일을 분석하는데 있어서 BugCheck Code는 아주 기본적인 정보일 뿐만아니라
분석을 풀어나가는 실마리가 됩니다. 그래서 누군가 BSOD 가 떴다고 문제를 풀어달라고
할 때 가장 먼저 물어 보게 되는게 "BugCheck Code 가 무엇입니까?" 가 되는 겁니다.

이제부터 여러가지 BugCheck Code 들에 대해서 기본적으로 어떻게 분석을 진행해
나가는지 예제를 통해서 설명하려고 합니다. BugCheck Code 마다 다소 다른점은
있지만 기본적인 맥락은 동일하다는 것을 곧 알게 될 것입니다. 기본적인 분석방법을
익혀서 BSOD 가 발생했을 때 당황하지 않고 스스로 문제의 원인을 찾고 해결할 수
있는 능력을 가지는 것이 중요합니다. WinDbg Help 에도 BugCheck Code 마다의
분석 방법 및 예제가 몇가지 있으므로 이것들을 확인하는 습관을 가지는 것도 좋습니다.

여기서는 기본적으로 개발한 모듈의 심볼(pdb파일)을 가지고 있다는 전제를 합니다.
심볼이 없다면 WinDbg 디버깅이 아주 갑갑해 지겠지요.

첫번째로 BugCheck 0x50 부터 시작합니다.
live debugging 시에 문제가 생기면 다음과 같이 시스템이 정지합니다.


*** Fatal System Error: 0x00000050
                       (0xE2BFD011,0x00000000,0xF2EF9C65,0x00000001)

Driver at fault:
***  mydrv.sys - Address F2EF9C65 base at F2E98000, DateStamp 44ed34b4
.
Break instruction exception - code 80000003 (first chance)

A fatal system error has occurred.
Debugger entered on first try; Bugcheck callbacks have not been invoked.

A fatal system error has occurred.

Connected to Windows XP 2600 x86 compatible target, ptr64 FALSE
Loading Kernel Symbols
...................................................................................................................
Loading User Symbols
PEB is paged out (Peb.Ldr = 7ffdf00c).  Type ".hh dbgerr001" for details
Loading unloaded module list
.................
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

Use !analyze -v to get detailed debugging information.

BugCheck 50, {e2bfd011, 0, f2ef9c65, 1}

Probably caused by : mydrv.sys ( mydrv!My_strcmp+15 )

Followup: MachineOwner
---------

nt!RtlpBreakWithStatusInstruction:
804e5592 cc              int     3

여기까지가 기본적으로 뿌려집니다.
안타깝게도 이 상태에서 더 뭘 해야할지 모르고 재부팅을 해 버리는 경우가 많은데요.
이때 문제의 원인을 정확히 파악하고 문제를 해결해야 합니다.

자... 덤프 분석의 초식 1장 나갑니다. "WinDbg 가 하라는 대로 따라하라!"

위에 이미 나온 메시지들을 주의깊게 살펴볼 필요가 있습니다.
WinDbg 가 많은 정보를 알려주고 있습니다. 그중에서 우리에게 하라고 하는 것을 눈여겨 보시기 바랍니다.

바로 이줄 입니다. => Use !analyze -v to get detailed debugging information.
단지 우리는 하라는대로 하면 됩니다. 특히 !analyze -v 는 모든 덤프분석에서 첫번째로 하게 되는 작업이
될테니 앞으로 우리는 자동적으로 이 명령을 내리게 될 것입니다. 하지만 그 이외에도 하라고 하는게 있는지
항상 살펴보시기 바랍니다.

이제 하라는대로 명령을 내려 봅니다.

kd> !analyze -v
*******************************************************************************
*                                                                             *
*                        Bugcheck Analysis                                    *
*                                                                             *
*******************************************************************************

PAGE_FAULT_IN_NONPAGED_AREA (50)
Invalid system memory was referenced.  This cannot be protected by try-except,
it must be protected by a Probe.  Typically the address is just plain bad or it
is pointing at freed memory.
Arguments:
Arg1: e2bfd011, memory referenced.
Arg2: 00000000, value 0 = read operation, 1 = write operation.
Arg3: f2ef9c65, If non-zero, the instruction address which referenced the bad memory
 address.
Arg4: 00000001, (reserved)

Debugging Details:
------------------


READ_ADDRESS:  e2bfd011 Paged pool

FAULTING_IP:
mydrv!My_strcmp+15 [d:\mytest\mydrv\my_string.c @ 179]
f2ef9c65 8a02            mov     al,byte ptr [edx]

MM_INTERNAL_CODE:  1

IMAGE_NAME:  mydrv.sys

DEBUG_FLR_IMAGE_TIMESTAMP:  44ed34b4

MODULE_NAME: mydrv

FAULTING_MODULE: f2e98000 mydrv

DEFAULT_BUCKET_ID:  DRIVER_FAULT

BUGCHECK_STR:  0x50

PROCESS_NAME:  wuauclt.exe

TRAP_FRAME:  f4674280 -- (.trap fffffffff4674280)
ErrCode = 00000000
eax=f2ee6f6c ebx=81cec900 ecx=e2bfd011 edx=e2bfd011 esi=81b1d3f8 edi=f4674634
eip=f2ef9c65 esp=f46742f4 ebp=f4674308 iopl=0         nv up ei ng nz na po nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00010282
mydrv!My_strcmp+0x15:
f2ef9c65 8a02            mov     al,byte ptr [edx]          ds:0023:e2bfd011=??
Resetting default scope

LAST_CONTROL_TRANSFER:  from 8053425b to 804e5592

STACK_TEXT: 
f4673dd0 8053425b 00000003 e2bfd011 00000000 nt!RtlpBreakWithStatusInstruction
f4673e1c 80534d2e 00000003 806f0298 c038aff4 nt!KiBugCheckDebugBreak+0x19
f46741fc 8053531e 00000050 e2bfd011 00000000 nt!KeBugCheck2+0x574
f467421c 80525f44 00000050 e2bfd011 00000000 nt!KeBugCheckEx+0x1b
f4674268 804e3718 00000000 e2bfd011 00000000 nt!MmAccessFault+0x6f5
f4674268 f2ef9c65 00000000 e2bfd011 00000000 nt!KiTrap0E+0xcc
f4674308 f2ee82d3 e2bfd011 f2ee6f6c 00000000 mydrv!My_strcmp+0x15 [d:\mytest\mydrv\my_string.c @ 179]
f467435c f2ee709a e2909008 f2f1af04 e1196008 mydrv!My_Func3+0x323 [d:\mytest\mydrv\my_func3.c @ 78]
f467439c f2f09c01 e22088d8 e24d5418 00000000 mydrv!My_Func2+0x109 [d:\mytest\mydrv\my_func2.c @ 24]
f46743c0 f2f09b6a e22088d8 e24d5418 00000001 mydrv!My_Func1+0x91 [d:\mytest\mydrv\my_func1.c @ 118]
...
f4674c88 805964bf e1efa000 00080000 81d57020 nt!CcPfPrefetchScenario+0x7b
f4674d04 805831af 81d57020 e254f158 00000000 nt!CcPfBeginAppLaunch+0x158
f4674d50 804fc4da 00000000 7c810665 00000001 nt!PspUserThreadStartup+0xeb
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16


STACK_COMMAND:  kb

FOLLOWUP_IP:
mydrv!My_strcmp+15 [d:\mytest\mydrv\my_string.c @ 179]
f2ef9c65 8a02            mov     al,byte ptr [edx]

FAULTING_SOURCE_CODE: 
   175:
   176: int My_strcmp( const char* cs, const char* ct )
   177: {
   178: #ifdef HAVE_STRCMP
>  179:  return strcmp( cs, ct );
   180: #else
   181:  int res;
   182:
   183:  for( ; ; )
   184:  {


SYMBOL_STACK_INDEX:  6

SYMBOL_NAME:  mydrv!My_strcmp+15

FOLLOWUP_NAME:  MachineOwner

FAILURE_BUCKET_ID:  0x50_VRF_mydrv!My_strcmp+15

BUCKET_ID:  0x50_VRF_mydrv!My_strcmp+15

Followup: MachineOwner
---------

길게도 분석결과가 나왔습니다.
메시지를 처음부터 살펴보면 이 버그체크는 PAGE_FAULT_IN_NONPAGED_AREA 라는 것을 알려주고
이것은 잘못된 시스템 메모리를 참조해서 발생한 것이라고 친절하게 설명해 주고 있습니다.

앞으로 모든 덤프를 분석할 때 반드시 이 설명 문구를 읽으시기 바랍니다. 어떤 문제 때문에 발생한
것이고 심지어는 어떻게 분석하라는 내용까지 있는 경우도 있습니다. 그리고 WinDbg 가 업그레이드
될 때마다 메시지의 내용이 더더욱 심오해 집니다. 더 자세하게 기술되어 분석하기가 쉬워집니다.

이 내용을 읽었는데 여기서 하라는 것이 있으면 그대로 하면 됩니다. 이번 예제에서는 하라는 것은 없네요.
계속해서 전체적인 내용을 살펴봅니다.

친절하게도 콜스택까지 잘 보여주고 있습니다. 운이 좋으면 이 콜스택만 봐도 무슨 문제인지
금방 알 수도 있습니다. 하지만 이번에는 그런 경우는 아닌 것 같습니다. 좀 더 보도록 합시다.

최신 WinDbg 에서는 문제가 발생한 소스코드를 보여주는 기능이 추가되었습니다.
FAULTING_SOURCE_CODE 에서 보이고 있습니다. 역시 운이 좋으면 여기만 봐도 문제가 뭔지 알 수 있겠지요?

strcmp 에서 죽었는데 cs 에서 죽은건지 ct 에서 죽은건지 모르겠네요.
좀 더 분석해 봐야 할 것 같습니다.

메시지 중간에 다음과 같은 라인이 있습니다.
TRAP_FRAME:  f4674280 -- (.trap fffffffff4674280)

앞으로 이와 같은 라인이 보이면 무조건 .trap fffffffff4674280 명령을 실행하기 바랍니다.

kd> .trap fffffffff4674280
ErrCode = 00000000
eax=f2ee6f6c ebx=81cec900 ecx=e2bfd011 edx=e2bfd011 esi=81b1d3f8 edi=f4674634
eip=f2ef9c65 esp=f46742f4 ebp=f4674308 iopl=0         nv up ei ng nz na po nc
cs=0008  ss=0010  ds=0023  es=0023  fs=0030  gs=0000             efl=00010282
mydrv!My_strcmp+0x15:
f2ef9c65 8a02            mov     al,byte ptr [edx]          ds:0023:e2bfd011=??

콜스택을 보면서 설명하면 strcmp 에서 문제가 발생했을 때 시스템은 Trap 을 발생시켰고
OS 가 Trap 을 핸들링하면서 결국 BugCheck 를 호출하고 시스템이 죽은 겁니다.
.trap 명령을 수행하기 전에 WinDbg 에 보이는 레지스터 값들을 보면 RtlpBreakWithStatusInstruction
를 호출했을 때의 값들이 보여지고 있습니다. 이것은 strcmp 에서 문제가 발생했을 때의
레지스터 값들이 아니므로 문제를 분석하는데 전혀 도움이 되지 않습니다. strcmp 에서 문제가
발생했을 때의 레지스터 값들은 Trap 이 발생하면서 Trap Frame 에 저장되었고 .trap 명령을 사용하면
trap 이 발생한 시점의 상황으로 레지스터 값들을 돌려줍니다. 친절하게 명령과 파라미터까지
보여주니 그대로 실행해 주면 되는 겁니다.

이렇게 하면 콜스택이 문제가 발생했을 때의 상황으로 정리됩니다.
k 명령을 사용해서 콜스택을 다시 봅니다.

kd> kn
  *** Stack trace for last set context - .thread/.cxr resets it
 # ChildEBP RetAddr 
00 f4674308 f2ee82d3 mydrv!My_strcmp+0x15 [d:\mytest\mydrv\my_string.c @ 179]
01 f467435c f2ee709a mydrv!My_Func3+0x323 [d:\mytest\mydrv\my_func3.c @ 78]
02 f467439c f2f09c01 mydrv!My_Func2+0x109 [d:\mytest\mydrv\my_func2.c @ 24]
03 f46743c0 f2f09b6a mydrv!My_Func1+0x91 [d:\mytest\mydrv\my_func1.c @ 118]
...

n 옵션을 사용한 이유는 맨 앞에 스택 프레임 번호를 보이기 위함입니다. 나중에 k 명령 설명에서
자세하게 다루기로 하구요.

실제 디버깅 할 때는 콜스택 창에 위의 내용이 보이고 있을 것이고 첫번째 줄을 더블클릭하면
소스도 나타나고 지역변수 창에 변수들도 나올 텐데, 저는 지금 command 창에서만 설명해야 하니
여러가지 명령을 동원하게 되었습니다. MS 본사의 디버깅 고수들은 command 창 하나만 띄워놓고
현란한 명령어들로 디버깅하기도 합니다. 그걸 따라하고 싶어서 이러는 건 아닙니다. ^^

여하튼 저는 command 로 지역변수를 보고 싶습니다.
일단 스택 프레임을 첫번째 스택 라인에 맞춰 놓으려 합니다. 스택 프레임 번호가 00 이죠.
.frame 명령을 사용해서 스택 프레임을 변경합니다.

kd> .frame 0
00 f4674308 f2ee82d3 mydrv!My_strcmp+0x15 [d:\mytest\mydrv\my_string.c @ 179]

그리고 나서 지역변수를 보이는 dv 명령을 사용하면 이 함수가 호출되었을 때의 지역변수를 볼 수 있습니다.

kd> dv
             cs = 0xe2bfd011 ""
             ct = 0xf2ee6f6c "GetFileAttributesA"

이제 cs와 ct 가 뭔지 알 수 있습니다.

이렇게 찾고 보면 처음에 BugCheck에서 보여줬던 첫번째 값이 바로 cs 였다는 것을 알게 됩니다.
문제의 잘못된 메모리는 cs 라는 것입니다.

BugCheck 50, {e2bfd011, 0, f2ef9c65, 1}
Arguments:
Arg1: e2bfd011, memory referenced.
Arg2: 00000000, value 0 = read operation, 1 = write operation.

잘못된 메모리 e2bfd011 을 읽다가 죽었다는 뜻이었군요.

이렇게 되면 My_strcmp 함수는 혐의를 벗어나게 됩니다. 잘못된 메모리를 전달받은 죄 밖에 없거든요.
잘못된 메모리를 전달한 녀석이 문제지요. My_strcmp 를 호출한 녀석을 분석해야 합니다.
스택 프레임이 01 이군요.

kd> .frame 1
01 f467435c f2ee709a mydrv!MyFunc3+0x323 [d:\mytest\mydrv\my_func3.c @ 78]

지역변수도 보고 소스코드도 봅니다.

kd> dv
 pNameStrBuffer = 0xe2bf8008
      dwNameStr = 0x4ffd
       pNameStr = 0xe2bfd011 ""
         nFound = 0
              j = 0

*** 소스코드 ***
 pNameStr = (char*)pNameStrBuffer->abyData + dwNameStr;

 nFound = 0;
 for( j = 0; j < nNumOfFunctions; j++ )
 {
  if ( My_strcmp( pNameStr, ppNames[j] ) == 0 )

My_strcmp의 첫번재 파라미터는 pNameStr 입니다. 이게 문제구요.
호출하기 직전에 pNameStr 을 계산하는 것을 볼 수 있습니다. 이 계산이 뭐가 잘못된 것일까요?
결국 abyData + dwNameStr 의 결과가 e2bfd011 이라는 잘못된 메모리라는 뜻입니다.

abyData 를 살펴보기 위해 pNameStrBuffer 의 구조체 타입을 찾아서 살펴봅니다.
dt 명령은 구조체를 확인할 때 사용합니다. 역시 나중에 dt 명령 설명에서 자세히 다루도록 하구요.

kd> dt _MYNAMEBUFFER 0xe2bf8008
   +0x000 dwPos            : 0
   +0x004 ulFp             : 0
   +0x008 nLen             : 0x140000
   +0x00c abyData          : [1024]  "???"

이렇게 보니 문제가 드러납니다.

abyData 는 1024 바이트의 공간만 존재하는데 dwNameStr(0x4ffd) 만큼 더한 뒤에 있는 영역은
이 범위를 벗어나는 잘못된 메모리인 것입니다.

정확한 원인을 밝혀내기 위해서는 dwNameStr 에 왜 0x4ffd 와 같은 터무니 없는 값이
들어갔는지를 알아야 합니다. 그것은 더 상위 함수를 분석해 본다던가 소스코드를 살펴본다던가
해서 추가로 진행하면 될 것입니다.

여기까지 분석한 방법을 응용하면 여러분들도 BugCheck 0x50 을 어렵지 않게 분석할 수 있을 것입니다.

이 첫번째 예제를 설명하면서 제가 강조하고 싶은 부분은 WinDbg 메시지 내용 중에는 분석에 사용할 수
있는 명령어들이 존재하고 있다는 점입니다. 이것들을 눈여겨 보고 적절히 사용하면 분석에 많은 도움이
되므로 십분 활용하시기 바랍니다.


http://www.driveronline.org/bbs/view.asp?tb=tipbbs&GotoPage=6&s_bulu=&s_key=&no=24
반응형
Posted by GreeMate