Software Diagnostics Library

While working on Thread Cluster pattern I realized that we need a predicate version of Module Collection pattern, similar to the predicate version of Stack Trace Collection pattern. A predicate can be anything: a company vendor, semantic proximity, functionality such as printing, remote file management, and so on. Such module sub-collections can be used instead of modules in more complex patterns: an example of software diagnostics pattern substitution and composition. For example, we might be able to identify a possible coupling between 2 semantically different module groups explained by IPC Wait Chains such as on this diagram:

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

One of useful patterns for the analysis of system hangs is Thread Waiting Time. If there are many such threads of interest they can be partitioned by waiting time and modules of interest from their stack traces. Modules of interest may include Directing, Coupled, Blocking, Top, and/or Problem modules depending on the problem description. We call the resulting composite pattern Thread Cluster. Extra-dimensional information can also be added such as the number of threads having the same or similar waiting time and other attributes by using different colours. For example, on this diagram, illustrating a real system hang, we see clustering of threads running through one 3rd-party module of interest and having the longest waiting time. Also we are able to identify possibly coupled (semantically related) threads running through another module of interest:

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

This is a variation of a general Wait Chain pattern related to CLR threads. When looking at Stack Trace Collection from a complete memory dump we may find threads using a monitor synchronization mechanism:

[... 32-bit ...]
09d2e908 6ba4d409 clr!CLREvent::WaitEx+0x106
09d2e91c 6bb90160 clr!CLREvent::Wait+0x19
09d2e9ac 6bb90256 clr!AwareLock::EnterEpilogHelper+0xa8
09d2e9ec 6bb9029b clr!AwareLock::EnterEpilog+0x42
09d2ea0c 6ba90f78 clr!AwareLock::Enter+0x5f
09d2eaa8 05952499 clr!JIT_MonEnterWorker_Portable+0xf8
[…]

or

[... 64-bit ...]
00000000`2094e230 000007fe`eedc3e3a clr!CLREvent::WaitEx+0xc1
00000000`2094e2d0 000007fe`eedc3d43 clr!AwareLock::EnterEpilogHelper+0xca
00000000`2094e3a0 000007fe`eee3e613 clr!AwareLock::EnterEpilog+0x63
00000000`2094e400 000007ff`007f4c38 clr!JIT_MonEnterWorker_Portable+0×14f
[…]

When seeing such threads we may ask for a process memory dump to perform .NET memory dump analysis using SOS or other WinDbg extensions such as in Deadlock pattern example for CLR 2 (mscorwks).

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

The next trace and log analysis pattern name is borrowed from Factor Groups in mathematics (or quotient groups). Here a group is, of course, not a mathematical group but just a group (or set) of log messages or trace statements. However, every trace message has variable and invariant parts. Variable parts usually contain some values, addresses or status bits. It can even be string values. Such values form a set too and can be partitioned into disjoint (non-overlapping) subsets. For example, a window foreground status can be either true or false. And we can group messages into disjoint factor groups each one having either only true or only false foreground status. The following trace graph illustrates a WindowHistory64 log where it was reported that one window was periodically loosing and gaining focus:

We found messages related to the reported process window title. By using Density Distribution pattern another such group of messages was found for another process window. Then a factor group was formed with two subgroups and their Relative Density was compared. For correlated alternating values it was expected to be 1. This was a very simple case, of course, which was analysed just by looking at a textual log but in more complex cases a computer assistance is required. A member of a factor group can also be generalized as a message subset with messages having variable part values from some domain subset or even calculated from it (some sort of a predicate): M_i = { m | P(m) }, where the original group of messages is a disjoin union of such message subsets: M = U M_i.

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

Sometimes we find a grouping of some messages in one trace and then we are interested in the some groupings either in the same trace (Intra-Correlation) or in another trace (Inter-Correlation). We may consider such grouping as having some local density compared to global Message Density pattern. Then we might be interested in that selected message grouping Density Distribution illustrated on this minimal trace graph:

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

Activity Regions or blocks of messages having the same TID or PID usually follow each other in a typical complex software trace. Such following can be completely random and independent or it may be linear based on IPC or some inter-thread communication mechanism. For example, after filtering out Background Components we my find that an RPC client call setup is followed by messages from an RPC server:

Using a coordinate approach with message number and PID axes we can reformat this minimal trace diagram:

We call such pattern Piecewise Activity where we borrowed the concept of a piecewise linear function in mathematics (and piecewise continuity). In some problem software behaviour scenarios where we encountered such analysis pattern it was complemented by Discontinuity pattern. For example, an RPC call may be blocked and we don’t see client messages after that break till the end of the trace. In such cases we always recommended forcing a complete memory dump to check for wait chain memory analysis patterns.

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

Sometimes we look at a stack trace collection or it’s predicate subset and recognize that one of parameters is actually the same structure address or handle. We call this pattern Shared Structure. In x64 case we may possibly see it from the return address backwards disassembly (ub WinDbg command) but in x86 case most of the time we can spot that directly from the verbose stack trace, like in the snippet below (unless a parameter memory slot was reused):

THREAD 830f9990 Cid 0428.0e94 Teb: 7ffdf000 Win32Thread: 00000000 WAIT: (UserRequest) UserMode Non-Alertable
[...]
ChildEBP RetAddr  Args to Child
0031f74c 7784b071 00000000 00000000 7ffdb000 ntdll!RtlpWaitOnCriticalSection+0x154
0031f774 00a91150 00a9b7a8 00000000 00a91452 ntdll!RtlEnterCriticalSection+0×152
WARNING: Stack unwind information not available. Following frames may be wrong.
0031f7c8 76113833 7ffdb000 0031f814 7784a9bd Application+0×1150
0031f7d4 7784a9bd 7ffdb000 003114bf 00000000 kernel32!BaseThreadInitThunk+0xe
0031f814 00000000 00a914a9 7ffdb000 00000000 ntdll!_RtlUserThreadStart+0×23

THREAD 886ee030 Cid 0428.0ef4 Teb: 7ffde000 Win32Thread: 00000000 WAIT: (UserRequest) UserMode Non-Alertable
[...]
ChildEBP RetAddr  Args to Child
0098fcb8 77f881b1 00000000 00000000 001614a0 ntdll!RtlpUnWaitCriticalSection+0x1b
0098fce0 00a9102e 00a9b7a8 00000000 00000000 ntdll!RtlEnterCriticalSection+0×152
WARNING: Stack unwind information not available. Following frames may be wrong.
0098fd28 00a91275 0098fd3c 76113833 001614a0 Application+0×102e
0098fd30 76113833 001614a0 0098fd7c 7784a9bd Application+0×1275
0098fd3c 7784a9bd 001614a0 009811d7 00000000 kernel32!BaseThreadInitThunk+0xe
0098fd7c 00000000 00a911ff 001614a0 00000000 ntdll!_RtlUserThreadStart+0×23

In case of multiple exceptions or even a single exception on one thread involving invalid access to a structure field the reference to the same structure on a different thread may point to possible synchronization problems.

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

Sometimes we see the so called Small Values in memory (such as on raw stack) or in CPU registers which can be an ASCII or UNICODE value, some ID or even a handle. When in aggregates they can form a certain Semantic Structure such as a PID.TID example or Regular Data pattern. Here we illustrate a handle example (also an example of a Wait Chain analysis in user space):

0:000> kv
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`0016de78 000007fe`fcf010dc : 00000000`02c79fa0 00000000`08c3faf0 00000000`021551f0 00000000`08c3fb00 : ntdll!NtWaitForSingleObject+0xa
00000000`0016de80 000007fe`f90e6d7f : 00000000`10b40010 00000000`10b40010 00000000`00000000 00000000`000007e0 : KERNELBASE!WaitForSingleObjectEx+0×79
[…]

0:000> !handle 00000000`000007e0 ff
Handle 00000000000007d0
  Type          Thread
  Attributes    0
  GrantedAccess 0x1fffff:
         Delete,ReadControl,WriteDac,WriteOwner,Synch
         Terminate,Suspend,Alert,GetContext,SetContext,SetInfo,QueryInfo,SetToken,
Impersonate,DirectImpersonate
  HandleCount   5
  PointerCount  9
  Name          <none>
  Object specific information
    Thread Id   278c.a58
    Priority    13
    Base Priority 0

0:000> ~~[a58]s
ntdll!NtWaitForMultipleObjects+0xa:
00000000`770c186a c3              ret

0:002> kv
Child-SP          RetAddr           : Args to Child                                                           : Call Site
00000000`0f6af758 000007fe`fcf01430 : 00000000`00000025 00000000`00000000 00000000`00000000 000007fe`e35a1fb0 : ntdll!NtWaitForMultipleObjects+0xa
00000000`0f6af760 00000000`76e61220 : 00000000`0f6af8a8 00000000`0f6af890 00000000`00000000 00000000`00000000 : KERNELBASE!WaitForMultipleObjectsEx+0xe8
[...]

0:026> dp 00000000`0f6af890 L4
00000000`0f6af890  00000000`00000dbc 00000000`000007c0
00000000`0f6af8a0  00000000`00000000 00000000`00000000

0:002> !handle dbc ff
Handle 0000000000000dbc
  Type          Thread
  Attributes    0
  GrantedAccess 0x1fffff:
         Delete,ReadControl,WriteDac,WriteOwner,Synch
         Terminate,Suspend,Alert,GetContext,SetContext,SetInfo,QueryInfo,SetToken,
Impersonate,DirectImpersonate
  HandleCount   2
  PointerCount  4
  Name          <none>
  Object specific information
    Thread Id   278c.24ac
    Priority    14
    Base Priority 0

0:002> !handle 7c0 ff
Handle 00000000000007c0
  Type          Thread
  Attributes    0
  GrantedAccess 0x1fffff:
         Delete,ReadControl,WriteDac,WriteOwner,Synch
         Terminate,Suspend,Alert,GetContext,SetContext,SetInfo,QueryInfo,SetToken,
Impersonate,DirectImpersonate
  HandleCount   2
  PointerCount  4
  Name          <none>
  Object specific information
    Thread Id   278c.628
    Priority    14
    Base Priority 0

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

When analysing Inter-Correlation or Intra-Correlation and finding Discontinuities in one part or in a different trace (for example, in client-server environments) it is useful to see if there are corresponding Correlated Discontinuities in another part of the same trace (for example, a different Thread of Activity) or in a different trace. Such pattern may point to the underlying communication problem and may suggest to gather a different trace (for example, a network trace) for further analysis.

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

Sometimes there are similar crashes in multiplatform products where only some potion of Crash Signature is similar. We call such a pattern Crash Signature Invariant, for example:

x86: cmp dword ptr [eax], 1
x64: cmp dword ptr [r10]. 1

One crash dump had the following condensed stack trace: 

0: kd> kc
DriverA
win32k!DrvSetMonitorPowerState
win32k!xxxSysCommand
win32k!xxxRealDefWindowProc
win32k!NtUserfnNCDESTROY
win32k!NtUserMessageCall
nt!KiSystemServiceCopyEnd

with the following faulting instruction:

DriverA+0x1234:
cmp     dword ptr [r11],1 ds:002b:00000000`00000000=????????

A search for DriverA led to this x86 crash analysed some time ago:

0: kd> kc
DriverA
nt!IopfCallDriver
win32k!GreDeviceIoControl
win32k!DrvSetMonitorPowerState
win32k!xxxSysCommand
win32k!xxxRealDefWindowProc
win32k!xxxWrapRealDefWindowProc
win32k!NtUserfnNCDESTROY
win32k!NtUserMessageCall
nt!KiSystemServicePostCall

0: kd> r
DtiverA+0x1423:
cmp     dword ptr [ecx],1    ds:0023:00000000=????????

We see common function names on both stack traces and overall flow is the same (only 3 functions are omitted in x64 trace); we see the same NULL pointer dereference for the same comparison instruction with the same comparison operand, #1.

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

While working on Mobile Software Diagnostics webinar and exploring the richness of Android platform and similarity of its LogCat traces (Eclipse representation) to Minimal Trace Graphs (see a corresponding slide in trace analysis pattern reference) we recognized the time has come to provide a Java implementation for a general software narratological pattern-oriented trace analysis approach and also see what memory analysis patterns can also be applied there. Here by implementation we mean concrete platform examples. For example, in the past we did similar implementations of memory analysis patterns (originally developed for unmanaged and native Windows code) for .NET (WinDbg) and Mac OS X (GDB). The first trace analysis pattern we cover here is very obvious and simple and is called Exception Stack Trace. In the original pattern example a stack trace was inside a single trace message but can also be split such as each frame has its own message (date and time columns were removed for clarity):

E/AndroidRuntime(31416): java.lang.NullPointerException
E/AndroidRuntime(31416):  at android.view.MotionEvent.writeToParcel(MotionEvent.java:1596)
E/AndroidRuntime(31416):  at com.example.nullpointer.FullscreenActivity$1.onTouch(FullscreenActivity.java:139)
E/AndroidRuntime(31416):  at android.view.View.dispatchTouchEvent(View.java:3881)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at android.view.ViewGroup.dispatchTouchEvent(ViewGroup.java:869)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow$DecorView. superDispatchTouchEvent(PhoneWindow.java:1750)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow. superDispatchTouchEvent(PhoneWindow.java:1135)
E/AndroidRuntime(31416):  at android.app.Activity.dispatchTouchEvent(Activity.java:2096)
E/AndroidRuntime(31416):  at com.android.internal.policy.impl.PhoneWindow$DecorView. dispatchTouchEvent(PhoneWindow.java:1734)
E/AndroidRuntime(31416):  at android.view.ViewRoot.deliverPointerEvent(ViewRoot.java:2216)
E/AndroidRuntime(31416):  at android.view.ViewRoot.handleMessage(ViewRoot.java:1887)
E/AndroidRuntime(31416):  at android.os.Handler.dispatchMessage(Handler.java:99)
E/AndroidRuntime(31416):  at android.os.Looper.loop(Looper.java:130)
E/AndroidRuntime(31416):  at android.app.ActivityThread.main(ActivityThread.java:3687)
E/AndroidRuntime(31416):  at java.lang.reflect.Method.invokeNative(Native Method)
E/AndroidRuntime(31416):  at java.lang.reflect.Method.invoke(Method.java:507)
E/AndroidRuntime(31416):  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867)
E/AndroidRuntime(31416):  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:625)
E/AndroidRuntime(31416):  at dalvik.system.NativeStart.main(Native Method)

Since many memory analysis patterns are based on stack traces here we also have similarity with the following patterns names as Managed Code Exception and Managed Stack Trace. We hope that in the subsequent pattern implementation examples we show more complex patterns of abnormal software behaviour and may also discover any missing ones.

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

If you have found module related patterns in a complete memory dump and suspect a particular module it may be worth looking at Module Product Process if it exists especially if this module (component, DLL) has product information or some related hint (lmv or !lmi commands). In complex environments such modules may be loaded not only by hooking mechanisms but also as plugins. If you are not sure if there is any such process the best ways is to get module collection and find a process module that has the same vendor as the module in question. Then such process should also be analysed for anomalies.

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

Most of the time when we look at software trace fragments we recognize certain Motifs^* such as client-server interaction, publisher-subscriber notifications, database queries, plugin sequence initialization, etc. This pattern is different from Master Trace which corresponds to a normal use-case or working software scenario and may actually contain several Motifs as it is usually happens in complex software environments. On the other side of the spectrum there are software narremes (basic narrative units) and Macrofunctions (single semantic units). Motifs help to further bridge the great divide between software construction and software diagnostics with software narremes corresponding to implementation patterns, macrofunctions to design patterns, and motifs to architectural patterns although an overlap between these categories is possible.

^* The idea of a pattern name comes from motives in mathematics.

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

Dialogue is an important pattern especially in network trace analysis. It usually involves a message source, a different message target (although both can be the same) and some alternation between them as shown on this abstract trace diagram:

Message and source are not only IP addresses or port numbers. They can be window handles, for example. Sometimes, the roles of source and target play different Process ID and Thread ID combinations (Client ID, CID). In such cases some parts of a message text may signify reply and response as shown graphically:

The similar illustration can be done for multi-computer trace, for example, when several traces from different servers are combined into one, where a combination of CID and a computer ID (Co) or just Co can play the roles of source and target.

Note that on all illustrations above the 3rd request doesn’t have a reply message: a possible Incomplete History pattern.

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

This is a kernel space counterpart of Ubiquitous Component pattern. Such a component especially when it is Top Module can be a sign of Wait Chain(s) and Blocking Module and if it is present in the same process names - a sign of Distributed Wait Chain.

0: kd> !stacks 0 ModuleA
Proc.Thread  .Thread  Ticks   ThreadState Blocker

                            [fffffa800e673b30 svchost.exe]
 534.006240  fffffa801388f5f0 fffd41d9 Blocked    ModuleA+0x12468

                            [fffffa800e705b30 svchost.exe]
 630.000e14  fffffa800edacb50 fffdcf7a Blocked    ModuleA+0x12468
 630.000f04  fffffa8012c2fb50 fffdcf49 Blocked    ModuleA+0x12468
 630.006610  fffffa80134f5b50 fffdcf46 Blocked    ModuleA+0x12468
 630.001cfc  fffffa800f55a2d0 fffdcf44 Blocked    ModuleA+0x12468
 630.003db8  fffffa80121f1540 fffdcf43 Blocked    ModuleA+0x12468
 630.000b9c  fffffa80133d1780 fffdcf3c Blocked    ModuleA+0x12468
 630.0041c4  fffffa8013c77b50 fffdcf43 Blocked    ModuleA+0x12468
 630.00641c  fffffa8012476b50 fffdcf43 Blocked    ModuleA+0x12468
 630.006424  fffffa8013207b50 fffdcf40 Blocked    ModuleA+0x12468
 630.002fcc  fffffa80128f9060 fffdcf3e Blocked    ModuleA+0x12468
 630.003de8  fffffa80139edb50 fffdcf3d Blocked    ModuleA+0x12468
 630.0062c4  fffffa800f5ff2d0 fffdcf3c Blocked    ModuleA+0x12468
 630.0065e8  fffffa80139dcb50 fffdcf3b Blocked    ModuleA+0x12468
 630.004524  fffffa8011e51b50 fffdcf3a Blocked    ModuleA+0x12468
 630.004570  fffffa801346b060 fffdcf39 Blocked    ModuleA+0x12468
 630.00173c  fffffa8010b99b50 fffdcf39 Blocked    ModuleA+0x12468

                            [fffffa800f63db30 iexplore.exe]
24c4.0024c8  fffffa800fe854e0 fffcb6cf Blocked    ModuleA+0x12468

                            [fffffa8010b9ab30 explorer.exe]
2b64.0043d0  fffffa8012e8ab00 fffd9095 Blocked    ModuleA+0x12468

                            [fffffa800fe55060 explorer.exe]
2c80.002e58  fffffa8012e75060 fffba7af Blocked    ModuleA+0x12468

                            [fffffa8010c54b30 iexplore.exe]
2e3c.002e98  fffffa8010c75620 fffcbb7f Blocked    ModuleA+0x12468

                            [fffffa80111c3720 iexplore.exe]
32d8.003230  fffffa80111b1b00 fffd41d9 Blocked    ModuleA+0x12468

                            [fffffa80110cb690 iexplore.exe]
2e74.002854  fffffa8011121b00 fffbe8a4 Blocked    ModuleA+0x12468

                            [fffffa801146cb30 OUTLOOK.EXE]
35cc.0035e8  fffffa8013831b00 fffaf33a Blocked    ModuleA+0x12468

                            [fffffa80105a5640 OUTLOOK.EXE]
3858.00385c  fffffa801133ab00 fffd3691 Blocked    ModuleA+0x12468

                            [fffffa8011998060 explorer.exe]
3d70.004a0c  fffffa80139ddb00 fffd0482 Blocked    ModuleA+0x12468

                            [fffffa8010ff5850 OUTLOOK.EXE]
3540.000458  fffffa8011052b00 fffbd007 Blocked    ModuleA+0x12468

                            [fffffa8011d3d060 OUTLOOK.EXE]
49f8.0049fc  fffffa8011c78060 fffdbbf9 Blocked    ModuleA+0x12468

                            [fffffa801241b060 OUTLOOK.EXE]
4888.005af0  fffffa8012e8eab0 fffae442 Blocked    ModuleA+0x12468
4888.003d24  fffffa800eca7b00 fffae443 Blocked    ModuleA+0x12468

                            [fffffa8012687b30 explorer.exe]
5048.0051fc  fffffa801129cb00 fffca8bf Blocked    ModuleA+0x12468

                            [fffffa8011c1e060 OUTLOOK.EXE]
52c4.00117c  fffffa80130f8710 fffaa157 Blocked    ModuleA+0x12468
52c4.0045fc  fffffa801374f060 fffaa15e Blocked    ModuleA+0x12468

                            [fffffa8011c42b30 explorer.exe]
5898.0001ec  fffffa80137a1b00 fffd8da0 Blocked    ModuleA+0x12468

                            [fffffa8012e04b30 OUTLOOK.EXE]
5a74.004954  fffffa8012e05060 fffa9ff8 Blocked    ModuleA+0x12468

                            [fffffa8010908b30 spoolsv.exe]
2724.004190  fffffa8011ea1060 fffdcafb Blocked    ModuleA+0x12468

                            [fffffa801206eb30 WerFault.exe]
3e50.005424  fffffa8013c5eb00 fffdcf39 Blocked    ModuleA+0x12468

                            [fffffa800f8cf2a0 WerFault.exe]
 9f4.00570c  fffffa8013c8ab00 fffdca9f Blocked    ModuleA+0x12468

                            [fffffa8013af1060 WerFault.exe]
3c74.002b80  fffffa8013c5c060 fffd9dc8 Blocked    ModuleA+0x12468

                            [fffffa800f8053a0 WINWORD.EXE]
3dd0.0066a8  fffffa800ce618c0 fffd7c02 Blocked    ModuleA+0x12468

                            [fffffa8010b66b30 WINWORD.EXE]
62a4.001934  fffffa801368c430 fffd7ce7 Blocked    ModuleA+0x12468

                            [fffffa80141dc060 WerFault.exe]
17d0.0052e4  fffffa801347a060 fffd57b8 Blocked    ModuleA+0x12468

                            [fffffa8012629760 WerFault.exe]
621c.005b64  fffffa8011e395d0 fffc8dc2 Blocked    ModuleA+0x12468

                            [fffffa80131a75d0 explorer.exe]
4884.002b34  fffffa8013dc3b00 fffd67bc Blocked    ModuleA+0x12468

[...]

Threads Processed: 5948

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

Processes with one thread like Notepad are rare. Such a process is always suspicious especially if it is a service or belongs to a complex product. We call such a pattern One-Thread Process. Usually this happens when all other threads terminated and the remaining thread is blocked in some wait chain. For example, this process has a thread which is blocked in an ALPC request to itself (the same process):

0: kd> !process fffffa8013ed9b30 ff
PROCESS fffffa8013ed9b30
    SessionId: 0  Cid: 44b4    Peb: 7fffffd8000  ParentCid: 0114
    DirBase: 2da448000  ObjectTable: fffff8a01948c670  HandleCount: 660.
    Image: ServiceA.exe
    VadRoot fffffa801356dd10 Vads 398 Clone 0 Private 5795. Modified 204253. Locked 0.
    DeviceMap fffff8a000008340
    Token                             fffff8a01b546060
    ElapsedTime                       01:32:37.622
    UserTime                          00:00:01.421
    KernelTime                        00:00:01.578
    QuotaPoolUsage[PagedPool]         0
    QuotaPoolUsage[NonPagedPool]      0
    Working Set Sizes (now,min,max)  (1525, 50, 345) (6100KB, 200KB, 1380KB)
    PeakWorkingSetSize                7607
    VirtualSize                       178 Mb
    PeakVirtualSize                   182 Mb
    PageFaultCount                    752709
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      8043

        THREAD fffffa8012caab50  Cid 44b4.4f70  Teb: 000007fffff5a000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) KernelMode Non-Alertable
            fffffa8012caaf18  Semaphore Limit 0x1
        Waiting for reply to ALPC Message fffff8a0194d4780 : queued at port fffffa8012911c80 : owned by process fffffa8013ed9b30
        IRP List:
            fffffa8013923300: (0006,0118) Flags: 00060000  Mdl: 00000000
        Not impersonating
        DeviceMap                 fffff8a000008340
        Owning Process            fffffa8013ed9b30       Image:         ServiceA.exe
        Attached Process          N/A            Image:         N/A
        Wait Start TickCount      139828         Ticks: 347372 (0:01:30:27.687)
        Context Switch Count      7380            
        UserTime                  00:00:00.031
        KernelTime                00:00:04.890
        Win32 Start Address ServiceA (0×00000001401156e0)
        Stack Init fffff88014c9ddb0 Current fffff88014c9c6b0
        Base fffff88014c9e000 Limit fffff88014c98000 Call 0
        Priority 8 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
        Child-SP          RetAddr           Call Site
        fffff880`14c9c6f0 fffff800`01873652 nt!KiSwapContext+0×7a
        fffff880`14c9c830 fffff800`01884a9f nt!KiCommitThreadWait+0×1d2
        fffff880`14c9c8c0 fffff800`0189f04f nt!KeWaitForSingleObject+0×19f
        fffff880`14c9c960 fffff800`01b919f6 nt!AlpcpSignalAndWait+0×8f
        fffff880`14c9ca10 fffff800`01b910f0 nt!AlpcpReceiveSynchronousReply+0×46
        fffff880`14c9ca70 fffff800`01b9519d nt!AlpcpProcessSynchronousRequest+0×33d
        fffff880`14c9cbb0 fffff800`01b95276 nt!LpcpRequestWaitReplyPort+0×9c
        fffff880`14c9cc10 fffff800`0187ced3 nt!NtRequestWaitReplyPort+0×76
        fffff880`14c9cc60 fffff800`01879490 nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`14c9cc60)
        fffff880`14c9cdf8 fffff880`05c31050 nt!KiServiceLinkage
        fffff880`14c9ce70 fffff880`045ce005 ModuleA+0×12468
        […]
        fffff880`14c9da10 fffff800`01b9d3b6 nt!IopXxxControlFile+0×607
        fffff880`14c9db40 fffff800`0187ced3 nt!NtDeviceIoControlFile+0×56
        fffff880`14c9dbb0 00000000`76d8138a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`14c9dc20)
        00000000`082af028 000007fe`fd366cf6 ntdll!NtDeviceIoControlFile+0xa
        00000000`082af030 00000000`76c2683f KERNELBASE!TlsGetValue+0×1a36
        00000000`082af0a0 00000001`4019d38c kernel32!DeviceIoControlImplementation+0×7f
        […]

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

All previous wait chain patterns were about single wait chains. However, it is often a case when there are many different wait chains in a memory dump especially in terminal services environments. There can be ALPC and critical section wait chains at the same time. The can be related or completely disjoint. Here we call a special case of several wait chains having the same structure (and possibly pointing to one direction) Distributed Wait Chain. One such example we put below. In a stack trace collection from a complete memory dump from a hanging system we found several explorer.exe processes with critical section wait chains having the same structure and endpoint of a top and blocking ModuleA:

THREAD fffffa80137cf060  Cid 4884.4f9c  Teb: 000007fffffaa000 Win32Thread: fffff900c0fb98b0 WAIT: (UserRequest) UserMode Non-Alertable
    fffffa8013570dc0  SynchronizationEvent
Not impersonating
DeviceMap                 fffff8a014e21d90
Owning Process            fffffa80131a75d0       Image:         explorer.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      274752         Ticks: 212448 (0:00:55:19.500)
Context Switch Count      9889                 LargeStack
UserTime                  00:00:00.093
KernelTime                00:00:00.171
Win32 Start Address SHLWAPI!WrapperThreadProc (0×000007fefdafc608)
Stack Init fffff88013c25db0 Current fffff88013c25900
Base fffff88013c26000 Limit fffff88013c1b000 Call 0
Priority 11 BasePriority 9 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5
Kernel stack not resident.
Child-SP          RetAddr           Call Site
fffff880`13c25940 fffff800`01873652 nt!KiSwapContext+0×7a
fffff880`13c25a80 fffff800`01884a9f nt!KiCommitThreadWait+0×1d2
fffff880`13c25b10 fffff800`01b7768e nt!KeWaitForSingleObject+0×19f
fffff880`13c25bb0 fffff800`0187ced3 nt!NtWaitForSingleObject+0xde
fffff880`13c25c20 00000000`76d8135a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`13c25c20)
00000000`0489e518 00000000`76d7e4e8 ntdll!ZwWaitForSingleObject+0xa
00000000`0489e520 00000000`76d7e3db ntdll!RtlpWaitOnCriticalSection+0xe8
00000000`0489e5d0 000007fe`fdf8ff50 ntdll!RtlEnterCriticalSection+0xd1
00000000`0489e600 000007fe`fdf8fbd3 SHELL32!CFSFolder::GetIconOf+0×24b
00000000`0489f3a0 000007fe`fdf903d3 SHELL32!SHGetIconIndexFromPIDL+0×3f
00000000`0489f3d0 00000000`ff900328 SHELL32!SHMapIDListToSystemImageListIndexAsync+0×73
00000000`0489f470 00000000`ff8fff4b Explorer!SFTBarHost::AddImageForItem+0×9c
00000000`0489f4d0 00000000`ff8fd2f1 Explorer!SFTBarHost::_InternalRepopulateList+0×4ad
00000000`0489f5d0 00000000`ff8fd0b4 Explorer!SFTBarHost::_RepopulateList+0×1f3
00000000`0489f600 00000000`ff8fcccd Explorer!SFTBarHost::_OnBackgroundEnumDone+0xc1
00000000`0489f630 00000000`ff8fc9e2 Explorer!SFTBarHost::_WndProc+0×451
00000000`0489f680 00000000`76669bd1 Explorer!SFTBarHost::_WndProc_ProgramsMFU+0×1b
00000000`0489f6b0 00000000`766698da USER32!UserCallWinProcCheckWow+0×1ad
00000000`0489f770 00000000`ff8f1177 USER32!DispatchMessageWorker+0×3b5
00000000`0489f7f0 00000000`ff9130e9 Explorer!CTray::_MessageLoop+0×446
00000000`0489f880 000007fe`fdafc71e Explorer!CTray::MainThreadProc+0×8a
00000000`0489f8b0 00000000`76c2652d SHLWAPI!WrapperThreadProc+0×19b
00000000`0489f9b0 00000000`76d5c521 kernel32!BaseThreadInitThunk+0xd
00000000`0489f9e0 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0: kd> .process /r /p fffffa80131a75d0
Implicit process is now fffffa80`131a75d0
Loading User Symbols

0: kd> !cs -l -o -s
-----------------------------------------
DebugInfo          = 0x0000000000499d90
Critical section   = 0x000007fefe3d5900 (SHELL32!g_csIconCache+0x0)
LOCKED
LockCount          = 0×2
WaiterWoken        = No
OwningThread       = 0×0000000000002b34
RecursionCount     = 0×1
LockSemaphore      = 0×7F8
SpinCount          = 0×0000000000000000
OwningThread       = .thread fffffa8013dc3b00

THREAD fffffa8013dc3b00  Cid 4884.2b34  Teb: 000007fffffac000 Win32Thread: fffff900c2bc1010 WAIT: (Executive) KernelMode Non-Alertable
    fffff88011c03600  SynchronizationEvent
IRP List:
    fffffa800f8fc790: (0006,0430) Flags: 00000404  Mdl: 00000000
Not impersonating
DeviceMap                 fffff8a014e21d90
Owning Process            fffffa80131a75d0       Image:         explorer.exe
Attached Process          N/A            Image:         N/A
Wait Start TickCount      170052         Ticks: 317148 (0:01:22:35.437)
Context Switch Count      2                 LargeStack
UserTime                  00:00:00.000
KernelTime                00:00:00.000
Win32 Start Address SHELL32!ShutdownThreadProc (0x000007fefe13ef54)
Stack Init fffff88011c03db0 Current fffff88011c03320
Base fffff88011c04000 Limit fffff88011bfd000 Call 0
Priority 11 BasePriority 8 UnusualBoost 0 ForegroundBoost 2 IoPriority 2 PagePriority 5
Child-SP          RetAddr           Call Site
fffff880`11c03360 fffff800`01873652 nt!KiSwapContext+0x7a
fffff880`11c034a0 fffff800`01884a9f nt!KiCommitThreadWait+0x1d2
fffff880`11c03530 fffff880`05c12383 nt!KeWaitForSingleObject+0x19f
fffff880`11c035d0 fffff880`012b9288 ModuleA+0×12468
fffff880`11c03750 fffff880`012b7d1b fltmgr!FltpPerformPostCallbacks+0×368
fffff880`11c03820 fffff880`012b66df fltmgr!FltpLegacyProcessingAfterPreCallbacksCompleted+0×39b
fffff880`11c038b0 fffff880`01b895ff fltmgr!FltpDispatch+0xcf
fffff880`11c03a30 fffff800`01b783b4 nt!IopCloseFile+0×11f
fffff880`11c03ac0 fffff800`01b78171 nt!ObpDecrementHandleCount+0xb4
fffff880`11c03b40 fffff800`01b78734 nt!ObpCloseHandleTableEntry+0xb1
fffff880`11c03bd0 fffff800`0187ced3 nt!ObpCloseHandle+0×94
fffff880`11c03c20 00000000`76d8140a nt!KiSystemServiceCopyEnd+0×13 (TrapFrame @ fffff880`11c03c20)
00000000`0754f348 000007fe`fd341873 ntdll!NtClose+0xa
00000000`0754f350 00000000`76c32f51 KERNELBASE!CloseHandle+0×13
00000000`0754f380 000007fe`fdaf9690 kernel32!CloseHandleImplementation+0×3d
00000000`0754f490 000007fe`fe191d7f SHLWAPI!CFileStream::Release+0×84
00000000`0754f4c0 000007fe`fe13ed57 SHELL32!IconCacheSave+0×2b7
00000000`0754f780 000007fe`fe13f0c6 SHELL32!CommonRestart+0×2f
00000000`0754f7f0 00000000`76c2652d SHELL32!ShutdownThreadProc+0×172
00000000`0754f820 00000000`76d5c521 kernel32!BaseThreadInitThunk+0xd
00000000`0754f850 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

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

Sometimes we look at a trace or log and instead of Error Messages we only see their “signs” such as a DLL load event for an error or fault reporting module or a module that is related to symbol files such diasymreader.dll. We call this pattern Hidden Error by an analogy to Hidden Exception in memory dump analysis pattern catalogue although sometimes we can see such modules in memory dump Module Collection. For example, the presence of diasymreader module may signify an unreported .NET exception and suggest a dump collection strategy.

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

Sometimes we need to analyse Last Activity before Significant Event or Discontinuity. By this pattern we mean a loose semantic collection of messages before process exit, for example. This might give some clues to further troubleshooting. In one incident a process was suddenly exiting. Its own detailed trace didn’t have any messages explaining that probably due to insufficient tracing coverage (Sparse Trace). Fortunately, a different external trace (from Process Monitor) was collected (Inter-Correlation) and it had LDAP network communication messages just before thread and process exit events.

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

Another best practice that is directly related to productivity is a parallel processing of the same memory dump especially in the case of complete memory dumps. Here an analysis might start with running time consuming scripts that dump all process and threads in the variety of formats such as x64 and x86 thread stack traces. However, if the nature of the problem is such that it is possible to start with some pattern and continue unfolding its analysis then we can do that in parallel. One of examples may be a discovered Incomplete Session with an ALPC Wait Chain. Here we can follow such a wait chain while another WinDbg instance dumps all threads for further pattern search later.

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