Crash Dump Analysis Patterns (Part 232)

We already introduced Active Thread pattern variant for Mac OS X. Here we provide an example for Windows. Unless we have Evental Dumps, Active Threads in Windows are usually threads from Busy System or Spiking Threads, and, therefore, represent an abnormal behavior since most threads are waiting or calling some API. For Evental Dumps they may be just normal threads:

0:000> r
rax=0000000000000006 rbx=0000000000000003 rcx=0000000000000018
rdx=0000000000000000 rsi=000000000028c601 rdi=0000000002bee25e
rip=000007feff1a5a09 rsp=000000000028c380 rbp=0000000000000000
r8=0000000000000000 r9=00000000001653a0 r10=000000000000000e
r11=000000000000000a r12=0000000000000006 r13=000000000028ca38
r14=0000000002bec888 r15=0000000000173630
iopl=0 nv up ei pl nz ac po nc
cs=0033 ss=002b ds=002b es=002b fs=0053 gs=002b efl=00000216
usp10!otlChainingLookup::apply+0×2f9:
000007fe`ff1a5a09 498d0c06 lea rcx,[r14+rax]

0:000> k
# Child-SP RetAddr Call Site
00 00000000`0028c380 000007fe`ff19f4f2 usp10!otlChainingLookup::apply+0×2f9
01 00000000`0028c4b0 000007fe`ff19e777 usp10!ApplyLookup+0×592
02 00000000`0028c5a0 000007fe`ff19a634 usp10!ApplyFeatures+0×777
03 00000000`0028c860 000007fe`ff181800 usp10!SubstituteOtlGlyphs+0×224
04 00000000`0028c910 000007fe`ff174cc0 usp10!GenericEngineGetGlyphs+0×1000
05 00000000`0028ccb0 000007fe`ff1389c5 usp10!ShlShape+0×7a0
06 00000000`0028ced0 000007fe`ff147363 usp10!ScriptShape+0×205
07 00000000`0028cf70 000007fe`ff148ac9 usp10!RenderItemNoFallback+0×433
08 00000000`0028d030 000007fe`ff148d86 usp10!RenderItemWithFallback+0×129
09 00000000`0028d080 000007fe`ff14a5f7 usp10!RenderItem+0×36
0a 00000000`0028d0d0 000007fe`ff13b2c9 usp10!ScriptStringAnalyzeGlyphs+0×277
0b 00000000`0028d170 000007fe`fdd616bf usp10!ScriptStringAnalyse+0×399
0c 00000000`0028d1f0 000007fe`fdd614cc lpk!LpkCharsetDraw+0×4eb
0d 00000000`0028d3b0 00000000`774e85c5 lpk!LpkDrawTextEx+0×68
0e 00000000`0028d420 00000000`774e865c user32!DT_DrawStr+0xa6
0f 00000000`0028d4c0 00000000`774e826c user32!DT_DrawJustifiedLine+0xa6
10 00000000`0028d530 00000000`774e6cc8 user32!DrawTextExWorker+0×442
11 00000000`0028d640 000007fe`fbd840d1 user32!DrawTextW+0×57
12 00000000`0028d6b0 000007fe`fbd83e49 comctl32!CLVView::_ComputeLabelSizeWorker+0×1d1
13 00000000`0028da40 000007fe`fbd8cc48 comctl32!CLVView::v_RecomputeLabelSize+0×1f9
14 00000000`0028dd70 000007fe`fbda9d24 comctl32!CLVListView::v_DrawItem+0×284
15 00000000`0028e110 000007fe`fbd9773b comctl32!CLVDrawItemManager::DrawItem+0×4c0
16 00000000`0028e170 000007fe`fbd95f8e comctl32!CLVDrawManager::_PaintItems+0×3df
17 00000000`0028e3b0 000007fe`fbd95e87 comctl32!CLVDrawManager::_PaintWorkArea+0xda
18 00000000`0028e430 000007fe`fbd95cff comctl32!CLVDrawManager::_OnPaintWorkAreas+0×147
19 00000000`0028e4c0 000007fe`fbd06f1b comctl32!CLVDrawManager::_OnPaint+0×14b
1a 00000000`0028e570 000007fe`fbd06011 comctl32!CListView::WndProc+0xebf
1b 00000000`0028e770 00000000`774e9bd1 comctl32!CListView::s_WndProc+0×6cd
1c 00000000`0028e7d0 00000000`774e3bfc user32!UserCallWinProcCheckWow+0×1ad
1d 00000000`0028e890 00000000`774e3b78 user32!CallWindowProcAorW+0xdc
1e 00000000`0028e8e0 000007fe`fbca6215 user32!CallWindowProcW+0×18
1f 00000000`0028e920 000007fe`fbca69a0 comctl32!CallOriginalWndProc+0×1d
20 00000000`0028e960 000007fe`fbca6768 comctl32!CallNextSubclassProc+0×8c
21 00000000`0028e9e0 000007fe`fde1096a comctl32!DefSubclassProc+0×7c
22 00000000`0028ea30 000007fe`fdde9df4 shell32!DefSubclassProc+0×56
23 00000000`0028ea60 000007fe`fbca69a0 shell32!CListViewHost::s_ListViewSubclassWndProc+0×267
24 00000000`0028eb40 000007fe`fbca6877 comctl32!CallNextSubclassProc+0×8c
25 00000000`0028ebc0 00000000`774e9bd1 comctl32!MasterSubclassProc+0xe7
26 00000000`0028ec60 00000000`774e72cb user32!UserCallWinProcCheckWow+0×1ad
27 00000000`0028ed20 00000000`774e6829 user32!DispatchClientMessage+0xc3
28 00000000`0028ed80 00000000`776211f5 user32!_fnDWORD+0×2d
29 00000000`0028ede0 00000000`774e6e5a ntdll!KiUserCallbackDispatcherContinue
2a 00000000`0028ee68 00000000`774e6e6c user32!NtUserDispatchMessage+0xa
2b 00000000`0028ee70 00000000`774e67c2 user32!DispatchMessageWorker+0×55b
2c 00000000`0028eef0 000007fe`fbcc34a4 user32!IsDialogMessageW+0×153
2d 00000000`0028ef80 000007fe`fbcc583f comctl32!Prop_IsDialogMessage+0×1f0
2e 00000000`0028eff0 000007fe`fbcc5c05 comctl32!_RealPropertySheet+0×31b
2f 00000000`0028f0c0 000007fe`ff214e68 comctl32!_PropertySheet+0×55
30 00000000`0028f100 000007fe`ff214bb1 comdlg32!Print_InvokePropertySheets+0×2c6
31 00000000`0028f660 000007fe`ff21499c comdlg32!PrintDlgExX+0×2be
32 00000000`0028f6c0 00000000`ffec250f comdlg32!PrintDlgExW+0×38
33 00000000`0028f730 00000000`ffec242b notepad!GetPrinterDCviaDialog+0xab
34 00000000`0028f7f0 00000000`ffec23e8 notepad!PrintIt+0×46
35 00000000`0028fb70 00000000`ffec14eb notepad!NPCommand+0xdb
36 00000000`0028fca0 00000000`774e9bd1 notepad!NPWndProc+0×540
37 00000000`0028fce0 00000000`774e98da user32!UserCallWinProcCheckWow+0×1ad
38 00000000`0028fda0 00000000`ffec10bc user32!DispatchMessageWorker+0×3b5
39 00000000`0028fe20 00000000`ffec133c notepad!WinMain+0×16f
3a 00000000`0028fea0 00000000`773c59ed notepad!DisplayNonGenuineDlgWorker+0×2da
3b 00000000`0028ff60 00000000`775fc541 kernel32!BaseThreadInitThunk+0xd
3c 00000000`0028ff90 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

We see the thread is active, in the middle of the function. For comparison, the next 2 threads are waiting and calling API respectively:

0:000> ~1k
# Child-SP          RetAddr           Call Site
00 00000000`02edf748 00000000`775eb037 ntdll!NtWaitForMultipleObjects+0xa
01 00000000`02edf750 00000000`773c59ed ntdll!TppWaiterpThread+0×14d
02 00000000`02edf9f0 00000000`775fc541 kernel32!BaseThreadInitThunk+0xd
03 00000000`02edfa20 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0:000> ~2k
# Child-SP          RetAddr           Call Site
00 00000000`0344e048 000007fe`fd3f403e ntdll!NtUnmapViewOfSection+0xa
01 00000000`0344e050 00000000`774e2edf KERNELBASE!FreeLibrary+0xa4
02 00000000`0344e080 000007fe`fdddaab3 user32!PrivateExtractIconsW+0×34b
03 00000000`0344e5a0 000007fe`fdddac28 shell32!SHPrivateExtractIcons+0×50a
04 00000000`0344e870 000007fe`fdde34b4 shell32!SHDefExtractIconW+0×254
05 00000000`0344eb60 000007fe`fdde3435 shell32!CExtractIcon::_ExtractW+0xcd
06 00000000`0344ebe0 000007fe`fdf0d529 shell32!CExtractIconBase::Extract+0×21
07 00000000`0344ec20 000007fe`fdf0d2da shell32!IExtractIcon_Extract+0×43
08 00000000`0344ec60 000007fe`fdddfff0 shell32!_GetILIndexGivenPXIcon+0×22e
09 00000000`0344f100 000007fe`fdde27a4 shell32!_GetILIndexFromItem+0×87
0a 00000000`0344f1a0 000007fe`fddb6506 shell32!SHGetIconIndexFromPIDL+0×66
0b 00000000`0344f1d0 000007fe`fdedb186 shell32!MapIDListToIconILIndex+0×52
0c 00000000`0344f250 000007fe`fdddc54c shell32!CLoadSystemIconTask::InternalResumeRT+0×110
0d 00000000`0344f2e0 000007fe`fde0efcb shell32!CRunnableTask::Run+0xda
0e 00000000`0344f310 000007fe`fde12b56 shell32!CShellTask::TT_Run+0×124
0f 00000000`0344f340 000007fe`fde12cb2 shell32!CShellTaskThread::ThreadProc+0×1d2
10 00000000`0344f3e0 000007fe`ff2b3843 shell32!CShellTaskThread::s_ThreadProc+0×22
11 00000000`0344f410 00000000`775f15db shlwapi!ExecuteWorkItemThreadProc+0xf
12 00000000`0344f440 00000000`775f0c56 ntdll!RtlpTpWorkCallback+0×16b
13 00000000`0344f520 00000000`773c59ed ntdll!TppWorkerThread+0×5ff
14 00000000`0344f820 00000000`775fc541 kernel32!BaseThreadInitThunk+0xd
15 00000000`0344f850 00000000`00000000 ntdll!RtlUserThreadStart+0×1d

0:000> ub ntdll!NtUnmapViewOfSection+0xa
ntdll!NtAccessCheckAndAuditAlarm:
00000000`77621540 4c8bd1          mov     r10,rcx
00000000`77621543 b826000000      mov     eax,26h
00000000`77621548 0f05            syscall
00000000`7762154a c3              ret
00000000`7762154b 0f1f440000      nop     dword ptr [rax+rax]
ntdll!NtUnmapViewOfSection:
00000000`77621550 4c8bd1          mov     r10,rcx
00000000`77621553 b827000000      mov     eax,27h
00000000`77621558 0f05            syscall

Our Active Thread is not Spiking Thread since CPU consumption is minimal:

0:000> !runaway f
User Mode Time
Thread       Time
0:1ca4      0 days 0:00:00.171
11:1fb0      0 days 0:00:00.000
10:f98       0 days 0:00:00.000
9:eb8       0 days 0:00:00.000
8:1b80      0 days 0:00:00.000
7:139c      0 days 0:00:00.000
6:1d9c      0 days 0:00:00.000
5:1b44      0 days 0:00:00.000
4:1edc      0 days 0:00:00.000
3:830       0 days 0:00:00.000
2:1638      0 days 0:00:00.000
1:1ab0      0 days 0:00:00.000
Kernel Mode Time
Thread       Time
0:1ca4      0 days 0:00:00.421
11:1fb0      0 days 0:00:00.000
10:f98       0 days 0:00:00.000
9:eb8       0 days 0:00:00.000
8:1b80      0 days 0:00:00.000
7:139c      0 days 0:00:00.000
6:1d9c      0 days 0:00:00.000
5:1b44      0 days 0:00:00.000
4:1edc      0 days 0:00:00.000
3:830       0 days 0:00:00.000
2:1638      0 days 0:00:00.000
1:1ab0      0 days 0:00:00.000
Elapsed Time
Thread       Time
11:1fb0      24692 days 13:29:46.335
0:1ca4      0 days 0:02:39.671
1:1ab0      0 days 0:01:48.239
2:1638      0 days 0:01:18.837
4:1edc      0 days 0:01:18.697
3:830       0 days 0:01:18.697
5:1b44      0 days 0:01:18.497
6:1d9c      0 days 0:01:18.387
7:139c      0 days 0:01:15.957
8:1b80      0 days 0:01:14.397
9:eb8       0 days 0:01:01.485
10:f98       0 days 0:00:39.849

However, the huge Elapsed Time for the thread #11 (most likely the value is uninitialized) and its stack trace suggest that the dump was saved on Create Thread debugging event by a debugger:

0:000> ~11k
# Child-SP          RetAddr           Call Site
00 00000000`0666fb08 00000000`00000000 ntdll!RtlUserThreadStart

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

Leave a Reply