ToB企服应用市场:ToB评测及商务社交产业平台

标题: 记一次 .NET 某工控数据采集平台 线程数 爆高分析 [打印本页]
作者: 钜形不锈钢水箱    时间: 2022-8-22 15:12
标题: 记一次 .NET 某工控数据采集平台 线程数 爆高分析
一：背景

1. 讲故事

前几天有位朋友在 B站 加到我，说他的程序出现了 线程数 爆高的问题，让我帮忙看一下怎么回事，截图如下：

说来也奇怪，这些天碰到了好几起关于线程数无缘无故的爆高，不过那几个问题比这一篇要复杂的多，主要涉及到非托管层面，分享这一篇的目的主要是它很有代表性，很有必要。
闲话不多说，既然线程数爆高，那就上 windbg 说话。
二：WinDbg 分析

1. 线程数真的高吗

既然说线程数高，那到底有多少呢？ 我们可以用 !t 命令看一下。
  1. 0:000> !t
  2. ThreadCount:      109
  3. UnstartedThread:  0
  4. BackgroundThread: 104
  5. PendingThread:    0
  6. DeadThread:       1
  7. Hosted Runtime:   no
  8.                                                                          Lock  
  9.        ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
  10.    0    1 2970 00581020     26020 Preemptive  0294AE60:00000000 0057a5f0 0     STA
  11.    2    2 1d2c 00590670     2b220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Finalizer)
  12.    5    4 3388 0063a9b8   102a220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Threadpool Worker)
  13.    6    5 265c 0063b458   1020220 Preemptive  00000000:00000000 0057a5f0 0     Ukn (Threadpool Worker)
  14.    7    7 3370 07100fa8   202b220 Preemptive  00000000:00000000 0057a5f0 0     MTA
  15. ...
  16. 113   41 4af4 0a85a490   8029220 Preemptive  0294F918:00000000 0057a5f0 0     MTA (Threadpool Completion Port)
  17. 114   75 4b9c 0a83d818   8029220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Threadpool Completion Port)
  18. 115   76 4ba0 0a83d2d0   8029220 Preemptive  02B53AC4:00000000 0057a5f0 0     MTA (Threadpool Completion Port)
复制代码
从卦象看，当前有 115 个托管线程，从主线程的 STA 模式看 应该是一个 WinForm/WPF 程序，桌面程序这个线程数说多也不多，说少也不少，下一步的思路就是看下这些线程都在做什么。
2. 这些线程都在做什么

要探究每个线程都在做什么，可以用 ~*e !clrstack 调出所有线程栈，然后仔细耐心的观察这些线程。
  1. 0:000> ~*e !clrstack
  2. OS Thread Id: 0x488c (109)
  3. Child SP       IP Call Site
  4. 114de760 7704018d [GCFrame: 114de760]
  5. 114de90c 7704018d [GCFrame: 114de90c]
  6. 114de8bc 7704018d [HelperMethodFrame: 114de8bc] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
  7. 114de94c 6dfe2767 System.Threading.Monitor.Enter(System.Object, Boolean ByRef)
  8. 114de95c 056107e3 CSRedis.Internal.IO.RedisIO.Write(Byte[])
  9. 114de998 05cb338c CSRedis.Internal.RedisConnector.Write(CSRedis.RedisCommand)
  10. 114de9dc 05cb32fc CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Write[[System.__Canon, mscorlib]](CSRedis.RedisCommand`1<System.__Canon>)
  11. 114de9f0 05cb3263 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
  12. 114dea0c 050c4ffd CSRedis.RedisClient.Unsubscribe(System.String[])
  13. 114dea24 050c01e3 CSRedis.CSRedisClient+SubscribeObject+c__DisplayClass13_0.b__1(System.Object)
  14. 114deab4 6e026471 System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)
  15. 114deab8 6dfe2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
  16. 114deb24 6dfe2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
  17. 114deb38 6e026377 System.Threading.TimerQueueTimer.CallCallback()
  18. 114deb6c 6e0261fe System.Threading.TimerQueueTimer.Fire()
  19. 114debac 6e02612f System.Threading.TimerQueue.FireNextTimers()
  20. 114debec 6e025ff1 System.Threading.TimerQueue.AppDomainTimerCallback()
  21. 114dee10 6f38eaf6 [DebuggerU2MCatchHandlerFrame: 114dee10]
  22. ...
复制代码

从卦象看，线程特征非常明显，有 86 个线程卡在 Monitor.ReliableEnter 处，它就是我们C#中的 监视锁 ，既然是监视锁，那就好办了，查看它的 同步块表，看看谁在 lock 里赖着不出来导致其他线程等待，使用 windbg 的 !syncblk 命令。
  1. 0:000> !syncblk
  2. Index         SyncBlock MonitorHeld Recursion Owning Thread Info          SyncBlock Owner
  3.    72 005ef1f0           87         1 07176838 12c8  13   028374e4 System.Object
  4.    75 005efd1c           87         1 07176d80 32c0  14   028368ec System.Object
  5. -----------------------------
  6. Total           84
  7. CCW             0
  8. RCW             1
  9. ComClassFactory 0
  10. Free            17
复制代码
从表中看，当前有两个 lock 对象，并且线程 13 和 14 在 lock 区内不出来，导致各自有 43 个线程在等待，接下来思路就很清晰了，我们查看这两个线程到底在干嘛？
3. 持有线程正在做什么

我们就从 13 号线程入手，看看它正在做什么。
  1. 0:013> !clrstack
  2. OS Thread Id: 0x12c8 (13)
  3. Child SP       IP Call Site
  4. 0971eb84 7703f901 [InlinedCallFrame: 0971eb84]
  5. 0971eb80 6c5b940f DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
  6. 0971eb84 6c55b11d [InlinedCallFrame: 0971eb84] System.Net.UnsafeNclNativeMethods+OSSOCK.recv(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
  7. 0971ebbc 6c55b11d System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, System.Net.Sockets.SocketError ByRef)
  8. 0971ebec 6c55b00e System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags)
  9. 0971ec10 6c55af43 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32)
  10. 0971ec40 6e05add8 System.IO.Stream.ReadByte()
  11. 0971ec50 05610d2c CSRedis.Internal.IO.RedisIO.ReadByte()
  12. 0971ec8c 05610c5a CSRedis.Internal.IO.RedisReader.ReadType()
  13. 0971ecb0 05610a9e CSRedis.Internal.IO.RedisReader.ExpectType(CSRedis.RedisMessage)
  14. 0971ed28 05cb3696 CSRedis.Internal.Commands.RedisSubscription.Parse(CSRedis.Internal.IO.RedisReader)
  15. 0971ed90 05cb35bd CSRedis.Internal.RedisConnector.Read[[System.__Canon, mscorlib]](System.Func`2<CSRedis.Internal.IO.RedisReader,System.__Canon>)
  16. 0971ede0 05cb3487 CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Listen(System.Func`2<CSRedis.Internal.IO.RedisReader,System.__Canon>)
  17. 0971ee34 05cb32b9 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
  18. 0971ee50 05cb3156 CSRedis.RedisClient.Subscribe(System.String[])
  19. 0971ee68 05cb255a CSRedis.CSRedisClient+SubscribeObject.Subscribe(System.Object)
  20. 0971ef98 6dfb6063 System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
  21. 0971efa4 6dfe2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
  22. 0971f010 6dfe2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
  23. 0971f024 6dfe27f1 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
  24. 0971f03c 6e036ebe System.Threading.ThreadHelper.ThreadStart(System.Object)
  25. 0971f180 6f38eaf6 [GCFrame: 0971f180]
  26. 0971f364 6f38eaf6 [DebuggerU2MCatchHandlerFrame: 0971f364]
复制代码
从线程栈看，是这位朋友使用了 CSRedis 的订阅功能，最后在 CSRedis.Internal.IO.RedisIO.ReadByte() 方法处迟迟出不来，问题点找到了，接下来就可以看下它的源码。
4. 查看源码

看源码的话，可以用 ILSpy 工具，编译后的代码如下：

其实这地方用 lock 锁不太稳妥，一旦出现网络波动，持有线程就会一直等待，如果这个线程是由 ThreadPool 提供，那就会导致 ThreadPool 中的线程数暴增，从 Waiting 的线程上追查，发现这些线程数都是由 Timer 提供，线程栈和截图如下：
  1. OS Thread Id: 0x40e8 (67)
  2. Child SP       IP Call Site
  3. 0e7af608 7704018d [GCFrame: 0e7af608]
  4. 0e7af7b4 7704018d [GCFrame: 0e7af7b4]
  5. 0e7af764 7704018d [HelperMethodFrame: 0e7af764] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
  6. 0e7af7f4 6dfe2767 System.Threading.Monitor.Enter(System.Object, Boolean ByRef)
  7. 0e7af804 056107e3 CSRedis.Internal.IO.RedisIO.Write(Byte[])
  8. 0e7af840 05cb338c CSRedis.Internal.RedisConnector.Write(CSRedis.RedisCommand)
  9. 0e7af884 05cb32fc CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Write[[System.__Canon, mscorlib]](CSRedis.RedisCommand`1<System.__Canon>)
  10. 0e7af898 05cb3263 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
  11. 0e7af8b4 050c4ffd CSRedis.RedisClient.Unsubscribe(System.String[])
  12. 0e7af8cc 050c01e3 CSRedis.CSRedisClient+SubscribeObject+c__DisplayClass13_0.b__1(System.Object)
  13. 0e7af95c 6e026471 System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)
复制代码

三：总结

整体分析下来，这应该算是 CSRedis 的一个 Bug，这种问题我能做的就是让朋友升级到最新版本看看，不过既然是 Bug 那其他人肯定也会遇到，看了下 CSRedis.dll 程序集给的 github 地址。
  1. [assembly: CompilationRelaxations(8)]
  2. [assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
  3. [assembly: Debuggable(DebuggableAttribute.DebuggingModes.Default | DebuggableAttribute.DebuggingModes.DisableOptimizations | DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints | DebuggableAttribute.DebuggingModes.EnableEditAndContinue)]
  4. [assembly: TargetFramework(".NETFramework,Version=v4.5", FrameworkDisplayName = ".NET Framework 4.5")]
  5. [assembly: AssemblyCompany("CSRedisCore")]
  6. [assembly: AssemblyConfiguration("Debug")]
  7. [assembly: AssemblyDescription("CSRedis 是 redis.io 官方推荐库，支持 redis-trib集群、哨兵、私有分区与连接池管理技术，简易 RedisHelper 静态类。")]
  8. [assembly: AssemblyFileVersion("3.6.6.0")]
  9. [assembly: AssemblyInformationalVersion("3.6.6")]
  10. [assembly: AssemblyProduct("CSRedisCore")]
  11. [assembly: AssemblyTitle("CSRedisCore")]
  12. [assembly: AssemblyMetadata("RepositoryUrl", "https://github.com/2881099/csredis")]
  13. [assembly: AssemblyVersion("3.6.6.0")]
复制代码
果然在 Issues（ https://github.com/2881099/csredis/issues/414 ) 中找到了同样的问题， 很可惜作者没给解答。

说一个有意思的事情，我看了下提问者的昵称 thicktao 好像很熟悉，在微信上好像有这位朋友。

我去，他去年就曾今找过我，.NET圈子真小，缘分哈。。。

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



欢迎光临 ToB企服应用市场:ToB评测及商务社交产业平台 (https://dis.qidao123.com/) Powered by Discuz! X3.4