Crash Dump Analysis Patterns (Part 198)

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

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

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

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

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

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

Leave a Reply