當前位置：首頁 > 编程语言 > asp.net >内容正文

asp.net

万万没想到，一个 MongoDB.Driver 的 bug 导致 .NET5 程序死锁！

發布時間：2023/12/4 asp.net 28 豆豆

生活随笔收集整理的這篇文章主要介紹了万万没想到，一个 MongoDB.Driver 的 bug 导致 .NET5 程序死锁！小編覺得挺不錯的,現在分享給大家,幫大家做個參考.

一：背景

1. 講故事

這個月初，星球里的一位朋友找到我，說他的程序出現了死鎖，懷疑是自己的某些寫法導致mongodb出現了如此尷尬的情況，截圖如下：

說實話，看過這么多dump，還是第一次遇到真實的死鎖，這tmd的頓時就有了興趣。。。上 windbg 說話。

二：Windbg 分析

1. 真的是死鎖嗎

既然朋友說死鎖，我得先驗證一下,可以用命令 !syncblk 查看同步塊表。

0:000>?!syncblk Index?????????SyncBlock?MonitorHeld?Recursion?Owning?Thread?Info??????????SyncBlock?Owner97?000000F7B77CA1B8??????????107?????????1?000000F7D37A7210?8848??25???000000f7b853d480?System.Object144?000000F7D39BA2A8??????????495?????????1?000000F7DA4CDA70?75e0??63???000000f7b853de48?System.Object ----------------------------- Total???????????603 CCW?????????????1 RCW?????????????1 ComClassFactory?0 Free????????????490

從同步塊表中可得知如下信息。

25號線程正持有 000000f7b853d480 鎖對象。

63號線程正持有 000000f7b853de48 鎖對象。

我們知道所謂的死鎖就是兩個線程都渴望得到對方持有的鎖資源，誰也不讓步所造成的一種僵局，如果不明白，我就畫一張圖：

上圖就是一種死鎖的僵局，順便提一下，在 sqlserver 中也常會遇到這種情況，那它會怎么處理的呢？這就有點意思了，sqlserver 內部有一個調停的線程周期性執行，當檢測到這種死鎖僵局的時候，它會把優先級低的線程kill掉，這樣另外一個線程就能順利獲取鎖，被 kill 掉的線程就會出現如下異常信息：

System.Data.SqlClient.SqlException?(0x80131904):?事務(進程?ID?112)與另一個進程被死鎖在?鎖?|?通信緩沖區?資源上，并且已被選作死鎖犧牲品。請重新運行該事務。在?System.Data.SqlClient.SqlConnection.OnError(SqlException?exception,?Boolean?breakConnection,?Action`1?wrapCloseInAction)在?System.Data.SqlClient.SqlInternalConnection.OnError(SqlException?exception,?Boolean?breakConnection,?Action`1?wrapCloseInAction)在?System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject?stateObj,?Boolean?callerHasConnectionLock,?Boolean?asyncClose)在?System.Data.SqlClient.TdsParser.TryRun(RunBehavior?runBehavior,?SqlCommand?cmdHandler,?SqlDataReader?dataStream,?BulkCopySimpleResultSet?bulkCopyHandler,?TdsParserStateObject?stateObj,?Boolean&?dataReady)在?System.Data.SqlClient.SqlCommand.RunExecuteNonQueryTds(String?methodName,?Boolean?async,?Int32?timeout)在?System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(TaskCompletionSource`1?completion,?String?methodName,?Boolean?sendToPipe,?Int32?timeout,?Boolean?asyncWrite)在?System.Data.SqlClient.SqlCommand.ExecuteNonQuery()在?Microsoft.ApplicationBlocks.Data.SqlHelper.ExecuteNonQuery(SqlConnection?connection,?CommandType?commandType,?String?commandText,?SqlParameter[]?commandParameters)在?Microsoft.ApplicationBlocks.Data.SqlHelper.ExecuteNonQuery(String?connectionString,?CommandType?commandType,?String?commandText,?SqlParameter[]?commandParameters)

哈哈，是不是似曾相識，好了，對死鎖有了一定認識之后，我們假設一下，如果存在

25號線程想獲取 000000f7b853de48 鎖對象。

63號線程想獲取 000000f7b853d480 鎖對象。

的情況下，必然就會死鎖，對吧，接下來怎么用 windbg 驗證呢？切到 25 號線程查看線程棧及棧對象。

0:000>?~25s ntdll!NtWaitForMultipleObjects+0xa: 00007ffb`9f230c7a?c3??????????????ret0:025>?!clrstack? OS?Thread?Id:?0x8848?(25)Child?SP???????????????IP?Call?Site 000000F782904838?00007ffb9f230c7a?[HelperMethodFrame_1OBJ:?000000f782904838]?System.Threading.Monitor.ReliableEnter(System.Object,?Boolean?ByRef) 000000F782904990?00007ffb1d5e4d5c?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+ListConnectionHolder.Acquire()0:025>?!dso OS?Thread?Id:?0x8848?(25) RSP/REG??????????Object???????????Name 000000F782904648?000000f7b853de48?System.Object 000000F7829046D8?000000f7b84cb508?MongoDB.Driver.ReadPreference

可以清楚的看到 ReliableEnter 正在獲取 000000f7b853de48 鎖對象時被卡住，再切到 63號線程查看。

0:025>?~63s ntdll!NtWaitForMultipleObjects+0xa: 00007ffb`9f230c7a?c3??????????????ret 0:063>?!clrstack? OS?Thread?Id:?0x75e0?(63)Child?SP???????????????IP?Call?Site 000000F787774EE8?00007ffb9f230c7a?[HelperMethodFrame_1OBJ:?000000f787774ee8]?System.Threading.Monitor.ReliableEnter(System.Object,?Boolean?ByRef) 000000F787775040?00007ffb1d5e4d5c?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+ListConnectionHolder.Acquire() 0:063>?!dso OS?Thread?Id:?0x75e0?(63) RSP/REG??????????Object???????????Name 000000F787774A38?000000f7b82dc750?MongoDB.Bson.BsonBoolean 000000F787774BA0?000000f7b83a9a10?System.RuntimeType 000000F787774CF8?000000f7b853d480?System.Object

可以清楚的看到 ReliableEnter 正在獲取 000000f7b853d480，這就表明確實產生了死鎖，沒毛病。

2. 死鎖原因分析

要想追究死鎖的原因，只能仔細推敲線程棧 + 線程棧對象。

0:063>?!clrstack? OS?Thread?Id:?0x75e0?(63)Child?SP???????????????IP?Call?Site 000000F787774EE8?00007ffb9f230c7a?[HelperMethodFrame_1OBJ:?000000f787774ee8]?System.Threading.Monitor.ReliableEnter(System.Object,?Boolean?ByRef) 000000F787775040?00007ffb1d5e4d5c?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+ListConnectionHolder.Acquire() ... 000000F78777BD10?00007ffb1e2fc69f?System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean)?[/_/src/System.Private.CoreLib/shared/System/Threading/CancellationTokenSource.cs?@?724] 000000F78777BDA0?00007ffb1e2fc69f?System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean)?[/_/src/System.Private.CoreLib/shared/System/Threading/CancellationTokenSource.cs?@?724] 000000F78777BE30?00007ffb1e2fc69f?System.Threading.CancellationTokenSource.ExecuteCallbackHandlers(Boolean)?[/_/src/System.Private.CoreLib/shared/System/Threading/CancellationTokenSource.cs?@?724] 000000F78777BEC0?00007ffb1e325d55?MongoDB.Driver.Core.Misc.SemaphoreSlimSignalable.Signal() 000000F78777BF10?00007ffb1e35b98e?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+ListConnectionHolder.Return(PooledConnection) 000000F78777BF70?00007ffb1e35b728?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool.ReleaseConnection(PooledConnection) 000000F78777C0A0?00007ffb1e35b4f9?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+AcquiredConnection.Dispose() 000000F78777C0D0?00007ffb1e384164?MongoDB.Driver.Core.Operations.RetryableReadContext.Dispose() 000000F78777C100?00007ffb1e37ee31?MongoDB.Driver.Core.Operations.FindOperation`1+d__120[[System.__Canon,?System.Private.CoreLib]].MoveNext() ... 000000F78777E980?00007ffb1dd807bf?System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.InvokeContinuation(System.Action`1<System.Object>,?System.Object,?Boolean,?Boolean)?[/_/src/System.Net.Sockets/src/System/Net/Sockets/Socket.Tasks.cs?@?1019] 000000F78777E9F0?00007ffb1dd80519?System.Net.Sockets.Socket+AwaitableSocketAsyncEventArgs.OnCompleted(System.Net.Sockets.SocketAsyncEventArgs)?[/_/src/System.Net.Sockets/src/System/Net/Sockets/Socket.Tasks.cs?@?858] 000000F78777EA50?00007ffb1dd7f751?System.Threading._IOCompletionCallback.PerformIOCompletionCallback(UInt32,?UInt32,?System.Threading.NativeOverlapped*)?[/_/src/System.Private.CoreLib/src/System/Threading/Overlapped.cs?@?59]0:063>?!dso OS?Thread?Id:?0x75e0?(63) RSP/REG??????????Object???????????Name 000000F787774A38?000000f7b82dc750?MongoDB.Bson.BsonBoolean 000000F787774BA0?000000f7b83a9a10?System.RuntimeType 000000F787774CF8?000000f7b853d480?System.Object ... 000000F78777B658?000000f7be3407c8?System.String????OperationCanceled 000000F78777B670?000000f7b82c07e0?System.Resources.RuntimeResourceSet 000000F78777B698?000000f7b82bff38?System.Globalization.CultureInfo 000000F78777B730?000000f7a36525c8?System.Char[] 000000F78777B7E0?000000f7be3407c8?System.String????OperationCanceled ... 000000F78777BEF8?000000f7b853de10?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool+ListConnectionHolder 000000F78777BF10?000000f79f79e398?System.Runtime.CompilerServices.AsyncTaskMethodBuilder`1+AsyncStateMachineBox`1[[MongoDB.Driver.IAsyncCursor`1[[Czkj.AlibabaTools.Models.mongo.CopyRecords,?Czkj.AlibabaTools.Models]],?MongoDB.Driver.Core],[MongoDB.Driver.Core.Operations.FindOperation`1+<ExecuteAsync>d__120[[Czkj.AlibabaTools.Models.mongo.CopyRecords,?Czkj.AlibabaTools.Models]],?MongoDB.Driver.Core]] 000000F78777BF40?000000f7b853de48?System.Object ...

由于這代碼到處都是 await,async ，所以看這反編譯后的線程棧真的頭大，經過仔細比對，發現代碼流程大概是：

從處理 Mongodb 的異步請求回調開始 (System.Threading.OverlappedData)。

在 MongoDB.Driver.Core.Operations.FindOperation 時不知為啥拋了取消異常 OperationCanceled，然后調用 RetryableReadContext.Dispose()。

在 ListConnectionHolder.Return() 方法中獲取 000000f7b853de48 鎖對象。

在 SignalOrReset() -> SemaphoreSlimSignalable.Signal() 方法中執行一些注冊handler邏輯。

注意：在事件觸發中并沒有退出 lock 區域。

在幾個handler痙攣過程中進入了另外一個線程池的 ListConnectionHolder.Acquire() 方法中，希望能得到該池中的 000000f7b853d480 鎖對象。

同時 25號線程正在反向做這個操作，由于大家都是雙重 lock，所以最終導致死鎖的發生。

三：有幾個需要解答的問題

1. 為什么會有兩個線程池？

從線程棧對象看，應該也看到了有兩個線程池 ExclusiveConnectionPool。

0:000>?!dumpheap?-type?ExclusiveConnectionPool?-stat Statistics:MT????Count????TotalSize?Class?Name 00007ffb1d25eca0????????2??????????464?MongoDB.Driver.Core.ConnectionPools.ExclusiveConnectionPool

這是由于朋友的 mongodb 連接串用的是雙IP的副本集模式。

{"mongo":?{"Connection":?"mongodb://xxx.aliyuncs.com:3717,xxx.aliyuncs.com:3717/admin?replicaSet=mgset-500180544&readPreference=secondaryPreferred&maxPoolSize=1000&wtimeoutMS=10000"} }

2. 是程序員的鍋嗎？

從堆棧信息看并不是程序員的鍋，是 mongodb 在接收異步回調時，由于某種情況發生了 OperationCanceled 異常，面對異常的后續處理邏輯時出現了死鎖bug。

3. 當前的 mognodb sdk版本是多少？

這個mongodb 官方驅動是 ?2.13.1.0，也就是 2021-8-15 發布的，截至最新的是 10月份發布的 2.13.2.0。

4. 反饋

了解這些信息后，和朋友做了溝通，朋友說他給 mongodb 社區提交 issue，幾天后，官方給的回答是在最新的 v2.14.beta1 中做了處理。

https://github.com/mongodb/mongo-csharp-driver/commit/b961b81cb7dc1ffe7262c55a227afad0aab5a994
https://jira.mongodb.org/browse/CSHARP-3815

也就是說在未來的 release v2.14.0 版本中會得到解決，目前也只能等一等啦！期待中。。。哈哈😁😁😁

四：總結

總的來說，這是 mongodb 底層的一個 bug 導致的死鎖問題，dump的分析過程也幾經波折，雖是官方權威的 MongoDB.Driver 包，但同樣值得懷疑，而不要一味的深深懷疑自己... 最后期待即將發布的 release v2.14.0 吧。

創作挑戰賽新人創作獎勵來咯，堅持創作打卡瓜分現金大獎

總結

以上是生活随笔為你收集整理的万万没想到，一个 MongoDB.Driver 的 bug 导致 .NET5 程序死锁！的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。

上一篇： .NET 6新特性试用 | 异步流
下一篇： .NET6 新功能和新生态