.NET Core中遇到奇怪的執行緒死鎖問題:記憶體與執行緒數不停地增長
一個 asp.net core 站點,之前執行在Linux 伺服器上,執行一段時間後有時站點會掛掉,在日誌中記錄很多“EMFILE too many open files”的錯誤:
Microsoft.AspNetCore.Server.Kestrel.Internal.Networking.UvException: Error -24 EMFILE too many open files
後來將這個 asp.net 站點部署到 Windows 伺服器的 IIS 上。執行一段時間後,發現其中一臺伺服器出現503錯誤:
HTTP Error 503.2 - Service Unavailable The[email protected] setting is being exceeded.
登上伺服器一看,該站點的程序佔用的記憶體竟然有1.2G,而同一負載均衡中另外一臺正常的伺服器記憶體佔用只有40多M。然後看了一下程序中的執行緒數,驚呆了——竟然有8000多個執行緒!而另外一臺正常的伺服器只有20多個執行緒。
將這臺伺服器從負載均衡上摘下來之後,出現了更加讓人驚呆的現象——在沒有請求的情況下,這個 asp.net core 站點程序的記憶體佔用與執行緒數一直在增長。就像在程式碼中寫了一個死迴圈,在迴圈中不停地建立執行緒。
再後來記憶體增長到1.8G左右,執行緒數增長到1.3萬左右,而且還在持續增長。
不僅記憶體與執行緒數在增長,而且CPU也一直在波動,這可是在沒有任何請求的情況下,誰在偷偷地幹活?
強制結束程序後恢復正常,但執行一段時間(通常是1天時間)後又會出現同樣的問題。非常奇怪!
從目前分析的情況看,罪魁禍首可能是 EnyimMemcachedCore (支援.net core的memcached客戶端,是我們從 EnyimMemcached 移植過來的),EnyimMemcachedCore 用到了 Socket 池,問題可能出在 Socket 池部分,原始碼在 github 上(EnyimMemcachedCore原始碼)。
windbg分析程序dump檔案顯示的執行緒情況:
0:000> .load C:\Program Files\dotnet\shared\Microsoft.NETCore.App\1.0.1\sos.dll 0:000> !threads ThreadCount: 8014 UnstartedThread: 0 BackgroundThread: 8013 PendingThread: 0 DeadThread: 0 Hosted Runtime: no
發現大量執行緒中存在 coreclr!Thread::DoAppropriateWaitWorker 這個操作:
!uniqstack # Child-SP RetAddr Call Site 00 00000056`ed5ad118 00007ffa`080e13ed ntdll!NtWaitForMultipleObjects+0xa 01 00000056`ed5ad120 00007ff9`f1dc885e KERNELBASE!WaitForMultipleObjectsEx+0xed 02 00000056`ed5ad400 00007ff9`f1dc8a0d coreclr!Thread::DoAppropriateWaitWorker+0xfe 03 00000056`ed5ad4b0 00007ff9`f1dca52f coreclr!Thread::DoAppropriateWait+0x7d 04 00000056`ed5ad530 00007ff9`f1e3b726 coreclr!CLREventBase::WaitEx+0x7f 05 00000056`ed5ad580 00007ff9`f1e3b636 coreclr!AwareLock::EnterEpilogHelper+0xca 06 00000056`ed5ad640 00007ff9`f1f92b18 coreclr!AwareLock::EnterEpilog+0x62 07 00000056`ed5ad6a0 00007ff9`f1f92131 coreclr!AwareLock::Contention+0x258 08 00000056`ed5ad760 00007ff9`92388e2b coreclr!JITutil_MonContention+0xb1
該問題還在進一步排查中。。。
[12月3日13:00更新]
今天排查後懷疑是 EnyimMemcached 中下面的程式碼引起的:
private void ConnectWithTimeout(Socket socket, EndPoint endpoint, int timeout) { var completed = new AutoResetEvent(false); var args = new SocketAsyncEventArgs(); args.RemoteEndPoint = endpoint; args.Completed += OnConnectCompleted; args.UserToken = completed; socket.ConnectAsync(args); if (!completed.WaitOne(timeout) || !socket.Connected) { using (socket) { throw new TimeoutException("Could not connect to " + endpoint); } } } private void OnConnectCompleted(object sender, SocketAsyncEventArgs args) { EventWaitHandle handle = (EventWaitHandle)args.UserToken; handle.Set(); }
已修改程式碼以定位是不是上面的程式碼引起的,要等待下次deadlock的發生。
[12月4日8:50更新]
終於可以重現這個問題,在有負載的情況下強制結束程序,詳見錄屏。
[12月4日12:20更新]
終於定位到了引起問題的程式碼:
Task<IPAddress[]> task = System.Net.Dns.GetHostAddressesAsync(host); task.Wait(5000); var addresses = task.Result;
這是上次解決 EnyimMemcached 死鎖問題 時埋下的坑,死鎖發生在有併發請求時進行主機名的解析,在強制結束程序時重現是因為dns解析快取失效。
改為下面的程式碼可解決死鎖問題:
Task<IPAddress[]> task = System.Net.Dns.GetHostAddressesAsync(host); if (task.Wait(5000)) { var addresses = task.Result; }
雖然死鎖問題解決了,但在併發請求下task.Wait(5000)返回false,無法成功解析主機名。
問題的根源是在建構函式中用(且只能用)同步方式呼叫System.Net.Dns.GetHostAddressesAsync()非同步方法。
相關連結:
[12月3日16:10更新]
果然是上面的程式碼引起的死鎖,改為下面的程式碼後問題解決:
private void ConnectWithTimeout(Socket socket, EndPoint endpoint, int timeout) { var task = socket.ConnectAsync(endpoint); if (!task.Wait(timeout)) { using (socket) { throw new TimeoutException("Could not connect to " + endpoint); } } }