Windbg 分析

1. CPU 真的爆高吗

还是老规矩，要想找到这个答案，可以使用!tp命令。

0:044> !tplogStart: 1logSize: 200CPU utilization: 88 %Worker Thread: Total: 8 Running: 4 Idle: 4 MaxLimit: 1023 MinLimit: 4Work Request in Queue: 0--------------------------------------Number of Timers: 2--------------------------------------Completion Port Thread:Total: 2 Free: 2 MaxFree: 8 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 4

从卦中数据看当前cpu确实达到了 88%，接下来我们观察下这个程序的机器cpu是否给力，可以用!cpuid观察。

0:044> !cpuidCPF/M/SManufacturer MHz 06,94,3GenuineIntel3192 16,94,3GenuineIntel3192 26,94,3GenuineIntel3192 36,94,3GenuineIntel3192

从卦中看，尼玛也就4core，有点弱哈，好歹也是一个高利润的药厂，这么抠门哈。

2. 为什么会CPU爆高

导致 CPU 爆高的因素有很多，没有标准答案，需要自己去找原因，首先我们观察下这个程序的线程数量，可以使用!t命令即可。

0:044> !tThreadCount:451UnstartedThread:0BackgroundThread: 443PendingThread:0DeadThread: 1Hosted Runtime: no Lock DBG ID OSID ThreadOBJState GC Mode GC Alloc ContextDomain Count Apt Exception 01 22b8 04CE8728 26020 Preemptive18E5C92C:18E5E4DC 04c86c20 -00001 STA32 17c8 04B25768 2b220 Preemptive18CAF3A0:18CB1374 04c86c20 -00001 MTA (Finalizer)44 238c 04C0CDD8 202b020 Preemptive18E45D88:18E464DC 04c86c20 -00001 MTA55 230c 0A6C37A0 202b020 Preemptive18DAC318:18DAC47C 04c86c20 -00001 MTA66 23a0 0A70E620 202b220 Preemptive00000000:00000000 04c86c20 -00001 MTA...

从卦中数据看，当前有 451 个线程，其中后台线程是 443 个，再结合刚才的 !tp 看到的线程池线程也才 8 个，这就说明这个程序中有 400+ 的线程是直接通过new Thread创建的，这个信息就比较可疑了，为啥不用线程池用 Thread ，有蹊跷。

接下来的思路就是使用~*e !clrstack命令观察下每个线程此时都在做什么，命令一输入，刷了好久。

0:044> ~*e !clrstack...OS Thread Id: 0x220c (18)Child SP IP Call Site184CF614 77dd19dc [HelperMethodFrame: 184cf614] System.Threading.Thread.SleepInternal(Int32)184CF680 141975f4 System.Threading.Thread.Sleep(Int32) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 357]184CF694 165055b9 xxx.ActionThread`1[[xxx]].Loop()184CF878 74467741 System.Threading.Thread+StartHelper.Callback(System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 42]184CF888 7446fca1 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs @ 183]184CF8C0 74466742 System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]184CFA14 74cbc29f [DebuggerU2MCatchHandlerFrame: 184cfa14] ...

在卦中的各个线程栈上也没有看到什么特别明显的业务函数，大多都是停在Thread.SleepInternal上进行等待，这就让我陷入了迷茫。

3. 一朝顿悟，走出迷茫

CPU不可能无缘无故的爆高，总会是那些线程给抬起来的，但这个程序中的线程大多都在Thread.SleepInternal上，若说他们能把 CPU 弄爆总有点说不过去。

但问题总得要解决，在无突破口的情况也只能硬着头皮在Thread.SleepInternal上强行突破了，首先用Ctrl+F搜下有多少线程卡在SleepInternal上，截图如下：

尼玛，几乎所有线程都在 Sleep，一般来说有这么多线程都在 Sleep 也是少数，接下来抽一个线程看看业务方法是怎么进行 Sleep 的，参考代码如下：

在这个Loop方法中我发现有很多的Sleep(1)，看到这个我突然想到了高频的上下文切换导致的 CPU 爆高。

接下来这个代码的指令到底停在哪个方法呢？可以反编译 Loop 方法。

0:047> !clrstackOS Thread Id: 0xad8 (47)Child SP IP Call Site20B5F434 77dd19dc [HelperMethodFrame: 20b5f434] System.Threading.Thread.SleepInternal(Int32)20B5F4A0 141975f4 System.Threading.Thread.Sleep(Int32) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 357]20B5F4B4 1f123c71 xxx.ActionThread`1[[xxx].Loop()20B5F698 74467741 System.Threading.Thread+StartHelper.Callback(System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 42]20B5F6A8 1baab7da System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/ExecutionContext.cs @ 183]20B5F6E0 74466742 System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]20B5F834 74cbc29f [DebuggerU2MCatchHandlerFrame: 20b5f834] 0:047> !U /d 1f123c71Normal JIT generated codexxx.ActionThread`1[xxx].Loop()ilAddr is 0A324040 pImport is 08AD6468Begin 1F123C10, size abd1f123c10 55pushebp1f123c11 8becmov ebp,esp1f123c13 57pushedi1f123c14 56pushesi1f123c15 81ecd4010000sub esp,1D4h1f123c1b c5f877vzeroupper1f123c1e c5d857e4vxorpsxmm4,xmm4,xmm41f123c22 c5fa7fa524feffff vmovdqu xmmword ptr [ebp-1DCh],xmm41f123c2a c5fa7fa534feffff vmovdqu xmmword ptr [ebp-1CCh],xmm41f123c32 b850feffffmov eax,0FFFFFE50h1f123c37 c5fa7f6405f4vmovdqu xmmword ptr [ebp+eax-0Ch],xmm41f123c3d c5fa7f640504vmovdqu xmmword ptr [ebp+eax+4],xmm41f123c43 c5fa7f640514vmovdqu xmmword ptr [ebp+eax+14h],xmm41f123c49 83c030add eax,30h...1f123c5a e84115cc55callcoreclr!JIT_DbgIsJustMyCode (74de51a0)1f123c5f 90nop1f123c60 90nop1f123c61 e9300a0000jmp xxx.ActionThread.Loop+0xa86 (1f124696)1f123c66 90nop1f123c67 b901000000mov ecx,11f123c6c e87f54eaeacall09fc90f0 (System.Threading.Thread.Sleep(Int32), mdToken: 06002D01)>>> 1f123c71 90nop...

通过卦中的>>>可以确认很多的方法都是在while (!base.IsTerminated)中进行空转，如果 Sleep(1) 的线程比较少那可能没什么问题，但也扛不住400多线程一起玩哈，最后高频的上下文切换导致的 CPU 爆高。

在 Sleep(1) 内部会涉及到CPU的等待队列，就绪队列，以及定时器_KTIMER内核对象, 因为 Windows 源码不公开，内部还是比较搞的，可以用!pcr命令观察下 cpu的背包。

lkd> !pcr 0KPCR for Processor 0 at fffff8058023c000:Major 1 Minor 1NtTib.ExceptionList: fffff80589089fb0NtTib.StackBase: fffff80589088000 NtTib.StackLimit: 000000137e1fa158 NtTib.SubSystemTib: fffff8058023c000NtTib.Version: 000000008023c180NtTib.UserPointer: fffff8058023c870NtTib.SelfTib: 000000137dfe0000SelfPcr: 0000000000000000 Prcb: fffff8058023c180 Irql: 0000000000000000 ...CurrentThread: ffff910c66906080 NextThread: 0000000000000000 IdleThread: fffff80583d27a00DpcQueue: lkd> dt nt!_KPRCB fffff8058023c180 +0x008 CurrentThread: 0xffff910c`66906080 _KTHREAD +0x010 NextThread : (null)+0x018 IdleThread : 0xfffff805`83d27a00 _KTHREAD ... +0x7c00 WaitListHead : _LIST_ENTRY [ 0xffff910c`5ec30158 - 0xffff910c`628b1158 ] +0x7c80 DispatcherReadyListHead : [32] _LIST_ENTRY [ 0xfffff805`80243e00 - 0xfffff805`80243e00 ]

上面的[32]就是等待线程的32个优先级的数组队列。

有了上面的分析结果，最后就是告诉朋友做到如下两点：

  • 减少 Thread.Sleep(1) 的线程参与数。
  • 尽量将 1 -> 50 来缓解，当然越大越好。