Software Diagnostics Library

This is a very simple case study. One service was hanging and its user dump was taken. Inspection of its critical sections reveals the one thread blocking 32 other threads. The owner stack trace points to Message Box pattern:

0:000> !cs -l -o -s
[...]
DebugInfo          = 0x00151e20
Critical section   = 0x00455bd0 (ServiceA!g_CritSec+0x0)
LOCKED
LockCount          = 0×20
WaiterWoken        = No
OwningThread       = 0×00005774
RecursionCount     = 0×1
LockSemaphore      = 0×18
SpinCount          = 0×00000000
OwningThread DbgId = ~24s
OwningThread Stack =
ChildEBP RetAddr  Args to Child              
00d0d854 77e3bf53 77e3610a 00000000 00000000 ntdll!KiFastSystemCallRet
00d0d88c 77e2969d 07a1006e 00000000 00000001 user32!NtUserWaitMessage+0xc
00d0d8b4 77e3f762 77e20000 00181620 00000000 user32!InternalDialogBox+0xd0
00d0db74 77e3f047 00d0dcd0 00d0e810 00d0f3dc user32!SoftModalMessageBox+0×94b
00d0dcc4 77e3eec9 00d0dcd0 00000028 00000000 user32!MessageBoxWorker+0×2ba
00d0dd1c 77e3ee65 00000000 00d0de94 00d0dd84 user32!MessageBoxTimeoutW+0×7a
00d0dd3c 77e3ee41 00000000 00d0de94 00d0dd84 user32!MessageBoxExW+0×1b
00d0dd58 25010b67 00000000 00d0de94 00d0dd84 user32!MessageBoxW+0×45
WARNING: Stack unwind information not available. Following frames may be wrong.
00d0de84 25010372 00d0de94 00010010 00690044 moduleA!DllMain+0×8b27
00d0e298 25018e3d 00002754 25067c58 25066a74 moduleA!DllMain+0×8332
[…]
00d0f974 00403e83 00000008 00d0f98c 00d0fae0 ServiceA!Create+0×39
[…]

Inspecting message box parameters we see a self-diagnostic message:

0:000> du /c 100 00d0de94
00d0de94  “The installation of Software Product A was not successful because moduleA could not be installed.”

- Dmitry Vostokov @ DumpAnalysis.org -

Sometimes the timestamp of a module is not available when we want to see how old it is:

0:000> lmv m moduleA
start    end        module name
25000000 2507a000   moduleA  T (export symbols)       moduleA.dll
Loaded symbol image file: moduleA.dll
Image path: \moduleA.dll
Image name: moduleA.dll
Timestamp:        unavailable (00000000)
CheckSum:         00000000
ImageSize:        0007A000
File version:     0.3.0.0
Product version:  3.43.0.0
File flags:       0 (Mask 0)
File OS:          40004 NT Win32
File type:        0.0 Unknown
File date:        00000000.00000000
Translations:     0409.04e4
CompanyName:      A Software Company
ProductName:      A Software Product
ProductVersion:   3.43
FileVersion:      3.43
FileDescription:  A Software Product
LegalCopyright:   Copyright (c) 2001-2009 A Software Company

Fortunately, the legal copyright says that the module is the new as this year, 2009. This is useful in analyzing print driver problems where the numerous observations suggest that the older the driver the more suspect it should be especially in multi-threaded environments.

- Dmitry Vostokov @ DumpAnalysis.org -

Monthly summary of my Literate Scientist blog:

A First Course in String Theory

The Strangest Man

This Is Biology

- Dmitry Vostokov @ DumpAnalysis.org -

Andreas Zeller to publish the second edition of his book this summer:

Why Programs Fail, Second Edition: A Guide to Systematic Debugging

I really enjoyed reading the first edition a few years ago, liked the fact that he uses mathematics to prove propositions of delta debugging, illustrate memory graphs and cause-effect chains. I’m looking forward to reading the second edition.

- Dmitry Vostokov @ DumpAnalysis.org -

Microsoft to add 5th memory dump type to the final version of Windows 7. In addition to kernel, complete, mini and user dump file types new memory dumps will include all open files to allow full data recovery and postmortem process resurrection on another computer. The new coming soon version of WinDbg includes specialized extensions for process instantiation and recursive data recovery near the point of failure:

blogs.technet.com/5thcolumn

- Dmitry Vostokov @ DumpAnalysis.org -

The latest WinDbg 6.11.0001.404 has broken !ntsdexts.locks command (simply !locks in user dumps). I noticed that some time ago and switched to !cs command which works in user and complete memory dumps. I now like it more than !locks because the following command parameters give stack traces for critical section owners:

!cs -l -o -s

The following recent cases studies use !cs command:

Blocked threads, message box and self-diagnosis

Manual dump, wait chain, blocked thread, dynamic memory corruption and historical information: pattern cooperation

Coupled processes, wait chains, message box, waiting thread time, paged out data, incorrect stack trace, hidden exception, unknown component and execution residue: pattern cooperation

Easy to remember mnemonic is cslos: critical sections locked with stacks

This command is also featured on the back cover of March Debugged! magazine issue.

- Dmitry Vostokov @ DumpAnalysis.org -

The paperback version of the book Windows Debugging: Practical Foundations has been temporarily out of print since the last week but this should be resolved very soon in a few days. OpenTask also submitted to print a hardcover version (ISBN: 978-1906717674) and it should be available for sale by the end of this week.

- Dmitry Vostokov @ DumpAnalysis.org - 

Finally it has been published and available for orders from Amazon and other bookstores:

http://www.dumpanalysis.org/Debugged+Magazine

I had to increase the number of pages for the first issue from 16, planned originally, to 28 and this is reflected in the retail price of $10 (originally planned $8) but bookstores should sell it with a discount between 0% and 55%.

More information about the next issue should be ready by the end of the next week.

- Dmitry Vostokov @ DumpAnalysis.org - 

Previously announced Memory Analysis and Debugging Institute was registered in the Republic of Ireland (No. 382026) last week.

- Dmitry Vostokov @ DumpAnalysis.org - 

I’m very proud to announce that my first 2 volumes of Memory Dump Analysis Anthology are to be translated and published in the Republic of Korea this year:

http://www.opentask.com/korean-rights-mdaa-v1-v2

- Dmitry Vostokov @ DumpAnalysis.org -

While fighting the flu last week I forgot that on 26^th of March, 2006 I registered this domain. My excitement was so great that I couldn’t sleep the following night. I originally thought of domain names like crashdumpanalysis or memorydumpanalysis but was convinced by one of my colleagues that the shorter dumpanalysis is better.

- Dmitry Vostokov @ DumpAnalysis.org -

I was a big fan of Kitaro music for many years during 90s. Today I started re-listening to some of his albums and recommend

Heaven & Earth: Music From The Motion Picture Soundtrack

to listen to when analyzing complete memory dumps from complex issues, looking at user (Earth) and kernel (Heaven) spaces and trying to figure out which module started the conflict.

- Dmitry Vostokov @ DumpAnalysis.org -

In this part we start our discussion of Urstoff (Ger.), the primitive, primordial and basic element of everything and relation of memoidealism to Ionian school. In memoidealism, Memory serves the role of Urstoff as permanent primary element behind the process of state transition changes (technically speaking). In contrast, Ionians considered Urstoff to be of a material nature, for example, air (Anaximenes), fire (Heraclitus) or water (Thales). This abstraction (abstract materialism) of material elements parallels memory abstraction in memoidealism. Another parallel is the unity of science and philosophy.

- Dmitry Vostokov @ DumpAnalysis.org -

Just recently got news about a Microsoft security WinDbg extension released as open source:

http://www.microsoft.com/security/msec/default.mspx

http://www.codeplex.com/msecdbg 

- Dmitry Vostokov @ DumpAnalysis.org -

One day, last week, Dmitry was walking in Malahide Woods and thinking through his dangerous ideas about universal memory dumps and how to reconcile man-made PDB files with empirically discovered science files. Upon finding a problem resolution, Dmitry sat firmly on the ground and remained there happily for some time.

- Dmitry Vostokov @ DumpAnalysis.org -   

Sometimes a problem like a crash or a hang never happens again, the so called a unique computational event, like the extinction of dinosaurs if we apply biological metaphors. Biology science copes with such events via constructing historical narratives and multiple probabilistic explanations with cross data examinations. The same is true for memory dump analysis where we construct possible explanations based on evidence and collected supporting data. Like Ernst Mayr pointed, we try to answer both questions: “How?” and “Why?”. Usually the answer to the first question is very simple and straightforward, like NULL pointer access (proximate, functional causation) and the answer to the second question is provided by testing various possible historical narratives (ultimate or evolutionary causation) possibly involving an animate agent (a human user of a system).

- Dmitry Vostokov @ DumpAnalysis.org -   

In Windows Vista and Server 2008 LPC is implemented using undocumented Advanced Local Procedure Calls (ALPC) and the new formatting of the !process 0 ff output shows the owner of the port: 

THREAD fffffa801afae6f0  Cid 033c.3c40  Teb: 000007fffffa0000 Win32Thread: 0000000000000000 WAIT: (WrLpcReply) UserMode Non-Alertable
    fffffa801afaea80  Semaphore Limit 0x1
Waiting for reply to ALPC Message fffff8800f4cc950 : queued at port fffffa8017dbb060 : owned by process fffffa801807b8f0

Instead of !lpc we should use !alpc extension command: 

0: kd> !lpc message fffff8800f4cc950
LPC is now emulated over ALPC. Use !alpc
Arguments:

   /?                   - Print help
   /P [/V] PortAddress  - Dump the ALPC port information
   /M [/V] MsgAddress   - Searches the message and dumps the message information
   /R [/V] ResAddress   - Dumps the information regarding resources
   /G [/V]              - Dumps the global information

0: kd> !alpc /M fffff8800f4cc950

Message @ fffff8800f4cc950
  MessageID             : 0x0BFC (3068)
  CallbackID            : 0x1FEF27 (2092839)
  SequenceNumber        : 0x0004D4D4 (316628)
  Type                  : LPC_REQUEST
  DataLength            : 0x0068 (104)
  TotalLength           : 0x0090 (144)
  Canceled              : No
  Release               : No
  ReplyWaitReply        : No
  Continuation          : Yes
  OwnerPort             : fffffa8018a95e60 [ALPC_CLIENT_COMMUNICATION_PORT]
  WaitingThread         : fffffa801afae6f0
  QueueType             : ALPC_MSGQUEUE_PENDING
  QueuePort             : fffffa8017dbb060 [ALPC_CONNECTION_PORT]
  QueuePortOwnerProcess : fffffa801807b8f0 (svchost.exe)
  ServerThread          : fffffa801aeec060
  QuotaCharged          : No
  CancelQueuePort       : 0000000000000000
  CancelSequencePort    : 0000000000000000
  CancelSequenceNumber  : 0×00000000 (0)
  ClientContext         : 00000000025599e0
  ServerContext         : 0000000000000000
  PortContext           : 000000000030d640
  CancelPortContext     : 0000000000000000
  SecurityData          : 0000000000000000
  View                  : 0000000000000000

- Dmitry Vostokov @ DumpAnalysis.org -

Looking at one kernel memory dump from x64 Windows Server 2008 I noticed this API call (shown in blue):

0: kd> kL 100
Child-SP          RetAddr           Call Site
fffffa60`138f4720 fffff800`01875f8a nt!KiSwapContext+0x7f
fffffa60`138f4860 fffff800`0187776a nt!KiSwapThread+0x2fa
fffffa60`138f48d0 fffff800`01ab16d6 nt!KeWaitForSingleObject+0x2da
fffffa60`138f4960 fffff800`01ab1667 nt!FsRtlCancellableWaitForMultipleObjects+0x62
fffffa60`138f49c0 fffffa60`06c515e0 nt!FsRtlCancellableWaitForSingleObject+0x27
fffffa60`138f4a00 fffffa60`06c611dc rdbss!RxWaitForStableCondition+0x11c
fffffa60`138f4a40 fffffa60`06c61c07 rdbss!RxFindOrCreateConnections+0x44c
fffffa60`138f4b20 fffffa60`06c56840 rdbss!RxConstructVirtualNetRoot+0xb7
fffffa60`138f4bc0 fffffa60`06c6381a rdbss!RxFindOrConstructVirtualNetRoot+0x594
fffffa60`138f4d30 fffffa60`06c54c42 rdbss!RxCreateTreeConnect+0x13e
fffffa60`138f4dc0 fffffa60`06c2fbf6 rdbss!RxCommonCreate+0x20a
fffffa60`138f4e80 fffffa60`06c5191a rdbss!RxFsdCommonDispatch+0x786
fffffa60`138f4f70 fffffa60`07e4f21f rdbss!RxFsdDispatch+0x21a
fffffa60`138f4fe0 fffffa60`011e05f5 mrxsmb!MRxSmbFsdDispatch+0xbf
fffffa60`138f5020 fffffa60`011e0130 mup!MupiCallUncProvider+0x159
fffffa60`138f5090 fffffa60`011e17af mup!MupStateMachine+0x120
fffffa60`138f50e0 fffffa60`00d200b4 mup!MupCreate+0x2c3
fffffa60`138f5160 fffffa60`06d332d6 fltmgr!FltpCreate+0xa4
[...]
3rd party filter drivers
[...]
fffffa60`138f55a0 fffff800`01aefa59 nt!IopParseDevice+0x5e3
fffffa60`138f5740 fffff800`01af3944 nt!ObpLookupObjectName+0x5eb
fffffa60`138f5850 fffff800`01affee0 nt!ObOpenObjectByName+0x2f4
fffffa60`138f5920 fffff800`01b00a0c nt!IopCreateFile+0x290
fffffa60`138f59c0 fffff800`0186fdf3 nt!NtCreateFile+0x78
fffffa60`138f5a50 fffff800`01870300 nt!KiSystemServiceCopyEnd+0x13
fffffa60`138f5c58 fffffa60`06c91a5e nt!KiServiceLinkage
fffffa60`138f5c60 fffff800`018913d1 dfsc!DfscConnOpenIpcConnectionCallout+0xbe
fffffa60`138f5d20 fffffa60`06c91d08 nt!KeExpandKernelStackAndCalloutEx+0×2e1
fffffa60`138f5db0 fffffa60`06c9bbcc dfsc!DfscGetIpcConnection+0×1f0
fffffa60`138f5e30 fffffa60`06c9bb21 dfsc!DfscRmGetReferral+0×78
fffffa60`138f5ea0 fffffa60`06c91470 dfsc!DfscGetDomainDCReferral+0×31
fffffa60`138f5ef0 fffffa60`06c917ec dfsc!DfscRmValidateDomainIterate+0×5c
fffffa60`138f5f40 fffffa60`06c915f5 dfsc!DfscValidateReferral+0xa0
fffffa60`138f5fb0 fffffa60`06c917ec dfsc!DfscRmValidateRootGetParent+0×75
fffffa60`138f5fe0 fffffa60`06c90825 dfsc!DfscValidateReferral+0xa0
fffffa60`138f6050 fffffa60`06c93905 dfsc!DfscCmValidateState+0×79
fffffa60`138f6090 fffffa60`06c9e759 dfsc!DfscSurrogateCreate+0×7d
fffffa60`138f6100 fffffa60`011e03ab dfsc!DfscSurrogatePreProcess+0xb9
fffffa60`138f6130 fffffa60`011e014f mup!MupCallSurrogatePrePost+0×10b
fffffa60`138f6190 fffffa60`011e17af mup!MupStateMachine+0×13f
fffffa60`138f61e0 fffffa60`00d200b4 mup!MupCreate+0×2c3
fffffa60`138f6260 fffffa60`06d332d6 fltmgr!FltpCreate+0xa4
[…]
3rd party filter drivers
[…]
fffffa60`138f6610 fffff800`01aefa59 nt!IopParseDevice+0×5e3
fffffa60`138f67b0 fffff800`01af3944 nt!ObpLookupObjectName+0×5eb
fffffa60`138f68c0 fffff800`01ac22f1 nt!ObOpenObjectByName+0×2f4
fffffa60`138f6990 fffff800`0186fdf3 nt!NtQueryAttributesFile+0×134
fffffa60`138f6c20 00000000`77285e4a nt!KiSystemServiceCopyEnd+0×13

This API is mentioned in the following presentation and document and can also be found in WDK:

PPT: Windows Memory Management Advances

DOC: Advances in Memory Management 

KeExpandKernelStackAndCallout

Its 3rd parameter is the stack size and we can see it used in disassembly where r8d register is used for 3rd parameter according to x64 calling convention and rcx is used for the first parameter, a function procedure to be executed with a guaranteed kernel stack size:

0: kd> kv 100
Child-SP          RetAddr           : Args to Child                                                           : Call Site
[...]
fffffa60`138f5c60 fffff800`018913d1 : 00000000`00000000 fffff880`10d6d3f8 00000000`00000000 00000000`00000000 : dfsc!DfscConnOpenIpcConnectionCallout+0xbe
fffffa60`138f5d20 fffffa60`06c91d08 : fffffa60`06c919a0 fffffa60`138f5df0 fffff880`102128d0 fffffa60`138f5f10 : nt!KeExpandKernelStackAndCalloutEx+0×2e1
fffffa60`138f5db0 fffffa60`06c9bbcc : 00000000`00000000 fffff880`10d6d3f8 00000000`00000000 fffff880`10d6d460 : dfsc!DfscGetIpcConnection+0×1f0
[…]

0: kd> ub fffffa60`06c91d08
dfsc!DfscGetIpcConnection+0×1c6:
fffffa60`06c91cde xor     r9d,r9d
fffffa60`06c91ce1 mov     qword ptr [rsp+50h],rax
fffffa60`06c91ce6 mov     rax,qword ptr [dfsc!DfscGlobalData+0×138 (fffffa60`06c8d758)]
fffffa60`06c91ced mov     r8d,6000h
fffffa60`06c91cf3 mov     qword ptr [rsp+40h],rdi
fffffa60`06c91cf8 mov     byte ptr [rsp+58h],r11b
fffffa60`06c91cfd mov     qword ptr [rsp+20h],rax
fffffa60`06c91d02 call    qword ptr [dfsc!_imp_KeExpandKernelStackAndCalloutEx (fffffa60`06c8b0d0)]

0: kd> ub fffffa60`06c91cde
dfsc!DfscGetIpcConnection+0x199:
fffffa60`06c91cb1 488b88b8000000  mov     rcx,qword ptr [rax+0B8h]
fffffa60`06c91cb8 0fba61100a      bt      dword ptr [rcx+10h],0Ah
fffffa60`06c91cbd 450f42df        cmovb   r11d,r15d
fffffa60`06c91cc1 488b4338        mov     rax,qword ptr [rbx+38h]
fffffa60`06c91cc5 488d542440      lea     rdx,[rsp+40h]
fffffa60`06c91cca 488d0dcffcffff  lea     rcx,[dfsc!DfscConnOpenIpcConnectionCallout (fffffa60`06c919a0)]
fffffa60`06c91cd1 4889442448      mov     qword ptr [rsp+48h],rax
fffffa60`06c91cd6 488d842490000000 lea     rax,[rsp+90h]

It is good sign to see it used in file system stacks because in the past the fixed kernel stacks resulted in stack overflows and double faults:

Stack Overflow Pattern (kernel mode)

- Dmitry Vostokov @ DumpAnalysis.org -

Long time ago a professor of mathematical analysis told me a joke about reading comprehension levels:

Level 1: You feel good while reading

Level 2: You can repeat what you’ve read

Level 3: You can refute what you’ve read

After looking at some books on my shelves that I bought last month including 11 volume history of philosophy I would like to add

Level 0: You feel good before reading

- Dmitry Vostokov @ DumpAnalysis.org -

Yesterday I submitted the magazine to print and distribution world-wide. If everything is right it should be available by the end of this month. This first issue features 12 page WinDbg command supplement to pattern-driven memory dump analysis methodology, an overview of Win32dd complete memory dumper and PowerDbg enhancements to debug ASP.NET code. The magazine will only be available in print.

- Dmitry Vostokov @ DumpAnalysis.org -