发帖
翼度科技»论坛 › 编程开发 › .net › 查看内容

记一次 .NET 某药厂业务系统 CPU爆高分析

赵承杰

2

主题

2

帖子

6

积分

新手上路

Rank: 1

积分
6
显示全部楼层
一：背景

1. 讲故事

前段时间有位朋友找到我，说他们的程序出现了CPU爆高，让我帮忙看下怎么回事？这种问题好的办法就是抓个dump丢给我，推荐的工具就是用 procdump 自动化抓捕。
二：Windbg 分析

1. CPU 真的爆高吗

还是老规矩，要想找到这个答案，可以使用 !tp 命令。
  1. 0:044> !tp
  2. logStart: 1
  3. logSize: 200
  4. CPU utilization: 88 %
  5. Worker Thread: Total: 8 Running: 4 Idle: 4 MaxLimit: 1023 MinLimit: 4
  6. Work Request in Queue: 0
  7. --------------------------------------
  8. Number of Timers: 2
  9. --------------------------------------
  10. Completion Port Thread:Total: 2 Free: 2 MaxFree: 8 CurrentLimit: 2 MaxLimit: 1000 MinLimit: 4
复制代码
从卦中数据看当前cpu确实达到了 88%，接下来我们观察下这个程序的机器cpu是否给力，可以用 !cpuid 观察。
  1. 0:044> !cpuid
  2. CP  F/M/S  Manufacturer     MHz
  3. 0  6,94,3  GenuineIntel    3192
  4. 1  6,94,3  GenuineIntel    3192
  5. 2  6,94,3  GenuineIntel    3192
  6. 3  6,94,3  GenuineIntel    3192
复制代码
从卦中看，尼玛也就4core，有点弱哈，好歹也是一个高利润的药厂，这么抠门哈。
2. 为什么会CPU爆高

导致 CPU 爆高的因素有很多，没有标准答案，需要自己去找原因，首先我们观察下这个程序的线程数量，可以使用 !t 命令即可。
  1. 0:044> !t
  2. ThreadCount:      451
  3. UnstartedThread:  0
  4. BackgroundThread: 443
  5. PendingThread:    0
  6. DeadThread:       1
  7. Hosted Runtime:   no
  8.                                                                              Lock  
  9. DBG   ID     OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
  10.    0    1     22b8 04CE8728     26020 Preemptive  18E5C92C:18E5E4DC 04c86c20 -00001 STA
  11.    3    2     17c8 04B25768     2b220 Preemptive  18CAF3A0:18CB1374 04c86c20 -00001 MTA (Finalizer)
  12.    4    4     238c 04C0CDD8   202b020 Preemptive  18E45D88:18E464DC 04c86c20 -00001 MTA
  13.    5    5     230c 0A6C37A0   202b020 Preemptive  18DAC318:18DAC47C 04c86c20 -00001 MTA
  14.    6    6     23a0 0A70E620   202b220 Preemptive  00000000:00000000 04c86c20 -00001 MTA
  15.    ...
复制代码
从卦中数据看，当前有 451 个线程，其中后台线程是 443 个，再结合刚才的 !tp 看到的线程池线程也才 8 个，这就说明这个程序中有 400+ 的线程是直接通过 new Thread 创建的，这个信息就比较可疑了，为啥不用线程池用 Thread ，有蹊跷。
接下来的思路就是使用 ~*e !clrstack 命令观察下每个线程此时都在做什么，命令一输入，刷了好久。
  1. 0:044> ~*e !clrstack
  2. ...
  3. OS Thread Id: 0x220c (18)
  4. Child SP       IP Call Site
  5. 184CF614 77dd19dc [HelperMethodFrame: 184cf614] System.Threading.Thread.SleepInternal(Int32)
  6. 184CF680 141975f4 System.Threading.Thread.Sleep(Int32) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 357]
  7. 184CF694 165055b9 xxx.ActionThread`1[[xxx]].Loop()
  8. 184CF878 74467741 System.Threading.Thread+StartHelper.Callback(System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 42]
  9. 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]
  10. 184CF8C0 74466742 System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]
  11. 184CFA14 74cbc29f [DebuggerU2MCatchHandlerFrame: 184cfa14]
  12. ...
复制代码
在卦中的各个线程栈上也没有看到什么特别明显的业务函数，大多都是停在 Thread.SleepInternal 上进行等待，这就让我陷入了迷茫。
3. 一朝顿悟，走出迷茫

CPU不可能无缘无故的爆高，总会是那些线程给抬起来的，但这个程序中的线程大多都在 Thread.SleepInternal 上，若说他们能把 CPU 弄爆总有点说不过去。
但问题总得要解决，在无突破口的情况也只能硬着头皮在 Thread.SleepInternal 上强行突破了，首先用 Ctrl+F 搜下有多少线程卡在 SleepInternal 上，截图如下：

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

在这个Loop方法中我发现有很多的 Sleep(1)，看到这个我突然想到了高频的上下文切换导致的 CPU 爆高。
接下来这个代码的指令到底停在哪个方法呢？可以反编译 Loop 方法。
  1. 0:047> !clrstack
  2. OS Thread Id: 0xad8 (47)
  3. Child SP       IP Call Site
  4. 20B5F434 77dd19dc [HelperMethodFrame: 20b5f434] System.Threading.Thread.SleepInternal(Int32)
  5. 20B5F4A0 141975f4 System.Threading.Thread.Sleep(Int32) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 357]
  6. 20B5F4B4 1f123c71 xxx.ActionThread`1[[xxx].Loop()
  7. 20B5F698 74467741 System.Threading.Thread+StartHelper.Callback(System.Object) [/_/src/libraries/System.Private.CoreLib/src/System/Threading/Thread.cs @ 42]
  8. 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]
  9. 20B5F6E0 74466742 System.Threading.Thread.StartCallback() [/_/src/coreclr/System.Private.CoreLib/src/System/Threading/Thread.CoreCLR.cs @ 105]
  10. 20B5F834 74cbc29f [DebuggerU2MCatchHandlerFrame: 20b5f834]
  11. 0:047> !U /d 1f123c71
  12. Normal JIT generated code
  13. xxx.ActionThread`1[xxx].Loop()
  14. ilAddr is 0A324040 pImport is 08AD6468
  15. Begin 1F123C10, size abd
  16. 1f123c10 55              push    ebp
  17. 1f123c11 8bec            mov     ebp,esp
  18. 1f123c13 57              push    edi
  19. 1f123c14 56              push    esi
  20. 1f123c15 81ecd4010000    sub     esp,1D4h
  21. 1f123c1b c5f877          vzeroupper
  22. 1f123c1e c5d857e4        vxorps  xmm4,xmm4,xmm4
  23. 1f123c22 c5fa7fa524feffff vmovdqu xmmword ptr [ebp-1DCh],xmm4
  24. 1f123c2a c5fa7fa534feffff vmovdqu xmmword ptr [ebp-1CCh],xmm4
  25. 1f123c32 b850feffff      mov     eax,0FFFFFE50h
  26. 1f123c37 c5fa7f6405f4    vmovdqu xmmword ptr [ebp+eax-0Ch],xmm4
  27. 1f123c3d c5fa7f640504    vmovdqu xmmword ptr [ebp+eax+4],xmm4
  28. 1f123c43 c5fa7f640514    vmovdqu xmmword ptr [ebp+eax+14h],xmm4
  29. 1f123c49 83c030          add     eax,30h
  30. ...
  31. 1f123c5a e84115cc55      call    coreclr!JIT_DbgIsJustMyCode (74de51a0)
  32. 1f123c5f 90              nop
  33. 1f123c60 90              nop
  34. 1f123c61 e9300a0000      jmp     xxx.ActionThread<xxx>.Loop+0xa86 (1f124696)
  35. 1f123c66 90              nop
  36. 1f123c67 b901000000      mov     ecx,1
  37. 1f123c6c e87f54eaea      call    09fc90f0 (System.Threading.Thread.Sleep(Int32), mdToken: 06002D01)
  38. >>> 1f123c71 90              nop
  39. ...
复制代码
通过卦中的 >>> 可以确认很多的方法都是在 while (!base.IsTerminated) 中进行空转，如果 Sleep(1) 的线程比较少那可能没什么问题，但也扛不住400多线程一起玩哈，最后高频的上下文切换导致的 CPU 爆高。
在 Sleep(1) 内部会涉及到CPU的等待队列，就绪队列，以及定时器 _KTIMER 内核对象, 因为 Windows 源码不公开，内部还是比较搞的，可以用 !pcr 命令观察下 cpu的背包。
  1. lkd> !pcr 0
  2. KPCR for Processor 0 at fffff8058023c000:
  3.     Major 1 Minor 1
  4.         NtTib.ExceptionList: fffff80589089fb0
  5.             NtTib.StackBase: fffff80589088000
  6.            NtTib.StackLimit: 000000137e1fa158
  7.          NtTib.SubSystemTib: fffff8058023c000
  8.               NtTib.Version: 000000008023c180
  9.           NtTib.UserPointer: fffff8058023c870
  10.               NtTib.SelfTib: 000000137dfe0000
  12.                     SelfPcr: 0000000000000000
  13.                        Prcb: fffff8058023c180
  14.                        Irql: 0000000000000000
  15.                  ...
  17.               CurrentThread: ffff910c66906080
  18.                  NextThread: 0000000000000000
  19.                  IdleThread: fffff80583d27a00
  21.                   DpcQueue:
  23. lkd> dt nt!_KPRCB fffff8058023c180
  24.    +0x008 CurrentThread    : 0xffff910c`66906080 _KTHREAD
  25.    +0x010 NextThread       : (null)
  26.    +0x018 IdleThread       : 0xfffff805`83d27a00 _KTHREAD
  27.    ...
  28.    +0x7c00 WaitListHead     : _LIST_ENTRY [ 0xffff910c`5ec30158 - 0xffff910c`628b1158 ]
  29.    +0x7c80 DispatcherReadyListHead : [32] _LIST_ENTRY [ 0xfffff805`80243e00 - 0xfffff805`80243e00 ]
复制代码
上面的[32]就是等待线程的32个优先级的数组队列。
有了上面的分析结果，最后就是告诉朋友做到如下两点：

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

这次CPU的爆高还是挺有意思，不是业务方法导致的爆高，而是大量的 Sleep(1) 导致的高频上下文切换所致，有点意思，留下此文给大家避坑！

来源:https://www.cnblogs.com/huangxincheng/archive/2023/12/20/17916751.html
免责声明：由于采集信息均来自互联网，如果侵犯了您的权益，请联系我们【E-Mail:cb@itdo.tech】 我们会及时删除侵权内容，谢谢合作！

本帖子中包含更多资源

您需要 登录 才可以下载或查看，没有账号？立即注册

x

上一篇: 通过实例详细讲解Quartz.NET的一些高级功能的应用，你用到了多少

下一篇: Lock、Monitor线程锁

发表于 2023-12-20 19:48:42 来自手机

举报 回复 使用道具

返回列表 发新帖

Archiver|手机版|小黑屋|翼度科技

Copyright © 2001-2020, Tencent Cloud.　Powered by Discuz! X3.4