Archive for the 'Basic Debugging' Category

[Windbg] Wait Start TickCount, Ticks, KeTickCount

DeadLock 또는 Spiking Thread 등을 분석할 때 Wait Start TickCount, Ticks 등의 정보가 굉장히 유용하게 활용되곤 합니다.  각각의 정보에 대해 간단히 적어보도록 하곘습니다.

1: kd> !thread 8a362da8
THREAD 8a362da8  Cid 0004.0010  Teb: 00000000 Win32Thread: 00000000 WAIT: (WrQueue) UserMode Non-Alertable
8056c5c0  Unknown
Not impersonating
DeviceMap                 e10021a8
Owning Process            8a363830       Image:         System
Attached Process          N/A            Image:         N/A
Wait Start TickCount      87697 Ticks: 34 (0:00:00:00.531)
Context Switch Count      20714
UserTime                  00:00:00.000
KernelTime                00:00:00.203
Start Address nt!ExpWorkerThread (0×804e4311)
Stack Init f78bb000 Current f78bad24 Base f78bb000 Limit f78b8000 Call 0
Priority 13 BasePriority 13 PriorityDecrement 0 DecrementCount 16


ChildEBP RetAddr  Args to Child
f78bad3c 804e3bf2 8a362e18 8a362da8 804e42f6 nt!KiSwapContext+0×2f (FPO: [Uses EBP] [0,0,4])
f78bad48 804e42f6 8a358ac8 8056c5c0 8a362da8 nt!KiSwapThread+0×8a (FPO: [0,0,0])
f78bad74 804e43ae 00000001 00000001 00000000 nt!KeRemoveQueue+0×22a (FPO: [3,6,4])
f78badac 80577723 8a358ac8 00000000 00000000 nt!ExpWorkerThread+0xcc (FPO: [1,6,0])
f78baddc 804ee6f9 804e4311 00000000 00000000 nt!PspSystemThreadStartup+0×34 (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0×16

간단한 Worker Thread를 하나 예로 들어 보죠 .

Wait Start TickCount는 실제로 이 Thread가 “Wait 되기 시작한 시점”을 말해줍니다. ( 착각하기 쉬운건 전체 Wait Time이 아닙니다. ) 측 TickCount 가 87697인 시점 부터 Wait 되기 시작했다는 의미 입니다.  그 옆에 Ticks가 보이죠. Ticks는 이 “Thread가 Wait 되어 있던 시간”을 의미합니다.

그럼 Ticks = KeTickCount( 현재 TickCount ) - Wait Start TickCount 라는 공식이 성립하게 됩니다.

1: kd> dd KeTickCount L1
8055c000  000156b3

1: kd> .formats 000156b3
Evaluate expression:
Hex:     000156b3
Decimal: 87731
Octal:   00000253263
Binary:  00000000 00000001 01010110 10110011
Chars:   ..V.
Time:    Fri Jan 02 09:22:11 1970
Float:   low 1.22937e-040 high 0
Double:  4.33449e-319

주의 : Wait Start TickCount와 Ticks는 10진수로 나타나기 때문에 KeTickCount는 10진수로 변환 후 계산해야합니다
88731 - 87697 = 34 라는 게 정확히 성립되는걸 볼 수 있습니다. Ticks의 옆에 시간이 정확한지 여부를 판단하기 위해서 Ticks의 값을 16진수 ( 0×22 ) 로 바꿔서 !whattime Extension을 수행해 보겠습니다.
1: kd> !whattime 0×22
34 Ticks in Standard Time: 00.531s

값이 정확히 맞아 떨어지는 것을 확인 할 수있습니다.

Wait Time과 관련된 정보는 특히 동기화 Object 과련 Dead Lock , WorkQueue 관련 Dead Lock 과 같은 형태의 Memory Dump를 분석 할때 굉장히 유용하게 사용됩니다. 기회가 된다면 꼭 활용해 보시길..

Enjoy Debugging!!

Dump 파일과 Windbg 연결.

Dump 파일을 더블 클릭하면 Windbg랑 연결하는 방법 입니다.

windbg -IA

굉장히 쉽죠 .. 생각보다 편리한데 모르시는 분들이 의외로 꾀 있는거 같아서 올립니다.

-IA[S]
Associates WinDbg with the file extensions .dmp, .mdmp, and .wew in the registry. After this action is attempted, a success or failure message is displayed. If S is included, this procedure is done silently if it is successful; only failure messages are displayed. After this association is made, double-clicking a file with one of these extensions will start WinDbg. The -IA parameter must not be used with any other parameters. This command will not actually start WinDbg, although a WinDbg window may appear for a moment.

x64의 Trap Frame과 Register

x64 환경의 Trap Frame에 대한 정보를 찾다가 재미있는 글을 발견

OSR의 NT Insider에 보면 재미있는 글이 올라와 있군요  RCX, RDX, R8-11등의 정보를 믿지 말라는 내용 ㅎㅎ!!

http://www.osronline.com/article.cfm?id=542

[windbg]특정 API 모니터링하기

디버깅을 하다보면 특정API를 모니터링하고 싶어질때가 있습니다.  예를 들어 호출하는 API의 Parameter 값을 모두확인하면서 디버깅을 하고 싶다던지 말이죠. 이럴 경우  windbg의 bp ( Break Point) 명령과 .printf 를 이용하여 쉽게 모니터링이 가능합니다.

일단 bp command의 문법을 살펴보죠

[~Threadbp[ID] [Options] [Address [Passes]] ["CommandString"
[~Threadbu[ID] [Options] [Address [Passes]] ["CommandString"
[~Threadbm [OptionsSymbolPattern [Passes] ["CommandString"]

 

Kernel-Mode

bp[ID] [Options] [Address [Passes]] ["CommandString"
bu[ID] [Options] [Address [Passes]] ["CommandString"
bm [Options] SymbolPattern [Passes] ["CommandString"]

여기서 주목해봐야할 점은 가장 마지막인자인 CommandString입니다. 이 부분에 Break Point 가 걸렸을때 동작을 기술해주시면 Break Point가 걸리는 순간 CommandString에 포함된 동작을 하게 됩니다. 우리가 필요한것은 이 부분을 작성하여 Break Point가 걸리는 시점에 모니터링 하고자 하는 API의 Parameter를 Print 해주면 되겠죠.

간단히 notepad를 이용해서 테스트 해보죠. notepad를 띄우고 Windbg를 notepad에 Attach 합니다. 그리고 아래와 같이 CreateFileW에 Break Point를 걸어줍니다.

bp kernel32!CreateFileW “.printf \”CreateFileW(\%mu,\%x,\%x,\%p,\%x,\%x,\%p)\\n\”,poi(esp+0×04),poi(esp+0×08),poi(esp+0×0c),poi(esp+0×10),poi(esp+0×14),poi(esp+0×18),poi(esp+0×1c);g”

그리고 notepad를 그대로 실행해줍니다. 이제 정상적으로 Break Point가 걸린 시점에서 CreateFileW가 모니터링되는지 확인해보면 되겠죠. CreateFileW를 발생시키기위해서 “파일 열기”를 수행하게 되면 아래와 같이 발생되는 CreateFileW에 대한 Parameter가 모니터링 되는것을 확인 할 수 있습니다.

CreateFileW(\.\shadow,20,3,00000000,3,0,00000000)
CreateFileW(F:\WINDOWS\klangor.dll,
80000000,3,00076ad0,3,80,00000000)
CreateFileW(F:\WINDOWS\softcamp\sds\klangor.dll,
80000000,3,00076ad0,3,80,00000000)
CreateFileW(F:\WINDOWS\klangor.dll,
80000000,3,00076ad0,3,80,00000000)
CreateFileW(F:\WINDOWS\softcamp\sds\klangor.dll,
80000000,3,00076ad0,3,80,00000000)
CreateFileW(F:\WINDOWS\klangor.dll,
80000000,3,000772a0,3,80,00000000)
CreateFileW(F:\WINDOWS\softcamp\sds\klangor.dll,
80000000,3,000772a0,3,80,00000000)
CreateFileW(F:\WINDOWS\klangor.dll,
80000000,3,000772a0,3,80,00000000)
CreateFileW(F:\WINDOWS\softcamp\sds\klangor.dll,
80000000,3,000772a0,3,80,00000000)
CreateFileW(F:\WINDOWS\klangor.dll,
80000000,3,00076e64,3,80,00000000)
CreateFileW(F:\WINDOWS\softcamp\sds\klangor.dll,
80000000,3,00076e64,3,80,00000000)
... 생략

생각보다 쉽죠 . 이러한 방법의 모니터링은 디버깅시에 꽤 유용하게 사용이 가능합니다. 특히 DebugPrint 없이 Release 된 모듈을 디버깅할때는 이러한 방법으로 디버깅을해서 오류를 찾아내는 경우도 많습니다.

한번 활용해 보시길 … Enjoy Debugging

VirtualProtect & PAGE Protect Mask

User Level Hooking을 하다보면 각 Dll 들의 Function Table을 Hooking 하는 경우가 있습니다. 이러한 경우 Hooking 과정에서 Access violation 이 나타나는 경우가 종종 있지요. 예를 들면 Image의 특정 Table Address를 수정한다 던지 하는 경우에 말이죠. 이런 경우 Access violation이 발생했을때는 Image Memory Page의 Protect Mask를 확인해 보시는 것이 좋습니다. 한가지 예를 보여드리죠 .

FAULTING_IP:
XXX!Init+52bd
5ff064ad 8807 mov byte ptr [edi],al

EXCEPTION_RECORD: ffffffff — (.exr 0xffffffffffffffff)
ExceptionAddress: 5ff064ad (XXX!Init+0×000052bd)
ExceptionCode: c0000005 (Access violation)
ExceptionFlags: 00000000
NumberParameters: 2
Parameter[0]: 00000001
Parameter[1]: 76e39e1e
Attempt to write to address 76e39e1e

FAULTING_THREAD: 00001640

위에 표시한 부분은 !analyze -v를 쳤을 때 나타는 일부분입니다. Exception을 발생시킨 Instruction의 인자를 보면 edi와 al을 참조하고 있습니다. al의 경우 단순한 Value 이기 때문에 별로 상관 없지만 edi의 경우 Address Access를 하고 있습니다. 그렇다면 edi의 값이 잘못된 것일까 ??

0:000> r edi
edi=76e39e1e

0:000> dd 76e39e1e
76e39e1e 00000000 00000000 00000000 00000000
76e39e2e 00000000 02430000 00000000 00000000
76e39e3e 00000000 00000000 00000000 021e0000
76e39e4e 00000000 00000000 00000000 00000000
76e39e5e 00000000 00000000 0000007f 00000000
76e39e6e 00000000 00000000 00000000 00000000
76e39e7e 00000029 00000000 00000000 00000000
76e39e8e 00000000 021c0000 00000000 00000000

위에서 볼 수 있듯이 edi의 메모리는 정상적이군요. 그렇다면 왜 76e39e1e에 Write Access가 발생했을때 문제가 되는 것일까요 ? 이것은 생각 보다 단순합니다. 실제로 address 명령을 통해서 76e39e1e Memory의 Protect Mask를 확인해 보면 쉽게 그답을 찾을 수 있습니다.

0:000> !address 76e39e1e
76e30000 : 76e31000 - 0000a000
Type 01000000 MEM_IMAGE
Protect 00000020 PAGE_EXECUTE_READ
State 00001000 MEM_COMMIT
Usage RegionUsageImage
FullPath C:\WINDOWS\system32\rtutils.dll

76e39e1e가 포함된 Memory Page의 경우 현제 PAGE_EXECUTE_READ 가 Protect Mask로 설정되어 있군요. 그리고 Access 하고자 하는 Page에 Write 권한이 없기 때문에 Access violation 발생하게 된것이죠.

실제로 VirtualProtect를 사용해서 Protect Mask를 변경할 경우 Windows는 Memory Page 단위 ( x86기준 0×1000)로 Protect Mask를 변경합니다. 여기서 가장 실수하기 쉬운 것은 VirtualProtect를 이용하여 Memory Page 보다 작은 사이즈로 Write 권한이 없는 Protect Mask로 변경하고 그 다음 Address를 Access 하는 경우인데 이러한 경우는 어김없이 Access violation이 발생합니다.

조심해서 사용하시길…