.NET?webapi某化妝品直播卡死分析
一:背景
1. 講故事
10月份星球里的一位老朋友找到我,說他們公司的程序在一個(gè)網(wǎng)紅直播帶貨下給弄得無響應(yīng)了,無響應(yīng)期間有大量的 RabbitMQ 超時(shí),尋求如何找到根源,聊天截圖我就不發(fā)了。
既然無響應(yīng)了,那必然是程序的大量線程被主動(dòng)或者被動(dòng)的掛起,朋友也很及時(shí)的從程序上抽了一管血下來,接下來就上 windbg 一起探究下到底發(fā)生了什么?
二:Windbg 分析
1. 線程們都怎么了
要想看所有線程,還是老命令 !t 。
0:000> !t ThreadCount: 5221 UnstartedThread: 0 BackgroundThread: 5199 PendingThread: 0 DeadThread: 21 Hosted Runtime: no Lock DBG ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception 20 1 74e4 00000276CB778180 202a020 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA 31 2 42cc 00000276CB6CA830 2b220 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Finalizer) 32 3 2b40 00000276CB85D1B0 102a220 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Threadpool Worker) 2 6 bccc 00000276CBA5D2F0 20220 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 Ukn 33 9 7224 00000276CBA5C0C0 3029220 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Threadpool Worker) System.IO.IOException 00000279ccc56cd0 9 23 29e0 0000027BD86FD180 20220 Preemptive 0000000000000000:0000000000000000 00000276cb77c9d0 -00001 Ukn ...
從簡(jiǎn)要信息看,當(dāng)前有 5000+ 的線程,太牛了,一般一臺(tái)機(jī)器的所有進(jìn)程的線程加起來也沒這么多。。。不過我目前看到最多的是 1w + 的線程 ??????, 就是那種不用線程池,直接用 Thread 造成的一種線程垃圾。
可以看到線程列表中的 9號(hào)線程 拋了托管異常,接下來看看是個(gè)啥錯(cuò)誤, 使用 !wpe 00000279ccc56cd0 命令。
0:000> !wpe 00000279ccc56cd0 Address: 00000279ccc56cd0 Exception Type: System.IO.IOException Message: Unable to read data from the transport connection: 遠(yuǎn)程主機(jī)強(qiáng)迫關(guān)閉了一個(gè)現(xiàn)有的連接。. Inner Exception: 00000279ccc56b20 System.Net.Sockets.SocketException 遠(yuǎn)程主機(jī)強(qiáng)迫關(guān)閉了一個(gè)現(xiàn)有的連接。 Stack: SP IP Function 000000791b88c970 00007ffd844a1b31 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32) 000000791b88ee80 00007ffd849e6f8a System.IO.BufferedStream.ReadByteSlow() 000000791b88eeb0 00007ffd8312950a RabbitMQ.Client.Impl.InboundFrame.ReadFrom(System.IO.Stream, Byte[]) 000000791b88ef40 00007ffd849e6d7d RabbitMQ.Client.Framing.Impl.Connection.MainLoopIteration() 000000791b88efa0 00007ffd8312832f RabbitMQ.Client.Framing.Impl.Connection.MainLoop() HResult: 80131620
從堆棧信息來看,程序做了一個(gè)遠(yuǎn)程訪問 RabbitMQ,結(jié)果 tcp 連接被對(duì)方關(guān)閉了,貌似和朋友說的有大量 RabbitMQ 超時(shí)有關(guān)。
接下來就是查看各個(gè)線程棧,研究下此時(shí)這些線程都在干什么,使用 ~*e !clrstack 命令,通過仔細(xì)研讀線程棧,我發(fā)現(xiàn)有大量的方法卡在 xxx.RabbitMq.RabbitMqConnection.GetInstance 方法處。
Child SP IP Call Site 0000008B8A9ED6A8 00007ffdf5246594 [HelperMethodFrame_1OBJ: 0000008b8a9ed6a8] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef) 0000008B8A9ED800 00007ffd84a6a4a9 xxx.RabbitMq.RabbitMqConnection.GetInstance(Microsoft.Extensions.Options.IOptions`1<xxx.RabbitMq.RabbitMqConfig>, Microsoft.Extensions.Logging.ILogger`1<System.Object>) 0000008B8A9ED860 00007ffd84a6a317 xxx.RabbitMq.RabbitMqProducer..ctor(Microsoft.Extensions.Options.IOptionsSnapshot`1<xxx.RabbitMq.RabbitMqConfig>, Microsoft.Extensions.Logging.ILogger`1<xxx.RabbitMq.RabbitMqProducer>) 0000008B8A9ED8A0 00007ffd8334817b DynamicClass.ResolveService(ILEmitResolverBuilderRuntimeContext, Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope) 0000008B8A9ED930 00007ffd83347d76 DynamicClass.ResolveService(ILEmitResolverBuilderRuntimeContext, Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope) 0000008B8A9EDE90 00007ffd844f3cb3 Microsoft.Extensions.DependencyInjection.ActivatorUtilities.GetService(System.IServiceProvider, System.Type, System.Type, Boolean) [/_/src/libraries/Common/src/Extensions/ActivatorUtilities/ActivatorUtilities.cs @ 173] DynamicClass.lambda_method196(System.Runtime.CompilerServices.Closure, System.IServiceProvider, System.Object[]) 0000008B8A9EDF20 00007ffd84a0fc9c Microsoft.AspNetCore.Mvc.Controllers.ControllerFactoryProvider+c__DisplayClass5_0.g__CreateController|0(Microsoft.AspNetCore.Mvc.ControllerContext) 0000008B8A9EDF70 00007ffd8452ce7f Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ControllerActionInvoker.cs @ 285] 0000008B8A9EE030 00007ffd84a0fac8 Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ControllerActionInvoker.cs @ 490] 0000008B8A9EE0B0 00007ffd845346cd Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 883] 0000008B8A9EE240 00007ffd84a0f9ad Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextExceptionFilterAsync() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 1024] 0000008B8A9EE2C0 00007ffd84534272 Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 883] 0000008B8A9EE450 00007ffd84a0f850 Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResourceFilter() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 976] ...
從調(diào)用棧信息看,源頭是一個(gè)http請(qǐng)求,然后在 GetInstance 下的 lock 處被凍結(jié),這就激發(fā)了我很大的好奇心,接下來根據(jù) IP 導(dǎo)出源碼看看。
public sealed class RabbitMqConnection { public static RabbitMqConnection GetInstance(IOptions<RabbitMqConfig> options, ILogger<dynamic> logger) { if (_uniqueInstance == null || _uniqueInstance.Connection == null || !_uniqueInstance.Connection.IsOpen) { lock (_objLock) { if (_uniqueInstance == null || _uniqueInstance.Connection == null || !_uniqueInstance.Connection.IsOpen) { _uniqueInstance = new RabbitMqConnection(options.Value, logger); } } } return _uniqueInstance; } private RabbitMqConnection(RabbitMqConfig config, ILogger<dynamic> logger) { Policy.Handle<SocketException>().Or<BrokerUnreachableException>().WaitAndRetry(6, (int retryAttempt) => TimeSpan.FromSeconds(1.0), delegate (Exception ex, TimeSpan time, int retryCount, Context content) { if (6 == retryCount) { throw ex; } _logger.LogError(ex, $"{retryCount}:{ex.Message}"); }) .Execute(delegate { Connection = factory.CreateConnection(); }); } }
從代碼邏輯看,朋友用了 雙檢鎖 來給 RabbitMQ 實(shí)例做單例化,如果實(shí)例創(chuàng)建失敗還會(huì)有 6 次 1s 的嘗試,這種寫法乍一看沒什么問題。
2. 單例寫法真的沒問題嗎
如果單例寫法沒問題的話,為什么有大量的線程卡在 lock 處呢? 既然是 單例 那肯定是 rabbitmq 第一次被實(shí)例化后,后人直接乘涼就好了哈,帶著這個(gè)疑問再次檢查 雙檢索 寫法,尼瑪,在判斷單例的時(shí)候居然做了 _uniqueInstance.Connection.IsOpen 判斷,大家知道這意味著什么嗎?
這意味著,一旦 rabbitmq 在某個(gè)時(shí)刻掛掉了,單例條件就被破防了,無數(shù)的線程排隊(duì)來做 RabbimtMQ 的實(shí)例化,要知道這都是些不實(shí)例出來不罷休的勇士,繼而導(dǎo)致程序掛死...??????
3. 驗(yàn)證我的想法
既然從源碼中推出了這個(gè)代碼缺陷,但口說無憑,我得拿出證據(jù),要想驗(yàn)證很簡(jiǎn)單,到托管堆尋找 RabbitMqConnection 實(shí)例,看下此時(shí)它的 IsOpen 是不是 false 即可, 通過 ILSpy 查看源碼發(fā)現(xiàn)它是用 CloseReason==null 來判斷的。
接下來看看 CloseReason 不為空即可。
0:000> !dumpheap -type RabbitMqConnection Address MT Size 00000277cbd7aa68 00007ffd831f1570 32 00000277ccb13068 00007ffd831f1570 32 0:000> !DumpObj /d 00000277cbd7b858 Name: RabbitMQ.Client.Framing.Impl.AutorecoveringConnection MethodTable: 00007ffd83235db0 EEClass: 00007ffd83242898 Size: 200(0xc8) bytes File: G:\xxx\RabbitMQ.Client.dll Fields: MT Field Offset Type VT Attr Value Name 00007ffd82397238 4000180 bc System.Boolean 1 instance 0 _disposed 00007ffd82390c68 4000181 8 System.Object 0 instance 00000277cbd7b920 _eventLock 00007ffd831fc230 4000182 10 ...g.Impl.Connection 0 instance 00000277cbd7d5f8 _delegate 0:000> !DumpObj /d 00000277cbd7d5f8 Name: RabbitMQ.Client.Framing.Impl.Connection MethodTable: 00007ffd831fc230 EEClass: 00007ffd8322cd70 Size: 232(0xe8) bytes File: G:\xxx\RabbitMQ.Client.dll Fields: MT Field Offset Type VT Attr Value Name 00007ffd82397238 4000198 b8 System.Boolean 1 instance 0 _disposed 00007ffd82390c68 4000199 8 System.Object 0 instance 00000277cbd7d6e0 _eventLock 00007ffd82d93d00 400019a 10 ...ualResetEventSlim 0 instance 00000277cbd7d6f8 _appContinuation 00007ffd83276028 400019b 18 ...ShutdownEventArgs 0 instance 00000279ccc56e28 _closeReason 0:000> !do 00000277ccb13068 Name: xxx.RabbitMq.RabbitMqConnection MethodTable: 00007ffd831f1570 EEClass: 00007ffd831eb920 Size: 32(0x20) bytes File: G:\xxx\xxx.dll Fields: MT Field Offset Type VT Attr Value Name 00007ffd831f13f8 400001f 8 ...Private.CoreLib]] 0 instance 00000278cbe4c2a0 _logger 00007ffd831f2ab0 4000020 10 ...lient.IConnection 0 instance 0000000000000000 <Connection>k__BackingField 00007ffd831f1570 400001d 8 ...abbitMqConnection 0 static 00000277cbd7aa68 _uniqueInstance 00007ffd82390c68 400001e 10 System.Object 0 static 00000277cbd7aa50 _objLock
從輸出信息中可以很清楚的看到當(dāng)前托管堆有兩個(gè) RabbitMqConnection 對(duì)象,其中一個(gè)果然是失敗了(_closeReason=00000279ccc56e28),還有一個(gè)正在努力的new <Connection>k__BackingField=0000000000000000, 這也就驗(yàn)證了假設(shè)。
4. 后續(xù)
有了這些信息,和朋友做了下溝通,建議再優(yōu)化一下 IsOpen=false 時(shí)的異常處理邏輯,比如 return 或者 throw new,或者干脆不要用懶檢測(cè), 千萬不要硬著來。
至于造成 RabbitMQ 不響應(yīng)的一系列誘因,朋友通過參考的開源項(xiàng)目,發(fā)現(xiàn)將別人的 AddSingleton 改成了 AddScoped。
這也就造成了每一次Http請(qǐng)求都要試探性的判斷單例邏輯, 別人的解法是一旦上層單例化了,下層就不會(huì)再次處理了,也就不會(huì)走 IsOpen 邏輯。
三:總結(jié)
造成本次程序卡死的事故,主要有兩點(diǎn):
- RabbitMQ 生成單例化中的 IsOpen 判斷問題,建議改用自動(dòng)重連屬性 AutomaticRecoveryEnabled 和 TopologyRecoveryEnabled,或者用靜態(tài)構(gòu)造函數(shù)替代雙檢鎖。
- 過多的 http 請(qǐng)求對(duì)單例邏輯的試探,按照朋友的改發(fā)將 Scoped 改成 Singleton 來規(guī)避。
以上就是.NET webapi化妝品直播卡死分析的詳細(xì)內(nèi)容,更多關(guān)于.NET webapi直播卡死的資料請(qǐng)關(guān)注腳本之家其它相關(guān)文章!
相關(guān)文章
asp.net點(diǎn)選驗(yàn)證碼實(shí)現(xiàn)思路分享 (附demo)
這篇文章主要介紹了asp.net點(diǎn)選驗(yàn)證碼實(shí)現(xiàn)思路分享 (附demo),具有一定的參考價(jià)值,感興趣的小伙伴們可以參考一下。2017-01-01.Net?7.0實(shí)現(xiàn)支付寶退款和結(jié)果查詢接口
支付寶對(duì) .Net 的支持還是比較充分的,在每個(gè)接口文檔中都有關(guān)于 C# 語言的示例,這樣就大大降低了對(duì)接的難度,很容易上手,這篇文章主要介紹了支付寶退款和結(jié)果查詢接口簡(jiǎn)單實(shí)現(xiàn)(.Net?7.0),需要的朋友可以參考下2024-07-07asp.net操作Word實(shí)現(xiàn)批量替換
這篇文章主要介紹了asp.net操作Word實(shí)現(xiàn)批量替換的方法,需要的朋友可以參考下2015-10-10使用.NET Core創(chuàng)建exe應(yīng)用程序
這篇文章介紹了使用.NET Core創(chuàng)建exe應(yīng)用程序的方法,文中通過示例代碼介紹的非常詳細(xì)。對(duì)大家的學(xué)習(xí)或工作具有一定的參考借鑒價(jià)值,需要的朋友可以參考下2022-06-06WPF實(shí)現(xiàn)ScrollViewer滾動(dòng)到指定控件處
這篇文章主要為大家詳細(xì)介紹了WPF實(shí)現(xiàn)ScrollViewer滾動(dòng)到指定控件處,具有一定的參考價(jià)值,感興趣的小伙伴們可以參考一下2017-06-06