Crash Dump Analysis Patterns (Part 32)
Tuesday, October 23rd, 2007When 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 -