记一次 .NET 某新能源系统 线程疯涨 分析

小秦哥  金牌会员 | 2022-8-24 01:52:56 | 显示全部楼层 | 阅读模式
打印 上一主题 下一主题
楼主

主题 863|帖子 863|积分 2589

一：背景

1. 讲故事

前段时间收到一个朋友的求助，说他的程序线程数疯涨，寻求如何解决。

等我分析完之后，我觉得这个问题很有代表性，所以拿出来和大家分享下，还是上老工具 WinDbg。
二： WinDbg 分析

1. 线程真的在疯涨吗

要想查线程有没有疯涨，可以用 !t 命令看一下。
  1. 0:000:x86> !t
  2. ThreadCount:      382
  3. UnstartedThread:  1
  4. BackgroundThread: 376
  5. PendingThread:    0
  6. DeadThread:       2
  7. Hosted Runtime:   no
  8.                                                                          Lock  
  9.        ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
  10.    0    1  59c 00e52fb0     26020 Preemptive  12D67610:00000000 00e4b408 0     STA
  11.    2    2 2b30 00e61aa0     2b220 Preemptive  00000000:00000000 00e4b408 0     MTA (Finalizer)
  12.    3    3 18cc 00ea72b8   202b220 Preemptive  00000000:00000000 00e4b408 0     MTA
  13.    5    4 1f18 00f02998   1020220 Preemptive  00000000:00000000 00e4b408 0     Ukn (Threadpool Worker)
  14. XXXX    6    0 00f056f8     39820 Preemptive  00000000:00000000 00e4b408 0     MTA
  15.    6    7 2154 09052448   202b020 Preemptive  12E353E0:00000000 00e4b408 0     MTA
  16.    ...
  17. 377  373 2ee8 21a90958   1029220 Preemptive  12D1FCCC:00000000 00e4b408 0     MTA (Threadpool Worker)
  18. 378  374 227c 21b1d510   1029220 Preemptive  12DCBFC8:00000000 00e4b408 0     MTA (Threadpool Worker)
  19. 379  375  7e8 21b1baa8   1029220 Preemptive  12D39ADC:00000000 00e4b408 0     MTA (Threadpool Worker)
  20. 380  376 1d1c 21a8fec8   1029220 Preemptive  12D11F40:00000000 00e4b408 0     MTA (Threadpool Worker)
  21. 381  366 19ec 215c1bd0   1029220 Preemptive  12DB42D8:00000000 00e4b408 0     MTA (Threadpool Worker)
  22. 382  377 1dc8 21b1bff0   1029220 Preemptive  12C71F9C:00000000 00e4b408 0     MTA (Threadpool Worker)
  23. 383  378  f94 215bc750   1029220 Preemptive  12E10568:00000000 00e4b408 0     MTA (Threadpool Worker)
  24. 384  379 17d4 21ac5580   1029220 Preemptive  12D8EE98:00000000 00e4b408 0     MTA (Threadpool Worker)
  25. 385  381 2c1c 21b1b018   1029220 Preemptive  12D0DD00:00000000 00e4b408 0     MTA (Threadpool Worker)
  26. 386  380 309c 21b1da58   1029220 Preemptive  12E25028:00000000 00e4b408 0     MTA (Threadpool Worker)
  27. 387  382 3048 21ac6aa0   1029220 Preemptive  12DFA918:00000000 00e4b408 0     MTA (Threadpool Worker)
复制代码
从卦中看，主线程是一个 STA，说明是一个窗体程序，一个窗体能做到 387 个线程，也是挺牛的，同时也能观察到大多都是 ThreadPool Worker ，也就是线程池工作线程。
2. 这些线程都在干嘛

这里有一个小技巧，那就是线程号越大，往往都是最新创建的，往往从这里面就能套出来一些有用的东西，言外之意就扒一扒 380 ~ 387 这些线程的调用栈。
  1. 0:387:x86> ~387s
  2. ntdll_77380000!NtWaitForSingleObject+0xc:
  3. 773f29dc c20c00          ret     0Ch
  4. 0:387:x86> k
  5. CvRegToMachine(x86) conversion failure for 0x14f
  6. X86MachineInfo::SetVal: unknown register 0 requested
  7. # ChildEBP RetAddr      
  8. 00 31fef104 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
  9. 01 31fef104 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
  10. 02 31fef168 74b3efed     clr!CLRSemaphore::Wait+0xbe
  11. 03 31fef19c 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
  12. 04 31fef204 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
  13. 05 31feff24 7649fa29     clr!Thread::intermediateThreadProc+0x58
  14. 06 31feff34 773e7a7e     kernel32!BaseThreadInitThunk+0x19
  15. 07 31feff90 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
  16. 0:387:x86> ~386s
  17. ntdll_77380000!NtWaitForSingleObject+0xc:
  18. 773f29dc c20c00          ret     0Ch
  19. 0:386:x86> k
  20. CvRegToMachine(x86) conversion failure for 0x14f
  21. X86MachineInfo::SetVal: unknown register 0 requested
  22. # ChildEBP RetAddr      
  23. 00 31d6ede4 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
  24. 01 31d6ede4 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
  25. 02 31d6ee48 74b3efed     clr!CLRSemaphore::Wait+0xbe
  26. 03 31d6ee7c 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
  27. 04 31d6eee4 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
  28. 05 31d6fb84 7649fa29     clr!Thread::intermediateThreadProc+0x58
  29. 06 31d6fb94 773e7a7e     kernel32!BaseThreadInitThunk+0x19
  30. 07 31d6fbf0 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
  31. 0:386:x86> ~385s
  32. ntdll_77380000!NtWaitForSingleObject+0xc:
  33. 773f29dc c20c00          ret     0Ch
  34. 0:385:x86> k
  35. CvRegToMachine(x86) conversion failure for 0x14f
  36. X86MachineInfo::SetVal: unknown register 0 requested
  37. # ChildEBP RetAddr      
  38. 00 31eaee64 755a1539     ntdll_77380000!NtWaitForSingleObject+0xc
  39. 01 31eaee64 74b3ee3b     KERNELBASE!WaitForSingleObjectEx+0x99
  40. 02 31eaeec8 74b3efed     clr!CLRSemaphore::Wait+0xbe
  41. 03 31eaeefc 74b3eee2     clr!ThreadpoolMgr::UnfairSemaphore::Wait+0x13a
  42. 04 31eaef64 74a54c27     clr!ThreadpoolMgr::WorkerThreadStart+0x328
  43. 05 31eafb7c 7649fa29     clr!Thread::intermediateThreadProc+0x58
  44. 06 31eafb8c 773e7a7e     kernel32!BaseThreadInitThunk+0x19
  45. 07 31eafbe8 773e7a4e     ntdll_77380000!__RtlUserThreadStart+0x2f
复制代码
从线程栈上看，这些线程都在 UnfairSemaphore 处等待，这是一个正常现象，因为这些线程都是通过 UnfairSemaphore 锁来唤醒,不过奇怪的是，这些线程为什么产生，又为什么不被消亡？
根据经验预测：肯定有代码在不断的调度 线程池 线程，然后又做了一个短命的操作，导致线程池线程不断新增，又得不到线程可以被消亡的阈值。
3. 程序真的在频繁调度线程吗

既然猜测是程序在频繁的调用线程池线程，能做的只能是观察此时 dump 中的所有线程的线程栈，看能不能挖到点有价值的东西，可以使用 ~*e !clrstack  命令。

经过仔细观察这近400个线程栈，发现有 37 处都是 System.Threading.Thread.Sleep(Int32), 而且大多都是 HslCommunication.Core.Net.NetworkBase.ThreadPoolCheckTimeOut(System.Object) 函数，能清楚的看到是由线程池发起的，接下来就是用 ILSpy 反编译下这个函数看下到底是怎么回事。
  1.         protected void ThreadPoolCheckTimeOut(object obj)
  2.         {
  3.             HslTimeOut hslTimeOut;
  4.             if ((hslTimeOut = obj as HslTimeOut) == null)
  5.             {
  6.                 return;
  7.             }
  8.             while (!hslTimeOut.IsSuccessful)
  9.             {
  10.                 Thread.Sleep(100);
  11.                 if ((DateTime.Now - hslTimeOut.StartTime).TotalMilliseconds > (double)hslTimeOut.DelayTime)
  12.                 {
  13.                     if (!hslTimeOut.IsSuccessful)
  14.                     {
  15.                         LogNet?.WriteWarn(ToString(), "Wait Time Out : " + hslTimeOut.DelayTime);
  16.                         hslTimeOut.Operator?.Invoke();
  17.                         hslTimeOut.WorkSocket?.Close();
  18.                     }
  19.                     break;
  20.                 }
  21.             }
  22.         }
复制代码
接下来通过 ILSpy 查看这个方法的引用，发现有很多处，抽几个如下：
  1.         protected OperateResult<TNetMessage> ReceiveMessage<TNetMessage>(Socket socket, int timeOut, TNetMessage netMsg) where TNetMessage : INetMessage
  2.         {
  3.             ...
  4.             if (timeOut > 0)
  5.             {
  6.                 ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
  7.             }
  8.             ...
  9.         }
  11.         protected OperateResult<Socket> CreateSocketAndConnect(IPEndPoint endPoint, int timeOut)
  12.         {
  13.             ...
  14.             ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
  15.             ...
  16.         }
  18.         protected void CreateSocketAndConnect(IPEndPoint endPoint, int timeOut, Action<OperateResult<Socket>> connectCallback)
  19.         {
  20.             ...
  21.             ThreadPool.QueueUserWorkItem(ThreadPoolCheckTimeOut, hslTimeOut);
  22.             ...
  23.         }
复制代码
从上面代码看，确实存在一些商榷的地方，很多的 socket 操作都用线程池来处理 ThreadPoolCheckTimeOut() 函数，而在这个函数内当 hslTimeOut.IsSuccessful =false 的时候，在 if ((DateTime.Now - hslTimeOut.StartTime).TotalMilliseconds > (double)hslTimeOut.DelayTime) 不满足的时间区间内会一直 sleep，这就导致当 socket 请求量上去后，导致很多线程处于 sleep 状态, 线程池又不得不生成更多的线程来处理 ThreadPoolCheckTimeOut() 逻辑。
到这里终于就找到了符合 线程池线程 疯涨的底层逻辑，接下来看看 HslCommunication.dll 为何物，去找一下它的类库声明。
  1. [assembly: CompilationRelaxations(8)]
  2. [assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
  3. [assembly: Debuggable(DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints)]
  4. [assembly: AssemblyTitle("HslCommunication")]
  5. [assembly: AssemblyDescription("一个框架库，包含完善的网络通信及日志组件")]
  6. [assembly: AssemblyConfiguration("")]
  7. [assembly: AssemblyCompany("")]
  8. [assembly: AssemblyProduct("HslCommunication")]
  9. [assembly: AssemblyCopyright("Copyright © By Richard.Hu 2018")]
  10. [assembly: AssemblyTrademark("")]
  11. [assembly: ComVisible(false)]
  12. [assembly: Guid("d3710b78-1b32-4d53-9604-0451a795a2f5")]
  13. [assembly: AssemblyFileVersion("5.3.2.0")]
  14. [assembly: AssemblyVersion("5.3.2.0")]
复制代码
可以看到，这是一个商业组件。

三：总结

由于定位到疑似是 HslCommunication 组件的问题，看了下还是 商业版 , 这就尴尬了，建议的解决办法如下：
1） 短期：
用 ThreadPool.SetMaxThreads 限定线程上限。
2） 长期：
找作者看看有没有最新版，或者到 https://github.com/dathlin/HslCommunication 上提一个 issue，让别人系统性解决一下。

免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！

本帖子中包含更多资源

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

x
回复

使用道具 举报

0 个回复

倒序浏览
返回列表

快速回复

高级模式
B Color Image Link Quote Code Smilies
您需要登录后才可以回帖 登录 or 立即注册

本版积分规则

小秦哥

金牌会员
这个人很懒什么都没写!

楼主热帖

标签云

存储 挺好的 服务器
微信订阅号
微信服务号
微信客服
小程序
H5
关于我们 商务合作 网站地图
©Copyright 2022-2024 杭州祥升科技有限公司 版权所有 浙ICP备20004199号
快速回复 返回顶部 返回列表