Software Diagnostics Library

Crash Dump Analysis Patterns (Part 32)

October 23rd, 2007

When we look at a thread and it is not in the Passive Thread list and looks more like Blocked Thread we may ask whether it is Main Thread. Every process has at least one thread of execution called main or primary thread. Most GUI applications have window message processing loop inside their main process thread. When a memory dump is saved it is most likely that this thread is blocked waiting for window or user-defined messages to arrive and can be considered as Passive Thread. If we see it blocked on something else waiting for some time we may consider that the application was hanging.

Here is an example of the normal iexplore.exe thread stack taken from a kernel dump:

PROCESS 88de4140 SessionId: 3 Cid: 15a8 Peb: 7ffdf000 ParentCid: 0e28 DirBase: 0a43df40 ObjectTable: 88efe008 TableSize: 852. Image: IEXPLORE.EXE VadRoot 88dbbca8 Clone 0 Private 6604. Modified 951. Locked 0. DeviceMap 88de6408 Token e3f5ccf0 ElapsedTime 0:10:52.0281 UserTime 0:00:06.0250 KernelTime 0:00:10.0421 QuotaPoolUsage[PagedPool] 126784 QuotaPoolUsage[NonPagedPool] 197704 Working Set Sizes (now,min,max) (8347, 50, 345) (33388KB, 200KB, 1380KB) PeakWorkingSetSize 10000 VirtualSize 280 Mb PeakVirtualSize 291 Mb PageFaultCount 15627 MemoryPriority FOREGROUND BasePriority 8 CommitCharge 7440

THREAD 88ee2b00 Cid 15a8.1654 Teb: 7ffde000 Win32Thread: a2242018 WAIT: (WrUserRequest) UserMode Non-Alertable 88f82ee0 SynchronizationEvent Not impersonating Owning Process 88de4140 Wait Start TickCount 104916 Elapsed Ticks: 0 Context Switch Count 100208 LargeStack UserTime 0:00:04.0484 KernelTime 0:00:09.0859 Start Address KERNEL32!BaseProcessStartThunk (0x7c57b70c) Stack Init be597000 Current be596cc8 Base be597000 Limit be58f000 Call 0 Priority 12 BasePriority 8 PriorityDecrement 0 DecrementCount 0

ChildEBP RetAddr be596ce0 8042d8d7 nt!KiSwapThread+0x1b1 be596d08 a00019c2 nt!KeWaitForSingleObject+0x1a3 be596d44 a00138c5 win32k!xxxSleepThread+0x18a be596d54 a00138d1 win32k!xxxWaitMessage+0xe be596d5c 8046b2a9 win32k!NtUserWaitMessage+0xb be596d5c 77e3c7cd nt!KiSystemService+0xc9

In the same kernel dump there is another iexplore.exe process with the following main thread stack which had been blocked for 31 seconds:

PROCESS 8811ca00 SessionId: 21 Cid: 4d18 Peb: 7ffdf000 ParentCid: 34c8 DirBase: 0a086ee0 ObjectTable: 87d07528 TableSize: 677. Image: IEXPLORE.EXE VadRoot 87a92ae8 Clone 0 Private 4600. Modified 227. Locked 0. DeviceMap 88b174e8 Token e49508d0 ElapsedTime 0:08:03.0062 UserTime 0:00:01.0531 KernelTime 0:00:10.0375 QuotaPoolUsage[PagedPool] 120792 QuotaPoolUsage[NonPagedPool] 198376 Working Set Sizes (now,min,max) (7726, 50, 345) (30904KB, 200KB, 1380KB) PeakWorkingSetSize 7735 VirtualSize 272 Mb PeakVirtualSize 275 Mb PageFaultCount 11688 MemoryPriority BACKGROUND BasePriority 8 CommitCharge 6498

THREAD 87ce6da0 Cid 4d18.4c68 Teb: 7ffde000 Win32Thread: a22157b8 WAIT: (Executive) KernelMode Non-Alertable b5bd6370 NotificationEvent IRP List: 885d4808: (0006,00dc) Flags: 00000014 Mdl: 00000000 Not impersonating Owning Process 8811ca00 Wait Start TickCount 102908 Elapsed Ticks: 2008 Context Switch Count 130138 LargeStack UserTime 0:00:01.0125 KernelTime 0:00:08.0843 Start Address KERNEL32!BaseProcessStartThunk (0×7c57b70c) Stack Init b5bd7000 Current b5bd62f4 Base b5bd7000 Limit b5bcf000 Call 0 Priority 8 BasePriority 8 PriorityDecrement 0 DecrementCount 0

ChildEBP RetAddr b5bd630c 8042d8d7 nt!KiSwapThread+0x1b1 b5bd6334 bf09342d nt!KeWaitForSingleObject+0x1a3 b5bd6380 bf08896f mrxsmb!SmbCeAssociateExchangeWithMid+0x24b b5bd63b0 bf0aa0ef mrxsmb!SmbCeTranceive+0xff b5bd6490 bf0a92df mrxsmb!SmbTransactExchangeStart+0x559 b5bd64a8 bf0a9987 mrxsmb!SmbCeInitiateExchange+0x2ac b5bd64c4 bf0a96e2 mrxsmb!SmbCeSubmitTransactionRequest+0x124 b5bd6524 bf0ac7c3 mrxsmb!_SmbCeTransact+0x86 b5bd6608 bf104ea0 mrxsmb!MRxSmbQueryFileInformation+0x553 b5bd66b4 bf103aff rdbss!__RxInitializeTopLevelIrpContext+0x52 b5bd6784 bf10da73 rdbss!WPP_SF_ZL+0x4b b5bd67b4 bf0a8b29 rdbss!RxCleanupPipeQueues+0x117 b5bd67d4 8041ef05 mrxsmb!MRxSmbFsdDispatch+0x118 b5bd67e8 eb833839 nt!IopfCallDriver+0x35 b5bd6890 804a8109 nt!IopQueryXxxInformation+0x164 b5bd68b0 804c7d63 nt!IoQueryFileInformation+0x19 b5bd6a4c 80456562 nt!IopParseDevice+0xe8f b5bd6ac4 804de0c0 nt!ObpLookupObjectName+0x504 b5bd6bd4 804a929b nt!ObOpenObjectByName+0xc8 b5bd6d54 8046b2a9 nt!NtQueryFullAttributesFile+0xe7 b5bd6d54 77f88887 nt!KiSystemService+0xc9

0: kd> !whattime 0n2008 2008 Ticks in Standard Time: 31.375s

Main thread need not be GUI thread. Most input console applications have ReadConsole calls in normal main process thread stack:

0:000> kL ChildEBP RetAddr 0012fc6c 77d20190 ntdll!KiFastSystemCallRet 0012fc70 77d27fdf ntdll!NtRequestWaitReplyPort+0xc 0012fc90 765d705c ntdll!CsrClientCallServer+0xc2 0012fd8c 76634674 kernel32!ReadConsoleInternal+0x1cd 0012fe14 765eaf6a kernel32!ReadConsoleA+0×40 0012fe7c 6ec35196 kernel32!ReadFile+0×84 0012fec0 6ec35616 MSVCR80!_read_nolock+0×201 0012ff04 6ec45928 MSVCR80!_read+0xc0 0012ff1c 6ec49e47 MSVCR80!_filbuf+0×78 0012ff54 0040100d MSVCR80!getc+0×113 0012ff5c 0040117c ConsoleTest!wmain+0xd 0012ffa0 765d3833 ConsoleTest!__tmainCRTStartup+0×10f 0012ffac 77cfa9bd kernel32!BaseThreadInitThunk+0xe 0012ffec 00000000 ntdll!_RtlUserThreadStart+0×23

0:000> kL ChildEBP RetAddr 001cf594 77d20190 ntdll!KiFastSystemCallRet 001cf598 77d27fdf ntdll!NtRequestWaitReplyPort+0xc 001cf5b8 765d705c ntdll!CsrClientCallServer+0xc2 001cf6b4 765d6efe kernel32!ReadConsoleInternal+0x1cd 001cf740 49ecd538 kernel32!ReadConsoleW+0×47 001cf7a8 49ecd645 cmd!ReadBufFromConsole+0xb5 001cf7d4 49ec2247 cmd!FillBuf+0×175 001cf7d8 49ec2165 cmd!GetByte+0×11 001cf7f4 49ec20d8 cmd!Lex+0×75 001cf80c 49ec207f cmd!GeToken+0×27 001cf81c 49ec200a cmd!ParseStatement+0×36 001cf830 49ec6038 cmd!Parser+0×46 001cf878 49ecc703 cmd!main+0×1de 001cf8bc 765d3833 cmd!_initterm_e+0×163 001cf8c8 77cfa9bd kernel32!BaseThreadInitThunk+0xe 001cf908 00000000 ntdll!_RtlUserThreadStart+0×23

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns, Debugging | 7 Comments »

Old dumps, new extensions

October 23rd, 2007

Up to now I’ve been using old Windows 2000 WinDbg extensions to extract information from Windows 2003 and XP crash dumps when their native extensions failed. Today I have found I can do the way around, to extract information from old Windows 2000 crash dumps using WinDbg extensions written for Windows XP and later. Here is an example. WinDbg !stacks command shows the following not really helpful output from Windows 2000 complete memory dump:

2: kd> !stacks Proc.Thread Thread Ticks ThreadState Blocker [System] 8.000004 89df8220 0000000 BLOCKED nt!KiSwapThread+0x1b1 8.00000c 89dc1860 0003734 BLOCKED nt!KiSwapThread+0x1b1 8.000010 89dc15e0 0003734 BLOCKED nt!KiSwapThread+0x1b1 8.000014 89dc1360 00003b4 BLOCKED nt!KiSwapThread+0x1b1 8.000018 89dc10e0 0003734 BLOCKED nt!KiSwapThread+0x1b1 8.00001c 89dc0020 0000381 BLOCKED nt!KiSwapThread+0x1b1 8.000020 89dc0da0 00066f6 BLOCKED nt!KiSwapThread+0x1b1 8.000024 89dc0b20 00025b4 BLOCKED nt!KiSwapThread+0x1b1 8.000028 89dc08a0 00025b4 BLOCKED nt!KiSwapThread+0x1b1 8.00002c 89dc0620 0003734 BLOCKED nt!KiSwapThread+0x1b1 8.000030 89dc03a0 0003734 BLOCKED nt!KiSwapThread+0x1b1 8.000034 89dbf020 00025b4 BLOCKED nt!KiSwapThread+0x1b1 8.000038 89dbfda0 00025b4 BLOCKED nt!KiSwapThread+0x1b1 8.00003c 89dbfb20 00007b4 BLOCKED nt!KiSwapThread+0x1b1 8.000040 89dbf8a0 00007b4 BLOCKED nt!KiSwapThread+0x1b1 8.000044 89dbf620 0000074 BLOCKED nt!KiSwapThread+0x1b1 8.000048 89dbf3a0 00007b4 BLOCKED nt!KiSwapThread+0x1b1 ... ... ...

This command belongs to different WinDbg extension DLLs (from WinDbg help):

Windows NT 4.0 Unavailable Windows 2000 Kdextx86.dll Windows XP and later Kdexts.dll

and I tried newer kdexts.dll with better results:

2: kd> !winxp\kdexts.stacks Proc.Thread .Thread Ticks ThreadState Blocker [89df84a0 System] 8.0000c8 89db77c0 0000000 Blocked nt!MiRemoveUnusedSegments+0xf4 8.0000f0 89c8a020 0019607 Blocked cpqasm2+0x1ef0 8.000108 89881900 0000085 Blocked CPQCISSE+0x3ae8 8.000110 8982cda0 000000a Blocked cpqasm2+0x2a523 8.00013c 8974a9a0 00007d7 Blocked rdbss!RxSetMinirdrCancelRoutine+0x3d 8.000148 89747b20 000010a Blocked rdbss!RxIsOkToPurgeFcb+0x3f 8.00014c 89758a80 0019493 Blocked nt!NtNotifyChangeMultipleKeys+0x434 8.0002dc 89620680 000000e Blocked cpqasm2+0x5523 8.0002e0 89620400 00000d2 Blocked cpqasm2+0x584d 8.0004ac 895ae9c0 000955b Blocked srv!SrvOemStringTo8dot3+0xb7 8.0004c0 8937b4e0 0018fea Blocked srv!SrvOemStringTo8dot3+0xb7 8.0004a0 895b09e0 0018fe9 Blocked srv!SrvOemStringTo8dot3+0xb7 8.0004cc 893784e0 0018fe8 Blocked srv!SrvOemStringTo8dot3+0xb7 8.0004d0 893774e0 000955b Blocked srv!SrvOemStringTo8dot3+0xb7 8.0004d4 893764e0 0018fe8 Blocked srv!SrvOemStringTo8dot3+0xb7 8.003d68 87abb580 00000b7 Blocked rdbss!RxSearchForCollapsibleOpen+0x17c 8.002b94 88e4f180 00000b9 Blocked rdbss!RxSearchForCollapsibleOpen+0x17c

[89736940 smss.exe]

[896d3b20 csrss.exe] 178.000180 896c8020 0000012 Blocked ntdll!NtReplyWaitReceivePort+0xb 178.00018c 896c5320 0000012 Blocked ntdll!NtReplyWaitReceivePort+0xb 178.001260 88fbcb20 0000060 Blocked ntdll!NtReplyWaitReceivePort+0xb 178.001268 88fbbda0 0000060 Blocked ntdll!NtReplyWaitReceivePort+0xb

[896c8740 WINLOGON.EXE] 174.00019c 896b7740 0000299 Blocked ntdll!ZwDelayExecution+0xb 174.0001a0 896b6020 00015dd Blocked ntdll!NtRemoveIoCompletion+0xb 174.000f08 8913eda0 00000b0 Blocked ntdll!ZwWaitForMultipleObjects+0xb 174.000f0c 8901b020 00000b0 Blocked ntdll!ZwWaitForSingleObject+0xb

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Debugging, Tools, WinDbg Tips and Tricks | No Comments »

The search for ‘Ddk’ tag

October 22nd, 2007

Sometimes we get pool allocation failures and the driver’s tag is ‘Ddk’:

0: kd> !vm

*** Virtual Memory Usage *** Physical Memory: 851775 ( 3407100 Kb) Page File: \??\C:\pagefile.sys Current: 4190208 Kb Free Space: 4175708 Kb Minimum: 4190208 Kb Maximum: 4190208 Kb Available Pages: 147274 ( 589096 Kb) ResAvail Pages: 769287 ( 3077148 Kb) Locked IO Pages: 118 ( 472 Kb) Free System PTEs: 184910 ( 739640 Kb) Free NP PTEs: 110 ( 440 Kb) Free Special NP: 0 ( 0 Kb) Modified Pages: 168 ( 672 Kb) Modified PF Pages: 168 ( 672 Kb) NonPagedPool Usage: 64445 ( 257780 Kb) NonPagedPool Max: 64640 ( 258560 Kb) ********** Excessive NonPaged Pool Usage ***** PagedPool 0 Usage: 21912 ( 87648 Kb) PagedPool 1 Usage: 691 ( 2764 Kb) PagedPool 2 Usage: 706 ( 2824 Kb) PagedPool 3 Usage: 704 ( 2816 Kb) PagedPool 4 Usage: 708 ( 2832 Kb) PagedPool Usage: 24721 ( 98884 Kb) PagedPool Maximum: 134144 ( 536576 Kb)

********** 429 pool allocations have failed **********

Shared Commit: 5274 ( 21096 Kb) Special Pool: 0 ( 0 Kb) Shared Process: 3958 ( 15832 Kb) PagedPool Commit: 24785 ( 99140 Kb) Driver Commit: 19289 ( 77156 Kb) Committed pages: 646282 ( 2585128 Kb) Commit limit: 1860990 ( 7443960 Kb)

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

Pool Used: NonPaged Tag Allocs Frees Diff Used Ddk 9074558 3859522 5215036 225708304 Default for driver allocated memory (user’s of ntddk.h)

How do we find which driver had caused this memory leak? We can search for drivers using the following command:

C:\>findstr /S /m /l hDdk *.sys

or we can guess the driver using the fact that long time ago ExAllocatePool was defined as ExAllocatePoolWithTag(, … ‘Ddk ‘). Currently all DDK samples use their separate driver tags and ExAllocatePool uses ‘None’:

0: kd> .asm no_code_bytes Assembly options: no_code_bytes

0: kd> uf ExAllocatePool nt!ExAllocatePool: 80894d1f mov edi,edi 80894d21 push ebp 80894d22 mov ebp,esp 80894d24 push 656E6F4Eh 80894d29 push dword ptr [ebp+0Ch] 80894d2c push dword ptr [ebp+8] 80894d2f call nt!ExAllocatePoolWithTag (8089b93f) 80894d34 pop ebp 80894d35 ret 8

0: kd> .formats 656E6F4Eh Evaluate expression: Hex: 656e6f4e Decimal: 1701736270 Octal: 14533467516 Binary: 01100101 01101110 01101111 01001110 Chars: enoN Time: Tue Dec 05 00:31:10 2023 Float: low 7.03735e+022 high 0 Double: 8.40769e-315

Note: we push ‘None’ but see ‘enoN’ in memory because of little endian byte ordering.

Most of the recent drivers use their own tags and it is common not to encounter ‘None’ at all:

kd> !poolused Sorting by Tag

Pool Used: NonPaged Paged Tag Allocs Used Allocs Used ... ... ... None 0 0 1 8192 call to ExAllocatePool … …

Therefore the driver must be old and if we see most drivers dated 2006-2007 and some dated 1998-2001 the chances are that 2001 drivers were responsible for our memory leak:

b9840000 b9842980 newdriver Sat Feb 10 00:33:41 2007 (45CD12E5) b8cfa000 b8d39e00 olddriver Tue Aug 21 12:18:35 2001 (3B82438B) f79e5000 f79e6400 veryolddriver Wed Sep 23 13:09:52 1998 (3608E510)

However veryolddriver.sys doesn’t use ExAllocatePoolWithTag so olddriver.sys is under suspicion:

0: kd> !dh f79e5000 ... ... ... A00 [ 33] address [size] of Export Directory C00 [ 3C] address [size] of Import Directory E00 [ 3A4] address [size] of Resource Directory 0 [ 0] address [size] of Exception Directory 0 [ 0] address [size] of Security Directory 1200 [ 34] address [size] of Base Relocation Directory 440 [ 54] address [size] of Debug Directory 0 [ 0] address [size] of Description Directory 0 [ 0] address [size] of Special Directory 0 [ 0] address [size] of Thread Storage Directory 0 [ 0] address [size] of Load Configuration Directory 0 [ 0] address [size] of Bound Import Directory 400 [ 34] address [size] of Import Address Table Directory 0 [ 0] address [size] of Delay Import Directory 0 [ 0] address [size] of COR20 Header Directory 0 [ 0] address [size] of Reserved Directory … … …

0: kd> dds f79e5000+400 f79e5400 80a82264 hal!HalTranslateBusAddress f79e5404 80a84358 hal!READ_PORT_BUFFER_UCHAR f79e5408 00000000 f79e540c 80840bd9 nt!IofCompleteRequest f79e5410 808e8f01 nt!IoCreateSymbolicLink f79e5414 80838035 nt!RtlInitUnicodeString f79e5418 808fbe85 nt!IoDeleteSymbolicLink f79e541c 80816a6e nt!MmUnmapIoSpace f79e5420 808ef1f1 nt!IoCreateDevice f79e5424 80837e3a nt!READ_REGISTER_BUFFER_UCHAR f79e5428 80815fc8 nt!IoDeleteDevice f79e542c 80816814 nt!MmMapIoSpace f79e5430 00000000 f79e5434 00000000

To confirm that olddriver.sys uses ‘Ddk ‘ tag we can search its address space for code that calls ExAllocatePoolWithTag:

b8cfa000 b8d39e00 olddriver Tue Aug 21 12:18:35 2001 (3B82438B)

0: kd> !dh b8cfa000 ... ... ... 0 [ 0] address [size] of Export Directory 3D330 [ 50] address [size] of Import Directory 3DE00 [ 380] address [size] of Resource Directory 0 [ 0] address [size] of Exception Directory 3FE00 [ 88] address [size] of Security Directory 3E180 [ 1BE8] address [size] of Base Relocation Directory 3B640 [ 1C] address [size] of Debug Directory 0 [ 0] address [size] of Description Directory 0 [ 0] address [size] of Special Directory 0 [ 0] address [size] of Thread Storage Directory 0 [ 0] address [size] of Load Configuration Directory 0 [ 0] address [size] of Bound Import Directory 3B480 [ 1B4] address [size] of Import Address Table Directory 0 [ 0] address [size] of Delay Import Directory 0 [ 0] address [size] of COR20 Header Directory 0 [ 0] address [size] of Reserved Directory … … …

0: kd> dds b8cfa000+3B480 b8cfa000+3B480+1B4 b8d35480 80a83dba hal!KeQueryPerformanceCounter b8d35484 80a7e3c0 hal!KfAcquireSpinLock b8d35488 80a7e440 hal!KfReleaseSpinLock b8d3548c 00000000 ... ... ... b8d35544 80812b1a nt!IoWriteErrorLogEntry b8d35548 8081287b nt!IoAllocateErrorLogEntry b8d3554c 8082f12f nt!swprintf b8d35550 8089b93f nt!ExAllocatePoolWithTag b8d35554 8087c465 nt!KeBugCheckEx b8d35558 80815407 nt!wcsncat b8d3555c 8083bc54 nt!ZwQueryValueKey b8d35560 8083affb nt!ZwClose b8d35564 80841a14 nt!_wcsicmp b8d35568 80928d30 nt!ObReferenceObjectByHandle … … …

0: kd> s-d b8cfa000 b8d39e00 b8d35550 b8d19f08 b8d35550 555425ff 25ffb8d3 b8d35480 PU…%TU…%.T.. b8d1a068 b8d35550 ff85f88b 75fc7d89 b85e5f0c PU…….}.u._^. b8d2c4e4 b8d35550 0375c085 89c35d5e 04c08330 PU….u.^]..0…

0: kd> u b8d19f08-2 olddriver!ExAllocatePoolWithTag: b8d19f06 jmp dword ptr [olddriver!_imp__ExAllocatePoolWithTag (b8d35550)]

0: kd> u b8d2c4e4-2 olddriver!malloc+0x12 b8d2c4e2 call dword ptr [olddriver!_imp__ExAllocatePoolWithTag (b8d35550)] b8d2c4e8 test eax,eax b8d2c4ea jne olddriver!malloc+0x1f (b8d2c4ef) b8d2c4ec pop esi b8d2c4ed pop ebp b8d2c4ee ret b8d2c4ef mov dword ptr [eax],esi b8d2c4f1 add eax,4

0: kd> ub b8d1a068-2 olddriver!TraceRoutine+0xc1 b8d1a051 mov esp,ebp b8d1a053 pop ebp b8d1a054 ret b8d1a055 cmp edi,8 b8d1a058 jbe olddriver!TraceRoutine+0x157 (b8d1a0e7) b8d1a05e push 206b6444h b8d1a063 push edx b8d1a064 push 0

0: kd> .formats 206b6444 Evaluate expression: Hex: 206b6444 Decimal: 543908932 Octal: 04032662104 Binary: 00100000 01101011 01100100 01000100 Chars: kdD Time: Sat Mar 28 05:48:52 1987 Float: low 1.99384e-019 high 0 Double: 2.68727e-315

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns | 1 Comment »

Local crash dumps on Vista

October 18th, 2007

It appears that Microsoft decided to help customers to save full user dumps locally for later postmortem analysis. According to MSDN this is done via LocalDumps registry key starting from Vista SP1 and Windows Server 2008:

http://msdn2.microsoft.com/en-us/library/bb787181.aspx

This is a quote from the article above:

[…] Prior to application termination, the system will check the registry settings to determine whether a local dump is to be collected. The registry settings control whether a full dump is collected versus a minidump. The custom flags specified also determine which information is collected in the dump. […] You can make use of the local dump collection even if WER is disabled. The local dumps are collected even if the user cancels WER reporting at any point. […]

From my understanding it is independent from the default postmortem debugger mechanism via AeDebug registry key and might help to solve the problem with native services. I haven’t tried it yet but will do as soon as I install Vista SP1 or install Windows Server 2008 RC0. If it works then dump collection might be easier in production environments because of no need to install Debugging Tools for Windows to set up a postmortem debugger.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Announcements, Crash Dump Analysis, Debugging, Tools, Vista, Windows Server 2008 | 5 Comments »

Crash Dump Analysis Patterns (Part 31)

October 17th, 2007

When trying to understand why the particular application or service hangs we look at Stack Trace Collection and hope to find some suspicious threads that are waiting for a response. These are active blocked threads. Other threads may appear waiting but they are merely waiting for some notification or data which may or may not come during their lifetime and, therefore, are normal. In other words, they are passive and hence the name of the pattern Passive Thread. Typical examples from user space include

- the main service thread and dispatch threads (when idle)
- a thread waiting for file or registry notifications
- a generic RPC/LPC/COM thread waiting for messages
- worker threads waiting for a data to appear in a queue
- window message loops (when idle)
- socket and network protocol threads (when idle)
- a thread with function names on its stack trace suggesting that it is a notification or listener thread

Of course, sometimes these passive threads can be the reason for an application or service hang, but from my experience, most of the time they are not, unless there are other threads which they block. Let’s now look at example stack traces.

Note: Generic threads spawned to service various requests and waiting for data to arrive can be filtered using !uniqstack WinDbg command. Conceptually these threads are part of the so called thread pool software design pattern.

LPC/RPC/COM threads waiting for requests:

70 Id: 8f8.1100 Suspend: 1 Teb: 7ff80000 Unfrozen ChildEBP RetAddr 0d82fe18 7c82783b ntdll!KiFastSystemCallRet 0d82fe1c 77c885ac ntdll!NtReplyWaitReceivePortEx+0xc 0d82ff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198 0d82ff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd 0d82ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 0d82ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 0d82ffec 00000000 kernel32!BaseThreadStart+0x34

71 Id: 8f8.1e44 Suspend: 1 Teb: 7ffde000 Unfrozen ChildEBP RetAddr 0c01fe18 7c82783b ntdll!KiFastSystemCallRet 0c01fe1c 77c885ac ntdll!NtReplyWaitReceivePortEx+0xc 0c01ff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198 0c01ff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd 0c01ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 0c01ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 0c01ffec 00000000 kernel32!BaseThreadStart+0x34

72 Id: 8f8.1804 Suspend: 1 Teb: 7ff90000 Unfrozen ChildEBP RetAddr 0e22fe18 7c82783b ntdll!KiFastSystemCallRet 0e22fe1c 77c885ac ntdll!NtReplyWaitReceivePortEx+0xc 0e22ff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198 0e22ff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd 0e22ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 0e22ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 0e22ffec 00000000 kernel32!BaseThreadStart+0x34

73 Id: 8f8.1860 Suspend: 1 Teb: 7ff79000 Unfrozen ChildEBP RetAddr 0da2fe18 7c82783b ntdll!KiFastSystemCallRet 0da2fe1c 77c885ac ntdll!NtReplyWaitReceivePortEx+0xc 0da2ff84 77c88792 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198 0da2ff8c 77c8872d rpcrt4!RecvLotsaCallsWrapper+0xd 0da2ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 0da2ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 0da2ffec 00000000 kernel32!BaseThreadStart+0x34

74 Id: 8f8.f24 Suspend: 1 Teb: 7ff7e000 Unfrozen ChildEBP RetAddr 0d20feac 7c8277db ntdll!KiFastSystemCallRet 0d20feb0 77e5bea2 ntdll!ZwRemoveIoCompletion+0xc 0d20fedc 77c7b900 kernel32!GetQueuedCompletionStatus+0x29 0d20ff18 77c7b703 rpcrt4!COMMON_ProcessCalls+0xa1 0d20ff84 77c7b9b5 rpcrt4!LOADABLE_TRANSPORT::ProcessIOEvents+0x117 0d20ff8c 77c8872d rpcrt4!ProcessIOEventsWrapper+0xd 0d20ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 0d20ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 0d20ffec 00000000 kernel32!BaseThreadStart+0x34

75 Id: 8f8.11f8 Suspend: 1 Teb: 7ffa1000 Unfrozen ChildEBP RetAddr 08e0feac 7c8277db ntdll!KiFastSystemCallRet 08e0feb0 77e5bea2 ntdll!ZwRemoveIoCompletion+0xc 08e0fedc 77c7b900 kernel32!GetQueuedCompletionStatus+0x29 08e0ff18 77c7b703 rpcrt4!COMMON_ProcessCalls+0xa1 08e0ff84 77c7b9b5 rpcrt4!LOADABLE_TRANSPORT::ProcessIOEvents+0x117 08e0ff8c 77c8872d rpcrt4!ProcessIOEventsWrapper+0xd 08e0ffac 77c7b110 rpcrt4!BaseCachedThreadRoutine+0x9d 08e0ffb8 77e64829 rpcrt4!ThreadStartRoutine+0x1b 08e0ffec 00000000 kernel32!BaseThreadStart+0x34

2 Id: ecc.c94 Suspend: 1 Teb: 7efac000 Unfrozen ChildEBP RetAddr 0382f760 76e31330 ntdll!NtDelayExecution+0x15 0382f7c8 76e30dac kernel32!SleepEx+0x62 0382f7d8 75ec40f4 kernel32!Sleep+0xf 0382f7e4 75eafc0d ole32!CROIDTable::WorkerThreadLoop+0x14 0382f800 75eafc73 ole32!CRpcThread::WorkerLoop+0x26 0382f80c 76ea19f1 ole32!CRpcThreadCache::RpcWorkerThreadEntry+0x20 0382f818 7797d109 kernel32!BaseThreadInitThunk+0xe 0382f858 00000000 ntdll!_RtlUserThreadStart+0x23

Worker threads waiting for data items to process:

43 Id: 8f8.17c0 Suspend: 1 Teb: 7ff8c000 Unfrozen ChildEBP RetAddr 0c64ff20 7c8277db ntdll!KiFastSystemCallRet 0c64ff24 77e5bea2 ntdll!ZwRemoveIoCompletion+0xc 0c64ff50 67823549 kernel32!GetQueuedCompletionStatus+0x29 0c64ff84 77bcb530 component!WorkItemThread+0×1a9 0c64ffb8 77e64829 msvcrt!_endthreadex+0xa3 0c64ffec 00000000 kernel32!BaseThreadStart+0×34

44 Id: 8f8.7b4 Suspend: 1 Teb: 7ff8b000 Unfrozen ChildEBP RetAddr 0c77ff20 7c8277db ntdll!KiFastSystemCallRet 0c77ff24 77e5bea2 ntdll!ZwRemoveIoCompletion+0xc 0c77ff50 67823549 kernel32!GetQueuedCompletionStatus+0x29 0c77ff84 77bcb530 component!WorkItemThread+0×1a9 0c77ffb8 77e64829 msvcrt!_endthreadex+0xa3 0c77ffec 00000000 kernel32!BaseThreadStart+0×34

45 Id: 8f8.1708 Suspend: 1 Teb: 7ff8a000 Unfrozen ChildEBP RetAddr 0c87ff20 7c8277db ntdll!KiFastSystemCallRet 0c87ff24 77e5bea2 ntdll!ZwRemoveIoCompletion+0xc 0c87ff50 67823549 kernel32!GetQueuedCompletionStatus+0x29 0c87ff84 77bcb530 component!WorkItemThread+0×1a9 0c87ffb8 77e64829 msvcrt!_endthreadex+0xa3 0c87ffec 00000000 kernel32!BaseThreadStart+0×34

5 Id: 11fc.16f4 Suspend: 1 Teb: 7ffd9000 Unfrozen ChildEBP RetAddr 0109bf10 7c822124 ntdll!KiFastSystemCallRet 0109bf14 77e6baa8 ntdll!NtWaitForSingleObject+0xc 0109bf84 77e6ba12 kernel32!WaitForSingleObjectEx+0xac 0109bf98 66886519 kernel32!WaitForSingleObject+0x12 0109ff84 77bcb530 component!WorkerThread+0xe8 0109ffb8 77e66063 msvcrt!_endthreadex+0xa3 0109ffec 00000000 kernel32!BaseThreadStart+0x34

A thread waiting for registry change notification:

1 Id: 13c4.350 Suspend: 1 Teb: 000007ff`fffde000 Unfrozen Child-SP RetAddr Call Site 00000000`0012fdd8 000007fe`fd62c361 ntdll!ZwNotifyChangeKey+0xa 00000000`0012fde0 00000001`40001181 ADVAPI32!RegNotifyChangeKeyValue+0×115 00000000`0012ff30 00000000`76d9cdcd sample12!WaitForRegChange+0xe 00000000`0012ff60 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

Idle main service thread and service dispatch threads:

. 0 Id: 65c.660 Suspend: 1 Teb: 000007ff`fffdc000 Unfrozen Child-SP RetAddr Call Site 00000000`0011f2c8 00000000`76d926da ntdll!NtReadFile+0xa 00000000`0011f2d0 000007fe`fd6665aa kernel32!ReadFile+0x8a 00000000`0011f360 000007fe`fd6662e3 ADVAPI32!ScGetPipeInput+0x4a 00000000`0011f440 000007fe`fd6650f3 ADVAPI32!ScDispatcherLoop+0x9a 00000000`0011f540 00000000`ff0423a3 ADVAPI32!StartServiceCtrlDispatcherW+0x176 00000000`0011f7e0 00000000`ff042e66 spoolsv!main+0x23 00000000`0011f850 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0011f880 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

1 Id: 65c.664 Suspend: 1 Teb: 000007ff`fffda000 Unfrozen Child-SP RetAddr Call Site 00000000`0009f9c8 00000000`76d9d820 ntdll!NtWaitForSingleObject+0xa 00000000`0009f9d0 00000000`ff04307f kernel32!WaitForSingleObjectEx+0x9c 00000000`0009fa90 000007fe`fd664bf5 spoolsv!SPOOLER_main+0x80 00000000`0009fac0 00000000`76d9cdcd ADVAPI32!ScSvcctrlThreadW+0x25 00000000`0009faf0 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0009fb20 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

Idle window message loops:

10 Id: 65c.514 Suspend: 1 Teb: 000007ff`fffa2000 Unfrozen Child-SP RetAddr Call Site 00000000`02c5fc18 00000000`76cae6ea USER32!ZwUserGetMessage+0xa 00000000`02c5fc20 000007fe`f88523f0 USER32!GetMessageW+0×34 00000000`02c5fc50 00000000`76d9cdcd usbmon!CPNPNotifications::WindowMessageThread+0×1a0 00000000`02c5fd20 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`02c5fd50 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

11 Id: 65c.9bc Suspend: 1 Teb: 000007ff`fffa0000 Unfrozen Child-SP RetAddr Call Site 00000000`037cf798 00000000`76cae6ea USER32!ZwUserGetMessage+0xa 00000000`037cf7a0 000007fe`f7ea0d3a USER32!GetMessageW+0×34 00000000`037cf7d0 00000000`76d9cdcd WSDMon!Ncd::TPower::WindowMessageThread+0xe6 00000000`037cf870 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`037cf8a0 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

13 Id: ecc.b34 Suspend: 1 Teb: 7ef85000 Unfrozen ChildEBP RetAddr 0621fc18 75b86458 USER32!NtUserGetMessage+0x15 0621fc3c 74aa1404 USER32!GetMessageA+0xa2 0621fc74 76ea19f1 WINMM!mciwindow+0×102 0621fc80 7797d109 kernel32!BaseThreadInitThunk+0xe 0621fcc0 00000000 ntdll!_RtlUserThreadStart+0×23

Idle socket and network protocol threads:

5 Id: ecc.920 Suspend: 1 Teb: 7efa3000 Unfrozen ChildEBP RetAddr 0412f534 751b3b28 ntdll!ZwWaitForSingleObject+0x15 0412f574 751b2690 mswsock!SockWaitForSingleObject+0x19f 0412f660 771d3781 mswsock!WSPSelect+0x38c 0412f6dc 760f60fd ws2_32!select+0x456 0412fa34 760f2a78 WININET!ICAsyncThread::SelectThread+0x242 0412fa3c 76ea19f1 WININET!ICAsyncThread::SelectThreadWrapper+0xd 0412fa48 7797d109 kernel32!BaseThreadInitThunk+0xe 0412fa88 00000000 ntdll!_RtlUserThreadStart+0x23

6 Id: ecc.b1c Suspend: 1 Teb: 7ef9d000 Unfrozen ChildEBP RetAddr 047afa6c 751b1b25 ntdll!NtRemoveIoCompletion+0x15 047afaa4 76ea19f1 mswsock!SockAsyncThread+0x69 047afab0 7797d109 kernel32!BaseThreadInitThunk+0xe 047afaf0 00000000 ntdll!_RtlUserThreadStart+0x23

7 Id: 820.f90 Suspend: 1 Teb: 7ffd9000 Unfrozen ChildEBP RetAddr 018dff84 7c93e9ab ntdll!KiFastSystemCallRet (FPO: [0,0,0]) 018dff88 60620e6c ntdll!ZwWaitForMultipleObjects+0xc 018dffb4 7c80b683 NETAPI32!NetbiosWaiter+0x73 018dffec 00000000 kernel32!BaseThreadStart+0x37

Function names showing passive nature of threads:

8 Id: 65c.b40 Suspend: 1 Teb: 000007ff`fffa6000 Unfrozen Child-SP RetAddr Call Site 00000000`0259fdc8 00000000`76d9d820 ntdll!NtWaitForSingleObject+0xa 00000000`0259fdd0 000007fe`f8258084 kernel32!WaitForSingleObjectEx+0x9c 00000000`0259fe90 000007fe`fee994e7 wsnmp32!thrNotify+0×9c 00000000`0259fef0 000007fe`fee9967d msvcrt!endthreadex+0×47 00000000`0259ff20 00000000`76d9cdcd msvcrt!endthreadex+0×100 00000000`0259ff50 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0259ff80 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

12 Id: 65c.908 Suspend: 1 Teb: 000007ff`fff9e000 Unfrozen Child-SP RetAddr Call Site 00000000`0368fd48 00000000`76d9d820 ntdll!NtWaitForSingleObject+0xa 00000000`0368fd50 000007fe`fa49afd0 kernel32!WaitForSingleObjectEx+0x9c 00000000`0368fe10 00000000`76d9cdcd FunDisc!CNotificationQueue::ThreadProc+0×2ec 00000000`0368fe70 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0368fea0 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

13 Id: 65c.904 Suspend: 1 Teb: 000007ff`fff9c000 Unfrozen Child-SP RetAddr Call Site 00000000`034af9f8 00000000`76d9ed73 ntdll!NtWaitForMultipleObjects+0xa 00000000`034afa00 00000000`76cae96d kernel32!WaitForMultipleObjectsEx+0x10b 00000000`034afb10 00000000`76cae85e USER32!RealMsgWaitForMultipleObjectsEx+0x129 00000000`034afbb0 00000000`76ca3680 USER32!MsgWaitForMultipleObjectsEx+0x46 00000000`034afbf0 000007fe`fa49b60a USER32!MsgWaitForMultipleObjects+0x20 00000000`034afc30 00000000`76d9cdcd FunDisc!ListenerThread+0×1a6 00000000`034afd20 00000000`76eec6e1 kernel32!BaseThreadInitThunk+0xd 00000000`034afd50 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

64 Id: 8f8.1050 Suspend: 1 Teb: 7ff74000 Unfrozen ChildEBP RetAddr 0ef5fa48 7c82787b ntdll!KiFastSystemCallRet 0ef5fa4c 77c80a6e ntdll!NtRequestWaitReplyPort+0xc 0ef5fa98 77c7fcf0 rpcrt4!LRPC_CCALL::SendReceive+0x230 0ef5faa4 77c80673 rpcrt4!I_RpcSendReceive+0x24 0ef5fab8 77ce315a rpcrt4!NdrSendReceive+0x2b 0ef5fea0 771f4fbd rpcrt4!NdrClientCall2+0x22e 0ef5feb8 771f4f60 winsta!RpcWinStationWaitSystemEvent+0x1c 0ef5ff00 76f01422 winsta!WinStationWaitSystemEvent+0x51 0ef5ff24 0c922ace wtsapi32!WTSWaitSystemEvent+0×97 0ef5ff48 67823331 component!MonitorEvents+0xaf 0ef5ffb8 77e64829 msvcrt!_endthreadex+0xa3 0ef5ffec 00000000 kernel32!BaseThreadStart+0×34

11 Id: 140c.e8c Suspend: 1 Teb: 7ffaf000 Unfrozen ChildEBP RetAddr 01e3fec0 7c822114 ntdll!KiFastSystemCallRet 01e3fec4 77e6711b ntdll!NtWaitForMultipleObjects+0xc 01e3ff6c 77e61075 kernel32!WaitForMultipleObjectsEx+0x11a 01e3ff88 76928415 kernel32!WaitForMultipleObjects+0x18 01e3ffb8 77e66063 userenv!!NotificationThread+0×5f 01e3ffec 00000000 kernel32!BaseThreadStart+0×34

When in doubt it is always a good idea to examine threads in non-hanging processes to see their normal idle stack traces.

I’ll discuss passive threads from kernel space in the next part.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns | 6 Comments »

Crash Dumps for Dummies (Part 6)

October 16th, 2007

Bugtation No. 73:
Crash “must be distinguished from” hang “with which it is often confounded.”
Sydney Smith

In part 4 I highlighted the difference between crashes and hangs. In this part I will elaborate on this terminology a bit further. First of all, we have to unify them as manifestations of a functional failure. Considering computer as a system of components having certain functions we shall subdivide failures into system and component failures. Of course, systems may be components in some larger hierarchy, like in the case of virtualization. Application and service process failures fall under component failures category. Blue screen and server freezes fall under system failures category. Now it is obvious why most computer users confuse crashes and hangs. They are just failures and often the distinction between them is blurred from user perspective.

Software developers tend to make sharp distinction between crash and hang terms because they consider a situation when a computer accesses wrong memory or gets and executes an invalid instruction as a crash. However, after such situation a computer system may or may not terminate that application or service.

Therefore, I propose to consider crashes as situations when a system or a component is not observed anymore. For example, a running application or service disappears from Task Manager, computer system shows blue screen or reboots. In hang situations we can observe that existence of a failed component in Task Manager or a computer system doesn’t reboot automatically and shows some screen image different from BSOD or panic message. The so called sluggish behavior or long response time can also be considered as hang situations.

Here is a simple rough diagram I devised to illuminate the proposed terminological difference:

Based on the clarification above the task of collecting memory or crash dumps is much simpler and clearer.

In the case of a system crash or hang we need to setup correct crash dump options in Advanced System Settings in Control Panel and check page file size in case of the complete memory dump option. A system crash will save the dump automatically. For system hangs we need to actively trigger crash dump saving procedure using either standard keyboard method, SystemDump tool or live system debugging.

In the case of an application crash we need to set up a postmortem debugger, get WER report or attach a debugger to a component and wait for a failure to happen. In the case of a hang we save a memory dump manually either by using process dumpers like userdump.exe or attaching a debugger.

Links to some dump collection techniques can be found in the previously published part 3 (crashes explained) and part 4 (hangs explained). Forthcoming Windows® Crash Dump Analysis book will discuss all memory dump collection methods thoroughly and in detail.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dumps for Dummies, Software Architecture, Tools | 6 Comments »

TOC for Windows® Crash Dump Analysis

October 15th, 2007

Following up the announcement of the forthcoming book I’ve published a preliminary Table of Contents which can be found here:

http://www.dumpanalysis.org/index.php?q=TOC+for+Windows+Crash+Dump+Analysis+Book

In November I’m going to publish a sample chapter and by that time try to finalize TOC.

As a part of my preparatory work I also installed TinyMCE module for my Drupal installation and can now enjoy writing anytime and anywhere:

At the same time I’m trying to improve my writing by reading these two books:

Spring Into Technical Writing for Engineers and Scientists (Spring Into… Series)

BUGS in Writing, Revised Edition: A Guide to Debugging Your Prose (2nd Edition)

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Announcements, Books, Crash Dump Analysis | No Comments »

Crash Dump Analysis Patterns (Part 30)

October 15th, 2007

When a system is unresponsive or sluggish we usually check _ERESOURCE locks in kernel or complete memory dumps to see deadlock or high resource contention. However there is some chance that reported locks are purely accidental and appear in a crash dump because they just happened at that time. We need to look at Contention Count, Ticks and KernelTime in both blocking and blocked threads to recognize an Accidental Lock. Also the current version of WinDbg doesn’t distinguish between prolonged and accidental locks when we use !analyze -v -hang command and merely reports some lock chain it finds among equal alternatives.

Here is an example. The system was reported hang and kernel memory dump was saved. WinDbg analysis command reports one thread blocking 3 other threads and the driver on top of the blocking thread stack is AVDriver.sys. The algorithm WinDbg uses to point to specific image name is described here and in our case it chooses AVDriver:

BLOCKED_THREAD: 8089d8c0

BLOCKING_THREAD: 8aab4700

LOCK_ADDRESS: 8859a570 -- (!locks 8859a570)

Resource @ 0x8859a570 Exclusively owned Contention Count = 3 NumberOfExclusiveWaiters = 3 Threads: 8aab4700-01<*> Threads Waiting On Exclusive Access: 885d0020 88a7c020 8aafc7d8

1 total locks, 1 locks currently held

BUGCHECK_STR: LOCK_HELD

FAULTING_THREAD: 8aab4700

STACK_TEXT: f592f698 80832f7a nt!KiSwapContext+0x26 f592f6c4 80828705 nt!KiSwapThread+0x284 f592f70c f720a394 nt!KeDelayExecutionThread+0x2ab WARNING: Stack unwind information not available. Following frames may be wrong. f592f734 f720ae35 AVDriver+0×1394 f592f750 f720b208 AVDriver+0×1e35 f592f794 f721945a AVDriver+0×2208 f592f7cc 8081dcdf AVDriver+0×1045a f592f7e0 f5b9f76a nt!IofCallDriver+0×45 f592f7f0 f5b9c621 Driver!FS_Dispatch+0xa4 f592f7fc 8081dcdf Driver!Kernel_dispatch+0×53 f592f810 f5eb2856 nt!IofCallDriver+0×45 f592f874 8081dcdf AVFilter!QueryFullName+0×5c10 f592f888 f5e9eae3 nt!IofCallDriver+0×45 f592f8b8 f5e9eca4 DrvFilter!PassThrough+0×115 f592f8d4 8081dcdf DrvFilter!Create+0xda f592f8e8 808f8275 nt!IofCallDriver+0×45 f592f9d0 808f86bc nt!IopParseDevice+0xa35 f592fa08 80936689 nt!IopParseFile+0×46 f592fa88 80932e04 nt!ObpLookupObjectName+0×11f f592fadc 808ea231 nt!ObOpenObjectByName+0xea f592fb58 808eb4cb nt!IopCreateFile+0×447 f592fbb4 f57c8efd nt!IoCreateFile+0xa3 f592fc24 f57c9f29 srv!SrvIoCreateFile+0×36d f592fcf0 f57ca5e4 srv!SrvNtCreateFile+0×5cc f592fd78 f57adbc6 srv!SrvSmbNtCreateAndX+0×15c f592fd84 f57c3451 srv!SrvProcessSmb+0xb7 f592fdac 80948bd0 srv!WorkerThread+0×138 f592fddc 8088d4e2 nt!PspSystemThreadStartup+0×2e 00000000 00000000 nt!KiThreadStartup+0×16

STACK_COMMAND: .thread 0xffffffff8aab4700 ; kb

FOLLOWUP_IP: AVDriver+1394 f720a394 eb85 jmp AVDriver+0x131b (f720a31b)

MODULE_NAME: AVDriver

IMAGE_NAME: AVDriver.sys

Motivated by this “discovery” we want to see all locks:

0: kd> !locks **** DUMP OF ALL RESOURCE OBJECTS **** KD: Scanning for held locks...

Resource @ 0x895a62d8 Shared 1 owning threads Threads: 89570520-01<*>

Resource @ 0x897ceba8 Shared 1 owning threads Threads: 89584020-01<*>

Resource @ 0x8958e020 Shared 1 owning threads Threads: 89555020-01<*>

Resource @ 0x89590608 Shared 1 owning threads Threads: 89666020-01<*>

Resource @ 0x89efc398 Shared 1 owning threads Threads: 89e277c0-01<*>

Resource @ 0x88d70820 Shared 1 owning threads Threads: 88e43948-01<*>

Resource @ 0x89f2fb00 Shared 1 owning threads Threads: 89674688-01<*>

Resource @ 0x89c80370 Shared 1 owning threads Threads: 888496b8-01<*>

Resource @ 0x89bfdf08 Shared 1 owning threads Threads: 88b62910-01<*>

Resource @ 0x888b5488 Shared 1 owning threads Threads: 88536730-01<*>

Resource @ 0x89f2e348 Shared 1 owning threads Threads: 89295930-01<*>

Resource @ 0x891a0838 Shared 1 owning threads Threads: 88949020-01<*>

Resource @ 0x8825bf08 Shared 1 owning threads Threads: 882b9a08-01<*>

Resource @ 0x881a6510 Shared 1 owning threads Threads: 88a88338-01<*>

Resource @ 0x885c5890 Shared 1 owning threads Threads: 881ab020-01<*>

Resource @ 0x886633a8 Shared 1 owning threads Threads: 89b5f8b0-01<*>

Resource @ 0x88216390 Shared 1 owning threads Threads: 88820020-01<*>

Resource @ 0x88524490 Shared 1 owning threads Threads: 88073020-01<*>

Resource @ 0x88f6a020 Shared 1 owning threads Threads: 88e547b0-01<*>

Resource @ 0x88cf2020 Shared 1 owning threads Threads: 89af32d8-01<*>

Resource @ 0x889cea80 Shared 1 owning threads Threads: 88d18b40-01<*>

Resource @ 0x88486298 Shared 1 owning threads Threads: 88af7db0-01<*>

Resource @ 0x88b22270 Exclusively owned Contention Count = 4 NumberOfExclusiveWaiters = 4 Threads: 8aad07d8-01<*> Threads Waiting On Exclusive Access: 8ad78020 887abdb0 88eb39a8 8aa1f668

Resource @ 0x88748c20 Exclusively owned Contention Count = 2 NumberOfExclusiveWaiters = 2 Threads: 8873c8d8-01<*> Threads Waiting On Exclusive Access: 88477478 88db6020

Resource @ 0x8859a570 Exclusively owned Contention Count = 3 NumberOfExclusiveWaiters = 3 Threads: 8aab4700-01<*> Threads Waiting On Exclusive Access: 885d0020 88a7c020 8aafc7d8

KD: Scanning for held locks... 18911 total locks, 25 locks currently held

We can ignore shared locks and concentrate on the last 3 exclusively owned resources. It looks suspicious that Contention Count has the same number as the number of threads waiting on exclusive access (NumberOfExclusiveWaiters). This means that these resources had never been used before. If we dump locks verbosely we would see that blocked threads had been waiting no more than 2 seconds, for example, for resource 0×8859a570:

0: kd> !thread 885d0020; !thread 88a7c020; !thread 8aafc7d8 THREAD 885d0020 Cid 0004.1c34 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 89908d50 SynchronizationEvent 885d0098 NotificationTimer Not impersonating DeviceMap e10022c8 Owning Process 8ad80648 Image: System Wait Start TickCount 7689055 Ticks: 127 (0:00:00:01.984) Context Switch Count 248 UserTime 00:00:00.000 KernelTime 00:00:00.000 Start Address srv!WorkerThread (0xf57c3394) Stack Init b4136000 Current b4135b74 Base b4136000 Limit b4133000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0 ChildEBP RetAddr b4135b8c 80832f7a nt!KiSwapContext+0×26 b4135bb8 8082925c nt!KiSwapThread+0×284 b4135c00 8087c1ad nt!KeWaitForSingleObject+0×346 b4135c3c 8087c3a1 nt!ExpWaitForResource+0xd5 b4135c5c f57c9e95 nt!ExAcquireResourceExclusiveLite+0×8d b4135cf0 f57ca5e4 srv!SrvNtCreateFile+0×510 b4135d78 f57adbc6 srv!SrvSmbNtCreateAndX+0×15c b4135d84 f57c3451 srv!SrvProcessSmb+0xb7 b4135dac 80948bd0 srv!WorkerThread+0×138 b4135ddc 8088d4e2 nt!PspSystemThreadStartup+0×2e 00000000 00000000 nt!KiThreadStartup+0×16

THREAD 88a7c020 Cid 0004.3448 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 89908d50 SynchronizationEvent 88a7c098 NotificationTimer Not impersonating DeviceMap e10022c8 Owning Process 8ad80648 Image: System Wait Start TickCount 7689112 Ticks: 70 (0:00:00:01.093) Context Switch Count 210 UserTime 00:00:00.000 KernelTime 00:00:00.000 Start Address srv!WorkerThread (0xf57c3394) Stack Init b55dd000 Current b55dcb74 Base b55dd000 Limit b55da000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0 ChildEBP RetAddr b55dcb8c 80832f7a nt!KiSwapContext+0×26 b55dcbb8 8082925c nt!KiSwapThread+0×284 b55dcc00 8087c1ad nt!KeWaitForSingleObject+0×346 b55dcc3c 8087c3a1 nt!ExpWaitForResource+0xd5 b55dcc5c f57c9e95 nt!ExAcquireResourceExclusiveLite+0×8d b55dccf0 f57ca5e4 srv!SrvNtCreateFile+0×510 b55dcd78 f57adbc6 srv!SrvSmbNtCreateAndX+0×15c b55dcd84 f57c3451 srv!SrvProcessSmb+0xb7 b55dcdac 80948bd0 srv!WorkerThread+0×138 b55dcddc 8088d4e2 nt!PspSystemThreadStartup+0×2e 00000000 00000000 nt!KiThreadStartup+0×16

THREAD 8aafc7d8 Cid 0004.058c Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 89908d50 SynchronizationEvent 8aafc850 NotificationTimer Not impersonating DeviceMap e10022c8 Owning Process 8ad80648 Image: System Wait Start TickCount 7689171 Ticks: 11 (0:00:00:00.171) Context Switch Count 310 UserTime 00:00:00.000 KernelTime 00:00:00.000 Start Address srv!WorkerThread (0xf57c3394) Stack Init f592c000 Current f592bb18 Base f592c000 Limit f5929000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0 ChildEBP RetAddr f592bb30 80832f7a nt!KiSwapContext+0×26 f592bb5c 8082925c nt!KiSwapThread+0×284 f592bba4 8087c1ad nt!KeWaitForSingleObject+0×346 f592bbe0 8087c3a1 nt!ExpWaitForResource+0xd5 f592bc00 f57c8267 nt!ExAcquireResourceExclusiveLite+0×8d f592bc18 f57ff0ed srv!UnlinkRfcbFromLfcb+0×33 f592bc34 f57ff2ea srv!SrvCompleteRfcbClose+0×1df f592bc54 f57b5e8f srv!CloseRfcbInternal+0xb6 f592bc78 f57ce8a9 srv!SrvCloseRfcbsOnSessionOrPid+0×74 f592bc94 f57e2b22 srv!SrvCloseSession+0xb0 f592bcb8 f57aeb12 srv!SrvCloseSessionsOnConnection+0xa9 f592bcd4 f57c79ed srv!SrvCloseConnection+0×143 f592bd04 f5808c50 srv!SrvCloseConnectionsFromClient+0×17f f592bdac 80948bd0 srv!WorkerThread+0×138 f592bddc 8088d4e2 nt!PspSystemThreadStartup+0×2e 00000000 00000000 nt!KiThreadStartup+0×16

Blocking threads themselves are not blocked and active: the number of ticks passed since their last wait or preemption is 0. This could be a sign of CPU spike pattern. However their accumulated KernelTime is less than a second:

0: kd> !thread 8aad07d8 THREAD 8aad07d8 Cid 0004.0580 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 8aad0850 NotificationTimer IRP List: 8927ade0: (0006,0220) Flags: 00000884 Mdl: 00000000 Impersonation token: eafdc030 (Level Impersonation) DeviceMap e5d69340 Owning Process 8ad80648 Image: System Wait Start TickCount 7689182 Ticks: 0 Context Switch Count 915582 UserTime 00:00:00.000 KernelTime 00:00:00.125 Start Address srv!WorkerThread (0xf57c3394) Stack Init f59d8000 Current f59d7680 Base f59d8000 Limit f59d5000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0

0: kd> !thread 8873c8d8 THREAD 8873c8d8 Cid 0004.2898 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 8873c950 NotificationTimer IRP List: 882a8de0: (0006,0220) Flags: 00000884 Mdl: 00000000 Impersonation token: eafdc030 (Level Impersonation) DeviceMap e5d69340 Owning Process 8ad80648 Image: System Wait Start TickCount 7689182 Ticks: 0 Context Switch Count 917832 UserTime 00:00:00.000 KernelTime 00:00:00.031 Start Address srv!WorkerThread (0xf57c3394) Stack Init ac320000 Current ac31f680 Base ac320000 Limit ac31d000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0

0: kd> !thread 8aab4700 THREAD 8aab4700 Cid 0004.0588 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable 8aab4778 NotificationTimer IRP List: 88453008: (0006,0220) Flags: 00000884 Mdl: 00000000 Impersonation token: e9a82728 (Level Impersonation) DeviceMap eb45f108 Owning Process 8ad80648 Image: System Wait Start TickCount 7689182 Ticks: 0 Context Switch Count 1028220 UserTime 00:00:00.000 KernelTime 00:00:00.765 Start Address srv!WorkerThread (0xf57c3394) Stack Init f5930000 Current f592f680 Base f5930000 Limit f592d000 Call 0 Priority 9 BasePriority 9 PriorityDecrement 0

Based on this observation we could say that locks were accidental and indeed, when the problem happened again, the new dump didn’t show them.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns | 1 Comment »

Minidump Analysis (Part 4)

October 11th, 2007

In part 3 we explored raw stack dumps. Now suppose we have a minidump with a stack trace that involves our product driver and due to some reason WinDbg doesn’t pick symbols automatically and shows the following stack trace and crash address that point to driver.sys module:

1: kd> kL ChildEBP RetAddr WARNING: Stack unwind information not available. Following frames may be wrong. ba0fd0e4 bfabd64b driver+0×2df2a ba0fd1c8 bf8b495d driver+0×1f64b ba0fd27c bf9166ae win32k!NtGdiBitBlt+0×52d ba0fd2d8 bf9168d0 win32k!TileWallpaper+0xd4 ba0fd2f8 bf826c83 win32k!xxxDrawWallpaper+0×50 ba0fd324 bf8651df win32k!xxxDesktopPaintCallback+0×48 ba0fd388 bf8280f3 win32k!xxxEnumDisplayMonitors+0×13a ba0fd3d4 bf8283ab win32k!xxxInternalPaintDesktop+0×66 ba0fd3f8 80833bdf win32k!NtUserPaintDesktop+0×41 ba0fd3f8 7c9485ec nt!KiFastCallEntry+0xfc

1: kd> r eax=000007d0 ebx=000007d0 ecx=00000086 edx=bfb371a3 esi=bc492000 edi=bfb3775b eip=bfacbf2a esp=ba0fd0b8 ebp=ba0fd0e4 iopl=0 nv up ei pl nz na po nc cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010202 driver+0×2df2a: bfacbf2a f3a5 rep movs dword ptr es:[edi],dword ptr [esi] es:0023:bfb3775b=e4405a64 ds:0023:bc492000=????????

We can get timestamp of this module too:

1: kd> lmv m driver start end module name bfa9e000 bfb42a00 driver T (no symbols) Loaded symbol image file: driver.sys Image path: driver.sys Image name: driver.sys Timestamp: Thu Mar 01 20:50:04 2007 (45E73C7C) CheckSum: 000A5062 ImageSize: 000A4A00 Translations: 0000.04b0 0000.04e0 0409.04b0 0409.04e0

We see that no symbols for driver.sys were found and this is also indicated by the absence of function names and huge code offsets like 0×2df2a. Perhaps we don’t have a symbol server and store our symbol files somewhere. Or we got symbols from the developer of the recent fix that bugchecks and we want to apply them. In any case if we add a path to Symbol Search Path dialog (File -> Symbol File Path …) or use .sympath WinDbg command

we are able to get better stack trace and crash point:

1: kd> .reload Loading Kernel Symbols ... Loading User Symbols Loading unloaded module list ... Unable to load image driver.sys, Win32 error 0n2 *** WARNING: Unable to verify timestamp for driver.sys

1: kd> kL ChildEBP RetAddr ba0fd0c0 bfabc399 driver!ProcessBytes+0×18 ba0fd0e4 bfabd64b driver!ProcessObject+0xc9 ba0fd1c8 bf8b495d driver!CacheBitBlt+0×13d ba0fd27c bf9166ae win32k!NtGdiBitBlt+0×52d ba0fd2d8 bf9168d0 win32k!TileWallpaper+0xd4 ba0fd2f8 bf826c83 win32k!xxxDrawWallpaper+0×50 ba0fd324 bf8651df win32k!xxxDesktopPaintCallback+0×48 ba0fd388 bf8280f3 win32k!xxxEnumDisplayMonitors+0×13a ba0fd3d4 bf8283ab win32k!xxxInternalPaintDesktop+0×66 ba0fd3f8 80833bdf win32k!NtUserPaintDesktop+0×41 ba0fd3f8 7c9485ec nt!KiFastCallEntry+0xfc

1: kd> r eax=000007d0 ebx=000007d0 ecx=00000086 edx=bfb371a3 esi=bc492000 edi=bfb3775b eip=bfacbf2a esp=ba0fd0b8 ebp=ba0fd0e4 iopl=0 nv up ei pl nz na po nc cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010202 driver!ProcessBytes+0×18: bfacbf2a f3a5 rep movs dword ptr es:[edi],dword ptr [esi] es:0023:bfb3775b=e4405a64 ds:0023:bc492000=????????

Because WinDbg reports that it was unable to verify timestamp for driver.sys we might want to double check the return address saved when ProcessBytes function was called. If symbols are correct then disassembling the return address backwards will most likely show ProcessObject function code and “call” instruction with ProcessBytes address. Unfortunately minidumps don’t have code except for the currently executing function:

1: kd> ub bfabc399 ^ Unable to find valid previous instruction for 'ub bfabc399'

1: kd> uf driver!ProcessObject No code found, aborting

Therefore we need to point WinDbg to our driver.sys which contains executable code. This can be done by specifying a path in Executable Image Search Path dialog (File -> Image File Path …) or using .exepath WinDbg command.

Now we get more complete stack trace and we are able to double check the return address:

1: kd> .reload Loading Kernel Symbols ... Loading User Symbols Loading unloaded module list ...

1: kd> kL ChildEBP RetAddr ba0fd0c0 bfabc399 driver!ProcessBytes+0×18 ba0fd0e4 bfabd64b driver!ProcessObject+0xc9 ba0fd104 bfac5aac driver!CacheBitBlt+0×13d ba0fd114 bfac6840 driver!ProcessCommand+0×150 ba0fd140 bfac1878 driver!CheckSurface+0×258 ba0fd178 bfaba0ee driver!CopyBitsEx+0xfa ba0fd1c8 bf8b495d driver!DrvCopyBits+0xb6 ba0fd27c bf9166ae win32k!NtGdiBitBlt+0×52d ba0fd2d8 bf9168d0 win32k!TileWallpaper+0xd4 ba0fd2f8 bf826c83 win32k!xxxDrawWallpaper+0×50 ba0fd324 bf8651df win32k!xxxDesktopPaintCallback+0×48 ba0fd388 bf8280f3 win32k!xxxEnumDisplayMonitors+0×13a ba0fd3d4 bf8283ab win32k!xxxInternalPaintDesktop+0×66 ba0fd3f8 80833bdf win32k!NtUserPaintDesktop+0×41 ba0fd3f8 7c9485ec nt!KiFastCallEntry+0xfc

1: kd> ub bfabc399 driver!ProcessObject+0xb7: bfabc387 57 push edi bfabc388 40 inc eax bfabc389 50 push eax bfabc38a e861fb0000 call driver!convert (bfacbef0) bfabc38f ff7508 push dword ptr [ebp+8] bfabc392 57 push edi bfabc393 50 push eax bfabc394 e879fb0000 call driver!ProcessBytes (bfacbf12)

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Debugging, Minidump Analysis, WinDbg Tips and Tricks | 6 Comments »

Software Technical Support Patterns

October 9th, 2007

I was wondering today whether there are any published patterns for software technical support and to my delight I found this interesting EuroPLoP conference paper:

Technical Support Patterns

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Software Technical Support | No Comments »

Crash Dump Analysis Patterns (Part 29)

October 8th, 2007

Some Windows synchronization objects like executive resources and critical sections have a struct member called ContentionCount. This is the number of times a resource was accessed or, in another words, it is the accumulated number of threads waiting for an object: when a thread tries to acquire an object and put into a wait state the count is incremented. Hence the name of this pattern: High Contention.

Here is an example. In a kernel memory dump we have just one exclusively owned lock and seems no other threads were blocked by it at the time the dump was saved. However the high contention count reveals CPU spike:

3: kd> !locks **** DUMP OF ALL RESOURCE OBJECTS **** KD: Scanning for held locks...

Resource @ 0x8abc11f0 Exclusively owned Contention Count = 19648535 Threads: 896395f8-01<*> KD: Scanning for held locks…

Resource @ 0x896fab88 Shared 1 owning threads Threads: 88c78608-01<*> KD: Scanning for held locks... 15464 total locks, 2 locks currently held

3: kd> !thread 896395f8 THREAD 896395f8 Cid 04c0.0138 Teb: 7ffde000 Win32Thread: bc922d20 RUNNING on processor 1 Not impersonating DeviceMap e3d4c008 Owning Process 8a035020 Image: MyApp.exe Wait Start TickCount 36969283 Ticks: 0 Context Switch Count 1926423 LargeStack UserTime 00:00:53.843 KernelTime 00:13:10.703 Win32 Start Address 0×00401478 Start Address 0×77e617f8 Stack Init ba14b000 Current ba14abf8 Base ba14b000 Limit ba146000 Call 0 Priority 11 BasePriority 6 PriorityDecrement 5 ChildEBP RetAddr Args to Child ba14ac94 bf8c6505 001544c8 bf995948 000c000a nt!_wcsicmp+0×3a (FPO: [Non-Fpo]) ba14ace0 bf8c6682 00000000 00000000 00000000 win32k!_FindWindowEx+0xfb (FPO: [Non-Fpo]) ba14ad48 8088978c 00000000 00000000 0012f8d4 win32k!NtUserFindWindowEx+0xef (FPO: [Non-Fpo]) ba14ad48 7c8285ec 00000000 00000000 0012f8d4 nt!KiFastCallEntry+0xfc (FPO: [0,0] TrapFrame @ ba14ad64)

3: kd> !process 8a035020 PROCESS 8a035020 SessionId: 9 Cid: 04c0 Peb: 7ffdf000 ParentCid: 10e8 DirBase: cffaf7a0 ObjectTable: e4ba30a0 HandleCount: 73. Image: MyApp.exe VadRoot 88bc1bf8 Vads 82 Clone 0 Private 264. Modified 0. Locked 0. DeviceMap e3d4c008 Token e5272028 ElapsedTime 00:14:19.360 UserTime 00:00:53.843 KernelTime 00:13:10.703 QuotaPoolUsage[PagedPool] 40660 QuotaPoolUsage[NonPagedPool] 3280 Working Set Sizes (now,min,max) (1139, 50, 345) (4556KB, 200KB, 1380KB) PeakWorkingSetSize 1141 VirtualSize 25 Mb PeakVirtualSize 27 Mb PageFaultCount 1186 MemoryPriority BACKGROUND BasePriority 6 CommitCharge 315

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns | 7 Comments »

Reading Windows-based Code (Part 6)

October 4th, 2007

The HTML version of the presentation is located here:

Reading Windows-based Code (Part 6)

Contents:

Function pointers
Reading declarations
Pointers to structures

In Part 7 I’m planning to include the following topics:

Linked lists and their implementation overview
Windows linked lists (SINGLE_LIST_ENTRY, LIST_ENTRY)
Anatomy of a typical Windows service

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Announcements, C and C++, Code Reading | No Comments »

XEN from a system programmer’s perspective

October 3rd, 2007

I’m trying to educate myself about virtualization and XEN and found the book The Definitive Guide to the Xen Hypervisor written by David Chisnall that is about to be published:

Table of Contents

I’ll write a review once I get it and read it.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Assembly Language, Books, Citrix, Virtualization | 1 Comment »

Heaps and heap corruption explained

October 2nd, 2007

Excellent free chapter explaining process heap implementation and debugging heap corruption issues from the authors of Advanced Windows Debugging book:

Sample Chapter

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Announcements, Books, Crash Dump Analysis, Debugging, Tools | No Comments »

My unsorted collection of books

October 1st, 2007

Recently brought almost all my programming and math books into one place:

Will spend some time sorting them and publish the new picture afterwards.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Books | 7 Comments »

Windows service crash dumps in Vista

October 1st, 2007

I was playing with Vista Platform SDK samples to create the minimal native Windows service that crashes to test various postmortem debugger configurations, Windows Error Reporting (WER) options and conditions under which crash dumps are available. Initially I put a NULL pointer dereference into the service control handler processing service stop command and although the service crashed under WinDbg I couldn’t get CDB or NTSD configured as a default postmortem debugger to save the crash dump automatically. I tested under x64 Vista and Windows Server 2003 x64 both 32-bit and 64-bit versions of my service.

Here is the source code and stack trace from WinDbg when we attach it to the running service and then try to stop it:

// // FUNCTION: service_ctrl // // PURPOSE: This function is called by the SCM whenever // ControlService() is called on this service. // // PARAMETERS: // dwCtrlCode - type of control requested // // RETURN VALUE: // none // // COMMENTS: // VOID WINAPI service_ctrl(DWORD dwCtrlCode) { // Handle the requested control code. // switch (dwCtrlCode) { case SERVICE_CONTROL_STOP:     *(int *)NULL = 0;     ReportStatusToSCMgr(SERVICE_STOP_PENDING, NO_ERROR, 0);     ServiceStop();     return;

// Update the service status. // case SERVICE_CONTROL_INTERROGATE:     break;

// invalid control code // default:     break;

}

ReportStatusToSCMgr(ssStatus.dwCurrentState, NO_ERROR, 0); }

0:000> r rax=0000000000000001 rbx=00000000001e36d0 rcx=0000000000000001 rdx=000000000a9ff32c rsi=0000000000000000 rdi=0000000000401aa0 rip=0000000000401ab9 rsp=000000000012fab0 rbp=00000000001e36d0 r8=0000000000400000 r9=0000000077b3f990 r10=00000000004000d8 r11=00000000004000d8 r12=0000000000000000 r13=000000000a9ff32c r14=00000000001e36e8 r15=000000000012fc20 iopl=0 nv up ei pl zr na po nc cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00010246 simple!service_ctrl+0x19: 00000000`00401ab9 c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=????????

0:000> k Child-SP RetAddr Call Site 00000000`0012fab0 000007fe`fe276cee simple!service_ctrl+0x19 00000000`0012faf0 000007fe`fe2cea5d ADVAPI32!ScDispatcherLoop+0x54c 00000000`0012fbf0 00000000`004019f5 ADVAPI32!StartServiceCtrlDispatcherA+0x8d 00000000`0012fe70 00000000`00408b8c simple!main+0x155 00000000`0012fec0 00000000`0040895e simple!__tmainCRTStartup+0x21c 00000000`0012ff30 00000000`7792cdcd simple!mainCRTStartup+0xe 00000000`0012ff60 00000000`77a7c6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

If we put while(1); code instead of NULL pointer dereference the process will be interrupted via breakpoint and then terminated. There is no postmortem dump saved too. Therefore it looks like any fault inside the service main thread is not allowed to execute the potentially blocking operation of unhandled exception filter perhaps to avoid blocking the service control manager (SCM) communicating with service dispatcher code.

On Vista if Windows Error Reporting service is running and WER is configured in Control Panel to allow a user to choose reporting settings we get the following familiar dialog but without Debug option to attach a postmortem debugger and save a crash dump:

If we choose the recommended option we get the following dialog showing the path where a minidump file was temporarily stored:

We need to leave this dialog open if we want to open the crash dump or copy it to another location otherwise report files will be removed as soon as we dismiss the dialog box (they may be stored temporarily in another location - check Problem Reports and Solutions\View Problem History in Control Panel). If we open the crash dump using WinDbg we get the same stack trace that we got previously during live debugging:

Loading Dump File [C:\ProgramData\Microsoft\Windows\WER\ReportQueue\Report19527353 \WER7346.tmp.mdmp] User Mini Dump File: Only registers, stack and portions of memory are available

Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols Executable search path is: Windows Vista Version 6000 MP (2 procs) Free x64 Product: WinNt, suite: SingleUserTS Debug session time: Fri Sep 28 16:36:38.000 2007 (GMT+1) System Uptime: 2 days 1:42:22.810 Process Uptime: 0 days 0:00:10.000 ..... This dump file has an exception of interest stored in it. The stored exception information can be accessed via .ecxr. (13b0.d54): Access violation - code c0000005 (first/second chance not available) *** WARNING: Unable to verify checksum for simple.exe simple!service_ctrl+0x19: 00000000`00401ab9 c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=???????? 0:000> k Child-SP RetAddr Call Site 00000000`0012fab0 000007fe`fe276cee simple!service_ctrl+0x19 00000000`0012faf0 000007fe`fe2cea5d advapi32!ScDispatcherLoop+0x54c 00000000`0012fbf0 00000000`004019f5 advapi32!StartServiceCtrlDispatcherA+0x8d 00000000`0012fe70 00000000`00408b8c simple!main+0x155 00000000`0012fec0 00000000`0040895e simple!__tmainCRTStartup+0x21c 00000000`0012ff30 00000000`7792cdcd simple!mainCRTStartup+0xe 00000000`0012ff60 00000000`77a7c6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

Fault in any other service thread, for example, the one that SCM starts per every SERVICE_TABLE_ENTRY in dispatch table results in a default postmortem debugger saving a crash dump on Windows Server 2003 x64 but not on Vista x64 or Vista x86 (32-bit):

void __cdecl main(int argc, char **argv) { SERVICE_TABLE_ENTRY dispatchTable[] = { { TEXT(SZSERVICENAME), (LPSERVICE_MAIN_FUNCTION)service_main}, { NULL, NULL} }; ... ... ... if (!StartServiceCtrlDispatcher(dispatchTable))     AddToMessageLog(TEXT("StartServiceCtrlDispatcher failed.")); }

void WINAPI service_main(DWORD dwArgc, LPTSTR *lpszArgv) { // register our service control handler: // sshStatusHandle = RegisterServiceCtrlHandler( TEXT(SZSERVICENAME), service_ctrl);

if (!sshStatusHandle)     goto cleanup;

// SERVICE_STATUS members that don't change in example // ssStatus.dwServiceType = SERVICE_WIN32_OWN_PROCESS; ssStatus.dwServiceSpecificExitCode = 0;

// report the status to the service control manager. // if (!ReportStatusToSCMgr(       SERVICE_START_PENDING, // service state       NO_ERROR, // exit code       3000)) // wait hint     goto cleanup; *(int *)NULL = 0; … … … }

Seems the only way to get a crash mindump for analysis is to copy it from the report data like I explained above:

Loading Dump File [C:\ProgramData\Microsoft\Windows\WER\ReportQueue\Report0fa05f9d \WER5F42.tmp.mdmp] User Mini Dump File: Only registers, stack and portions of memory are available

Symbol search path is: srv*c:\mss*http://msdl.microsoft.com/download/symbols Executable search path is: Windows Vista Version 6000 MP (2 procs) Free x64 Product: WinNt, suite: SingleUserTS Debug session time: Fri Sep 28 17:50:06.000 2007 (GMT+1) System Uptime: 0 days 0:30:59.495 Process Uptime: 0 days 0:00:04.000 ..... This dump file has an exception of interest stored in it. The stored exception information can be accessed via .ecxr. (d6c.fcc): Access violation - code c0000005 (first/second chance not available) *** WARNING: Unable to verify checksum for simple.exe simple!service_main+0x60: 00000000`00401aa0 c704250000000000000000 mov dword ptr [0],0 ds:00000000`00000000=???????? 0:001> ~*k

0 Id: d6c.cf4 Suspend: 0 Teb: 000007ff`fffdd000 Unfrozen Child-SP RetAddr Call Site 00000000`0012f978 00000000`777026da ntdll!NtReadFile+0xa 00000000`0012f980 000007fe`feb265aa kernel32!ReadFile+0x8a 00000000`0012fa10 000007fe`feb262e3 advapi32!ScGetPipeInput+0x4a 00000000`0012faf0 000007fe`feb7ea5d advapi32!ScDispatcherLoop+0x9a 00000000`0012fbf0 00000000`004019f5 advapi32!StartServiceCtrlDispatcherA+0x8d 00000000`0012fe70 00000000`00408bac simple!main+0x155 00000000`0012fec0 00000000`0040897e simple!__tmainCRTStartup+0x21c 00000000`0012ff30 00000000`7770cdcd simple!mainCRTStartup+0xe 00000000`0012ff60 00000000`7792c6e1 kernel32!BaseThreadInitThunk+0xd 00000000`0012ff90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

# 1 Id: d6c.fcc Suspend: 0 Teb: 000007ff`fffdb000 Unfrozen Child-SP RetAddr Call Site 00000000`008eff00 000007fe`feb24bf5 simple!service_main+0x60 00000000`008eff30 00000000`7770cdcd advapi32!ScSvcctrlThreadW+0x25 00000000`008eff60 00000000`7792c6e1 kernel32!BaseThreadInitThunk+0xd 00000000`008eff90 00000000`00000000 ntdll!RtlUserThreadStart+0x1d

Spawning a custom thread with NULL pointer access violation doesn’t result in a crash dump on my Vista x86 and x64 too. Therefore it appears that there are no automatic postmortem crash dumps saved for native Window services in Vista unless there is some setting that I missed. This might create some problems for traditional 3rd party Technical Support procedures especially if Windows Server 2008 (Longhorn) will have the same behavior.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Debugging, Tools, Vista | 3 Comments »

Crash Dump Analysis Patterns (Part 28)

September 26th, 2007

Sometimes we have a problem that some functionality is not available or it is unresponsive when we request it. We can suppose that the process implementing that functionality has crashed or hangs. If we know the relationship between processes we can request several user dumps at once or a complete memory dump to analyze the dependency between processes by looking at their stack traces. This is an example of the system level crash dump analysis pattern that I call Coupled Processes.

Process relationship can be implemented via different interprocess communication mechanisms (IPC), for example, Remote Procedure Call (RPC) via LPC (Local Procedure Call) which can be easily identified in stack traces.

My favorite example here is when some application tries to print and hangs. Printing API is exported from WINSPOOL.DLL and it forwards via RPC most requests to Windows Print Spooler service. Therefore it is logical to take two dumps, one from that application and one from spoolsv.exe. Similar example is from Citrix Presentation Server environments related to printer autocreation when there are dependencies between Citrix Printing Service CpSvc.exe and spoolsv.exe. Therefore if new user connections hang and restarting both printing services resolves the issue then we might need to analyze dumps from both services together to confirm this Procedure Call Chain and find the problem 3rd-party printing component or driver.

Back to my favorite example. In the hang application we have the following thread:

18 Id: 2130.6320 Suspend: 1 Teb: 7ffa8000 Unfrozen ChildEBP RetAddr 01eae170 7c821c94 ntdll!KiFastSystemCallRet 01eae174 77c72700 ntdll!NtRequestWaitReplyPort+0xc 01eae1c8 77c713ba rpcrt4!LRPC_CCALL::SendReceive+0x230 01eae1d4 77c72c7f rpcrt4!I_RpcSendReceive+0x24 01eae1e8 77ce219b rpcrt4!NdrSendReceive+0x2b 01eae5d0 7307c9ef rpcrt4!NdrClientCall2+0x22e 01eae5e8 73082d8d winspool!RpcAddPrinter+0x1c 01eaea70 0040d81a winspool!AddPrinterW+0x102 01eaef58 0040ee7c App!AddNewPrinter+0x816 ... ... ...

Notice winspool and rpcrt4 modules. The application is calling spooler service using RPC to add a new printer and waiting for a reply back. Looking at spooler service dump shows several threads displaying message boxes and waiting for user input:

20 Id: 790.5950 Suspend: 1 Teb: 7ffa2000 Unfrozen ChildEBP RetAddr Args to Child 03deea70 7739d02f 77392bf3 00000000 00000000 ntdll!KiFastSystemCallRet 03deeaa8 7738f122 03dd0058 00000000 00000001 user32!NtUserWaitMessage+0xc 03deead0 773a1722 77380000 00123690 00000000 user32!InternalDialogBox+0xd0 03deed90 773a1004 03deeeec 03dae378 03dae160 user32!SoftModalMessageBox+0x94b 03deeee0 773b1a28 03deeeec 00000028 00000000 user32!MessageBoxWorker+0x2ba 03deef38 773b19c4 00000000 03defb9c 03def39c user32!MessageBoxTimeoutW+0x7a 03deef58 773b19a0 00000000 03defb9c 03def39c user32!MessageBoxExW+0x1b 03deef74 021f265b 00000000 03defb9c 03def39c user32!MessageBoxW+0×45 WARNING: Stack unwind information not available. Following frames may be wrong. 03deef88 00000000 03dae160 03deffec 03dae16a PrinterDriver!UninstallerInstall+0×2cb

Dumping the 3rd parameter of MessageBoxW using WinDbg du command shows the message:

“Installation of the software for your printer is now complete. Restart your computer to make the new settings active.”

Another example when one process starts another and is waiting for it to finish:

0 Id: 2a34.24d0 Suspend: 1 Teb: 7ffde000 Unfrozen ChildEBP RetAddr 0007ec8c 7c822124 ntdll!KiFastSystemCallRet 0007ec90 77e6bad8 ntdll!NtWaitForSingleObject+0xc 0007ed00 77e6ba42 kernel32!WaitForSingleObjectEx+0xac 0007ed14 01002f4c kernel32!WaitForSingleObject+0x12 0007f79c 01003137 userinit!ExecApplication+0x2d3 0007f7dc 0100366b userinit!ExecProcesses+0x1bb 0007fe68 010041fd userinit!StartTheShell+0x132 0007ff1c 010056f1 userinit!WinMain+0x263 0007ffc0 77e523e5 userinit!WinMainCRTStartup+0x186 0007fff0 00000000 kernel32!BaseProcessStart+0x23

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns, Debugging, Software Architecture | 15 Comments »

Resolving “Symbol file could not be found”

September 17th, 2007

On one of my debugging workstations I couldn’t analyze kernel and complete memory dumps from Windows 2003 Server R02. I was always getting this message:

*** ERROR: Symbol file could not be found. Defaulted to export symbols for ntkrnlmp.exe -

An attempt to reload and overwrite PDB files using .reload /o /f command didn’t resolve the issue but the following WinDbg command helped:

1: kd> !sym noisy noisy mode - symbol prompts on

Reloading symbol files showed that default symbol path contained corrupt ntkrnlmp.pdb:

1: kd> .reload DBGHELP: C:\Program Files\Debugging Tools for Windows\sym\ntkrnlmp.pdb\A91CA63E49A840F4A50509F90ADE10D52\ntkrnlmp.pdb - E_PDB_CORRUPT DBGHELP: ntkrnlmp.pdb - file not found *** ERROR: Symbol file could not be found. Defaulted to export symbols for ntkrnlmp.exe - DBGHELP: nt - export symbol

Deleting it and reloading symbols again showed problems with the file downloaded from MS symbol server too:

1: kd> .reload SYMSRV: c:\mss\ntkrnlmp.pdb\A91CA63E49A840F4A50509F90ADE10D52\ntkrnlmp.pd_ The file or directory is corrupted and unreadable. DBGHELP: ntkrnlmp.pdb - file not found *** ERROR: Symbol file could not be found. Defaulted to export symbols for ntkrnlmp.exe - DBGHELP: nt - export symbols

Removing the folder and reloading symbols resolved the problem:

1: kd> .reload DBGHELP: nt - public symbols c:\mss\ntkrnlmp.pdb\A91CA63E49A840F4A50509F90ADE10D52\ntkrnlmp.pdb

Now it was time to switch noisy mode off:

1: kd> !sym quiet quiet mode - symbol prompts on

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Debugging, WinDbg Tips and Tricks | No Comments »

Crash Dump Analysis Patterns (Part 27)

September 14th, 2007

Sometimes a problem can be identified not from a single Stack Trace pattern but from a Stack Trace Collection.

These include Coupled Processes, Procedure Call Chains and Blocked Threads. All of them will be discussed in subsequent parts and in this part I only discuss various methods to list stack traces.

Process dumps including various process minidumps:

~*kv command lists all process threads

!findstack module[!symbol] 2 command filters all stack traces to show ones containing module or module!symbol

!uniqstack command

Kernel minidumps:

have only one problem thread. kv command or its variant is suffice.

Kernel and complete memory dumps:

!process 0 ff command lists all processes and their threads including user space process thread stacks for complete memory dumps. This command is valid for Windows XP and later. For older systems use WinDbg scripts

!stacks 2 [module[!symbol]] command shows kernel mode stack traces and you can filter the output based on module or module!symbol. Filtering is valid only for dumps from Windows XP and later systems

~[ProcessorN]s;.reload /user;kv command sequence shows stack trace for the running thread on the specified processor.

!sprocess 0n<SessionId> ff lists all processes and their threads for the specified [terminal services] session.

!for_each_thread “.thread /r /p @#Thread; kv” allows execution of stack trace command variants per each thread. The following script takes the advantage of this command to list complete stack traces from an x64 system.

The processor change command is illustrated in this example:

0: kd> ~2s

2: kd> k ChildEBP RetAddr eb42bd58 00000000 nt!KiIdleLoop+0x14

2: kd> ~1s;.reload /user;k Loading User Symbols ... ChildEBP RetAddr be4f8c30 eb091f43 i8042prt!I8xProcessCrashDump+0x53 be4f8c8c 8046bfe2 i8042prt!I8042KeyboardInterruptService+0x15d be4f8c8c 8049470f nt!KiInterruptDispatch+0x32 be4f8d54 80468389 nt!NtSetEvent+0x71 be4f8d54 77f8290a nt!KiSystemService+0xc9 081cfefc 77f88266 ntdll!ZwSetEvent+0xb 081cff0c 77f881b1 ntdll!RtlpUnWaitCriticalSection+0x1b 081cff14 1b00c7d1 ntdll!RtlLeaveCriticalSection+0x1d 081cff4c 1b0034da msjet40!Database::ReadPages+0x81 081cffb4 7c57b3bc msjet40!System::WorkerThread+0x115 081cffec 00000000 KERNEL32!BaseThreadStart+0x52

Example of !findstack command (process dump):

0:000> !findstack kernel32!RaiseException 2 Thread 000, 1 frame(s) match * 00 0013b3f8 72e8d3ef kernel32!RaiseException+0x53 01 0013b418 72e9a26b msxml3!Exception::raiseException+0x5f 02 0013b424 72e8ff00 msxml3!Exception::_throwError+0x22 03 0013b46c 72e6abaa msxml3!COMSafeControlRoot::getBaseURL+0x3d 04 0013b4bc 72e6a888 msxml3!Document::loadXML+0x82 05 0013b510 64b73a9b msxml3!DOMDocumentWrapper::loadXML+0x5a 06 0013b538 64b74eb6 iepeers!CPersistUserData::initXMLCache+0xa6 07 0013b560 77d0516e iepeers!CPersistUserData::load+0xfc 08 0013b57c 77d14abf oleaut32!DispCallFunc+0x16a ... ... ... 66 0013fec8 0040243d shdocvw!IEWinMain+0x129 67 0013ff1c 00402744 iexplore!WinMain+0x316 68 0013ffc0 77e6f23b iexplore!WinMainCRTStartup+0x182 69 0013fff0 00000000 kernel32!BaseProcessStart+0x23

Example of !stacks command (kernel dump):

2: kd> !stacks 2 nt!PspExitThread Proc.Thread .Thread Ticks ThreadState Blocker [8a390818 System]

[8a1bbbf8 smss.exe]

[8a16cbf8 csrss.exe]

[89c14bf0 winlogon.exe]

[89dda630 services.exe]

[89c23af0 lsass.exe]

[8a227470 svchost.exe]

[89f03bb8 svchost.exe]

[89de3820 svchost.exe]

[89d09b60 svchost.exe]

[89c03530 ccEvtMgr.exe]

[89b8f4f0 ccSetMgr.exe]

[89dfe8c0 SPBBCSvc.exe]

[89c9db18 svchost.exe]

[89dfa268 spoolsv.exe]

[89dfa6b8 msdtc.exe]

[89df38f0 CpSvc.exe]

[89d97d88 DefWatch.exe]

[89e04020 IBMSPSVC.EXE]

[89b54710 IBMSPREM.EXE]

[89d9e4b0 IBMSPREM.EXE]

[89c2c4e8 svchost.exe]

[89d307c0 SavRoam.exe]

[89bfcd88 Rtvscan.exe]

[89b53b60 uphclean.exe]

[89c24020 AgentSVC.exe]

[89d75b60 sAginst.exe]

[89cf0d88 CdfSvc.exe]

[89d87020 cdmsvc.exe]

[89dafd88 ctxxmlss.exe]

[89d8dd88 encsvc.exe]

[89d06d88 ImaSrv.exe]

[89d37b60 mfcom.exe]

[89c8bb18 SmaService.exe]

[89d2ba80 svchost.exe]

[89ce8630 XTE.exe]

[89b64b60 XTE.exe]

[89b7c680 ctxcpusched.exe]

[88d94a88 ctxcpuusync.exe]

[89ba5418 unsecapp.exe]

[89d846e0 wmiprvse.exe]

[89cda9d8 ctxwmisvc.exe]

[88d6cb78 logon.scr]

[88ba0a70 csrss.exe]

[88961968 winlogon.exe]

[8865f740 rdpclip.exe]

[8858db20 wfshell.exe]

[88754020 explorer.exe]

[88846d88 BacsTray.exe]

[886b6180 ccApp.exe]

[884bc020 fppdis3a.exe]

[885cb350 ctfmon.exe]

[888bb918 cscript.exe]

[8880b3c8 cscript.exe]

[88ad2950 csrss.exe] b68.00215c 88930020 0000000 RUNNING nt!KeBugCheckEx+0x1b nt!MiCheckSessionPoolAllocations+0xe3 nt!MiDereferenceSessionFinal+0x183 nt!MmCleanProcessAddressSpace+0x6b nt!PspExitThread+0x5f1 nt!PspTerminateThreadByPointer+0x4b nt!PspSystemThreadStartup+0x3c nt!KiThreadStartup+0x16

[88629310 winlogon.exe]

[88a4d9b0 csrss.exe]

[88d9f8b0 winlogon.exe]

[88cd5840 wfshell.exe]

[8a252440 OUTLOOK.EXE]

[8a194bf8 WINWORD.EXE]

[88aabd20 ctfmon.exe]

[889ef440 EXCEL.EXE]

[88bec838 HogiaGUI2.exe]

[88692020 csrss.exe]

[884dd508 winlogon.exe]

[88be1d88 wfshell.exe]

[886a7d88 OUTLOOK.EXE]

[889baa70 WINWORD.EXE]

[8861e3d0 ctfmon.exe]

[887bbb68 EXCEL.EXE]

[884e4020 csrss.exe]

[8889d218 winlogon.exe]

[887c8020 wfshell.exe]

Threads Processed: 1101

What if we have a list of processes from a complete memory dump by using !process 0 0 command and we want to interrogate the specific process? In this case we need to switch to that process and reload user space symbol files (.process /r /p address).

There is also a separate command to reload user space symbol files any time (.reload /user).

After switching we can list threads (!process address), dump or search process virtual memory, etc. For example:

1: kd> !process 0 0 **** NT ACTIVE PROCESS DUMP **** PROCESS 890a3320 SessionId: 0 Cid: 0008 Peb: 00000000 ParentCid: 0000 DirBase: 00030000 ObjectTable: 890a3e08 TableSize: 405. Image: System

PROCESS 889dfd60 SessionId: 0 Cid: 0144 Peb: 7ffdf000 ParentCid: 0008 DirBase: 0b9e7000 ObjectTable: 889fdb48 TableSize: 212. Image: SMSS.EXE

PROCESS 890af020 SessionId: 0 Cid: 0160 Peb: 7ffdf000 ParentCid: 0144 DirBase: 0ce36000 ObjectTable: 8898e308 TableSize: 747. Image: CSRSS.EXE

PROCESS 8893d020 SessionId: 0 Cid: 0178 Peb: 7ffdf000 ParentCid: 0144 DirBase: 0d33b000 ObjectTable: 890ab4c8 TableSize: 364. Image: WINLOGON.EXE

PROCESS 88936020 SessionId: 0 Cid: 0194 Peb: 7ffdf000 ParentCid: 0178 DirBase: 0d7d5000 ObjectTable: 88980528 TableSize: 872. Image: SERVICES.EXE

PROCESS 8897f020 SessionId: 0 Cid: 01a0 Peb: 7ffdf000 ParentCid: 0178 DirBase: 0d89d000 ObjectTable: 889367c8 TableSize: 623. Image: LSASS.EXE

1: kd> .process /r /p 8893d020 Implicit process is now 8893d020 Loading User Symbols ...

1: kd> !process 8893d020 PROCESS 8893d020 SessionId: 0 Cid: 0178 Peb: 7ffdf000 ParentCid: 0144 DirBase: 0d33b000 ObjectTable: 890ab4c8 TableSize: 364. Image: WINLOGON.EXE VadRoot 8893a508 Clone 0 Private 1320. Modified 45178. Locked 0. DeviceMap 89072448 Token e392f8d0 ElapsedTime 9:54:06.0882 UserTime 0:00:00.0071 KernelTime 0:00:00.0382 QuotaPoolUsage[PagedPool] 34828 QuotaPoolUsage[NonPagedPool] 43440 Working Set Sizes (now,min,max) (737, 50, 345) (2948KB, 200KB, 1380KB) PeakWorkingSetSize 2764 VirtualSize 46 Mb PeakVirtualSize 52 Mb PageFaultCount 117462 MemoryPriority FOREGROUND BasePriority 13 CommitCharge 1861

THREAD 8893dda0 Cid 178.15c Teb: 7ffde000 Win32Thread: a2034908 WAIT: (WrUserRequest) UserMode Non-Alertable 8893bee0 SynchronizationEvent Not impersonating Owning Process 8893d020 Wait Start TickCount 29932455 Elapsed Ticks: 7 Context Switch Count 28087 LargeStack UserTime 0:00:00.0023 KernelTime 0:00:00.0084 Start Address winlogon!WinMainCRTStartup (0x0101cbb0) Stack Init eb1b0000 Current eb1afcc8 Base eb1b0000 Limit eb1ac000 Call 0 Priority 15 BasePriority 15 PriorityDecrement 0 DecrementCount 0

ChildEBP RetAddr Args to Child eb1afce0 8042d893 00000000 a2034908 00000001 nt!KiSwapThread+0x1b1 eb1afd08 a00019c2 8893bee0 0000000d 00000001 nt!KeWaitForSingleObject+0x1a3 eb1afd44 a0013993 000020ff 00000000 00000001 win32k!xxxSleepThread+0x18a eb1afd54 a001399f 0006fdd8 80468389 00000000 win32k!xxxWaitMessage+0xe eb1afd5c 80468389 00000000 00000000 00000000 win32k!NtUserWaitMessage+0xb eb1afd5c 77e58b53 00000000 00000000 00000000 nt!KiSystemService+0xc9 0006fdd0 77e33630 00000000 00000000 0000ffff USER32!NtUserWaitMessage+0xb 0006fe04 77e44327 000100d2 00000000 00000010 USER32!DialogBox2+0x216 0006fe28 77e38d37 76b90000 76c75c78 00000000 USER32!InternalDialogBox+0xd1 0006fe48 77e39eba 76b90000 76c75c78 00000000 USER32!DialogBoxIndirectParamAorW+0x34 0006fe6c 01011749 76b90000 00000578 00000000 USER32!DialogBoxParamW+0x3d 0006fea8 01018bd3 000755e8 76b90000 00000578 winlogon!TimeoutDialogBoxParam+0x27 0006fee0 76b93701 000755e8 76b90000 00000578 winlogon!WlxDialogBoxParam+0×7b 0006ff08 010164c6 0008d0e0 5ffa0000 000755e8 3rdPartyGINA!WlxDisplaySASNotice+0×43 0006ff20 01014960 000755e8 00000005 00072c9c winlogon!MainLoop+0×96 0006ff58 0101cd06 00071fc8 00000000 00072c9c winlogon!WinMain+0×37a 0006fff4 00000000 7ffdf000 000000c8 00000100 winlogon!WinMainCRTStartup+0×156

THREAD 88980020 Cid 178.188 Teb: 7ffdc000 Win32Thread: 00000000 WAIT: (DelayExecution) UserMode Alertable 88980108 NotificationTimer Not impersonating Owning Process 8893d020 Wait Start TickCount 29930810 Elapsed Ticks: 1652 Context Switch Count 15638 UserTime 0:00:00.0000 KernelTime 0:00:00.0000 Start Address KERNEL32!BaseThreadStartThunk (0x7c57b740) Win32 Start Address ntdll!RtlpTimerThread (0x77faa02d) Stack Init bf6f7000 Current bf6f6cc4 Base bf6f7000 Limit bf6f4000 Call 0 Priority 13 BasePriority 13 PriorityDecrement 0 DecrementCount 0

ChildEBP RetAddr Args to Child bf6f6cdc 8042d340 bf6f6d64 00bfffac 00bfffac nt!KiSwapThread+0x1b1 bf6f6d04 8052aac9 8046c101 00000001 bf6f6d34 nt!KeDelayExecutionThread+0x182 bf6f6d54 80468389 00000001 00bfffac 00000000 nt!NtDelayExecution+0x7f bf6f6d54 77f82831 00000001 00bfffac 00000000 nt!KiSystemService+0xc9 00bfff9c 77f842c4 00000001 00bfffac 00000000 ntdll!NtDelayExecution+0xb 00bfffb4 7c57b3bc 0006fe60 00000000 00000000 ntdll!RtlpTimerThread+0x42 00bfffec 00000000 77faa02d 0006fe60 00000000 KERNEL32!BaseThreadStart+0x52

1: kd> dds 0006fee0 0006fee0 0006ff08 0006fee4 76b93701 3rdPartyGINA!WlxDisplaySASNotice+0x43 0006fee8 000755e8 0006feec 76b90000 3rdParty 0006fef0 00000578 0006fef4 00000000 0006fef8 76b9370b 3rdParty!WlxDisplaySASNotice+0x4d 0006fefc 0008d0e0 0006ff00 00000008 0006ff04 00000080 0006ff08 0006ff20 0006ff0c 010164c6 winlogon!MainLoop+0x96 0006ff10 0008d0e0 0006ff14 5ffa0000 0006ff18 000755e8 0006ff1c 00000000 0006ff20 0006ff58 0006ff24 01014960 winlogon!WinMain+0x37a 0006ff28 000755e8 0006ff2c 00000005 0006ff30 00072c9c 0006ff34 00000001 0006ff38 000001bc 0006ff3c 00000005 0006ff40 00000001 0006ff44 0000000d 0006ff48 00000000 0006ff4c 00000000 0006ff50 00000000 0006ff54 0000ffe4 0006ff58 0006fff4 0006ff5c 0101cd06 winlogon!WinMainCRTStartup+0x156

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Crash Dump Analysis, Crash Dump Patterns, Debugging, WinDbg Tips and Tricks | 32 Comments »

Is there any life inside Windows?

September 13th, 2007

This question came into my mind while reading the fascinating book “Life Itself: A Comprehensive Inquiry into the Nature, Origin, and Fabrication of Life” written by theoretical biologist Robert Rosen and recalling that 13-14 years ago one Unix guru saw a Matt Pietrek’s book “Windows Internals” about Windows 3.x and asked me a rhetorical question: “Is there a life?”. Now we can ask the question again: “Is there any life inside a contemporary computer system?”.

Jokes apart, Rosen’s book about life is the most interesting science book I have ever read. It is a bit mathematical but doesn’t require more mathematical maturity than general science undergraduate level and even covers Category Theory in the context of modeling systems. Most people learnt about sets and their foundational nature at school or university but have never heard about a different approach via categories. Hopefully, this book will provide the right answer to me when I finish reading it.

- Dmitry Vostokov @ DumpAnalysis.org -

Posted in Books, Software Architecture | 3 Comments »

June 2026
M	T	W	T	F	S	S
« May
1	2	3	4	5	6	7
8	9	10	11	12	13	14
15	16	17	18	19	20	21
22	23	24	25	26	27	28
29	30

Pages

Recent Comments

Categories

Archives

ARM64

Automated Analysis

Blogroll

Debugging Channels

Forensics

Hardware

Linux

Mac OS X

Magazines and Newspapers

Malware Analysis

Medical Diagnostics

Narratology

Related Links

Reversing

Scripting Languages

Source Code

Tracing Tools

Meta