Software Diagnostics Library

Sending process crash dumps can lead to the exposure of passwords and other sensitive information especially if they were saved before a process was trying to send entered user data over a secure protocol. Here’s an incident that happened to me this morning. I was trying to login to an online banking system to check my balances and when I entered my user id and password in IE and clicked Continue button the system experienced a small delay and then a WER dialog box appeared asking me to either check online for a solution, debug or close the program. I chose Close the program and a full process memory dump was saved because I have already set up LocalDumps on my old Vista system (the problem was also reproducible).

I opened the crash dump and found that it was a heap corruption:

0:004> kL 100
ChildEBP RetAddr 
02c9cb18 77815620 ntdll!KiFastSystemCallRet
02c9cb1c 77843c62 ntdll!NtWaitForSingleObject+0xc
02c9cba0 77843d4b ntdll!RtlReportExceptionEx+0x14b
02c9cbe0 7785fa87 ntdll!RtlReportException+0x3c
02c9cbf4 7785fb0d ntdll!RtlpTerminateFailureFilter+0x14
02c9cc00 777b9bdc ntdll!RtlReportCriticalFailure+0x6b
02c9cc14 777b4067 ntdll!_EH4_CallFilterFunc+0x12
02c9cc3c 77815f79 ntdll!_except_handler4+0x8e
02c9cc60 77815f4b ntdll!ExecuteHandler2+0x26
02c9cd10 77815dd7 ntdll!ExecuteHandler+0x24
02c9cd10 7785faf8 ntdll!KiUserExceptionDispatcher+0xf
02c9d084 77860704 ntdll!RtlReportCriticalFailure+0x5b
02c9d094 778607f2 ntdll!RtlpReportHeapFailure+0×21
02c9d0c8 7782b1a5 ntdll!RtlpLogHeapFailure+0xa1
02c9d110 7781730a ntdll!RtlpCoalesceFreeBlocks+0×4b9
02c9d208 77817545 ntdll!RtlpFreeHeap+0×1e2
02c9d224 76277e4b ntdll!RtlFreeHeap+0×14e
02c9d26c 760f7277 kernel32!GlobalFree+0×47
02c9d280 76594a1f ole32!ReleaseStgMedium+0×124
02c9d294 765f7feb urlmon!ReleaseBindInfo+0×4c
02c9d2a4 765b9a87 urlmon!CINet::ReleaseCNetObjects+0×3d
02c9d2bc 765b93f0 urlmon!CINetHttp::OnWininetRequestHandleClosing+0×60
02c9d2d0 77582078 urlmon!CINet::CINetCallback+0×2de
02c9d418 77588f5d wininet!InternetIndicateStatus+0xfc
02c9d448 7758937a wininet!HANDLE_OBJECT::~HANDLE_OBJECT+0xc9
02c9d464 7758916b wininet!INTERNET_CONNECT_HANDLE_OBJECT::~INTERNET_CONNECT_HANDLE_OBJECT+0×209
02c9d470 77588d5e wininet!HTTP_REQUEST_HANDLE_OBJECT::`vector deleting destructor’+0xd
02c9d480 77584e72 wininet!HANDLE_OBJECT::Dereference+0×22
02c9d48c 77589419 wininet!DereferenceObject+0×21
02c9d4b4 77589114 wininet!_InternetCloseHandle+0×9d
02c9d4d4 0004aaaf wininet!InternetCloseHandle+0×11e
WARNING: Frame IP not in any known module. Following frames may be wrong.
02c9d4e0 765a5d25 0×4aaaf
02c9d4fc 765a5c1b urlmon!CINet::TerminateRequest+0×82
02c9d50c 765a5a3c urlmon!CINet::MyTerminate+0×7b
02c9d51c 765a5998 urlmon!CINetProtImpl::Terminate+0×13
02c9d538 765a5b92 urlmon!CINetEmbdFilter::Terminate+0×17
02c9d548 765b9bc1 urlmon!CINet::Terminate+0×23
02c9d55c 765979f2 urlmon!CINetHttp::Terminate+0×48
02c9d574 7659766b urlmon!COInetProt::Terminate+0×1d
02c9d598 765979c0 urlmon!CTransaction::Terminate+0×12d
02c9d5b8 76597a2d urlmon!CBinding::ReportResult+0×92
02c9d5d0 76596609 urlmon!COInetProt::ReportResult+0×1a
02c9d5f8 76596322 urlmon!CTransaction::DispatchReport+0×1d9
02c9d624 7659653e urlmon!CTransaction::DispatchPacket+0×31
02c9d644 765a504b urlmon!CTransaction::OnINetCallback+0×92
02c9d65c 7741fd72 urlmon!TransactionWndProc+0×28
02c9d688 7741fe4a user32!InternalCallWinProc+0×23
02c9d700 7742018d user32!UserCallWinProcCheckWow+0×14b
02c9d764 7742022b user32!DispatchMessageWorker+0×322
02c9d774 7094c1d5 user32!DispatchMessageW+0xf
02c9f87c 708f337e ieframe!CTabWindow::_TabWindowThreadProc+0×54c
02c9f934 7647426d ieframe!LCIETab_ThreadProc+0×2c1
02c9f944 7627d0e9 iertutil!CIsoScope::RegisterThread+0xab
02c9f950 777f19bb kernel32!BaseThreadInitThunk+0xe
02c9f990 777f198e ntdll!__RtlUserThreadStart+0×23
02c9f9a8 00000000 ntdll!_RtlUserThreadStart+0×1b

So I quicky enable full page heap for iexpolore.exe and tried to login again. The crash happened after the same GUI sequence and the new dump was saved again with the following stack trace:

0:004> kL 100
ChildEBP RetAddr 
04c590cc 77815610 ntdll!KiFastSystemCallRet
04c590d0 7627a5d7 ntdll!NtWaitForMultipleObjects+0xc
04c5916c 7627a6f0 kernel32!WaitForMultipleObjectsEx+0x11d
04c59188 762ee2a5 kernel32!WaitForMultipleObjects+0x18
04c591f4 762ee4d1 kernel32!WerpReportFaultInternal+0x16d
04c59208 762cff4d kernel32!WerpReportFault+0x70
04c59294 77827fc1 kernel32!UnhandledExceptionFilter+0x1b5
04c5929c 777b9bdc ntdll!__RtlUserThreadStart+0x6f
04c592b0 777b4067 ntdll!_EH4_CallFilterFunc+0x12
04c592d8 77815f79 ntdll!_except_handler4+0x8e
04c592fc 77815f4b ntdll!ExecuteHandler2+0x26
04c593ac 77815dd7 ntdll!ExecuteHandler+0x24
04c593ac 0004a058 ntdll!KiUserExceptionDispatcher+0xf
WARNING: Frame IP not in any known module. Following frames may be wrong.
04c596b4 0004a12e 0x4a058
04c596d4 765bb7b1 0×4a12e
04c59714 765bb32b urlmon!CINetHttp::INetAsyncSendRequest+0×347
04c59f34 765bb4c8 urlmon!CINetHttp::INetAsyncOpenRequest+0×2cf
04c59f48 765bac97 urlmon!CINet::INetAsyncConnect+0×24b
04c59f60 765a6af9 urlmon!CINet::INetAsyncOpen+0×11b
04c59f70 765a6aaa urlmon!CINet::INetAsyncStart+0×1a
04c59f8c 765a693f urlmon!CINet::StartCommon+0×198
04c59fa8 765a6b5e urlmon!CINet::StartEx+0×1c
04c59fdc 76598e84 urlmon!COInetProt::StartEx+0xc2
04c5a02c 76599411 urlmon!CTransaction::StartEx+0×3e1
04c5a0b4 76599022 urlmon!CBinding::StartBinding+0×602
04c5a0f8 76599fc0 urlmon!CUrlMon::StartBinding+0×169
04c5a120 6ca4eac6 urlmon!CUrlMon::BindToStorage+0×90
04c5a14c 6ca4e9cb mshtml!CStreamProxy::Bind+0xce
04c5a3ec 6ca4b277 mshtml!CDwnBindData::Bind+0×74b
04c5a414 6ca4b118 mshtml!NewDwnBindData+0×15f
04c5a464 6c9cf0aa mshtml!CDwnLoad::Init+0×121
04c5a4b8 6ca4aa61 mshtml!CHtmLoad::Init+0×1fe
04c5a4dc 6ca4a967 mshtml!CDwnInfo::SetLoad+0×119
04c5a4fc 6c9ce021 mshtml!CDwnCtx::SetLoad+0×7a
04c5a514 6c9cec7b mshtml!CHtmCtx::SetLoad+0×13
04c5a534 6c9c25c9 mshtml!CMarkup::Load+0×167
04c5a738 6cb6f395 mshtml!CMarkup::LoadFromInfo+0xb5a
04c5a910 6cb6f532 mshtml!CDoc::DoNavigate+0×1508
04c5aa30 6cde557e mshtml!CDoc::FollowHyperlink2+0xda7
04c5aaf8 6cde5170 mshtml!CFormElement::DoSubmit+0×405
04c5ab0c 6ca01bc5 mshtml!CFormElement::submit+0×11
04c5ab28 6ca8adc3 mshtml!Method_void_void+0×75
04c5ab9c 6ca96e11 mshtml!CBase::ContextInvokeEx+0×5d1
04c5abec 6cb89057 mshtml!CElement::ContextInvokeEx+0×9d
04c5ac28 6ca8a7c1 mshtml!CFormElement::VersionedInvokeEx+0xf0
04c5ac78 6d1f392a mshtml!PlainInvokeEx+0xea
04c5acb8 6d1f3876 jscript!IDispatchExInvokeEx2+0xf8
04c5acf4 6d1f4db6 jscript!IDispatchExInvokeEx+0×6a
04c5adb4 6d1f4d10 jscript!InvokeDispatchEx+0×98
04c5ade8 6d1f2bfd jscript!VAR::InvokeByName+0×135
04c5ae34 6d1f40c5 jscript!VAR::InvokeDispName+0×7a
04c5ae64 6d1f4e23 jscript!VAR::InvokeByDispID+0xce
04c5b000 6d1f123b jscript!CScriptRuntime::Run+0×2abe
04c5b0e8 6d1f1175 jscript!ScrFncObj::CallWithFrameOnStack+0xff
04c5b134 6d1f493c jscript!ScrFncObj::Call+0×8f
04c5b1b8 6d1f2755 jscript!NameTbl::InvokeInternal+0×137
04c5b1ec 6d1f2fa4 jscript!VAR::InvokeByDispID+0×17c
04c5b388 6d1f123b jscript!CScriptRuntime::Run+0×29e0
04c5b470 6d1f1175 jscript!ScrFncObj::CallWithFrameOnStack+0xff
04c5b4bc 6d1f0fa3 jscript!ScrFncObj::Call+0×8f
04c5b538 6d1d3ea3 jscript!CSession::Execute+0×175
04c5b584 6d1d552f jscript!COleScript::ExecutePendingScripts+0×1c0
04c5b5e8 6d1d5345 jscript!COleScript::ParseScriptTextCore+0×29a
04c5b610 6c9ca304 jscript!COleScript::ParseScriptText+0×30
04c5b668 6cb954c2 mshtml!CScriptCollection::ParseScriptText+0×219
04c5d700 6cb7a568 mshtml!CWindow::ExecuteScriptUri+0×19f
04c5d748 6cb95810 mshtml!CWindow::NavigateEx+0×5a
04c5d7b4 6cb956b5 mshtml!CDoc::ExecuteScriptUri+0×262
04c5d7f0 6cc66b68 mshtml!CDoc::ExecuteScriptURL+0×4e
04c5d844 6cad41a7 mshtml!CHyperlink::ClickAction+0×269
04c5d854 6cad416e mshtml!CAnchorElement::ClickAction+0×10
04c5d888 6cb296c5 mshtml!CElement::DoClick+0×155
04c5d8b8 6cad01ff mshtml!CAnchorElement::DoClick+0×6d
04c5d954 6cbae941 mshtml!CDoc::PumpMessage+0xf63
04c5dacc 6cad4408 mshtml!CDoc::OnMouseMessage+0×55d
04c5dbf8 6caa9241 mshtml!CDoc::OnWindowMessage+0×9d9
04c5dc24 7741fd72 mshtml!CServer::WndProc+0×78
04c5dc50 7741fe4a user32!InternalCallWinProc+0×23
04c5dcc8 7742018d user32!UserCallWinProcCheckWow+0×14b
04c5dd2c 7742022b user32!DispatchMessageWorker+0×322
04c5dd3c 7094c1d5 user32!DispatchMessageW+0xf
04c5fe44 708f337e ieframe!CTabWindow::_TabWindowThreadProc+0×54c
04c5fefc 7647426d ieframe!LCIETab_ThreadProc+0×2c1
04c5ff0c 7627d0e9 iertutil!CIsoScope::RegisterThread+0xab
04c5ff18 777f19bb kernel32!BaseThreadInitThunk+0xe
04c5ff58 777f198e ntdll!__RtlUserThreadStart+0×23
04c5ff70 00000000 ntdll!_RtlUserThreadStart+0×1b

We see that IE was trying to send an HTTP request:

 0:004> ub 765bb7b1
urlmon!CINetHttp::INetAsyncSendRequest+0x31f:
765bb799 8bce            mov     ecx,esi
765bb79b e8ef000000      call    urlmon!CINetHttp::SetOptionUserAgent (765bb88f)
765bb7a0 ff75f0          push    dword ptr [ebp-10h]
765bb7a3 ff75ec          push    dword ptr [ebp-14h]
765bb7a6 53              push    ebx
765bb7a7 53              push    ebx
765bb7a8 ff767c          push    dword ptr [esi+7Ch]
765bb7ab ff1544a06576    call    dword ptr [urlmon!_imp__HttpSendRequestW (7665a044)]

From MSDN we get the following function prototype:

BOOL HttpSendRequest(
  __in  HINTERNET hRequest,
  __in  LPCTSTR lpszHeaders,
  __in  DWORD dwHeadersLength,
  __in  LPVOID lpOptional,
  __in  DWORD dwOptionalLength
);

So we check raw stack for parameters:

0:004> dps 04c596d4
04c596d4  04c59714
04c596d8  765bb7b1 urlmon!CINetHttp::INetAsyncSendRequest+0x347
04c596dc  00cc000c ; hRequest
04c596e0  1122cd58 ; lpszHeaders
04c596e4  ffffffff ; dwHeadersLength (-1)
04c596e8  11152e88 ; lpOptional
04c596ec  00000179 ; dwOptionalLength
04c596f0  00000001
04c596f4  77583302 wininet!InternetSetOptionA
04c596f8  110f6d68
04c596fc  0000000b
04c59700  11152e88
04c59704  00000178
04c59708  00000000
04c5970c  11230fe8
04c59710  00000000
04c59714  04c59f34
04c59718  765bb32b urlmon!CINetHttp::INetAsyncOpenRequest+0×2cf
04c5971c  00cc0008
04c59720  110f6d68
04c59724  00000000
04c59728  112d2fe8
04c5972c  112d4fe8
04c59730  112d6fe0

lpszHeaders points to this string:

0:004> du 1122cd58
1122cd58  "Referer: https://www.[...XXX...].ie/o"
1122cd98  "nline/login.aspx..Accept-Languag"
1122cdd8  "e: en-ie..User-Agent: Mozilla/4."
1122ce18  "0 (compatible; MSIE 8.0; Windows"
1122ce58  " NT 6.0; Trident/4.0; MathPlayer"
1122ce98  " 2.10d; SLCC1; .NET CLR 2.0.5072"
1122ced8  "7; Media Center PC 5.0; .NET CLR"
1122cf18  " 3.5.30729; .NET CLR 3.0.30729)."
1122cf58  ".Content-Type: application/x-www"
1122cf98  "-form-urlencoded..Accept-Encodin"
1122cfd8  "g: gzip, deflate"

But lpOptional points to a string that contains the login id and password:

0:004> da 11152e88
11152e88  "__EVENTTARGET=lbtnContinue&__EVE"
11152ea8  "NTARGUMENT=&__VIEWSTATE=%2FwEPDw"
[...]
11152fc8  "u7j7pXFuOFg1%2B&txtLogin=0123456”
11152fe8  “789&txtPassword=password???????”

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

Today we introduce an icon for Corrupt Dump pattern (the motivation is that we can’t open such dumps):

B/W

Color

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

Now it’s time to divide memory analysis patterns discerned so far as mostly abnormal software behavior memory dump and software trace patterns into behavioral and structural catalogues. The goal is to account for normal system-independent structural entities and relationships visible in memory like modules, threads, processes and so on.

The first pattern (and also a super-pattern) we discuss in this part is called Memory Snapshot. It is further subdivided into Structured Memory Snapshot and BLOB Memory Snapshot. Structured sub-pattern includes:

- Contiguous memory dump files with artificially generated headers (for example, physical or process virtual space memory dump)

- Software trace messages with imposed internal structure

BLOB sub-pattern variety includes address range snapshots without any externally imposed structure, for example, saved by .writemem WinDbg command or ReadProcessMemory API and contiguous buffer and raw memory dumps saved by various memory acquisition tools.

Behavioral patterns that relate to Memory Snapshot pattern are:

• False Positive Dump
• Lateral Damage
• Inconsistent Dump
• Truncated Dump
• Early Crash Dump
• Manual Dump (kernel)
• Manual Dump (process)
• Corrupt Dump
• No Process Dumps
• No System Dumps
• Self-Dump
• Abridged Dump

I strive initially to publish at least one such pattern every day to fill the gap of normal patterns in memory analysis and later add more multi-platform details and examples from other platforms like Linux, Mac OS X, embedded and selected important historical architectures.

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

Today we introduce an icon for Wait Chain (RPC) pattern:

B/W

Color

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

100% CPU consumption was reported for one system and a complete memory dump was generated. Unfortunately, it was very inconsistent:

0: kd> !process 0 0
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
Unable to get program counter
GetContextState failed, 0xD0000147
Unable to read selector for PCR for processor 0
**** NT ACTIVE PROCESS DUMP ****
PROCESS 8b57f648  SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000
    DirBase: bffd0020  ObjectTable: e1000e10  HandleCount: 3801.
    Image: System

[...]

PROCESS 8a33fd88  SessionId: 4294963440  Cid: 1508    Peb: 7ffdb000  ParentCid: 3a74
    DirBase: bffd2760  ObjectTable: e653c110  HandleCount: 1664628019.
    Image: explorer.exe

[...]

PROCESS 87bd9d88  SessionId: 4294963440  Cid: 3088    Peb: 7ffda000  ParentCid: 1508
    DirBase: bffd23e0  ObjectTable: e4e73d30  HandleCount: 1717711416.
    Image: iexplore.exe

[...]

PROCESS 88c741a0  SessionId: 0  Cid: 46b0    Peb: 7ffd9000  ParentCid: 01f8
    DirBase: bffd2ac0  ObjectTable: e8b60c58  HandleCount: 1415935346.
    Image: csrss.exe

[...]

!process 0 ff command was looping through the same system thread forever. Fortunately !running command was functional:

0: kd> !running
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
Unable to get program counter

System Processors 3 (affinity mask)
  Idle Processors 0

Prcbs  Current   Next   
  0    ffdff120  888ab360            …………….
  1    f7727120  880d1db0            …………….

GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147

Curiously !ready command showed a different thread running on the same processor 0 before infinitely looping (it was aborted):

0: kd> !ready
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
Unable to get program counter
Processor 0: Ready Threads at priority 6
    THREAD 88fe2b30  Cid 3b8c.232c  Teb: 7ffdf000 Win32Thread: bc6b38f0 RUNNING on processor 0
TYPE mismatch for thread object at ffdffaf0
TYPE mismatch for thread object at ffdffaf0
TYPE mismatch for thread object at ffdffaf0
TYPE mismatch for thread object at ffdffaf0
TYPE mismatch for thread object at ffdffaf0
TYPE mismatch for thread object at ffdffaf0
[…]

The both “running” threads were showing signs of a spiking thread:

0: kd> !thread 88fe2b30 1f
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
Unable to get program counter
THREAD 88fe2b30  Cid 3b8c.232c  Teb: 7ffdf000 Win32Thread: bc6b38f0 RUNNING on processor 0
Not impersonating
DeviceMap                 e3899900
Owning Process            8862ead8       Image:         ApplicationA.exe
Attached Process          N/A            Image:         N/A
ffdf0000: Unable to get shared data
Wait Start TickCount      1980369     
Context Switch Count      239076                 LargeStack
UserTime                  00:01:33.187
KernelTime                00:01:49.734
Win32 Start Address 0×0066c181
Start Address 0×77e617f8
Stack Init b97bfbd0 Current b97bf85c Base b97c0000 Limit b97b9000 Call b97bfbd8
Priority 8 BasePriority 8 PriorityDecrement 0
Unable to get context for thread running on processor 0, HRESULT 0×80004002

GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002
GetContextState failed, 0x80004002

0: kd> !thread 888ab360 1f
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
Unable to get program counter
THREAD 888ab360  Cid 2a3c.4260  Teb: 7ffde000 Win32Thread: bc190570 WAIT: (Unknown) UserMode Non-Alertable
    88e4d8d8  SynchronizationEvent
Not impersonating
DeviceMap                 e62a50e0
Owning Process            8a1a5d88       Image:         ApplicationA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      1979505     
Context Switch Count      167668                 LargeStack
UserTime                  00:01:03.468
KernelTime                00:01:21.875
Win32 Start Address ApplicationA (0×0066c181)
Start Address kernel32!BaseProcessStartThunk (0×77e617f8)
Stack Init ba884000 Current ba883bac Base ba884000 Limit ba87d000 Call 0
Priority 10 BasePriority 10 PriorityDecrement 0
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
ChildEBP RetAddr 
ba883c14 bf8a1305 win32k!RGNOBJ::UpdateUserRgn+0×5d
ba883c38 bf8a2a1a win32k!xxxSendMessage+0×1b
ba883c64 bf8a2ac3 win32k!xxxUpdateWindow2+0×79
ba883c84 bf8a1a6a win32k!xxxInternalUpdateWindow+0×6f
ba883cc8 bf8a291b win32k!xxxInternalInvalidate+0×148
ba883cf4 bf858314 win32k!xxxRedrawWindow+0×103
ba883d4c 8088b41c win32k!NtUserRedrawWindow+0xac
ba883d4c 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ ba883d64)
0012fd10 7739b82a ntdll!KiFastSystemCallRet
0012fd98 78a3ed73 USER32!UserCallWinProcCheckWow+0×5c
0012fdb8 78a3f68b mfc90u!CWnd::DefWindowProcW+0×44
0012fdd4 78a3e29a mfc90u!CWnd::WindowProc+0×3b
0012fe58 78585f1a mfc90u!AfxCallWndProc+0xa3
7739ceb8 c25d008b MSVCR90!_msize+0xf8
WARNING: Frame IP not in any known module. Following frames may be wrong.
7739cec0 9090f8eb 0xc25d008b
7739cec4 8b909090 0×9090f8eb
7739cec8 ec8b55ff 0×8b909090
7739cecc e8084d8b 0xec8b55ff
7739ced0 ffffe838 0xe8084d8b
7739ced4 0374c085 0xffffe838
7739ced8 5d78408b 0×374c085
7739cedc 900004c2 0×5d78408b
7739cee0 90909090 0×900004c2
7739cee4 8b55ff8b 0×90909090
7739cee8 18a164ec 0×8b55ff8b
7739ceec 83000000 0×18a164ec
7739cef0 0f004078 0×83000000
7739cef4 fe87d484 0xf004078
7739cef8 087d83ff 0xfe87d484
7739cefc 2c830f20 0×87d83ff
7739cf00 64ffff94 0×2c830f20
7739cf04 0018158b 0×64ffff94
7739cf08 828b0000 0×18158b
7739cf0c 00000000 0×828b0000

GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147
GetContextState failed, 0xD0000147

We see that both threads belong to 2 process instances of ApplicationA.

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

Today we introduce an icon for Wait Chain (process objects) pattern:

B/W

Color

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

A page to reference all different kinds of contention is necessary, so I created this post:

• High Contention (executive resources)
• High Contention (critical sections)
• High Contention (processors)
• High Contention (.NET CLR monitors)
• Critical Region
• High Contention (.NET heap)
• High Contention (sockets)

I’ll update it as soon as I add more similar patterns.

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

Today we introduce an icon for Wait Chain (LPC/ALPC) pattern:

B/W

Color

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

Today we introduce an icon for Wait Chain (thread objects) pattern:

B/W

Color

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

Abnormal CPU consumption detection usually goes at a process level when we detect it using Task Manager, for example. Sometimes that process has only one spiking thread among many but there are cases when CPU consumption is spread among many threads. I call this pattern Distributed Spike. This behavior could be a consequence of a weak process coupling, for example, in these 2 services (where, for simplicity, I highlight in red color threads with more than 1 second CPU time spent in user mode):

0:000> !runaway
 User Mode Time
  Thread       Time
 120:4e518      0 days 0:05:09.937
 126:531bc      0 days 0:03:56.546
  44:334c      0 days 0:03:40.765
 133:4fe1c      0 days 0:03:31.156
  45:42b4      0 days 0:03:27.328
 107:25ae0      0 days 0:03:19.921
  49:627c      0 days 0:02:48.250
 147:6b90c      0 days 0:02:33.046
 136:6620c      0 days 0:02:05.109
 127:4f2d0      0 days 0:02:04.046
 129:5bc30      0 days 0:02:02.171
  48:623c      0 days 0:02:01.796
 119:41f00      0 days 0:02:00.562
  74:cd18      0 days 0:01:59.453
  51:7a4c      0 days 0:01:54.234
  35:21d4      0 days 0:01:47.390
 148:326dc      0 days 0:01:32.640
 123:43c8c      0 days 0:01:32.515
 135:67b08      0 days 0:01:32.296
  11:aa8       0 days 0:01:30.906
 118:42f8c      0 days 0:01:20.265
  42:3a3c      0 days 0:01:20.000
  77:d024      0 days 0:01:19.734
 115:3a840      0 days 0:01:15.625
  89:145f4      0 days 0:01:10.500
 157:4e310      0 days 0:01:07.625
  80:d07c      0 days 0:01:07.468
  33:1ab0      0 days 0:01:00.593
 117:10bd4      0 days 0:00:59.421
 151:1aaa0      0 days 0:00:59.015
  28:17bc      0 days 0:00:58.796
  83:f3a4      0 days 0:00:55.828
 122:41964      0 days 0:00:55.578
 149:4101c      0 days 0:00:55.234
  10:aa4       0 days 0:00:52.453
 106:21b80      0 days 0:00:51.187
 132:62e5c      0 days 0:00:49.437
 160:3a3a8      0 days 0:00:48.875
 137:6bf90      0 days 0:00:48.687
 145:6f594      0 days 0:00:47.968
 143:58d60      0 days 0:00:45.703
  72:ba64      0 days 0:00:44.515
  41:19b0      0 days 0:00:44.000
 130:5d480      0 days 0:00:43.750
 139:6d090      0 days 0:00:42.062
 138:6d578      0 days 0:00:40.406
  91:17974      0 days 0:00:40.359
 152:37f80      0 days 0:00:39.781
  81:de68      0 days 0:00:39.265
 150:65b2c      0 days 0:00:36.625
 162:1f340      0 days 0:00:35.125
  85:10650      0 days 0:00:33.546
 131:614e8      0 days 0:00:33.093
 128:2eddc      0 days 0:00:33.000
 146:6f690      0 days 0:00:32.015
 161:3c4b4      0 days 0:00:30.421
 167:3cde4      0 days 0:00:29.390
 171:3979c      0 days 0:00:28.515
 166:3cd40      0 days 0:00:28.312
 168:68ef0      0 days 0:00:27.781
  65:aad0      0 days 0:00:26.593
 109:267f4      0 days 0:00:26.390
  88:13624      0 days 0:00:26.000
 173:5282c      0 days 0:00:24.640
 153:71e14      0 days 0:00:23.390
 112:322b4      0 days 0:00:22.812
 110:9578      0 days 0:00:22.125
 175:20230      0 days 0:00:20.250
  79:b458      0 days 0:00:20.218
  66:61b8      0 days 0:00:19.875
  62:9498      0 days 0:00:19.562
 156:d900      0 days 0:00:19.015
 121:5106c      0 days 0:00:18.687
 142:6bb28      0 days 0:00:18.562
  46:2cbc      0 days 0:00:17.796
 169:d920      0 days 0:00:16.875
 154:720b4      0 days 0:00:16.484
 170:4ac8c      0 days 0:00:15.968
  73:b010      0 days 0:00:13.609
  39:3224      0 days 0:00:13.406
 172:722e4      0 days 0:00:12.375
  63:9780      0 days 0:00:12.203
 177:8464      0 days 0:00:11.906
 184:22908      0 days 0:00:10.234
 140:5765c      0 days 0:00:09.750
 174:2f484      0 days 0:00:08.390
  50:7230      0 days 0:00:07.125
 187:3c324      0 days 0:00:06.765
 125:46cf0      0 days 0:00:06.296
 178:3a424      0 days 0:00:05.125
 114:33d20      0 days 0:00:03.734
 165:3ca74      0 days 0:00:01.203
 189:3c358      0 days 0:00:01.000
 164:3124c      0 days 0:00:00.578
  25:be4       0 days 0:00:00.515
  17:ba8       0 days 0:00:00.125
 104:5cf8      0 days 0:00:00.109
  26:e4c       0 days 0:00:00.109
  96:5d44      0 days 0:00:00.093
  99:5b18      0 days 0:00:00.078
  56:8a6c      0 days 0:00:00.078
  55:8a68      0 days 0:00:00.078
   6:a08       0 days 0:00:00.078
   4:a00       0 days 0:00:00.062
 103:5cfc      0 days 0:00:00.046
 100:5ab8      0 days 0:00:00.046
  68:bf34      0 days 0:00:00.046
  37:29d4      0 days 0:00:00.046
 101:5ab4      0 days 0:00:00.031
  98:5b44      0 days 0:00:00.031
  97:5d40      0 days 0:00:00.031
  57:8a70      0 days 0:00:00.031
  53:8a60      0 days 0:00:00.031
  36:29c0      0 days 0:00:00.031
  16:ac4       0 days 0:00:00.031
   1:9e4       0 days 0:00:00.031
  60:880c      0 days 0:00:00.015
  58:8a5c      0 days 0:00:00.015
  24:be0       0 days 0:00:00.015
  15:abc       0 days 0:00:00.015
 188:13044      0 days 0:00:00.000
 186:6530      0 days 0:00:00.000
 185:2013c      0 days 0:00:00.000
 183:6047c      0 days 0:00:00.000
 182:65400      0 days 0:00:00.000
 181:61560      0 days 0:00:00.000
 180:2b7a4      0 days 0:00:00.000
 179:56294      0 days 0:00:00.000
 176:20300      0 days 0:00:00.000
 163:2ab1c      0 days 0:00:00.000
 159:276cc      0 days 0:00:00.000
 158:72134      0 days 0:00:00.000
 155:6a078      0 days 0:00:00.000
 144:6ce98      0 days 0:00:00.000
 141:5404      0 days 0:00:00.000
 134:65718      0 days 0:00:00.000
 124:4bed4      0 days 0:00:00.000
 116:3c770      0 days 0:00:00.000
 113:b08       0 days 0:00:00.000
 111:28e54      0 days 0:00:00.000
 108:25fbc      0 days 0:00:00.000
 105:20504      0 days 0:00:00.000
 102:5cf4      0 days 0:00:00.000
  95:5c70      0 days 0:00:00.000
  94:5ed4      0 days 0:00:00.000
  93:18c2c      0 days 0:00:00.000
  92:19fd8      0 days 0:00:00.000
  90:c870      0 days 0:00:00.000
  87:7994      0 days 0:00:00.000
  86:124cc      0 days 0:00:00.000
  84:eab8      0 days 0:00:00.000
  82:f2a4      0 days 0:00:00.000
  78:d5c0      0 days 0:00:00.000
  76:cfd0      0 days 0:00:00.000
  75:cf64      0 days 0:00:00.000
  71:b4f8      0 days 0:00:00.000
  70:c628      0 days 0:00:00.000
  69:c484      0 days 0:00:00.000
  67:be84      0 days 0:00:00.000
  64:aa00      0 days 0:00:00.000
  61:93f0      0 days 0:00:00.000
  59:89e4      0 days 0:00:00.000
  54:8a64      0 days 0:00:00.000
  52:89a8      0 days 0:00:00.000
  47:4c64      0 days 0:00:00.000
  43:3fa0      0 days 0:00:00.000
  40:2c88      0 days 0:00:00.000
  38:2a28      0 days 0:00:00.000
  34:1928      0 days 0:00:00.000
  32:1668      0 days 0:00:00.000
  31:8dc       0 days 0:00:00.000
  30:15d4      0 days 0:00:00.000
  29:1044      0 days 0:00:00.000
  27:fb4       0 days 0:00:00.000
  23:bd8       0 days 0:00:00.000
  22:bd4       0 days 0:00:00.000
  21:bd0       0 days 0:00:00.000
  20:bc8       0 days 0:00:00.000
  19:bc4       0 days 0:00:00.000
  18:bc0       0 days 0:00:00.000
  14:ab8       0 days 0:00:00.000
  13:ab4       0 days 0:00:00.000
  12:ab0       0 days 0:00:00.000
   9:aa0       0 days 0:00:00.000
   8:a9c       0 days 0:00:00.000
   7:a98       0 days 0:00:00.000
   5:a04       0 days 0:00:00.000
   3:9f4       0 days 0:00:00.000
   2:9f0       0 days 0:00:00.000
   0:994       0 days 0:00:00.000

This is a real spike in the first service process as can be confirmed by a random non-waiting thread:

0:000> ~143k
ChildEBP RetAddr 
050dfc68 7c82d6a4 ntdll!RtlEnterCriticalSection+0x1d
050dfc84 77c7bc50 ntdll!RtlInitializeCriticalSectionAndSpinCount+0x92
050dfc98 77c7bc7c rpcrt4!MUTEX::CommonConstructor+0x1b
050dfcac 77c7c000 rpcrt4!MUTEX::MUTEX+0x13
050dfcc8 77c6ff47 rpcrt4!BINDING_HANDLE::BINDING_HANDLE+0x2d
050dfcd8 77c6ff1f rpcrt4!SVR_BINDING_HANDLE::SVR_BINDING_HANDLE+0x10
050dfcfc 77c6d338 rpcrt4!RPC_ADDRESS::InquireBinding+0x8a
050dfd0c 77c6fd1d rpcrt4!LRPC_SCALL::ToStringBinding+0x16
050dfd1c 76554c83 rpcrt4!RpcBindingToStringBindingW+0x4d
050dfd5c 77c7c42a ServiceA!RpcSecurityCallback+0x1e
050dfdb4 77c7c4b0 rpcrt4!RPC_INTERFACE::CheckSecurityIfNecessary+0x6f
050dfdcc 77c7c46c rpcrt4!LRPC_SBINDING::CheckSecurity+0x4f
050dfdfc 77c812f0 rpcrt4!LRPC_SCALL::DealWithRequestMessage+0x2bb
050dfe20 77c88678 rpcrt4!LRPC_ADDRESS::DealWithLRPCRequest+0x127
050dff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x430
050dff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd
050dffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d
050dffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b
050dffec 00000000 kernel32!BaseThreadStart+0x34

0:000> ~143r
eax=00000000 ebx=00000000 ecx=7c887784 edx=7c887780 esi=7c887784 edi=00163fb0
eip=7c81a37d esp=050dfc5c ebp=050dfc68 iopl=0 nv up ei ng nz na pe cy
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000287
ntdll!RtlEnterCriticalSection+0x1d:
7c81a37d 0f92c0          setb    al

0:000> .asm no_code_bytes
Assembly options: no_code_bytes

0:000> u 7c81a37d
ntdll!RtlEnterCriticalSection+0x1d:
7c81a37d setb    al
7c81a380 test    al,al
7c81a382 je      ntdll!RtlEnterCriticalSection+0x28 (7c82b096)
7c81a388 mov     ecx,dword ptr fs:[18h]
7c81a38f mov     eax,dword ptr [ecx+24h]
7c81a392 pop     edi
7c81a393 mov     dword ptr [edx+0Ch],eax
7c81a396 mov     dword ptr [edx+8],1

0:000> ub 7c81a37d
ntdll!RtlEnterCriticalSection+0x6:
7c81a366 mov     edx,dword ptr [ebp+8]
7c81a369 push    esi
7c81a36a lea     esi,[edx+4]
7c81a36d push    edi
7c81a36e mov     dword ptr [ebp-4],esi
7c81a371 mov     eax,0
7c81a376 mov     ecx,dword ptr [ebp-4]
7c81a379 lock btr dword ptr [ecx],eax

The second service is weakly (waiting for event notifications) coupled to the first service above:

0:000> !runaway
 User Mode Time
  Thread       Time
   5:dbec      0 days 0:01:50.031
   8:46008      0 days 0:01:46.062
  11:ad0c      0 days 0:01:13.921
  17:932c      0 days 0:01:03.234
  14:45d78      0 days 0:00:58.109
  15:6d4d0      0 days 0:00:00.015
   2:725a4      0 days 0:00:00.015
   0:6101c      0 days 0:00:00.015
  18:d1c4      0 days 0:00:00.000
  16:76bc      0 days 0:00:00.000
  13:456a8      0 days 0:00:00.000
  12:459e4      0 days 0:00:00.000
  10:3c768      0 days 0:00:00.000
   9:12d20      0 days 0:00:00.000
   7:46010      0 days 0:00:00.000
   6:4600c      0 days 0:00:00.000
   4:dbf0      0 days 0:00:00.000
   3:17ed4      0 days 0:00:00.000
   1:61024      0 days 0:00:00.000

0:000> ~11k
ChildEBP RetAddr 
0223fa68 7c82787b ntdll!KiFastSystemCallRet
0223fa6c 77c80a6e ntdll!NtRequestWaitReplyPort+0xc
0223fab8 77c7fcf0 rpcrt4!LRPC_CCALL::SendReceive+0x230
0223fac4 77c80673 rpcrt4!I_RpcSendReceive+0x24
0223fad8 77ce315a rpcrt4!NdrSendReceive+0x2b
0223fec0 771f4fbd rpcrt4!NdrClientCall2+0x22e
0223fed8 771f4f60 ServiceB!RpcWaitEvent+0x1c
[...]

0:000> ~17k
ChildEBP RetAddr 
0283fa68 7c82787b ntdll!KiFastSystemCallRet
0283fa6c 77c80a6e ntdll!NtRequestWaitReplyPort+0xc
0283fab8 77c7fcf0 rpcrt4!LRPC_CCALL::SendReceive+0x230
0283fac4 77c80673 rpcrt4!I_RpcSendReceive+0x24
0283fad8 77ce315a rpcrt4!NdrSendReceive+0x2b
0283fec0 771f4fbd rpcrt4!NdrClientCall2+0x22e
0283fed8 771f4f60 ServiceB!RpcWaitEvent+0x1c
[...]

Sometimes, semantic process coupling also results in distributed spikes and most often it is possible to predict another spiking process in such cases. In our example above both spiking processes were semantically coupled with another service and it was confirmed that it was spiking too:

0:000> !runaway
 User Mode Time
  Thread       Time
  89:10d4      0 days 0:03:03.500
  28:a94       0 days 0:00:39.562
  73:c10       0 days 0:00:37.531
  54:b88       0 days 0:00:37.140
  29:a98       0 days 0:00:35.906
  27:a90       0 days 0:00:35.500
  75:c2c       0 days 0:00:28.812
  90:10d8      0 days 0:00:27.000
  93:10e4      0 days 0:00:24.265
  32:aa4       0 days 0:00:12.906
  41:ac8       0 days 0:00:11.890
  35:ab0       0 days 0:00:11.875
  58:bc4       0 days 0:00:10.218
  42:acc       0 days 0:00:09.546
  85:e74       0 days 0:00:08.859
  36:ab4       0 days 0:00:08.578
  72:c0c       0 days 0:00:05.890
  70:c04       0 days 0:00:05.687
  33:aa8       0 days 0:00:05.046
  74:c14       0 days 0:00:04.953
  40:ac4       0 days 0:00:04.953
  38:abc       0 days 0:00:04.359
  39:ac0       0 days 0:00:04.312
  34:aac       0 days 0:00:04.140
  64:bec       0 days 0:00:03.812
  88:10d0      0 days 0:00:03.187
  30:a9c       0 days 0:00:02.859
   9:a10       0 days 0:00:01.968
  37:ab8       0 days 0:00:01.953
  92:10e0      0 days 0:00:01.718
  83:d00       0 days 0:00:01.125
  94:1150      0 days 0:00:01.031
  77:c54       0 days 0:00:00.890
  98:f2c0      0 days 0:00:00.265
  97:eb1c      0 days 0:00:00.265
  76:c50       0 days 0:00:00.265
  21:a48       0 days 0:00:00.187
  22:a4c       0 days 0:00:00.140
  63:be8       0 days 0:00:00.093
  23:a50       0 days 0:00:00.093
  53:af8       0 days 0:00:00.078
  24:a54       0 days 0:00:00.046
  71:c08       0 days 0:00:00.031
  65:bf0       0 days 0:00:00.031
  87:e8c       0 days 0:00:00.015
  57:bc0       0 days 0:00:00.015
 104:6454c      0 days 0:00:00.000
 103:63fb4      0 days 0:00:00.000
 102:3c5ec      0 days 0:00:00.000
 101:65178      0 days 0:00:00.000
 100:5d0e4      0 days 0:00:00.000
  99:5bae4      0 days 0:00:00.000
  96:574       0 days 0:00:00.000
  95:b84       0 days 0:00:00.000
  91:10dc      0 days 0:00:00.000
  86:e88       0 days 0:00:00.000
  84:e70       0 days 0:00:00.000
  82:c84       0 days 0:00:00.000
  81:c68       0 days 0:00:00.000
  80:c64       0 days 0:00:00.000
  79:c60       0 days 0:00:00.000
  78:c5c       0 days 0:00:00.000
  69:c00       0 days 0:00:00.000
  68:bfc       0 days 0:00:00.000
  67:bf8       0 days 0:00:00.000
  66:bf4       0 days 0:00:00.000
  62:bd8       0 days 0:00:00.000
  61:bd4       0 days 0:00:00.000
  60:bd0       0 days 0:00:00.000
  59:bcc       0 days 0:00:00.000
  56:bbc       0 days 0:00:00.000
  55:bb8       0 days 0:00:00.000
  52:af4       0 days 0:00:00.000
  51:af0       0 days 0:00:00.000
  50:aec       0 days 0:00:00.000
  49:ae8       0 days 0:00:00.000
  48:ae4       0 days 0:00:00.000
  47:ae0       0 days 0:00:00.000
  46:adc       0 days 0:00:00.000
  45:ad8       0 days 0:00:00.000
  44:ad4       0 days 0:00:00.000
  43:ad0       0 days 0:00:00.000
  31:aa0       0 days 0:00:00.000
  26:a8c       0 days 0:00:00.000
  25:a64       0 days 0:00:00.000
  20:a44       0 days 0:00:00.000
  19:a40       0 days 0:00:00.000
  18:a34       0 days 0:00:00.000
  17:a30       0 days 0:00:00.000
  16:a2c       0 days 0:00:00.000
  15:a28       0 days 0:00:00.000
  14:a24       0 days 0:00:00.000
  13:a20       0 days 0:00:00.000
  12:a1c       0 days 0:00:00.000
  11:a18       0 days 0:00:00.000
  10:a14       0 days 0:00:00.000
   8:a0c       0 days 0:00:00.000
   7:a08       0 days 0:00:00.000
   6:a04       0 days 0:00:00.000
   5:a00       0 days 0:00:00.000
   4:9fc       0 days 0:00:00.000
   3:9f8       0 days 0:00:00.000
   2:9f4       0 days 0:00:00.000
   1:9f0       0 days 0:00:00.000
   0:9e4       0 days 0:00:00.000 

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

A complete memory dump was generated from a totally unresponsive frozen system. Looking at its virtual memory stats we see the shortage of nonpaged pool (insufficient kernel pool memory pattern):

0: kd> !vm

*** Virtual Memory Usage ***
 Physical Memory:     1047977 (   4191908 Kb)
 Page File: \??\C:\pagefile.sys
   Current:   4195328 Kb  Free Space:   4167696 Kb
   Minimum:   4195328 Kb  Maximum:      4195328 Kb
 Page File: \??\E:\pagefile.sys
   Current:   8372224 Kb  Free Space:   8348916 Kb
   Minimum:   8372224 Kb  Maximum:      8388608 Kb
 Available Pages:      855939 (   3423756 Kb)
 ResAvail Pages:       958559 (   3834236 Kb)
 Locked IO Pages:         100 (       400 Kb)
 Free System PTEs:     200627 (    802508 Kb)
 Free NP PTEs:              0 (         0 Kb)
 Free Special NP:      120925 (    483700 Kb)
 Modified Pages:           52 (       208 Kb)
 Modified PF Pages:        52 (       208 Kb)
 NonPagedPool Usage:    65199 (    260796 Kb)
 NonPagedPool Max:      65536 (    262144 Kb)
 ********** Excessive NonPaged Pool Usage *****
 PagedPool 0 Usage:      7731 (     30924 Kb)
 PagedPool 1 Usage:      6334 (     25336 Kb)
 PagedPool 2 Usage:      6316 (     25264 Kb)
 PagedPool 3 Usage:      6333 (     25332 Kb)
 PagedPool 4 Usage:      6318 (     25272 Kb)
 PagedPool Usage:       33032 (    132128 Kb)
 PagedPool Maximum:     66560 (    266240 Kb)

 ********** 7041316 pool allocations have failed **********

 Session Commit:         2860 (     11440 Kb)
 Shared Commit:          3904 (     15616 Kb)
 Special Pool:            255 (      1020 Kb)
 Shared Process:         9336 (     37344 Kb)
 PagedPool Commit:      33032 (    132128 Kb)
 Driver Commit:          2147 (      8588 Kb)
 Committed pages:      174724 (    698896 Kb)
 Commit limit:        4148057 (  16592228 Kb)

Dumping sorted pool consumers we see the most used were DRV* pool tags:

0: kd> !poolused 3
   Sorting by  NonPaged Pool Consumed

  Pool Used:
            NonPaged                    
 Tag    Allocs    Frees     Diff     Used 
 DRV2 21683882 21280457   403425 80685000 UNKNOWN pooltag ‘DRV2′, please update pooltag.txt
 DRV4 46621052 46217627   403425 54156728 UNKNOWN pooltag ‘DRV4′, please update pooltag.txt
 DRV5 37848660 37065132   783528 31341120 UNKNOWN pooltag ‘DRV5′, please update pooltag.txt
 MmCm    15754    14607     1147 24917536 Calls made to MmAllocateContiguousMemory , Binary: nt!mm
 DRV3 16189418 15785993   403425 19364400 UNKNOWN pooltag ‘DRV3′, please update pooltag.txt
[…]

We also check CPU consumption and see two spiking threads:

0: kd> !running

System Processors f (affinity mask)
  Idle Processors 9

Prcbs  Current   Next   
  1    f7727120  87c5ca48            …………….
  2    f772f120  881ccae0            …………….

We see the first thread spent much more kernel time and stack trace involved DriverA module:

0: kd> !thread 87c5ca48 1f
THREAD 87c5ca48  Cid 0ba0.0bc8  Teb: 7ffd7000 Win32Thread: 00000000 RUNNING on processor 1
Not impersonating
DeviceMap                 e10028f0
Owning Process            87c3a978       Image:         ApplicationB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      4516745        Ticks: 2 (0:00:00:00.031)
Context Switch Count      2234544            
UserTime                  00:00:58.500
KernelTime                00:55:09.218
Win32 Start Address ApplicationB (0×402016bd)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b8771000 Current b87708b4 Base b8771000 Limit b876e000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 1
ChildEBP RetAddr 
b8770bd0 80892b6f nt!ExFreePoolWithTag+0xb7
b8770be0 80933bcd nt!ExFreePool+0xf
b8770c0c 808bb471 nt!ObOpenObjectByName+0×163
b8770cf8 b951f08e nt!NtOpenKey+0×1ad
WARNING: Stack unwind information not available. Following frames may be wrong.
b8770d50 808897cc DriverA+0×1608e
b8770d50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ b8770d64)
00c0f0b4 7c827369 ntdll!KiFastSystemCallRet
00c0f0b8 7d206cb1 ntdll!ZwOpenKey+0xc
00c0f118 7d1fe187 ADVAPI32!LocalBaseRegOpenKey+0xd0
00c0f14c 40202284 ADVAPI32!RegOpenKeyExA+0×11c
[…]
00c0ffb8 77e6482f ApplicationB+0×1891
00c0ffec 00000000 kernel32!BaseThreadStart+0×34

0: kd> !thread 881ccae0 1f
THREAD 881ccae0  Cid 05b8.05c4  Teb: 7ffde000 Win32Thread: 00000000 RUNNING on processor 2
Not impersonating
DeviceMap                 e10028f0
Owning Process            881cf020       Image:         ApplicationC.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      4516747        Ticks: 0
Context Switch Count      115916            
UserTime                  00:00:03.468
KernelTime                00:00:53.156
Win32 Start Address ADVAPI32!ScSvcctrlThreadA (0×7d1f5e70)
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init b900d000 Current b900cc50 Base b900d000 Limit b900a000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
005bf9c4 7d1eef7e ADVAPI32!LocalBaseRegEnumKey+0×2
005bfc24 010091c9 ADVAPI32!RegEnumKeyExA+0×12f
WARNING: Stack unwind information not available. Following frames may be wrong.
005bfc74 0100a28c ApplicationC+0×91c9
[…]
005bffb8 77e6482f ApplicationC+0×8b13
005bffec 00000000 kernel32!BaseThreadStart+0×34

We check the pool entry it was freeing:

0: kd> .thread /r /p 87c5ca48
Implicit thread is now 87c5ca48
Implicit process is now 87c3a978
Loading User Symbols

0: kd> kv L1
ChildEBP RetAddr  Args to Child             
b8770bd0 80892b6f 8ab6b3c8 00000000 b8770c0c nt!ExFreePoolWithTag+0xb7

0: kd> !pool 8ab6b3c8
Pool page 8ab6b3c8 region is Nonpaged pool
 8ab6b000 size:   c8 previous size:    0  (Allocated)  DRV2
 8ab6b0c8 size:   70 previous size:   c8  (Allocated)  MmCa
 8ab6b138 size:   10 previous size:   70  (Free)       DRV2
 8ab6b148 size:   30 previous size:   10  (Allocated)  DRV3
 8ab6b178 size:   30 previous size:   30  (Allocated)  DRV3
 8ab6b1a8 size:   28 previous size:   30  (Allocated)  NtFs
 8ab6b1d0 size:   30 previous size:   28  (Allocated)  DRV3
 8ab6b200 size:   18 previous size:   30  (Free)       IrpC
 8ab6b218 size:   a8 previous size:   18  (Allocated)  File (Protected)
 8ab6b2c0 size:  100 previous size:   a8  (Allocated)  MmCi
*8ab6b3c0 size:   38 previous size:  100  (Allocated) *ObCi
  Pooltag ObCi : captured information for ObCreateObject, Binary : nt!ob
 8ab6b3f8 size:   48 previous size:   38  (Allocated)  DRV2
 8ab6b440 size:    8 previous size:   48  (Free)       DRV4
 8ab6b448 size:   28 previous size:    8  (Allocated)  NtFs
 8ab6b470 size:    8 previous size:   28  (Free)       Mdl
 8ab6b478 size:   60 previous size:    8  (Allocated)  DRV4
 8ab6b4d8 size:   c8 previous size:   60  (Allocated)  DRV2
 8ab6b5a0 size:   a8 previous size:   c8  (Allocated)  File (Protected)
 8ab6b648 size:   c8 previous size:   a8  (Allocated)  DRV2
 8ab6b710 size:   c8 previous size:   c8  (Allocated)  DRV2
 8ab6b7d8 size:   10 previous size:   c8  (Free)       File
 8ab6b7e8 size:   98 previous size:   10  (Allocated)  DRV4
 8ab6b880 size:   30 previous size:   98  (Allocated)  DRV3
 8ab6b8b0 size:   28 previous size:   30  (Allocated)  NtFs
 8ab6b8d8 size:   28 previous size:   28  (Allocated)  DRV5
 8ab6b900 size:   30 previous size:   28  (Allocated)  DRV3
 8ab6b930 size:   a8 previous size:   30  (Allocated)  File (Protected)
 8ab6b9d8 size:  100 previous size:   a8  (Allocated)  MmCi
 8ab6bad8 size:   10 previous size:  100  (Free)       ObCi
[…]

In the output above we see all clustering of DRV* pool tags and check their contents:

0: kd> dps 8ab6b000
8ab6b000  0a190000
[…]
8ab6b06c  b95349a0 DriverA+0×2b9a0
8ab6b070  87cb85c8
8ab6b074  002d0000
8ab6b078  8ab6b078
8ab6b07c  8ab6b078

0: kd> dps 8ab6b8d8
8ab6b8d8  0a050005
[…]
8ab6b8f8  b95349a0 DriverA+0×2b9a0
8ab6b8fc  00000074
[…]

It looks like all DRV* pool entries have symbolic references in the range of DriverA (data contents locality):

0: kd> lm m DriverA
start    end        module name
b9509000 b9537f00   DriverA       (no symbols)

So the conclusion was to refer to DriverA vendor for any updates.

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

Today we introduce an icon for Wait Chain (executive resources) pattern:

B/W

Color

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

In addition to LPC / ALPC wait chains we can also see RPC chains in complete memory dumps and even mixed (A)LPC / RPC chains. How to distinguish RPC from (A)LPC (and RPC over LPC) threads? Here’s a fragment from an RPC over LPC thread (they also have “waiting for …” or “working on …” strings in THREAD output):

f50e4c20 80833491 nt!KiSwapContext+0x26
f50e4c4c 80829a82 nt!KiSwapThread+0x2e5
f50e4c94 8091ecf2 nt!KeWaitForSingleObject+0x346
f50e4d50 808897cc nt!NtRequestWaitReplyPort+0×776
f50e4d50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f50e4d64)
00e5f2b8 7c827899 ntdll!KiFastSystemCallRet
00e5f2bc 77c80a6e ntdll!ZwRequestWaitReplyPort+0xc
00e5f308 77c7fcf0 RPCRT4!LRPC_CCALL::SendReceive+0×230
00e5f314 77c80673 RPCRT4!I_RpcSendReceive+0×24
00e5f328 77ce315a RPCRT4!NdrSendReceive+0×2b
00e5f710 771f40c4 RPCRT4!NdrClientCall2+0×22e

Here’s the thread stack of an RPC waiting thread (the connection was over a pipe):

THREAD 8a4b7320  Cid 0208.0220  Teb: 7ffa4000 Win32Thread: bc3eaea8 WAIT: (Unknown) UserMode Non-Alertable
        8bc379f8  NotificationEvent
IRP List:
        891879a8: (0006,0094) Flags: 00000800  Mdl: 00000000
Not impersonating
DeviceMap                 e1002270
Owning Process            8a5c8828       Image:         ApplicationA.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      3044574        Ticks: 37746 (0:00:09:49.781)
Context Switch Count      54673                 LargeStack
UserTime                  00:00:00.015
KernelTime                00:00:00.046
Win32 Start Address MSVCR90!_threadstartex (0x7854345e)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f473b000 Current f473ac60 Base f473b000 Limit f4737000 Call 0
Priority 11 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
f473ac78 80833491 nt!KiSwapContext+0x26
f473aca4 80829a82 nt!KiSwapThread+0x2e5
f473acec 80938dea nt!KeWaitForSingleObject+0x346
f473ad50 808897cc nt!NtWaitForSingleObject+0x9a
f473ad50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f473ad64)
0155f0f4 7c827d29 ntdll!KiFastSystemCallRet
0155f0f8 77e61d1e ntdll!ZwWaitForSingleObject+0xc
0155f168 77c6a85f kernel32!WaitForSingleObjectEx+0xac
0155f184 77c69bf7 RPCRT4!UTIL_WaitForSyncIO+0×20
0155f1a8 77c6a935 RPCRT4!UTIL_GetOverlappedResultEx+0×1d
0155f1c4 77c6a8f3 RPCRT4!UTIL_GetOverlappedResult+0×17
0155f1e4 77c6944f RPCRT4!NMP_SyncSendRecv+0×73
0155f20c 77c69667 RPCRT4!OSF_CCONNECTION::TransSendReceive+0×7d
0155f294 77c695d4 RPCRT4!OSF_CCONNECTION::SendFragment+0×2ae
0155f2ec 77c6977a RPCRT4!OSF_CCALL::SendNextFragment+0×1e2
0155f334 77c699f2 RPCRT4!OSF_CCALL::FastSendReceive+0×148
0155f350 77c69975 RPCRT4!OSF_CCALL::SendReceiveHelper+0×5b
0155f380 77c7fcf0 RPCRT4!OSF_CCALL::SendReceive+0×41
0155f38c 77c80673 RPCRT4!I_RpcSendReceive+0×24
0155f3a0 77ce315a RPCRT4!NdrSendReceive+0×2b
0155f788 7d1fa0b1 RPCRT4!NdrClientCall2+0×22e
[…]
0155ffac 785434c7 MSVCR90!_callthreadstartex+0×1b
0155ffb8 77e6482f MSVCR90!_threadstartex+0×69
0155ffec 00000000 kernel32!BaseThreadStart+0×34

Here’s the endpoint thread stack in the RPC service processing the client call:

THREAD 8a631d80  Cid 0244.0290  Teb: 7ffd4000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    8a6354d8  SynchronizationEvent
IRP List:
    882d0008: (0006,0094) Flags: 00000900  Mdl: 00000000
    8811c450: (0006,0094) Flags: 00000900  Mdl: 00000000
    8a4d1b28: (0006,0190) Flags: 00000000  Mdl: 8a4d2e40
    8a634188: (0006,0094) Flags: 00000800  Mdl: 00000000
Not impersonating
DeviceMap                 e1002270
Owning Process            8a5b3ac8       Image:         ServiceB.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      3041752        Ticks: 40568 (0:00:10:33.875)
Context Switch Count      36194            
UserTime                  00:00:00.562
KernelTime                00:00:01.093
Win32 Start Address RPCRT4!ThreadStartRoutine (0x77c7b0f5)
Start Address kernel32!BaseThreadStartThunk (0x77e617ec)
Stack Init f5f3e000 Current f5f3dc60 Base f5f3e000 Limit f5f3b000 Call 0
Priority 12 BasePriority 10 PriorityDecrement 0
ChildEBP RetAddr 
f5f3dc78 80833491 nt!KiSwapContext+0x26
f5f3dca4 80829a82 nt!KiSwapThread+0x2e5
f5f3dcec 80938dea nt!KeWaitForSingleObject+0x346
f5f3dd50 808897cc nt!NtWaitForSingleObject+0x9a
f5f3dd50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f5f3dd64)
00def83c 7c827d29 ntdll!KiFastSystemCallRet
00def840 7c83d266 ntdll!ZwWaitForSingleObject+0xc
00def87c 7c83d2b1 ntdll!RtlpWaitOnCriticalSection+0×1a3
00def89c 4ab773ea ntdll!RtlEnterCriticalSection+0xa8
00def8ac 4ab78726 ServiceB!AcquireLock+0×7c
[…]
00def944 77ce33e1 RPCRT4!Invoke+0×30
00defd44 77ce35c4 RPCRT4!NdrStubCall2+0×299
00defd60 77c7ff7a RPCRT4!NdrServerCall2+0×19
00defd94 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
00defde8 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
00defe0c 77c68e0d RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
00defe40 77c68cb3 RPCRT4!OSF_SCALL::DispatchHelper+0×149
00defe54 77c68c2b RPCRT4!OSF_SCALL::DispatchRPCCall+0×10d
00defe84 77c68b5e RPCRT4!OSF_SCALL::ProcessReceivedPDU+0×57f
00defea4 77c6e8db RPCRT4!OSF_SCALL::BeginRpcCall+0×194
00deff04 77c6e7b4 RPCRT4!OSF_SCONNECTION::ProcessReceiveComplete+0×435
00deff18 77c7b799 RPCRT4!ProcessConnectionServerReceivedEvent+0×21
00deff84 77c7b9b5 RPCRT4!LOADABLE_TRANSPORT::ProcessIOEvents+0×1b8
00deff8c 77c8872d RPCRT4!ProcessIOEventsWrapper+0xd
00deffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
00deffb8 77e6482f RPCRT4!ThreadStartRoutine+0×1b
00deffec 00000000 kernel32!BaseThreadStart+0×34

We also see that the latter thread is waiting for a critical section so we have an example of a mixed wait chain here as well. Another example is an RPC over LPC server thread that is also an RPC client thread:

THREAD 8989f020  Cid 0170.1cfc  Teb: 7ff8c000 Win32Thread: 00000000 WAIT: (Unknown) UserMode Non-Alertable
    89a1c368  NotificationEvent
IRP List:
    887aac68: (0006,0094) Flags: 00000800  Mdl: 00000000
Not impersonating
DeviceMap                 e1002270
Owning Process            8a056b80       Image:         ServiceC.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      3075354        Ticks: 6966 (0:00:01:48.843)
Context Switch Count      2521            
UserTime                  00:00:00.031
KernelTime                00:00:00.015
Win32 Start Address 0x00750d91
LPC Server thread working on message Id 750d91
Start Address kernel32!BaseThreadStartThunk (0×77e617ec)
Stack Init f26da000 Current f26d9c60 Base f26da000 Limit f26d7000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr 
f26d9c78 80833491 nt!KiSwapContext+0×26
f26d9ca4 80829a82 nt!KiSwapThread+0×2e5
f26d9cec 80938dea nt!KeWaitForSingleObject+0×346
f26d9d50 808897cc nt!NtWaitForSingleObject+0×9a
f26d9d50 7c82860c nt!KiFastCallEntry+0xfc (TrapFrame @ f26d9d64)
03e9efa8 7c827d29 ntdll!KiFastSystemCallRet
03e9efac 77e61d1e ntdll!ZwWaitForSingleObject+0xc
03e9f01c 77c6a85f kernel32!WaitForSingleObjectEx+0xac
03e9f038 77c69bf7 RPCRT4!UTIL_WaitForSyncIO+0×20
03e9f05c 77c6a935 RPCRT4!UTIL_GetOverlappedResultEx+0×1d
03e9f078 77c6a8f3 RPCRT4!UTIL_GetOverlappedResult+0×17
03e9f098 77c6944f RPCRT4!NMP_SyncSendRecv+0×73
03e9f0c0 77c69667 RPCRT4!OSF_CCONNECTION::TransSendReceive+0×7d
03e9f148 77c695d4 RPCRT4!OSF_CCONNECTION::SendFragment+0×2ae
03e9f1a0 77c6977a RPCRT4!OSF_CCALL::SendNextFragment+0×1e2
03e9f1f8 77c699f2 RPCRT4!OSF_CCALL::FastSendReceive+0×148
03e9f214 77c69975 RPCRT4!OSF_CCALL::SendReceiveHelper+0×5b
03e9f244 77c7fcf0 RPCRT4!OSF_CCALL::SendReceive+0×41
03e9f250 77c80673 RPCRT4!I_RpcSendReceive+0×24
03e9f264 77ce315a RPCRT4!NdrSendReceive+0×2b
03e9f64c 7d1fa0b1 RPCRT4!NdrClientCall2+0×22e
03e9f8ac 7654fa50 ServiceC!QueryInformation+0×801
[…]
03e9f8f8 77ce33e1 RPCRT4!Invoke+0×30
03e9fcf8 77ce35c4 RPCRT4!NdrStubCall2+0×299
03e9fd14 77c7ff7a RPCRT4!NdrServerCall2+0×19
03e9fd48 77c8042d RPCRT4!DispatchToStubInCNoAvrf+0×38
03e9fd9c 77c80353 RPCRT4!RPC_INTERFACE::DispatchToStubWorker+0×11f
03e9fdc0 77c811dc RPCRT4!RPC_INTERFACE::DispatchToStub+0xa3
03e9fdfc 77c812f0 RPCRT4!LRPC_SCALL::DealWithRequestMessage+0×42c
03e9fe20 77c88678 RPCRT4!LRPC_ADDRESS::DealWithLRPCRequest+0×127
03e9ff84 77c88792 RPCRT4!LRPC_ADDRESS::ReceiveLotsaCalls+0×430
03e9ff8c 77c8872d RPCRT4!RecvLotsaCallsWrapper+0xd
03e9ffac 77c7b110 RPCRT4!BaseCachedThreadRoutine+0×9d
03e9ffb8 77e6482f RPCRT4!ThreadStartRoutine+0×1b
03e9ffec 00000000 kernel32!BaseThreadStart+0×34

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

Today we introduce an icon for Wait Chain (critical sections) pattern:

B/W

Color

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

Today we introduce an icon for Wait Chain (general) pattern:

B/W

Color

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

Today we introduce an icon for Manual Dump (process) pattern:

B/W

Color

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

This forthcoming full color book is the complete transcript of a Webinar organized by Memory Dump Analysis Services (www.DumpAnalysis.com).

It discusses user vs. kernel vs. physical (complete) memory space, challenges of complete memory dump analysis, common WinDbg commands, patterns and pattern-driven analysis methodology, common mistakes, fiber bundles, DumpAnalysis.org case studies and illustrates step by step a hands-on exercise in a complete memory dump analysis.

• Title: Fundamentals of Complete Crash and Hang Memory Dump Analysis
• Author: Dmitry Vostokov
• Publisher: OpenTask (October 2010)
• Language: English
• Product Dimensions: 28.0 x 21.6
• Paperback: 48 pages
• ISBN-13: 978-1906717155

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

Today we introduce an icon for Manual Dump (kernel) pattern:

B/W

Color

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

If you attended Fundamentals of Complete Crash and Hang Memory Dump Analysis you probably remember the memory dump visualization question that I repeat here on this slide fragment:

I got a few responses:

“Unfortunately they are not identical - visual inspection shows that. I tried differencing the relevant sub-images in Photoshop and I can’t get zero.  Of course this can be due to compression artifacts and, more likely, the fact that the duplication is not required to be aligned to the borders. A stronger confirmation/refutation would require unrolling the bitmap to one dimension and sliding it back and forth until maximum correlation is found. Since I have not done the examples step by step, I am left guessing about just what the dump you show illustrates. An aliased memory mapped area is my first guess, and a flip/flop garbage collector is my second.”

“perhaps some module such as a .NET assembly is getting loaded twice in a .NET app, pre .NET 4, such as is dicsussed in this thread:
http://forum.sysinternals.com/why-some-net-assemblies-are-duplicated-in-memory_topic15279_post121591.html“

Initially I also thought that there was the same module loaded twice from different location like in Duplicated Module pattern. Unfortunately lm command didn’t show any duplicated loaded and unloaded modules as well as any hidden modules. So I looked at address information and found two identical relatively large regions at the beginning:

0:000> !address
[...]
BaseAddress EndAddress+1 RegionSize Type       State      Protect       Usage
[...]
0`00470000  0`007f0000   0`00380000 MEM_MAPPED MEM_COMMIT PAGE_READONLY <unclassified>
[…]
0`01f10000  0`02290000   0`00380000 MEM_MAPPED MEM_COMMIT PAGE_READONLY <unclassified>
[…]

The image above was scaled by ImageMagic from a bitmap generated by Dump2Picture:

The original image from Dump2Picture had different colors:

I quickly checked the colorimetric structure of those regions: 0`00470000  0`007f0000 and 0`01f10000  0`02290000 using MemPicture WinDbg script and they seem to conform with the magnified picture above:

0:000> $$>a< d:\Dump2Picture\mempicture.txt 0`00470000 L?0`007f0000-0`00470000
Writing 380000 bytes

C:\Program Files\Debugging Tools for Windows (x64)>dump2picture d2p-range.bin d2p-range.bmp

Dump2Picture version 1.1
Written by Dmitry Vostokov, 2007

d2p-range.bmp
d2p-range.bin
        1 file(s) copied.

C:\Program Files\Debugging Tools for Windows (x64)>d2p-range.bmp
.shell: Process exited

Here is the magnified slice from the original picture:

We see the same partitioning if we juxtapose the original picture and the picture of the address region:

Also these regions are completely identical if we compare their data:

0:000> c 0`00470000 L?(0`007f0000-0`00470000)/8 0`01f10000

So it looks like some file was mapped twice. Inspected via dc command it shows remarkable regularity not seen in executable modules. This regularity also manifests itself in color:

In order to verify I modeled this by writing a simple program that maps a file twice passed as a command line parameter:

int _tmain(int argc, _TCHAR* argv[])
{
 if (argc < 2)
 {
  puts("Usage: MappedFiles.exe <File_Name_To_Map>\n");
  return -1;
 }

 HANDLE hf = CreateFile(argv[1], GENERIC_READ, FILE_SHARE_READ, NULL, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL, NULL);
 HANDLE hm = CreateFileMapping(hf, NULL, PAGE_READONLY, 0, 0, NULL);
 MapViewOfFile(hm, FILE_MAP_READ, 0, 0, 0);

 hf = CreateFile(argv[1], GENERIC_READ, FILE_SHARE_READ, NULL, OPEN_EXISTING, FILE_ATTRIBUTE_NORMAL, NULL);
 hm = CreateFileMapping(hf, NULL, PAGE_READONLY, 0, 0, NULL);
 MapViewOfFile(hm, FILE_MAP_READ, 0, 0, 0);

 DebugBreak();
 return 0;
}

I ran it and chose to map explorer.exe because it was a sufficiently large image file:

C:\MappedFiles\Release>MappedFiles.exe c:\windows\explorer.exe

The dump file was saved and its processing shows this picture:

We clearly see identical regions and double check them from the dump file:

0:000> !address
BaseAddr EndAddr+1 RgnSize Type       State         Protect       Usage
[...]
a60000   d1d000    2bd000  MEM_MAPPED MEM_COMMIT    PAGE_READONLY <unclassified>
d1d000   d20000    3000    MEM_FREE   PAGE_NOACCESS Free
d20000   fdd000    2bd000  MEM_MAPPED MEM_COMMIT    PAGE_READONLY <unclassified>
[…] 

0:000> $$>a< d:\Dump2Picture\mempicture.txt 0`00470000 L?0`007f0000-0`00470000
Writing 380000 bytes

C:\Program Files\Debugging Tools for Windows (x64)>dump2picture d2p-range.bin d2p-range.bmp 

Dump2Picture version 1.1
Written by Dmitry Vostokov, 2007

d2p-range.bmp
d2p-range.bin
        1 file(s) copied.

C:\Program Files\Debugging Tools for Windows (x64)>d2p-range.bmp
.shell: Process exited

We see the same partitioning if we juxtapose results:

The application can be downloaded from here: MappedFiles.zip

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

Finally I compiled a Questions and Answers page with all necessary links and examples during the weekend:

http://www.dumpanalysis.com/FCMDA-Q-A

I also added text versions of logs (in addition to zip files) to a Webinar materials page:

http://www.dumpanalysis.com/FCMDA-materials

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