Software Diagnostics Library

One application was constantly crashing in a highly dynamic multi-user environment with various value-added GUI-enhancing hooking and patching 3rd-party products. The dump was analyzed and it shows the data NULL pointer access violation:

0:000> r
eax=05503ff0 ebx=05503f10 ecx=6bb7da25 edx=00000000 esi=02203c10 edi=00000000
eip=6b542ba3 esp=04f6f860 ebp=04f6f87c iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00010246
gui_plugin!entry+0xe63:
6b542ba3 8b0f            mov     ecx,dword ptr [edi]  ds:0023:00000000=????????

Unfortunately due to the lack of gui_plugin symbols the stack trace is incorrect:

0:000> kv
ChildEBP RetAddr  Args to Child             
WARNING: Stack unwind information not available. Following frames may be wrong.
04f6f87c 00000000 000003b9 00000690 00000d20 gui_plugin!entry+0xe63

We do not attempt stack trace reconstruction here but show one of troubleshooting methods to eliminate possible effects of the changed environment. We look for any code patching modules by examining hooked functions:

0:000> !chkimg -lo 50 -d !kernel32 -v
Searching for module with expression: !kernel32
Will apply relocation fixups to file used for comparison
Will ignore NOP/LOCK errors
Will ignore patched instructions
Image specific ignores will be applied
Comparison image path: c:\mss\kernel32.dll\4791A76Ddb000\kernel32.dll
No range specified

Scanning section:    .text
Size: 835001
Range to scan: 76701000-767ccdb9
    7670a672-7670a676  5 bytes - kernel32!MoveFileW
 [ 8b ff 55 8b ec:e9 89 59 80 09 ]
    7671c5c8-7671c5cc  5 bytes - kernel32!DeleteFileW (+0×11f56)
 [ 8b ff 55 8b ec:e9 33 3a 80 09 ]
    76721070-76721074  5 bytes - kernel32!MoveFileExW (+0×4aa8)
 [ 8b ff 55 8b ec:e9 8b ef 83 09 ]
    7678ff3f-7678ff43  5 bytes - kernel32!ReplaceFileW (+0×6eecf)
 [ 68 b4 03 00 00:e9 bc 00 7a 09 ]
Total bytes compared: 835001(100%)
Number of errors: 20
20 errors : !kernel32 (7670a672-7678ff43)

0:000> u 7670a672
kernel32!MoveFileW:
7670a672 e989598009      jmp     7ff10000
7670a677 6a02            push    2
7670a679 6a00            push    0
7670a67b 6a00            push    0
7670a67d ff750c          push    dword ptr [ebp+0Ch]
7670a680 ff7508          push    dword ptr [ebp+8]
7670a683 e8c4690100      call    kernel32!MoveFileWithProgressW (7672104c)
7670a688 5d              pop     ebp

0:000> u 7ff10000
7ff10000 e99b1e94f5      jmp     3rdPartyHook!MoveFileW (75851ea0)
7ff10005 8bff            mov     edi,edi
7ff10007 55              push    ebp
7ff10008 8bec            mov     ebp,esp
7ff1000a e968a67ff6      jmp     kernel32!MoveFileW+0×5 (7670a677)
7ff1000f 0000            add     byte ptr [eax],al
7ff10011 0000            add     byte ptr [eax],al
7ff10013 0000            add     byte ptr [eax],al

We see lots of references to 3rdPartyHook on the thread raw stack:

0:000> !teb
TEB at 7ffd5000
    ExceptionList:        04f6ff70
    StackBase:            04f70000
    StackLimit:           04f6c000
    SubSystemTib:         00000000
    FiberData:            00001e00
    ArbitraryUserPointer: 00000000
    Self:                 7ffd5000
    EnvironmentPointer:   00000000
    ClientId:             00001790 . 000017d0
    RpcHandle:            00000000
    Tls Storage:          7ffd502c
    PEB Address:          7ffd8000
    LastErrorValue:       0
    LastStatusValue:      0
    Count Owned Locks:    0
    HardErrorMode:        0

0:000> dds 04f6c000 04f70000
[...]
04f6cf28  00440042
04f6cf2c  04f6d2d4
04f6cf30  77179834 ntdll!_except_handler4
04f6cf34  003ce48e
04f6cf38  fffffffe
04f6cf3c  7719d584 ntdll!LdrpResSearchResourceInsideDirectory+0x80f
04f6cf40  7719cf9d ntdll!LdrpResSearchResourceMappedFile+0x521
04f6cf44  6b920002
04f6cf48  00000000
04f6cf4c  000bf000
04f6cf50  6b9d9000
04f6cf54  6b9200f8
04f6cf58  00000000
04f6cf5c  01f6d1d4 <Unloaded_D3D9.DLL>+0x12d1d4
04f6cf60  00000003
04f6cf64  04f6cf88
04f6cf68  04f6d370
04f6cf6c  04f6d340
04f6cf70  771d8fb2 ntdll!_SEH_epilog4_GS+0xa
04f6cf74  7719d018 ntdll!LdrpResSearchResourceMappedFile+0x781
04f6cf78  73d77612
04f6cf7c  6b920002
04f6cf80  000bf000
04f6cf84  00000000
04f6cf88  00000001
04f6cf8c  00000000
04f6cf90  00000000
04f6cf94  00000000
04f6cf98  00000000
04f6cf9c  04f6d44c
04f6cfa0  75851c2f 3rdPartyHook+0×1c2f
04f6cfa4  04f6d1e8
04f6cfa8  00000000
04f6cfac  00000000
04f6cfb0  00000000
04f6cfb4  00000000
[…]

The symbolic references point to valid and sound code:

0:000> ub 75851c2f
3rdPartyHook!GetData+0x22d:
75851c1d c20c00          ret     0Ch
75851c20 8b4dfc          mov     ecx,dword ptr [ebp-4]
75851c23 5f              pop     edi
75851c24 5e              pop     esi
75851c25 33cd            xor     ecx,ebp
75851c27 33c0            xor     eax,eax
75851c29 5b              pop     ebx
75851c2a e8590f0000      call    3rdPartyHook!__security_check_cookie (75852b88)

0:000> u 75851c2f
3rdPartyHook!GetData+0x23f:
75851c2f 8be5            mov     esp,ebp
75851c31 5d              pop     ebp
75851c32 c20c00          ret     0Ch
75851c35 cc              int     3
75851c36 cc              int     3
75851c37 cc              int     3
75851c38 cc              int     3
75851c39 cc              int     3
 

We also see the other 4th-party module that we know as patching from our past experience:

[...]
04f6f850  00000000
04f6f854  00000000
04f6f858  00000000
04f6f85c  00000000
04f6f860  1000c200 4thPartyHook!Shared+0×80
04f6f864  00000000
04f6f868  04f6f87c
04f6f86c  00000001
04f6f870  00000000
04f6f874  00000000
04f6f878  00000000
04f6f87c  0000006c
[…]

The address 1000c200 looks suspicious and coincidental as the set of flags. However, when we disassemble the address, we see the valid and sound code and the module seems to be loaded at 0×10000000 address:

0:000> ub 1000c200
4thPartyHook!Shared+0x80:
1000c1e8 e8234effff      call    10001010
1000c1ed a160020710      mov     eax,dword ptr [10070260]
1000c1f2 83c418          add     esp,18h
1000c1f5 8b750c          mov     esi,dword ptr [ebp+0Ch]
1000c1f8 85f6            test    esi,esi
1000c1fa 7530            jne     1000c22c
1000c1fc 85c0            test    eax,eax
1000c1fe 742c            je      1000c22c

0:000> u 1000c200
4thPartyHook!Shared+0x80:
1000c200 8b08            mov     ecx,dword ptr [eax]
1000c202 8b5004          mov     edx,dword ptr [eax+4]
1000c205 53              push    ebx
1000c206 8bd9            mov     ebx,ecx
1000c208 0bda            or      ebx,edx
1000c20a 5b              pop     ebx
1000c20b 741f            je      1000c22c
1000c20d f6400801        test    byte ptr [eax+8],1

0:000> !dh 10000000
[...]
File Type: DLL
FILE HEADER VALUES
     14C machine (i386)
       5 number of sections
       0 file pointer to symbol table
       0 number of symbols
      E0 size of optional header
    2102 characteristics
            Executable
            32 bit word machine
            DLL
[...]
OPTIONAL HEADER VALUES
     10B magic #
    8.00 linker version
   62000 size of code
   15000 size of initialized data
       0 size of uninitialized data
   3E1B6 address of entry point
    1000 base of code
         ----- new -----
10000000 image base
    1000 section alignment
    1000 file alignment
       2 subsystem (Windows GUI)
    4.00 operating system version
    0.00 image version
    4.00 subsystem version
   7A000 size of image
    1000 size of headers
[...]

0:000> lm
start    end        module name
00400000 00425000   App        
[...]
10000000 1007a000   4thPartyHook
[...]  

The recommendation I usually give in such cases it to remove or disable 3rd- and 4th-party products that do code patching to see if this resolves the problem. This makes the module list internally clean and if the problem persists then we should look for another causes and restore 3rd- and 4th-party products.

- Dmitry Vostokov @ DumpAnalysis.org -

After coming back to engineering I decided to expand the domain of my research and start the new series of posts called Trace Analysis Patterns. In addition to Citrix CDF / Microsoft ETW traces I plan to cover other variants based on my extensive software engineering background in the past where I used tracing in software products ranging from soft multi-platform real-time systems to static code analysis tools. Connection with memory dump analysis will be covered too because sometimes the combination of static and dynamic data leads to interesting observations and helps to troubleshoot and resolve customer problems especially when not all data can be collected dynamically.

In fact, stack traces and their collections are specializations of the more general traces. Another example is historical information in memory dump files especially when it is somehow timestamped.  

In this part I start with the obvious and to some extent the trivial pattern called Periodic Error. This is an error or a status value that is observed periodically many times:

No     PID  TID   Date      Time         Statement
[...]
664957 1788 22504 4/23/2009 17:59:14.600 MyClass::Initialize: Cannot open connection “Client ID: 310″, status=5  
[…]
668834 1788 19868 4/23/2009 19:11:52.979 MyClass::Initialize: Cannot open connection “Client ID: 612″, status=5 
[…]

or 

No     PID  TID   Date      Time         Statement
[...] 
202314 1788 19128 4/21/2009 16:03:46.861 HandleDataLevel: Error 12005 Getting Mask
[…]
347653 1788 17812 4/22/2009 13:26:00.735 HandleDataLevel: Error 12005 Getting Mask
[…]

Here single trace entries can be isolated from the trace and studied in detail. 

Be aware though that some modules might report periodic errors that are false positive, in the sense, that they are expected as a part of implementation details, for example, when a function returns an error to indicate that bigger buffer is required or to estimate its size for a subsequent call. It merits its own pattern name and I come to it next time with more examples.

I also created a page where I’ll will be adding all tracing patterns:

Trace Analysis Patterns   

- Dmitry Vostokov @ TraceAnalysis.org -

I’m RARE rule #5 says:

“Provide appropriate explanations and narrative in the cases where analysis is inconclusive”.

Here is the typical example of such case when a kernel dump was taken with the vague description about server problems. The dump file analysis revealed the following abnormal conditions warranting further troubleshooting steps:

The AppA.exe, the part of the customer product, is about 1Gb in size when its typical size should be no more than 200Mb. Perhaps we have a memory leak here. We can suggest to take a few consecutive memory dumps of the growing memory and analyze it later as described in a heap leak pattern. This can also be a .NET leak too if unmanaged AppA.exe happened to load any managed components through 3rd-party DLLs. It could be also  some unknown loaded component reserved and committed large portion of virtual memory space.

0: kd> !vm
[...]
0eec AppA.exe        241366 (    965464 Kb)
03c0 svchost.exe      10304 (     41216 Kb)
0230 lsass.exe         8764 (     35056 Kb)
0298 svchost.exe       6402 (     25608 Kb)
01f4 winlogon.exe      5787 (     23148 Kb)
[…]

We can confirm the absence of handle leaks:

0: kd> !process 0eec
Searching for Process with Cid == eec
Cid Handle table at fffffa80014d6000 with 794 Entries in use
PROCESS fffffade6e601860
    SessionId: 0  Cid: 0eec    Peb: 7efdf000  ParentCid: 0eb8
    DirBase: b10fa000  ObjectTable: fffffa8000c39170  HandleCount: 865.
    Image: AppA.exe
    VadRoot fffffade68d7e580 Vads 1961 Clone 0 Private 237843. Modified 77. Locked 1.
    DeviceMap fffffa8001221580
    Token                             fffffa8001fdebe0
    ElapsedTime                       6 Days 22:18:09.271
    UserTime                          00:23:00.406
    KernelTime                        00:27:31.281
    QuotaPoolUsage[PagedPool]         106968
    QuotaPoolUsage[NonPagedPool]      19055186
    Working Set Sizes (now,min,max)  (240529, 50, 345) (962116KB, 200KB, 1380KB)
    PeakWorkingSetSize                240671
    VirtualSize                       1244 Mb
    PeakVirtualSize                   1246 Mb
    PageFaultCount                    244053
    MemoryPriority                    BACKGROUND
    BasePriority                      8
    CommitCharge                      241366

Kernel and user times seem high (about 30 minutes) but it correlates with almost 7 day extensive application usage that involves constant database access.

Looking further at running processes we see that the crucial AppB and AppC applications that were supposed to be running to serve user requests are orphaned:

09e8 AppB.exe            0 (         0 Kb)
09c0 AppC.exe            0 (         0 Kb)

Were they closed normally, forcefully terminated after being hang or crashed? These questions should be asked and appropriate measures taken to capture crash dumps in case event logs reveal access violations.

- Dmitry Vostokov @ DumpAnalysis.org -

Before we explain stages of the analysis process shown in Part 1, let’s start with a brief overview of memory dumps, debuggers and logs. Recall that a memory dump is a snapshot of a process, system or physical memory state. This unifies post-mortem analysis and live debugging. Debuggers are tools that allow us to get and modify these memory snapshots. Other tools that allow us to get memory dump files are process dumpers like userdump.exe, Task Manager since Vista, WER, and system dumpers like LiveKd and Win32dd. We should not forget tools and methods that allow us to trigger Windows kernel ability to save consistent memory dump files: NMI button, keyboard method and various software bugcheck-triggers like Citrix SystemDump. Now coming back to debuggers. One of their essential features is to save a debugging session log, formatted textual output saved in a text file for further processing. One good example is !process 0 ff WinDbg command to output all processes and their thread stack traces (see Stack Trace Collection pattern for other variations). 

I’ve created a page to add all P-DMA parts as soon as I write them:

Pattern-Driven Memory Analysis

- 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 - 

Last week I had an opportunity to present a pattern-driven memory dump analysis methodology at a global engineering conference. Now in a series of articles I’m going to clarify certain points and extend it to wider domain of memory analysis including computer memory forensics and intelligence.

Today I post the reworked picture of a waterfall-like analysis process:

Various phases and their relationship will be discussed in subsequent parts together with examples. 

- Dmitry Vostokov @ DumpAnalysis.org -

I’ve been thinking through the so called First Faults after Dan Skwire, a veteran in mission-critical computer system  problem resolution, problem prevention, and system recovery, organized a group on LinkedIn for first fault problem solving activity. He also has a website:

http://www.firstfaultproblemresolution.com/ 

From my software technical support experience first fault problem resolution is very important on Windows platforms, especially in enterprise terminal service and virtualized environments where hundreds of users can be hosted on just one server. Therefore, proper tools, processes and checklists need to be set up and established for effective and efficient troubleshooting and problem resolution from both engineering and customer relationship managing perspectives. Here crash and hang dump analysis helps immensely, especially memory analysis patterns and fault databases. More on this later with specific examples. I’m also working currently on incorporating first fault problem resolution into VERSION troubleshooting steps and PARTS troubleshooting methodology.

- Dmitry Vostokov @ DumpAnalysis.org -

As one of the new initiatives for the Year of Debugging  DumpAnalysis Portal will publish bimonthly full color 16 page publication called:

Debugged! MZ/PE: MagaZine for/from Practicing Engineers
The only serial publication dedicated entirely to Windows® debugging

The first issue is planned for March, 2009 and will have ISBN-13: 978-1-906717-38-4. If it goes well I’m planning to have ISSN number assigned to it too. More details will be announced soon.

- Dmitry Vostokov @ DumpAnalysis.org - 

This “Hamlet’s Question” of software technical support is often asked and unfortunately sometimes not even asked at all when troubleshooting and debugging complex enterprise environments. For applications the question of saving crash dumps is trivial. If a process is not in memory and not visible in Task Manager we won’t be able to dump it manually. With OS always running even when hanging the question often degenerates to “Let’s bugcheck and send the crash dump to dump file divers”. After that decision huge amounts of energy are spent in collecting, sending and storing gigabytes of data with always very little or no return. Therefore here is the preliminary list of symptoms where manual system dumps are appropriate and when they are not:

When a manual system dump is appropriate

• - The system hangs visually (no GUI activity possible)

• - No connections or logins are possible

• - Abnormal system metrics (like pool, thread or process number growth)

• - Insufficient system or session memory

When a manual process user dump is more appropriate than a complete memory dump

• - Process hangs visually (other applications work as normal)

• - Error message box appears

• - Abnormal process metrics (like process memory growth or handle leaks)

When manual kernel and complete memory dumps are almost useless (I say almost because in rare circumstances they can aid in problem resolution so it is better not to collect them until explicitly asked from skilled memory dump file diver)

• - Application failures resulted in their disappearance from the list of running processes

• - Functional bugs (dynamic activity that requires historical tracing of events)

Note: 3rd-party kernel mode software developers should not face this question during the development of their drivers and delegate the responsibility for difficult bugcheck or panic decisions to an operating system. Surely Windows core developers face this question too.

Next we discuss another related question about choosing between kernel and complete memory dump options in Control Panel. 

- Dmitry Vostokov @ DumpAnalysis.org -

It is not about me. It is the reciprocal counterpart to Five golden rules of troubleshooting. Whereas the former are for artefact submitters, internal and external customers of memory dump analysts and complex trace readers, I‘m RARE are rules for writing analysis reports with easy to remember mnemonic:

I‘m RARE  - Iridium Rules of Analysis Report Excellence

Note about Iridium metal from Wikipedia: “It is one of the rarest elements in the Earth’s crust, with annual production and consumption of only three tonnes.” 

Here is the draft number 5 of them (subject to change in the forthcoming weeks):

1. Use a template.

2. Structure a report according to audience technical level and organizational processes.

3. Use checklists not only for commands and tools but also for things to avoid in reports and things to encourage.

4. Put all relevant data for later search and for other engineers to reproduce the analysis.

5. Provide appropriate explanations and narrative in the cases where analysis is inconclusive.

This also needs to be integrated with PARTS methodology. 

- Dmitry Vostokov @ DumpAnalysis.org -

Paperback edition of Memory Dump Analysis Anthology, Volume 2 is finally available on Amazon and Barnes & Noble. Search Inside is also available on Amazon. In addition, I updated the list of recommended books:

Listmania! Crash Dump Analysis and Debugging

Hardcover edition will be available on Amazon and B&N in 2-3 weeks.

- Dmitry Vostokov @ DumpAnalysis.org -

This one is called No Question and is summarized by the following dialog that I observed many times:

As an engineer proceeds with analysis of a problem a phone rings and an irritated customer (internal or external) asks “What is the answer?”, an engineer glancing over the problem description replies, “What is the question?”.

This immediately came to my mind when I found this famous dialog:

“As the poet Gertrude Stein lay on her deathbed, her partner, Alice B. Toklas, leaned over and whispered, ‘What is the answer, Gertrude?’. Replied Stein, ‘What’s the question?’”

- Dmitry Vostokov @ DumpAnalysis.org -

“Good” troubleshooters “see analogies between” applications “or” services, “the very best ones see analogies between analogies.”

Stefan Banach

- Dmitry Vostokov @ DumpAnalysis.org -

Crash dumps “have another hypnotic effect. Because they are not immediately understood, they, like certain jokes, are suspected of holding in some sort of magic embrace the secret of” troubleshooting, “or at least some of its more” difficult “parts.”

Scott Milross Buchanan, Poetry and Mathematics

- Dmitry Vostokov @ DumpAnalysis.org -

“Everything is memory dump.”

I’m very excited to announce that Volume 2 is available in paperback, hardcover and digital editions:

Memory Dump Analysis Anthology, Volume 2

In one or two weeks paperback edition should also appear on Amazon and other bookstores. Amazon hardcover edition is planned to be available by the end of October.

I’m often asked when Volume 3 is available and I currently plan to release it in October - November, 2009. In the mean time I’m planning to concentrate on other publishing projects. 

- Dmitry Vostokov @ DumpAnalysis.org -

The book is nearly finished and here is the final TOC:

Memory Dump Analysis Anthology, Volume 2: Table of Contents

- Dmitry Vostokov @ DumpAnalysis.org -

Sometimes ETW (or CDF) traces can be really huge. Unless we trace the elusive but the specific error we already know about, there is no need to make such traces if we can reproduce the issue. My favourite example is connectivity problems when you cannot connect to a terminal server. The best way is to start tracing, try to connect, get an error and stop tracing. Usually it takes no more than a couple of minutes. We can even trace all modules here just to make sure that we don’t miss anything. It is also better to focus on one specific scenario per one lean trace instead of packing several of them into one big trace.

- Dmitry Vostokov @ DumpAnalysis.org -

How does software change in production environment? My experience suggests 3 major ways:

1. Executive decision to replace the whole software product with another competing product.
2. Software troubleshooting at component level like upgrading or eliminating suspicious components and unrelated products that influence behaviour.
3. Correction of individual components after debugging to address implementation and functional defects, non-functional, design or architecture deficiencies.

This can be shown on the following rough diagram (excluding possible overlapping of levels) highlighting the often hidden role of memory dump analysis in software change:

- Dmitry Vostokov @ DumpAnalysis.org -

Often engineers spend 10 minutes pursuing a certain investigation path and then prematurely closing it and switching to another. This is what I call Myopic Troubleshooting and Debugging.

This anti-pattern name was inspired by Daniel Dennett’s discussion of insufficiently patient scientists doing computer simulations:

“mistaking a failure of imagination for an insight into necessity” (Darwin’s Dangerous Idea, page 175).

Paraphrasing we can say that engineers think of impossibility where their imagination fails.

- Dmitry Vostokov @ DumpAnalysis.org -

Problem Analysis and Resolution Troubleshooting System (PARTS) is the new troubleshooting methodology for critical problem analysis and resolution. It consists of Problem Analysis and Resolution Tasks (PARTs). The motivation to create this system came to me after looking at various software support processes in various companies around the globe, how they relate to software engineering methodologies and the scientific method, and finally after looking at “The Master Key System” devised by Charles Haanel almost 100 years ago. Borrowing the idea of “Creative Power of Thought” I subtitle PARTS as Problem Solving Power of Thought.

PARTS (Problem Analysis and Resolution Troubleshooting System): Problem Solving Power of Thought.

More on this later.

- Dmitry Vostokov @ DumpAnalysis.org -