Blog (Debugging Slang, Part 15)
Thursday, July 29th, 2010Blog - Binary log.
Examples: This program blogged. I’m reading its blog now.
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -
Blog - Binary log.
Examples: This program blogged. I’m reading its blog now.
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -
Here we show the possible signs of the classical Thread Starvation.
Suppose we have two running threads with a priority 8:
0: kd> !running
System Processors 3 (affinity mask)
Idle Processors 0
Prcbs Current Next
0 ffdff120 89a92020 O...............
1 f7737120 89275020 W...............
0: kd> !thread 89a92020
THREAD 89a92020 Cid 11d8.27d8 Teb: 7ffd9000 Win32Thread: bc1e6860 RUNNING on processor 0
[...]
Priority 8 BasePriority 8 PriorityDecrement 0
0: kd> !thread 89275020
THREAD 89275020 Cid 1cd0.2510 Teb: 7ffa9000 Win32Thread: bc343180 RUNNING on processor 1
[...]
Priority 8 BasePriority 8 PriorityDecrement 0
If we have other threads ready with the same priority contending for the same processors other threads with less priority might starve (shown in red):
0: kd> !ready
Processor 0: Ready Threads at priority 8
THREAD 894a1db0 Cid 1a98.25c0 Teb: 7ffde000 Win32Thread: bc19cea8 READY
THREAD 897c4818 Cid 11d8.1c5c Teb: 7ffa2000 Win32Thread: bc2c5ba8 READY
THREAD 8911fd18 Cid 2730.03f4 Teb: 7ffd9000 Win32Thread: bc305830 READY
Processor 0: Ready Threads at priority 7
THREAD 8a9e5ab0 Cid 0250.0470 Teb: 7ff9f000 Win32Thread: 00000000 READY
THREAD 8a086838 Cid 0250.0654 Teb: 7ff93000 Win32Thread: 00000000 READY
THREAD 8984b8b8 Cid 0250.1dc4 Teb: 7ff99000 Win32Thread: 00000000 READY
THREAD 8912a4c0 Cid 0f4c.2410 Teb: 7ff81000 Win32Thread: 00000000 READY
THREAD 89e5c570 Cid 0f4c.01c8 Teb: 00000000 Win32Thread: 00000000 READY
Processor 0: Ready Threads at priority 6
THREAD 8a9353b0 Cid 1584.1598 Teb: 7ff8b000 Win32Thread: bc057698 READY
THREAD 8aba2020 Cid 1584.15f0 Teb: 7ff9f000 Win32Thread: bc2a0ea8 READY
THREAD 8aab17a0 Cid 1584.01a8 Teb: 7ff92000 Win32Thread: bc316ea8 READY
THREAD 8a457020 Cid 1584.0634 Teb: 7ff8d000 Win32Thread: bc30fea8 READY
THREAD 8a3d4020 Cid 1584.1510 Teb: 7ff8f000 Win32Thread: bc15b8a0 READY
THREAD 8a5f5db0 Cid 1584.165c Teb: 7ff9d000 Win32Thread: bc171be8 READY
THREAD 8a297020 Cid 0f4c.0f54 Teb: 7ffde000 Win32Thread: bc20fda0 READY
THREAD 8a126020 Cid 1584.175c Teb: 7ffa9000 Win32Thread: 00000000 READY
THREAD 8a548478 Cid 0250.07b0 Teb: 7ff9a000 Win32Thread: 00000000 READY
THREAD 8a478020 Cid 0944.0988 Teb: 7ffd9000 Win32Thread: 00000000 READY
THREAD 8986ad08 Cid 1d2c.1cf0 Teb: 7ffa8000 Win32Thread: bc285800 READY
THREAD 897f4db0 Cid 1d2c.2554 Teb: 7ffdb000 Win32Thread: bc238e80 READY
THREAD 89a2e618 Cid 1d2c.1de4 Teb: 7ffdd000 Win32Thread: bc203908 READY
Processor 0: Ready Threads at priority 0
THREAD 8b184db0 Cid 0004.0008 Teb: 00000000 Win32Thread: 00000000 READY
Processor 1: Ready Threads at priority 8
THREAD 89d89db0 Cid 1b10.20ac Teb: 7ffd7000 Win32Thread: bc16e680 READY
THREAD 891f24a8 Cid 1e2c.20d0 Teb: 7ffda000 Win32Thread: bc1b9ea8 READY
THREAD 89214db0 Cid 1e2c.24d4 Teb: 7ffd7000 Win32Thread: bc24ed48 READY
THREAD 89a28020 Cid 1b10.21b4 Teb: 7ffa7000 Win32Thread: bc25b3b8 READY
THREAD 891e03b0 Cid 1a98.05c4 Teb: 7ffdb000 Win32Thread: bc228bb0 READY
THREAD 891b0020 Cid 1cd0.0144 Teb: 7ffde000 Win32Thread: bc205ea8 READY
Processor 1: Ready Threads at priority 7
THREAD 898367a0 Cid 0f4c.1cd4 Teb: 00000000 Win32Thread: 00000000 READY
THREAD 8a1ac020 Cid 0f4c.1450 Teb: 00000000 Win32Thread: 00000000 READY
THREAD 8aa1ab90 Cid 0f4c.11b0 Teb: 00000000 Win32Thread: 00000000 READY
THREAD 89cc92e0 Cid 0f4c.1b34 Teb: 00000000 Win32Thread: 00000000 READY
THREAD 89579020 Cid 0f4c.2220 Teb: 00000000 Win32Thread: 00000000 READY
Processor 1: Ready Threads at priority 6
THREAD 8a487db0 Cid 1584.14bc Teb: 7ffa2000 Win32Thread: bc304ea8 READY
THREAD 8a3ce020 Cid 1584.0630 Teb: 7ff8e000 Win32Thread: bc293c20 READY
THREAD 8a1b6db0 Cid 1584.1590 Teb: 7ff8c000 Win32Thread: bc310ea8 READY
THREAD 8a1fe6e0 Cid 1584.15ec Teb: 7ffa1000 Win32Thread: bc15bea8 READY
THREAD 8ac0adb0 Cid 1584.156c Teb: 7ff8a000 Win32Thread: bc153be8 READY
THREAD 8b1e35a0 Cid 1584.15f4 Teb: 7ff9e000 Win32Thread: bc0567e8 READY
THREAD 8a3288e8 Cid 1584.14b8 Teb: 7ff9a000 Win32Thread: bc2fbea8 READY
THREAD 8a5056a0 Cid 1584.1518 Teb: 7ff91000 Win32Thread: bc337ea8 READY
THREAD 891afdb0 Cid 1d2c.27e8 Teb: 7ffaf000 Win32Thread: bc217c18 READY
THREAD 8a07d308 Cid 1d2c.2548 Teb: 7ffae000 Win32Thread: bc235750 READY
THREAD 8a055d18 Cid 1584.17d0 Teb: 7ffd5000 Win32Thread: 00000000 READY
THREAD 8ac0b770 Cid 0250.0268 Teb: 7ffde000 Win32Thread: bc2349d8 READY
THREAD 8a0eeb40 Cid 1584.1560 Teb: 7ffdc000 Win32Thread: 00000000 READY
Here we should also analyze stack traces for running and ready threads with priority 8 and check kernel and user times. If we find anything common between them we should also check ready threads with lower priority to see if that commonality is unique to threads with priority 8. See also the similar pattern: Busy System and the similar starvation pattern resulted from realtime priority threads.
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -
Sometimes I accidentally use du WinDbg command (to interpret memory as Unicode) instead of da (to interpret memory as ASCII):
0:000> db 07329f28 l20
07329f28 68 69 64 70 6e 73 74 3d-26 74 78 74 74 6f 3d 26 hidpnst=&txtto=&
07329f38 74 78 74 63 63 3d 26 74-78 74 62 63 63 3d 26 74 txtcc=&txtbcc=&t
0:000> da 07329f28 l20
07329f28 "hidpnst=&txtto=&txtcc=&txtbcc=&t"
0:000> du 07329f28 l10
07329f28 "楨灤獮㵴琦瑸潴.硴捴㵣琦瑸换㵣琦"
This time I tried to get extra hidden meaning from a process dump taken after the process suffered a CPU spike by using Google translator and got this text (I put more lengthy Unicode sequence and removed some offensive words):
"Luan Xian Zhen Qi-bin 㵴 cisternae. Huasong 㵣 Qi, Qi-bin-bin for 㵣 pull 㵪 䕒 .. 䉉 Ya Hui material. Hong SHIKA King. Huajiayuyan nuts .. 䐰 〥 䅁 evil force. Rafter Hui Qi 䤫 Mi cat deterrent Junying hydrogen walk. cisternae Huzhao Man cat Wuzhou Wen Zhen Zhao Zhen Pan scene file Shan. prison Shang Tang. Jue Shi Pan. sewage knock Xi. generous Zhen. 䤫. ice. conflict. cisternae Zhao askance nuts. rafter .. On unfeigned domain knock. Kagesue Mankuo. 㜲 Ruo Yi enemy luster of gems. cisternae Yu Wei Shan scene. Tan knock Shan. tally Xia Pan Ying. rafter. Xia. luster of gems tumultuous. Jing Feng-Tou Airuo enemy luster of gems Yixian … additionally . Tu. civet eliminating the lot Shan Ying RB Thieme, Jr.-Voltage trapping Feng-潷 Man. Tan knock Ruo Yi Xian cat enemy luster of gems. rafter Shi Feng-Tou. Mu. Minli Bang domain sewage Huitangyuzhao Su-hai.-Voltage Jiumi. rafter. Qing Wei Jun. 歳 Mi hai 䤫 Panyu. Zhucuoqufang .. 䐰 〥. 䐰 〥 䥁 hydrogen walk. rafter. Mount Zao Man. .. Run-Voltage Rendering. Tang Ying Yi. Shisuqingshi Fangmaosheji Yu Zhao 䤫 Su-. tide. tatami knock Feng-generous. rafter. Min luster of gems. Que Tu Mei Shi Tang Pan Ying. Jijue-Voltage. rafter. Wei Hui Mongoose Feng-. hunting. rafter. revolves Recent-Voltage sewage 䤫. stay Jiao RB Thieme, Jr soup.潷 Han.’m setback Xun. Han Tun petty. Liaohe. 䥔 end of Tu Feng-generous. rafter Xiang Shan Li Tu. trapping the end of sleep ZHEJIANG NORMAL Feng-Tou Yu Xun Jing Wen Fang 䤫 .. 䠫 pine and methods of disease. tatami knock Feng-generous. apply Feng-evil force fell Junying Su-Ao Po .. knock .. Tan Li Shan Jie look askance alone. ㅆ Guang Tang rafter. pool just cultural and"
From the translation I see previously hidden notions of gems, disease and evil forces :-)
ASCII->Unicode->translation->ASCII
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -
8
A separating digit of user space and kernel space in equi-bipartitional 32-bit virtual memory, for example, on x86 Windows systems:
RetAddr
80833491 nt!KiSwapContext+0×26
80828f2b nt!KiSwapThread+0×2e5
8099490a nt!KeDelayExecutionThread+0×2ab
808897cc nt!NtDelayExecution+0×84
7c82860c nt!KiFastCallEntry+0xfc
7c826f69 ntdll!KiFastSystemCallRet
7c83d454 ntdll!NtDelayExecution+0xc
77e6482f ntdll!RtlpTimerThread+0×47
00000000 kernel32!BaseThreadStart+0×34
lkd> lm
start end module name
[…]
77bd0000 77c19000 GDI32
77c20000 77cbf000 RPCRT4
77cd0000 77d5b000 OLEAUT32
77e20000 77eb2000 USER32
77ec0000 77f12000 SHLWAPI
77f30000 77fdc000 ADVAPI32
7c800000 7c915000 kernel32
7c920000 7c9e8000 ntdll
7c9f0000 7d1f9000 SHELL32
7e020000 7e02f000 SAMLIB
80800000 80a5d000 nt
80a5d000 80a89000 hal
bf800000 bf9d0000 win32k
[…]This number doesn’t continue to be used in the same way on x64 Windows systems, for example:
RetAddr Call Site
fffff800`0167e082 nt!KiSwapContext+0×7a
fffff800`0167a34b nt!KiCommitThreadWait+0×1d2
fffff800`01973def nt!KeWaitForMultipleObjects+0×271
fffff800`019746f6 nt!ObpWaitForMultipleObjects+0×294
fffff800`01675ed3 nt!NtWaitForMultipleObjects+0xe5
00000000`77ca030a nt!KiSystemServiceCopyEnd+0×13
lkd> lm
start end module name
00000000`774a0000 00000000`7756d000 USER32
00000000`77570000 00000000`7769d000 kernel32
00000000`776a0000 00000000`77826000 ntdll
00000000`ffe60000 00000000`ffec0000 services
000007fe`fca90000 000007fe`fca97000 wshtcpip
000007fe`fcae0000 000007fe`fcb0c000 NTMARTA
000007fe`fcbe0000 000007fe`fcc34000 schannel
000007fe`fce10000 000007fe`fce5f000 mswsock
000007fe`fcf60000 000007fe`fcf69000 credssp
000007fe`fcf90000 000007fe`fcf97000 wship6
000007fe`fd0d0000 000007fe`fd207000 CRYPT32
000007fe`fd260000 000007fe`fd279000 MSASN1
000007fe`fd5a0000 000007fe`fd5b6000 NCObjAPI
000007fe`fd5c0000 000007fe`fd625000 SCESRV
000007fe`fd630000 000007fe`fd665000 apphelp
000007fe`fd680000 000007fe`fd6a6000 AUTHZ
000007fe`fd950000 000007fe`fd96c000 Secur32
000007fe`fd970000 000007fe`fd996000 USERENV
000007fe`fd9a0000 000007fe`fd9bc000 SAMLIB
000007fe`fdc80000 000007fe`fdce4000 GDI32
000007fe`fdd10000 000007fe`fdd1d000 LPK
000007fe`fdd20000 000007fe`fde28000 ADVAPI32
000007fe`fde30000 000007fe`fdecc000 msvcrt
000007fe`fded0000 000007fe`fdefd000 IMM32
000007fe`fdf00000 000007fe`fe0d8000 ole32
000007fe`fe0e0000 000007fe`fe0e7000 NSI
000007fe`fe190000 000007fe`fe22a000 USP10
000007fe`fe230000 000007fe`fe373000 RPCRT4
000007fe`ff340000 000007fe`ff395000 WLDAP32
000007fe`ff540000 000007fe`ff584000 WS2_32
000007fe`ff7d0000 000007fe`ff8d2000 MSCTF
fffff800`01802000 fffff800`01848000 hal
fffff800`01848000 fffff800`01d60000 nt
fffff960`000f0000 fffff960`003a1000 win32k
[…]
Synonyms:
Antonyms:
Also: virtual memory, user space, kernel space, x86, x64, 7
- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -