技術文章 » 記一次 .NET 某工控資料採集平臺 執行緒數 爆高分析

記一次 .NET 某工控資料採集平臺 執行緒數 爆高分析

2022-07-04 18:01:11

一：背景

1. 講故事

前幾天有位朋友在 B站 加到我，說他的程式出現了 執行緒數 爆高的問題，讓我幫忙看一下怎麼回事，截圖如下：

說來也奇怪，這些天碰到了好幾起關於執行緒數無緣無故的爆高，不過那幾個問題比這一篇要複雜的多，主要涉及到非託管層面，分享這一篇的目的主要是它很有代表性，很有必要。

閒話不多說，既然執行緒數爆高，那就上 windbg 說話。

二：WinDbg 分析

1. 執行緒數真的高嗎

既然說執行緒數高，那到底有多少呢？ 我們可以用 !t 命令看一下。


0:000> !t
ThreadCount:      109
UnstartedThread:  0
BackgroundThread: 104
PendingThread:    0
DeadThread:       1
Hosted Runtime:   no
                                                                         Lock  
       ID OSID ThreadOBJ    State GC Mode     GC Alloc Context  Domain   Count Apt Exception
   0    1 2970 00581020     26020 Preemptive  0294AE60:00000000 0057a5f0 0     STA 
   2    2 1d2c 00590670     2b220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Finalizer) 
   5    4 3388 0063a9b8   102a220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Threadpool Worker) 
   6    5 265c 0063b458   1020220 Preemptive  00000000:00000000 0057a5f0 0     Ukn (Threadpool Worker) 
   7    7 3370 07100fa8   202b220 Preemptive  00000000:00000000 0057a5f0 0     MTA 
 ...
 113   41 4af4 0a85a490   8029220 Preemptive  0294F918:00000000 0057a5f0 0     MTA (Threadpool Completion Port) 
 114   75 4b9c 0a83d818   8029220 Preemptive  00000000:00000000 0057a5f0 0     MTA (Threadpool Completion Port) 
 115   76 4ba0 0a83d2d0   8029220 Preemptive  02B53AC4:00000000 0057a5f0 0     MTA (Threadpool Completion Port)

從卦象看，當前有 115 個託管執行緒，從主執行緒的 STA 模式看 應該是一個 WinForm/WPF 程式，桌面程式這個執行緒數說多也不多，說少也不少，下一步的思路就是看下這些執行緒都在做什麼。

2. 這些執行緒都在做什麼

要探究每個執行緒都在做什麼，可以用 ~*e !clrstack 調出所有執行緒棧，然後仔細耐心的觀察這些執行緒。


0:000> ~*e !clrstack 
OS Thread Id: 0x488c (109)
Child SP       IP Call Site
114de760 7704018d [GCFrame: 114de760] 
114de90c 7704018d [GCFrame: 114de90c] 
114de8bc 7704018d [HelperMethodFrame: 114de8bc] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
114de94c 6dfe2767 System.Threading.Monitor.Enter(System.Object, Boolean ByRef)
114de95c 056107e3 CSRedis.Internal.IO.RedisIO.Write(Byte[])
114de998 05cb338c CSRedis.Internal.RedisConnector.Write(CSRedis.RedisCommand)
114de9dc 05cb32fc CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Write[[System.__Canon, mscorlib]](CSRedis.RedisCommand`1<System.__Canon>)
114de9f0 05cb3263 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
114dea0c 050c4ffd CSRedis.RedisClient.Unsubscribe(System.String[])
114dea24 050c01e3 CSRedis.CSRedisClient+SubscribeObject+c__DisplayClass13_0.b__1(System.Object)
114deab4 6e026471 System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)
114deab8 6dfe2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
114deb24 6dfe2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
114deb38 6e026377 System.Threading.TimerQueueTimer.CallCallback()
114deb6c 6e0261fe System.Threading.TimerQueueTimer.Fire()
114debac 6e02612f System.Threading.TimerQueue.FireNextTimers()
114debec 6e025ff1 System.Threading.TimerQueue.AppDomainTimerCallback()
114dee10 6f38eaf6 [DebuggerU2MCatchHandlerFrame: 114dee10] 
...

從卦象看，執行緒特徵非常明顯，有 86 個執行緒卡在 Monitor.ReliableEnter 處，它就是我們C#中的 監視鎖 ，既然是監視鎖，那就好辦了，檢視它的 同步塊表，看看誰在 lock 裡賴著不出來導致其他執行緒等待，使用 windbg 的 !syncblk 命令。


0:000> !syncblk
Index         SyncBlock MonitorHeld Recursion Owning Thread Info          SyncBlock Owner
   72 005ef1f0           87         1 07176838 12c8  13   028374e4 System.Object
   75 005efd1c           87         1 07176d80 32c0  14   028368ec System.Object
-----------------------------
Total           84
CCW             0
RCW             1
ComClassFactory 0
Free            17

從表中看，當前有兩個 lock 物件，並且執行緒 13 和 14 在 lock 區內不出來，導致各自有 43 個執行緒在等待，接下來思路就很清晰了，我們檢視這兩個執行緒到底在幹嘛？

3. 持有執行緒正在做什麼

我們就從 13 號執行緒入手，看看它正在做什麼。


0:013> !clrstack 
OS Thread Id: 0x12c8 (13)
Child SP       IP Call Site
0971eb84 7703f901 [InlinedCallFrame: 0971eb84] 
0971eb80 6c5b940f DomainBoundILStubClass.IL_STUB_PInvoke(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
0971eb84 6c55b11d [InlinedCallFrame: 0971eb84] System.Net.UnsafeNclNativeMethods+OSSOCK.recv(IntPtr, Byte*, Int32, System.Net.Sockets.SocketFlags)
0971ebbc 6c55b11d System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags, System.Net.Sockets.SocketError ByRef)
0971ebec 6c55b00e System.Net.Sockets.Socket.Receive(Byte[], Int32, Int32, System.Net.Sockets.SocketFlags)
0971ec10 6c55af43 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32)
0971ec40 6e05add8 System.IO.Stream.ReadByte()
0971ec50 05610d2c CSRedis.Internal.IO.RedisIO.ReadByte()
0971ec8c 05610c5a CSRedis.Internal.IO.RedisReader.ReadType()
0971ecb0 05610a9e CSRedis.Internal.IO.RedisReader.ExpectType(CSRedis.RedisMessage)
0971ed28 05cb3696 CSRedis.Internal.Commands.RedisSubscription.Parse(CSRedis.Internal.IO.RedisReader)
0971ed90 05cb35bd CSRedis.Internal.RedisConnector.Read[[System.__Canon, mscorlib]](System.Func`2<CSRedis.Internal.IO.RedisReader,System.__Canon>)
0971ede0 05cb3487 CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Listen(System.Func`2<CSRedis.Internal.IO.RedisReader,System.__Canon>)
0971ee34 05cb32b9 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
0971ee50 05cb3156 CSRedis.RedisClient.Subscribe(System.String[])
0971ee68 05cb255a CSRedis.CSRedisClient+SubscribeObject.Subscribe(System.Object)
0971ef98 6dfb6063 System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
0971efa4 6dfe2925 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
0971f010 6dfe2836 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
0971f024 6dfe27f1 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
0971f03c 6e036ebe System.Threading.ThreadHelper.ThreadStart(System.Object)
0971f180 6f38eaf6 [GCFrame: 0971f180] 
0971f364 6f38eaf6 [DebuggerU2MCatchHandlerFrame: 0971f364]

從執行緒棧看，是這位朋友使用了 CSRedis 的訂閱功能，最後在 CSRedis.Internal.IO.RedisIO.ReadByte() 方法處遲遲出不來，問題點找到了，接下來就可以看下它的原始碼。

4. 檢視原始碼

看原始碼的話，可以用 ILSpy 工具，編譯後的程式碼如下：

其實這地方用 lock 鎖不太穩妥，一旦出現網路波動，持有執行緒就會一直等待，如果這個執行緒是由 ThreadPool 提供，那就會導致 ThreadPool 中的執行緒數暴增，從 Waiting 的執行緒上追查，發現這些執行緒數都是由 Timer 提供，執行緒棧和截圖如下：


OS Thread Id: 0x40e8 (67)
Child SP       IP Call Site
0e7af608 7704018d [GCFrame: 0e7af608] 
0e7af7b4 7704018d [GCFrame: 0e7af7b4] 
0e7af764 7704018d [HelperMethodFrame: 0e7af764] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
0e7af7f4 6dfe2767 System.Threading.Monitor.Enter(System.Object, Boolean ByRef)
0e7af804 056107e3 CSRedis.Internal.IO.RedisIO.Write(Byte[])
0e7af840 05cb338c CSRedis.Internal.RedisConnector.Write(CSRedis.RedisCommand)
0e7af884 05cb32fc CSRedis.Internal.RedisListener`1[[System.__Canon, mscorlib]].Write[[System.__Canon, mscorlib]](CSRedis.RedisCommand`1<System.__Canon>)
0e7af898 05cb3263 CSRedis.Internal.SubscriptionListener.Send(CSRedis.Internal.Commands.RedisSubscription)
0e7af8b4 050c4ffd CSRedis.RedisClient.Unsubscribe(System.String[])
0e7af8cc 050c01e3 CSRedis.CSRedisClient+SubscribeObject+c__DisplayClass13_0.b__1(System.Object)
0e7af95c 6e026471 System.Threading.TimerQueueTimer.CallCallbackInContext(System.Object)

三：總結

整體分析下來，這應該算是 CSRedis 的一個 Bug，這種問題我能做的就是讓朋友升級到最新版本看看，不過既然是 Bug 那其他人肯定也會遇到，看了下 CSRedis.dll 程式集給的 github 地址。


[assembly: CompilationRelaxations(8)]
[assembly: RuntimeCompatibility(WrapNonExceptionThrows = true)]
[assembly: Debuggable(DebuggableAttribute.DebuggingModes.Default | DebuggableAttribute.DebuggingModes.DisableOptimizations | DebuggableAttribute.DebuggingModes.IgnoreSymbolStoreSequencePoints | DebuggableAttribute.DebuggingModes.EnableEditAndContinue)]
[assembly: TargetFramework(".NETFramework,Version=v4.5", FrameworkDisplayName = ".NET Framework 4.5")]
[assembly: AssemblyCompany("CSRedisCore")]
[assembly: AssemblyConfiguration("Debug")]
[assembly: AssemblyDescription("CSRedis 是 redis.io 官方推薦庫，支援 redis-trib叢集、哨兵、私有分割區與連線池管理技術，簡易 RedisHelper 靜態類。")]
[assembly: AssemblyFileVersion("3.6.6.0")]
[assembly: AssemblyInformationalVersion("3.6.6")]
[assembly: AssemblyProduct("CSRedisCore")]
[assembly: AssemblyTitle("CSRedisCore")]
[assembly: AssemblyMetadata("RepositoryUrl", "https://github.com/2881099/csredis")]
[assembly: AssemblyVersion("3.6.6.0")]

果然在 Issues（ https://github.com/2881099/csredis/issues/414 ) 中找到了同樣的問題， 很可惜作者沒給解答。

說一個有意思的事情，我看了下提問者的暱稱 thicktao 好像很熟悉，在微信上好像有這位朋友。

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

圖片名稱