PART 3: Pattern Interaction

Main Thread, Self-Diagnosis, Window Message Chain, Blocking Module, Ubiquitous Component, Dual Stack Trace, Pipe Wait Chain and Coupled Machines

An IE window was frozen and user process memory dump files from all IE process instances inside a user session were saved. The first instance revealed a main thread (Volume 1, page 436) which self-diagnosed (Volume 2, page 318) a hang tab and was blocked in a window message chain (page 55):

0:000> kL
ChildEBP RetAddr
0012ea84 7e4194be ntdll!KiFastSystemCallRet
0012eac0 7e4292e3 user32!NtUserMessageCall+0xc
0012eae0 3e4171a1 user32!SendMessageW+0×7f
0012eaf4 3e41863f ieframe!CTabWindow::_MakeBlockingCallToHungTabToTriggerNtUserHangDetection+0×11
0012eb00 3e31d261 ieframe!CTabWindow::MarkTabAsHung+0×48
0012eb1c 7e418734 ieframe!FrameTabWndProc+0×5c
0012eb48 7e418816 user32!InternalCallWinProc+0×28
0012ebb0 7e4189cd user32!UserCallWinProcCheckWow+0×150
0012ec10 7e418a10 user32!DispatchMessageWorker+0×306
0012ec20 3e2ed530 user32!DispatchMessageW+0xf
0012ec88 3e204dd9 ieframe!CBrowserFrame::FrameMessagePump+0×3d7
0012ecd0 3e1ea0a7 ieframe!BrowserThreadProc+0xf7
0012ecf0 3e1ea004 ieframe!BrowserNewThreadProc+0×88
0012fd60 3e1e9f26 ieframe!SHOpenFolderWindow+0×10e
0012fd84 3e1e9c75 ieframe!IEWinMainEx+0×1ff
0012fda0 3e1ebf1d ieframe!IEWinMain+0×77
0012fdd8 00402e11 ieframe!LCIEStartAsFrame+0×252
0012ff2c 0040128e iexplore!wWinMain+0×368
0012ffc0 7c817077 iexplore!_initterm_e+0×1b1
0012fff0 00000000 kernel32!BaseProcessStart+0×23

We looked at other IE instances and found the one thread with a blocking module (page 54):

0:017> kL 100
ChildEBP RetAddr
02c34100 7c90df5a ntdll!KiFastSystemCallRet
02c34104 7c8025db ntdll!ZwWaitForSingleObject+0xc
02c34168 7c802542 kernel32!WaitForSingleObjectEx+0xa8
02c3417c 009f0ed9 kernel32!WaitForSingleObject+0x12
WARNING: Stack unwind information not available. Following frames may be wrong.
02c34a08 00bc2c9a ModuleA!DllCanUnloadNow+0×6db39
02c3526c 00bc2fa4 ModuleA!DllCanUnloadNow+0×23f8fa
02c35ae0 00f6413c ModuleA!DllCanUnloadNow+0×23fc04
02c363e8 00c761ab ModuleA!DllCanUnloadNow+0×5e0d9c
02c36c74 00c74daa ModuleA!DllCanUnloadNow+0×2f2e0b
02c374e4 3d1a9eb4 ModuleA!DllCanUnloadNow+0×2f1a0a
02c3753c 3d0ed032 mshtml!CView::SetObjectRectsHelper+0×98
02c37578 3cf7e43b mshtml!CView::EndDeferSetObjectRects+0×75
02c375bc 3cf2542d mshtml!CView::EnsureView+0×39f
02c375d8 3cf4072c mshtml!CElement::EnsureRecalcNotify+0×17c
02c37614 3cf406ce mshtml!CElement::get_clientHeight_Logical+0×54
02c37628 3d0822a1 mshtml!CElement::get_clientHeight+0×27
02c37648 3cf8ad53 mshtml!G_LONG+0×7b
02c376bc 3cf96e21 mshtml!CBase::ContextInvokeEx+0×5d1
02c3770c 3cfa2baf mshtml!CElement::ContextInvokeEx+0×9d
02c37738 3cf8a751 mshtml!CElement::VersionedInvokeEx+0×2d
02c37788 3d7c389a mshtml!PlainInvokeEx+0xea
02c377c8 3d7c37e6 jscript!IDispatchExInvokeEx2+0xf8
02c37804 3d7c4d26 jscript!IDispatchExInvokeEx+0×6a
02c378c4 3d7c4c80 jscript!InvokeDispatchEx+0×98
02c378f8 3d7c4996 jscript!VAR::InvokeByName+0×135
02c37a90 3d7c11ab jscript!CScriptRuntime::Run+0×654
02c37b78 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c37bc4 3d7c48ac jscript!ScrFncObj::Call+0×8f
02c37c48 3d7c26c5 jscript!NameTbl::InvokeInternal+0×137
02c37c7c 3d7c2f14 jscript!VAR::InvokeByDispID+0×17c
02c37e18 3d7c11ab jscript!CScriptRuntime::Run+0×29e0
02c37f00 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c37f4c 3d7c48ac jscript!ScrFncObj::Call+0×8f
02c37fd0 3d7c26c5 jscript!NameTbl::InvokeInternal+0×137
02c38004 3d7c4d93 jscript!VAR::InvokeByDispID+0×17c
02c381a0 3d7c11ab jscript!CScriptRuntime::Run+0×2abe
02c38288 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c382d4 3d7c48ac jscript!ScrFncObj::Call+0×8f
02c38358 3d7c26c5 jscript!NameTbl::InvokeInternal+0×137
02c3838c 3d7c4d93 jscript!VAR::InvokeByDispID+0×17c
02c38528 3d7c11ab jscript!CScriptRuntime::Run+0×2abe
02c38610 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c3865c 3d7c2805 jscript!ScrFncObj::Call+0×8f
02c386e0 3d7c26c5 jscript!NameTbl::InvokeInternal+0×2a2
02c38714 3d7c41fc jscript!VAR::InvokeByDispID+0×17c
02c38754 3d7c22c1 jscript!VAR::InvokeJSObj<SYM *>+0xb8
02c38790 3d7c2b6d jscript!VAR::InvokeByName+0×170
02c387dc 3d7c4035 jscript!VAR::InvokeDispName+0×7a
02c3880c 3d7c4d93 jscript!VAR::InvokeByDispID+0xce
02c389a8 3d7c11ab jscript!CScriptRuntime::Run+0×2abe
02c38a90 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c38adc 3d7c48ac jscript!ScrFncObj::Call+0×8f
02c38b60 3d7c26c5 jscript!NameTbl::InvokeInternal+0×137
02c38b94 3d7c4d93 jscript!VAR::InvokeByDispID+0×17c
02c38d30 3d7c11ab jscript!CScriptRuntime::Run+0×2abe
02c38e18 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c38e64 3d7c2805 jscript!ScrFncObj::Call+0×8f
02c38ee8 3d7c26c5 jscript!NameTbl::InvokeInternal+0×2a2
02c38f1c 3d7c41fc jscript!VAR::InvokeByDispID+0×17c
02c38f5c 3d7c22c1 jscript!VAR::InvokeJSObj<SYM *>+0xb8
02c38f98 3d7c2b6d jscript!VAR::InvokeByName+0×170
02c38fe4 3d7c4035 jscript!VAR::InvokeDispName+0×7a
02c39014 3d7c2f14 jscript!VAR::InvokeByDispID+0xce
02c391b0 3d7c11ab jscript!CScriptRuntime::Run+0×29e0
02c39298 3d7c10e5 jscript!ScrFncObj::CallWithFrameOnStack+0xff
02c392e4 3d7c0f13 jscript!ScrFncObj::Call+0×8f
02c39360 3d7a3ea3 jscript!CSession::Execute+0×175
02c393ac 3d7a552f jscript!COleScript::ExecutePendingScripts+0×1c0
02c39410 3d7a5345 jscript!COleScript::ParseScriptTextCore+0×29a
02c39438 3ceca304 jscript!COleScript::ParseScriptText+0×30
02c39490 3d0955af mshtml!CScriptCollection::ParseScriptText+0×219
02c3b528 3d07a59c mshtml!CWindow::ExecuteScriptUri+0×19f
02c3b570 3d0958fd mshtml!CWindow::NavigateEx+0×5a
02c3b5dc 3d10a995 mshtml!CDoc::ExecuteScriptUri+0×262
02c3b648 3d056840 mshtml!CWindow::SuperNavigateInternal+0×335
02c3b67c 3e27d357 mshtml!CWindow::SuperNavigate2WithBindFlags+0×29
02c3b70c 3e27d1fb ieframe!CDocObjectHost::_NavigateDocument+0×1d9
02c3c7b0 3e27ab0e ieframe!CDocObjectHost::SetTarget+0×37b
02c3c7e8 3e27a8f1 ieframe!CDocObjectView::CreateViewWindow2+0xea
02c3c820 3e27a22a ieframe!CDocObjectView::CreateViewWindow+0×49
02c3c8dc 3e27a149 ieframe!FileCabinet_CreateViewWindow2+0×29d
02c3c900 3e27a067 ieframe!CBaseBrowser2::_CreateViewWindow+0×2b
02c3c940 3e279f1b ieframe!CBaseBrowser2::_CreateNewShellView+0×1a6
02c3c970 3e279e4e ieframe!CBaseBrowser2::_CreateNewShellViewPidl+0xe1
02c3d9f4 3e27c2dd ieframe!CBaseBrowser2::v_NavigateToPidl+0×2c3
02c3dc44 3e2ad948 ieframe!CBaseBrowser2::_OnGoto+0×2fb
02c3dc58 3e2e8a01 ieframe!CBaseBrowser2::v_WndProc+0×340
02c3dcbc 3e2e894f ieframe!CShellBrowser2::v_WndProc+0×3fe
02c3dce0 7e418734 ieframe!CShellBrowser2::s_WndProc+0xfb
02c3dd0c 7e418816 user32!InternalCallWinProc+0×28
02c3dd74 7e4189cd user32!UserCallWinProcCheckWow+0×150
02c3ddd4 7e418a10 user32!DispatchMessageWorker+0×306
02c3dde4 3e2ec2a5 user32!DispatchMessageW+0xf
02c3feec 3e293357 ieframe!CTabWindow::_TabWindowThreadProc+0×54c
02c3ffa4 3e134435 ieframe!LCIETab_ThreadProc+0×2c1
02c3ffb4 7c80b729 iertutil!CIsoScope::RegisterThread+0xab
02c3ffec 00000000 kernel32!BaseThreadStart+0×37

The ModuleA component was quite ubiquitous (Volume 4, page 94) and seen in other threads from the same process:

1 Id: e8c.b5c Suspend: 1 Teb: 7ffdc000 Unfrozen
ChildEBP RetAddr
01f9f698 7c90d21a ntdll!KiFastSystemCallRet
01f9f69c 7c8023f1 ntdll!NtDelayExecution+0xc
01f9f6f4 7c802455 kernel32!SleepEx+0x61
01f9f704 009d284a kernel32!Sleep+0xf
WARNING: Stack unwind information not available. Following frames may be wrong.
01f9ffb4 7c80b729 ModuleA!DllCanUnloadNow+0×4f4aa
01f9ffec 00000000 kernel32!BaseThreadStart+0×37

25 Id: e8c.f20 Suspend: 1 Teb: 7ff9c000 Unfrozen
ChildEBP RetAddr
086acac4 7c90df5a ntdll!KiFastSystemCallRet
086acac8 7c8025db ntdll!ZwWaitForSingleObject+0xc
086acb2c 7c802542 kernel32!WaitForSingleObjectEx+0xa8
086acb40 00fbba3a kernel32!WaitForSingleObject+0x12
WARNING: Stack unwind information not available. Following frames may be wrong.
086ad3c8 00fbc139 ModuleA!DllCanUnloadNow+0×63869a
086adc38 00faba75 ModuleA!DllCanUnloadNow+0×638d99
086ae4c8 00fa0da8 ModuleA!DllCanUnloadNow+0×6286d5
086aed60 00a45331 ModuleA!DllCanUnloadNow+0×61da08
086af6c4 00a44b10 ModuleA!DllCanUnloadNow+0xc1f91
086affb4 7c80b729 ModuleA!DllCanUnloadNow+0xc1770
086affec 00000000 kernel32!BaseThreadStart+0×37

Fortunately we also had a complete memory dump generated shortly after hang and from it we could find dual stack traces (page 52) from the same processes and find that blocked threads were waiting for named pipes (page 60) with endpoints on another PC. So we advised to take a complete memory dump from the coupled machine (Volume 5, page 81).

Abridged Dump, Embedded Comment, Spiking Thread, Incorrect Stack Trace and Top Module

When loading a process user memory dump we recognized it as abridged (Volume 5, page 88) and its embedded comment pointed to a spiking thread (Volume 1, page 305:

Loading Dump File [ApplicationA_101212_165342.dmp]
User Mini Dump File:  Only registers, stack and portions of memory are
available

Comment: '
*** procdump -c 60 -s 5 -n 3 ApplicationA.exe
*** Process exceeded 60% CPU for 5 seconds.  Thread consuming CPU: 540
(0×21c)‘

This thread is already a default thread:

0:005> ~
0 Id: c1c.c20 Suspend: 0 Teb: 7ffdf000 Unfrozen
1 Id: c1c.c44 Suspend: 0 Teb: 7ffde000 Unfrozen
2 Id: c1c.d34 Suspend: 0 Teb: 7ffdc000 Unfrozen
3 Id: c1c.d38 Suspend: 0 Teb: 7ffda000 Unfrozen
4 Id: c1c.d3c Suspend: 0 Teb: 7ffd9000 Unfrozen
. 5 Id: c1c.21c Suspend: 0 Teb: 7ffd8000 Unfrozen
6 Id: c1c.1c10 Suspend: 0 Teb: 7ffdd000 Unfrozen
7 Id: c1c.1678 Suspend: 0 Teb: 7ffd6000 Unfrozen
8 Id: c1c.cbc Suspend: 0 Teb: 7ffd5000 Unfrozen
9 Id: c1c.1754 Suspend: 0 Teb: 7ffaf000 Unfrozen
10 Id: c1c.c40 Suspend: 0 Teb: 7ffad000 Unfrozen
11 Id: c1c.1d24 Suspend: 0 Teb: 7ffd7000 Unfrozen

The stack trace looks incorrect (Volume 1, page 288):

0:005> kL
ChildEBP RetAddr
01abc4d8 6efba23d ntdll!KiFastSystemCallRet
WARNING: Stack unwind information not available. Following frames may be
wrong.
01abc988 7c820833 ModuleB+0×2a23d
01abcbe4 7c8207f6 kernel32!GetVolumeNameForRoot+0×26
01abcc0c 7c82e6de kernel32!BasepGetVolumeNameForVolumeMountPoint+0×75
01abcc54 6efaf70b kernel32!GetVolumePathNameW+0×18a
01abccdc 6efbd1a6 ModuleB+0×1f70b
01abcce0 00000000 ModuleB+0×2d1a6

However, we see a 3rd party top module (page 62) and advise to check its vendor for any updates:

0:005> lmt m ModuleB
start    end      module name
6ef90000 6efff000 ModuleB Wed Mar 10 20:18:21 2010

Stack Trace Collection, Message Box, Self-Diagnosis, Version-Specific Extension, Managed Stack Trace and Managed Code Exception

A service written in one of .NET languages was described as crashing and a process dump was collected for analysis. The default analysis command couldn't find an exception so we had to look at a stack trace collection (Volume 1, page 409) to find any anomalies. Indeed, there was a thread with message box (Volume 2, page 177) code:

0:010> kL
Child-SP RetAddr Call Site
00000000`1f69e808 00000000`774b4bc4 user32!ZwUserWaitMessage+0xa
00000000`1f69e810 00000000`774b4edd user32!DialogBox2+0x274
00000000`1f69e8a0 00000000`77502920 user32!InternalDialogBox+0x135
00000000`1f69e900 00000000`77501c15 user32!SoftModalMessageBox+0x9b4
00000000`1f69ea30 00000000`7750146b user32!MessageBoxWorker+0x31d
00000000`1f69ebf0 00000000`77501362 user32!MessageBoxTimeoutW+0xb3
00000000`1f69ecc0 000007fe`f1590ce7 user32!MessageBoxW+0×4e
00000000`1f69ed00 000007fe`eb0f5c59
mscorwks!DoNDirectCall__PatchGetThreadCall+0×7b
[...]

MessageBoxW parameters were showing self-diagnosis pattern (Volume 2, page 318) with a stack trace:

0:010> du 00000000`085f90c8
00000000`085f90c8 “...... at ClassA.foo()”
[...]

0:010> du 00000000`085f9c40
00000000`085f9c40 “Assertion Failed: Abort=Quit, Re”
00000000`085f9c80 “try=Debug, Ignore=Continue”

We tried unsuccessfully to load CLR extensions and requested the copy of .NET Framework from the affected computer. After that we were able to load version-specific extension (page 99), see managed stack trace (page 115) and managed code exception (Volume 1, page 331):

0:010> !DumpStack
OS Thread Id: 0x8dc (15)
Child-SP RetAddr Call Site
000000001f69e808 00000000774b4bc4 user32!ZwUserWaitMessage+0xa
000000001f69e810 00000000774b4edd user32!DialogBox2+0x274
000000001f69e8a0 0000000077502920 user32!InternalDialogBox+0x135
000000001f69e900 0000000077501c15 user32!SoftModalMessageBox+0x9b4
000000001f69ea30 000000007750146b user32!MessageBoxWorker+0x31d
000000001f69ebf0 0000000077501362 user32!MessageBoxTimeoutW+0xb3
000000001f69ecc0 000007fef1590ce7 user32!MessageBoxW+0x4e
000000001f69ed00 000007feeb0f5c59
mscorwks!DoNDirectCall__PatchGetThreadCall+0x7b
[...]
000000001f69e030 000007ff00a9ba1c ModuleA!ClassA.foo()+0×47
[...]
000000001f69fe30 000000007781c521 kernel32!BaseThreadInitThunk+0xd
000000001f69fe60 0000000000000000 ntdll!RtlUserThreadStart+0×1d

0:010> ~0s

0:000> !pe
Exception object: 0000000005a976b8
Exception type: System.FormatException
Message: Index (zero based) must be greater than or equal to zero and less
than the size of the argument list.
InnerException: <none>
StackTrace (generated):
SP IP Function
0000000000D0BE40 000007FEEC2153B0
mscorlib_ni!System.Text.StringBuilder.AppendFormat(System.IFormatProvider,
System.String, System.Object[])+0x999280
0000000000D0BEE0 000007FEEB87C0FA
mscorlib_ni!System.String.Format(System.IFormatProvider, System.String,
System.Object[])+0x5a
0000000000D0BF30 000007FF00AB336B ModuleA!ClassB.get()+0xeb