Archive for December 16th, 2010

Icons for Memory Dump Analysis Patterns (Part 85)

Thursday, December 16th, 2010

Today we introduce an icon for Self-Dump pattern:

B/W

Color

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Crash Dump Analysis Patterns (Part 42h)

Thursday, December 16th, 2010

This is another variant of the general Wait Chain pattern where blocked threads are waiting for synchronous window message calls (sent messages). For example, here three threads from different processes are blocked in such a chain where hWnd parameters for SendMessage calls and associated window procedures are marked with corresponding colors: 

0:000> ~*kbL

.  0  Id: 116c.1174 Suspend: 1 Teb: 7efdd000 Unfrozen
ChildEBP RetAddr  Args to Child             
0034f83c 76261c01 000a0e54 00000111 00000068 USER32!NtUserMessageCall+0x15
0034f87c 7625cd81 011114d0 00000000 00d41190 USER32!SendMessageWorker+0x5e9
0034f8a0 00fa1256 000a0e54 00000111 00000068 USER32!SendMessageW+0×7f
0034f90c 76256238 00040eb0 00000111 00000068 WCM_A!WndProc+0xc6
0034f938 762568ea 00fa1190 00040eb0 00000111 USER32!InternalCallWinProc+0×23
0034f9b0 76257d31 00000000 00fa1190 00040eb0 USER32!UserCallWinProcCheckWow+0×109
0034fa10 76257dfa 00fa1190 00000000 76257d79 USER32!DispatchMessageWorker+0×3bc
0034fa20 00fa10d3 0034fa3c 0034fae8 00000000 USER32!DispatchMessageW+0xf
0034fa54 00fa14b6 00fa0000 00000000 00571bee WCM_A!wWinMain+0xd3
0034fae8 76493677 7efde000 0034fb34 77399d72 WCM_A!__tmainCRTStartup+0×150
0034faf4 77399d72 7efde000 72afcb2e 00000000 kernel32!BaseThreadInitThunk+0xe
0034fb34 77399d45 00fa1625 7efde000 ffffffff ntdll!__RtlUserThreadStart+0×70
0034fb4c 00000000 00fa1625 7efde000 00000000 ntdll!_RtlUserThreadStart+0×1b

0:000> ~*kbL

.  0  Id: 10dc.e14 Suspend: 1 Teb: 7efdd000 Unfrozen
ChildEBP RetAddr  Args to Child             
0017f7c4 76261c01 000c0ea4 00000111 00000068 USER32!NtUserMessageCall+0x15
0017f804 7625cd81 00ec3ec0 00000000 012e1190 USER32!SendMessageWorker+0x5e9
0017f828 00d41256 000c0ea4 00000111 00000068 USER32!SendMessageW+0×7f
0017f890 76256238 000a0e54 00000111 00000068 WCM_B!WndProc+0xc6
0017f8bc 762568ea 00d41190 000a0e54 00000111 USER32!InternalCallWinProc+0×23
0017f934 76257177 00000000 00d41190 000a0e54 USER32!UserCallWinProcCheckWow+0×109
0017f990 762572f1 00eb14d0 00000000 00000111 USER32!DispatchClientMessage+0xe0
0017f9cc 773700e6 0017f9e4 00000000 0017fae4 USER32!__fnDWORD+0×2b
0017f9e0 00eb14d0 00000000 00000111 00000068 ntdll!KiUserCallbackDispatcher+0×2e
WARNING: Frame IP not in any known module. Following frames may be wrong.
0017fa20 00d410e0 0017fa48 00000000 00000000 0xeb14d0
0017fa60 00d414b6 00d40000 00000000 00601bee WCM_B!wWinMain+0xe0
0017faf4 76493677 7efde000 0017fb40 77399d72 WCM_B!__tmainCRTStartup+0×150
0017fb00 77399d72 7efde000 728cf6de 00000000 kernel32!BaseThreadInitThunk+0xe
0017fb40 77399d45 00d41625 7efde000 ffffffff ntdll!__RtlUserThreadStart+0×70
0017fb58 00000000 00d41625 7efde000 00000000 ntdll!_RtlUserThreadStart+0×1b

0:000> ~*kbL

.  0  Id: e68.fbc Suspend: 1 Teb: 7efdd000 Unfrozen
ChildEBP RetAddr  Args to Child             
0017f4c8 76272674 000c0ea4 00000000 00000000 USER32!NtUserWaitMessage+0x15
0017f504 7627288a 00070ee6 000c0ea4 00000000 USER32!DialogBox2+0x222
0017f530 762727b8 012e0000 012efc54 000c0ea4 USER32!InternalDialogBox+0xe5
0017f550 76272aa1 012e0000 012efc54 000c0ea4 USER32!DialogBoxIndirectParamAorW+0x37
0017f574 012e124d 012e0000 00000067 000c0ea4 USER32!DialogBoxParamW+0x3f
0017f5e4 76256238 000c0ea4 00000111 00000068 WCM_C!WndProc+0xbd
0017f610 762568ea 012e1190 000c0ea4 00000111 USER32!InternalCallWinProc+0×23
0017f688 76257177 00000000 012e1190 000c0ea4 USER32!UserCallWinProcCheckWow+0×109
0017f6e4 762572f1 01463ec0 00000000 00000111 USER32!DispatchClientMessage+0xe0
0017f720 773700e6 0017f738 00000000 0017f838 USER32!__fnDWORD+0×2b
0017f734 01463ec0 00000000 00000111 00000068 ntdll!KiUserCallbackDispatcher+0×2e
WARNING: Frame IP not in any known module. Following frames may be wrong.
0017f774 012e10e0 0017f79c 00000000 00000000 0×1463ec0
0017f7b4 012e1496 012e0000 00000000 00471bee WCM_C!wWinMain+0xe0
0017f848 76493677 7efde000 0017f894 77399d72 WCM_C!__tmainCRTStartup+0×150
0017f854 77399d72 7efde000 728ca9cf 00000000 kernel32!BaseThreadInitThunk+0xe
0017f894 77399d45 012e1605 7efde000 ffffffff ntdll!__RtlUserThreadStart+0×70
0017f8ac 00000000 012e1605 7efde000 00000000 ntdll!_RtlUserThreadStart+0×1b

Detailed modeling example (WCM application) is to follow soon.

Send message calls can also be directed to the same thread:

0: kd> kv 100
ChildEBP RetAddr  Args to Child             
aa839180 80833ed1 8c446b60 8c446c08 00000002 nt!KiSwapContext+0x26
aa8391ac 80829c14 8c446d4c 8c446d20 8c446b60 nt!KiSwapThread+0x2e5
aa8391f4 80921102 8c446d4c 00000011 8c4a8c01 nt!KeWaitForSingleObject+0x346
aa8392b0 8088b41c 000006a8 00172e58 00172e58 nt!NtRequestWaitReplyPort+0x776
aa8392b0 7c82860c 000006a8 00172e58 00172e58 nt!KiFastCallEntry+0xfc
0012f194 7c827899 77c80a6e 000006a8 00172e58 ntdll!KiFastSystemCallRet
0012f198 77c80a6e 000006a8 00172e58 00172e58 ntdll!ZwRequestWaitReplyPort+0xc
0012f1e4 77c7fcf0 0012f220 0012f204 77c80673 RPCRT4!LRPC_CCALL::SendReceive+0x230
0012f1f0 77c80673 0012f220 771f2918 0012f60c RPCRT4!I_RpcSendReceive+0x24
0012f204 77ce315a 0012f24c 00172ea8 77e63e5f RPCRT4!NdrSendReceive+0x2b
0012f5ec 771f4fbd 771f2918 771f1858 0012f60c RPCRT4!NdrClientCall2+0x22e
[...]
0012f698 7739b6e3 0004001a 00000016 00000001 ApplicationA!WndProc+0xcc
0012f6c4 7739b874 00407440 0004001a 00000016 USER32!InternalCallWinProc+0×28
0012f73c 7739c8b8 00000000 00407440 0004001a USER32!UserCallWinProcCheckWow+0×151
0012f798 7739c9c6 00607890 00000016 00000001 USER32!DispatchClientMessage+0xd9
0012f7c0 7c828556 0012f7d8 00000018 0012f894 USER32!__fnDWORD+0×24
0012f7c0 80831378 0012f7d8 00000018 0012f894 ntdll!KiUserCallbackDispatcher+0×2e
aa83957c 8091fbbb aa839634 aa839638 aa839608 nt!KiCallUserMode+0×4
aa8395d4 bf8a2492 00000002 aa839618 00000018 nt!KeUserModeCallback+0×8f
aa839658 bf8a229d be487890 00000016 00000001 win32k!SfnDWORD+0xb4
aa8396a0 bf8a1249 02487890 00000016 00000001 win32k!xxxSendMessageToClient+0×176
aa8396ec bf8a115e be487890 00000016 00000001 win32k!xxxSendMessageTimeout+0×1a6
aa839710 bf926e0d be487890 00000016 00000001 win32k!xxxSendMessage+0×1b
aa83974c bf926eb5 bc18cbc8 00000016 00000001 win32k!xxxClientShutdown2+0×87
aa839768 bf8ad9fa be487890 80000009 0000029e win32k!xxxClientShutdown+0×47
aa8397c4 bf8845d4 be487890 0000003b 80000009 win32k!xxxRealDefWindowProc+0×364
aa8397dc bf884604 be487890 0000003b 80000009 win32k!xxxWrapRealDefWindowProc+0×16
aa8397f8 bf8c1259 be487890 0000003b 80000009 win32k!NtUserfnNCDESTROY+0×27
aa839830 8088b41c 0004001a 0000003b 80000009 win32k!NtUserMessageCall+0xc0
aa839830 7c82860c 0004001a 0000003b 80000009 nt!KiFastCallEntry+0xfc (TrapFrame @ aa839854)
0012f7c0 7c828556 0012f7d8 00000018 0012f894 ntdll!KiFastSystemCallRet
0012f7c0 80831378 0012f7d8 00000018 0012f894 ntdll!KiUserCallbackDispatcher+0×2e
aa839b08 8091fbbb aa839bc0 aa839bc4 aa839b94 nt!KiCallUserMode+0×4
aa839b60 bf8a2492 00000002 aa839ba4 00000018 nt!KeUserModeCallback+0×8f
aa839be4 bf8a229d be487890 0000003b 80000009 win32k!SfnDWORD+0xb4
aa839c2c bf8c3f77 02487890 0000003b 80000009 win32k!xxxSendMessageToClient+0×176
aa839c9c bf89b88e bc18e838 aa839d64 0012fa38 win32k!xxxReceiveMessage+0×2b5
aa839cec bf89d201 aa839d18 0004001a 00000000 win32k!xxxRealInternalGetMessage+0×2d7
aa839d4c 8088b41c 0012fa5c 0004001a 00000000 win32k!NtUserGetMessage+0×3f
aa839d4c 7c82860c 0012fa5c 0004001a 00000000 nt!KiFastCallEntry+0xfc (TrapFrame @ aa839d64)
0012f9f0 7c828556 0012fa08 00000018 0012ffb0 ntdll!KiFastSystemCallRet
0012fa1c 7739c811 7739c844 0012fa5c 0004001a ntdll!KiUserCallbackDispatcher+0×2e
0012fa3c 0040634e 0012fa5c 0004001a 00000000 USER32!NtUserGetMessage+0xc
0012ff18 00408d9d 00000032 00000000 00142546 ApplicationA!WinMain+0×80f
0012ffc0 77e6f22b 00000000 00000000 7ffdf000 ApplicationA!WinMainCRTStartup+0×185
0012fff0 00000000 00408c18 00000000 78746341 kernel32!BaseProcessStart+0×23

Blocked sent message calls can also be manifested in kernel space and mixed with patterns like Message Box and Main Thread, for example:

1: kd> k250
ChildEBP RetAddr             
8d5d2808 82a7eb15 nt!KiSwapContext+0x26
8d5d2840 82a7d403 nt!KiSwapThread+0x266
8d5d2868 82a772cf nt!KiCommitThreadWait+0x1df
8d5d28e0 82550d75 nt!KeWaitForSingleObject+0x393
8d5d293c 82550e10 win32k!xxxRealSleepThread+0x1d7
8d5d2958 824ff4b0 win32k!xxxSleepThread+0x2d
8d5d29cc 825547e8 win32k!xxxInterSendMsgEx+0xb1c
8d5d2a1c 825546a4 win32k!xxxSendMessageTimeout+0x13b
8d5d2a44 82533843 win32k!xxxSendMessage+0×28
8d5d2b08 824fd865 win32k!xxxCalcValidRects+0xf7
8d5d2b64 82502c98 win32k!xxxEndDeferWindowPosEx+0×100
8d5d2b84 825170c9 win32k!xxxSetWindowPos+0xf6
8d5d2c08 82517701 win32k!xxxActivateThisWindow+0×2b1
8d5d2c38 82517537 win32k!xxxActivateWindow+0×144
8d5d2c4c 824fd9dd win32k!xxxSwpActivate+0×44
8d5d2ca4 82502c98 win32k!xxxEndDeferWindowPosEx+0×278
8d5d2cc4 824fff82 win32k!xxxSetWindowPos+0xf6
8d5d2d10 82a5342a win32k!NtUserSetWindowPos+0×140
8d5d2d10 76ee64f4 nt!KiFastCallEntry+0×12a (TrapFrame @ 8d5d2d34)
01e2cea0 7621358d ntdll!KiFastSystemCallRet
01e2cea4 6a8fa0eb USER32!NtUserSetWindowPos+0xc
01e2cf14 6a894b13 IEFRAME!SHToggleDialogExpando+0×15a
01e2cf28 6a894d5d IEFRAME!EleDlg::ToggleExpando+0×20
01e2d74c 6a895254 IEFRAME!EleDlg::OnInitDlg+0×229
01e2d7b8 762186ef IEFRAME!EleDlg::DlgProcEx+0×189
01e2d7e4 76209eb2 USER32!InternalCallWinProc+0×23
01e2d860 7620b98b USER32!UserCallDlgProcCheckWow+0xd6
01e2d8a8 7620bb7b USER32!DefDlgProcWorker+0xa8
01e2d8c4 762186ef USER32!DefDlgProcW+0×22
01e2d8f0 76218876 USER32!InternalCallWinProc+0×23
01e2d968 76217631 USER32!UserCallWinProcCheckWow+0×14b
01e2d9a8 76209b1d USER32!SendMessageWorker+0×4d0
01e2da64 76235500 USER32!InternalCreateDialog+0xb0d
01e2da94 76235553 USER32!InternalDialogBox+0xa7
01e2dab4 76235689 USER32!DialogBoxIndirectParamAorW+0×37
01e2dad8 6a5d4952 USER32!DialogBoxParamW+0×3f
01e2db00 6a5d5024 IEFRAME!Detour_DialogBoxParamW+0×47
01e2db24 6a8956df IEFRAME!SHFusionDialogBoxParam+0×32
01e2db58 6a8957bb IEFRAME!EleDlg::ShowDialog+0×398
01e2e638 6a8959d3 IEFRAME!ShowDialogBox+0xb6
01e2eb9c 6a9013ed IEFRAME!ShowElevationPrompt+0×1dd
01e2f010 7669fc8f IEFRAME!CIEUserBrokerObject::BrokerCoCreateInstance+0×202
01e2f040 76704c53 RPCRT4!Invoke+0×2a
01e2f448 76d9d936 RPCRT4!NdrStubCall2+0×2d6
01e2f490 76d9d9c6 ole32!CStdStubBuffer_Invoke+0xb6
01e2f4d8 76d9df1f ole32!SyncStubInvoke+0×3c
01e2f524 76cb213c ole32!StubInvoke+0xb9
01e2f600 76cb2031 ole32!CCtxComChnl::ContextInvoke+0xfa
01e2f61c 76d9a754 ole32!MTAInvoke+0×1a
01e2f64c 76d9dcbb ole32!AppInvoke+0xab
01e2f72c 76d9a773 ole32!ComInvokeWithLockAndIPID+0×372
01e2f778 7669f34a ole32!ThreadInvoke+0×302
01e2f7b4 7669f4da RPCRT4!DispatchToStubInCNoAvrf+0×4a
01e2f80c 7669f3c6 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×16c
01e2f834 766a0cef RPCRT4!RPC_INTERFACE::DispatchToStub+0×8b
01e2f86c 7669f882 RPCRT4!RPC_INTERFACE::DispatchToStubWithObject+0xb2
01e2f8b8 7669f7a4 RPCRT4!LRPC_SCALL::DispatchRequest+0×23b
01e2f8d8 7669f763 RPCRT4!LRPC_SCALL::QueueOrDispatchCall+0xbd
01e2f8f4 7669f5ff RPCRT4!LRPC_SCALL::HandleRequest+0×34f
01e2f928 7669f573 RPCRT4!LRPC_SASSOCIATION::HandleRequest+0×144
01e2f960 7669ee4f RPCRT4!LRPC_ADDRESS::HandleRequest+0xbd
01e2f9dc 7669ece7 RPCRT4!LRPC_ADDRESS::ProcessIO+0×50a
01e2f9e8 766a1357 RPCRT4!LrpcServerIoHandler+0×16
01e2f9f8 76ecd3a3 RPCRT4!LrpcIoComplete+0×16
01e2fa20 76ed0748 ntdll!TppAlpcpExecuteCallback+0×1c5
01e2fb88 76e11174 ntdll!TppWorkerThread+0×5a4
01e2fb94 76efb3f5 kernel32!BaseThreadInitThunk+0xe
01e2fbd4 76efb3c8 ntdll!__RtlUserThreadStart+0×70
01e2fbec 00000000 ntdll!_RtlUserThreadStart+0×1b

2: kd> !process 890ff430 1f
PROCESS 890ff430  SessionId: 1  Cid: 18a4    Peb: 7ffdc000  ParentCid: 1fdc
DirBase: 7fbf04e0  ObjectTable: da89fb80  HandleCount: 852.
Image: iexplore.exe

THREAD 89141db0  Cid 18a4.19c8  Teb: 7ffdf000 Win32Thread: bc373d18 WAIT: (Unknown) UserMode Non-Alertable
    8915b020  SynchronizationEvent
Not impersonating
DeviceMap                 da7f9680
Owning Process            890ff430       Image:         iexplore.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      56879          Ticks: 1634 (0:00:00:25.531)
Context Switch Count      12410  NoStackSwap    LargeStack
UserTime                  00:00:00.078
KernelTime                00:00:01.234
Win32 Start Address iexplore!wWinMainCRTStartup (0x004031b9)
Start Address kernel32!BaseProcessStartThunk (0x77e617f8)
Stack Init b5672000 Current b56717c4 Base b5672000 Limit b566c000 Call 0
Priority 4 BasePriority 4 PriorityDecrement 0
ChildEBP RetAddr              
b56717dc 80833ec5 nt!KiSwapContext+0x26
b5671808 80829c14 nt!KiSwapThread+0x2e5
b5671850 bf89ab73 nt!KeWaitForSingleObject+0x346
b56718ac bf8c4ba6 win32k!xxxSleepThread+0x1be
b5671948 bf8a13e0 win32k!xxxInterSendMsgEx+0x798
b5671994 bf8a132f win32k!xxxSendMessageTimeout+0x1f3
b56719b8 bf85ca01 win32k!xxxSendMessage+0×1b
b5671a7c bf85da04 win32k!xxxCalcValidRects+0xea
b5671ad8 bf85de2e win32k!xxxEndDeferWindowPosEx+0xf2
b5671af4 bf861cf2 win32k!xxxSetWindowPos+0xb1
b5671b3c bf882098 win32k!xxxProcessEventMessage+0×232
b5671c7c bf89b89e win32k!xxxScanSysQueue+0×21e
b5671ce4 bf89c529 win32k!xxxRealInternalGetMessage+0×2aa
b5671d48 8088b41c win32k!NtUserPeekMessage+0×42
b5671d48 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ b5671d64)
0012e6e8 7739bde5 ntdll!KiFastSystemCallRet
0012e714 7739be5e USER32!NtUserPeekMessage+0xc
0012e740 02935f8c USER32!PeekMessageW+0xab
0012e7b4 02936150 IEUI!DUserRegisterSuper+0×920
0012e7d4 40d2ee98 IEUI!PeekMessageExW+0×42
0012e818 40d2abf4 IEFRAME!CBrowserFrame::FrameMessagePump+0×23
0012e824 40d2bc63 IEFRAME!BrowserThreadProc+0×3f
0012e848 40d2bbb1 IEFRAME!BrowserNewThreadProc+0×7b
0012f8b8 40d2ba61 IEFRAME!SHOpenFolderWindow+0×188
0012fae8 00401484 IEFRAME!IEWinMain+0×2d9
0012ff2c 0040131f iexplore!wWinMain+0×2c6
0012ffc0 77e6f23b iexplore!_initterm_e+0×1b1
0012fff0 00000000 kernel32!BaseProcessStart+0×23

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -