Asp.net
ASP.NET 掛起 - 通用字典並發問題導致 GC 死鎖
在上個月，我們的 ASP.NET Web 應用程序停止響應請求，我們不得不重置應用程序池以使其恢復正常。
我們無法確定問題的確切原因，因為伺服器的事件日誌中沒有錯誤。該網站只是停止響應。
因此，在 Tess Ferrandez 的部落格條目的幫助下，我們一直在使用 WinDbg 來嘗試分析在站點沒有響應時進行的記憶體轉儲：GC 掛起和高 CPU 掛起
通過執行，
!threadpool我可以看到以下內容：CPU utilization: 81% Worker Thread: Total: 10 Running: 8 Idle: 2 MaxLimit: 400 MinLimit: 160 Work Request in Queue: 1930 -------------------------------------- Number of Timers: 72 -------------------------------------- Completion Port Thread:Total: 1 Free: 1 MaxFree: 8 CurrentLimit: 0 MaxLimit: 400 MinLimit: 120根據掛起部落格文章中的 Tess 的說法，這表明我們陷入了垃圾收集的中間（通常需要幾納秒的時間），因為處理器顯示81%，這是 .NET 框架設置的雖然它是垃圾收集。它被設置為這個，因為當這個值大於 80% 時不能產生新的執行緒。此外 - 您可以看到隊列中有 1930 個請求，即使可能的 400 個工作執行緒中只有 10 個工作執行緒。
通過執行
!threads命令，我可以看到兩個PreEmptive GC設置為禁用的執行緒：PreEmptive GC Alloc Lock ID OSID ThreadOBJ State GC Context Domain Count APT Exception 10 1 18bc 00000000001b9710 1008220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 16 2 e68 00000000001c0900 b220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Finalizer) 18 4 1118 00000000001df300 1009220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 19 5 1560 00000000001e9068 100a220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 20 6 11d0 00000000001f14d8 1220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 22 9 19d0 000000001bc666d0 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 9 c 13f4 000000001d173600 8008220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Completion Port) 24 23 17c4 00000000001a0c40 1009220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 25 24 1088 000000001d205900 1009220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 6 21 1248 000000001d1f6e80 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 4 27 eb0 000000000019df08 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 27 29 39c 000000001bc720f0 1009220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 28 26 17ec 00000000001a7be0 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 29 2c 1040 000000001d1c8160 1009220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 3 2a 1788 000000001d22ed48 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 30 1f 830 000000001bc5b180 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 32 1e b38 000000001d1995a0 1009220 Enabled 0000000000000000:0000000000000000 001f0d80 2 Ukn (Threadpool Worker) 33 1d 19fc 000000001d199a98 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 34 1c c84 000000000019f8a8 1009220 Enabled 0000000008d8d880:0000000008d8d88c 001f0d80 1 Ukn (Threadpool Worker) 35 1a 12e8 000000001d1a1468 10092a2 Disabled 000000000c88e294:000000000c88e6d0 001f0d80 1 Ukn (Threadpool Worker) 5 22 1a70 000000001d1a6008 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn 36 28 1050 000000001d209f18 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 37 25 19f0 000000001d22f738 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 38 2b 15cc 000000001d29b2d0 b220 Enabled 0000000000000000:0000000000000000 001f0d80 1 Ukn 39 20 1228 000000001d290a88 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 40 1b c98 000000001d290420 10092a2 Disabled 0000000010adc094:0000000010addcf8 001f0d80 1 Ukn (Threadpool Worker) 41 19 15dc 000000001d2a3168 1019220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn (Threadpool Worker) 43 18 1a64 000000001d2c8cc0 220 Enabled 0000000000000000:0000000000000000 001b3b98 0 Ukn據我了解，這很糟糕，基本上意味著在所有執行緒都啟用此功能之前，垃圾收集無法完成，這意味著該程序處於掛起狀態。
與文章相比存在細微差異，這讓我感到困惑，因為沒有標有“（GC）”的執行緒 - 觸發垃圾收集的執行緒？
但無論如何，由於兩個執行緒設置為禁用，我認為這是問題所在，Tess 的掛起部落格文章將繼續告訴我確切的原因和解決方案。但不幸的是，它暗示問題是“混合 DLL 載入問題”，在查看禁用執行緒的堆棧後，兩者都沒有嘗試載入 DLL。例如，這裡是
kb執行緒 40：1c93dc74 79142280 0ac30260 0bc85820 00000003 mscorlib_ni+0x29f318 1c93dc88 1e6a8c6c 1c93dc94 00000000 00000001 clr!OnHijackScalarTripThread WARNING: Frame IP not in any known module. Following frames may be wrong. 1c93dca0 1e6791f7 00000003 00000000 00000000 0x1e6a8c6c 1c93e270 791421bb 0c886820 1bac554d 00000000 0x1e6791f7 1c93e284 7916a553 1c93e354 00000001 1c93e320 clr!CallDescrWorker+0x33 1c93e300 7916a6f4 1c93e354 00000001 1c93e320 clr!CallDescrWorkerWithHandler+0x8e 1c93e450 7916a729 1bd17090 1c93e574 1c93e720 clr!MethodDesc::CallDescr+0x194 1c93e46c 7916a749 1bd17090 1c93e574 1c93e720 clr!MethodDesc::CallTargetWorker+0x21 1c93e484 79190c04 1c93e720 ed47daf9 1c93ea18 clr!MethodDescCallSite::Call_RetArgSlot+0x1c 1c93e648 79190f53 1c85ce30 1bd17090 1b8b6834 clr!CallWithValueTypes_RetArgSlotWrapper+0x5c 1c93e930 79191115 1c85ce30 00000000 0c886b80 clr!InvokeImpl+0x621 1c93e9fc 79b3d839 1d1a1468 00000096 1c93ea18 clr!RuntimeMethodHandle::InvokeMethodFast+0x180 1c93ea50 79b3d52c 0ecc3e60 00000096 1038d084 mscorlib_ni+0x2bd839 1c93ea88 79b3c19d 00000000 00000000 0c885530 mscorlib_ni+0x2bd52c 1c93eab0 79ad6d16 00000000 0c885530 0ec452c4 mscorlib_ni+0x2bc19d 1c93ec04 7a045331 00000000 00000000 00000000 mscorlib_ni+0x256d16 1c93ecbc 672d72b5 0c862b08 00000000 00000000 mscorlib_ni+0x7c5331 1c93ece8 672eb90c 00000000 1c93ed18 0c862b08 System_Web_ni+0x1772b5 1c93ed28 67301e9e 1c93ed54 07f81050 0c863014 System_Web_ni+0x18b90c 1c93ed80 672b5998 1b8b2010 1b8e12c4 1c93f208 System_Web_ni+0x1a1e9e 1c93ed9c 67300602 0c862b08 0ec4af84 0c862b08 System_Web_ni+0x155998 1c93edd8 6730034d 0ac37a80 0c861c1c 1c93ee5c System_Web_ni+0x1a0602 1c93ede8 672ff8fd a65adfcd 79145c50 1c93effc System_Web_ni+0x1a034d 1c93ee5c 67935cdc 00000002 6726b530 00000000 System_Web_ni+0x19f8fd 1c93ee98 791425a1 1c93f228 00000002 028f2b9c System_Web_ni+0x7d5cdc 1c93eeac 79208c9b 67935cc0 6726b530 0ac4ea6c clr!COMToCLRDispatchHelper+0x28 1c93ef40 79208d74 6726b530 0ac4ea6c 00000001 clr!BaseWrapper<Stub *,FunctionBase<Stub *,&DoNothing<Stub *>,&StubRelease<Stub>,2>,0,&CompareDefault<Stub *>,2>::~BaseWrapper<Stub *,FunctionBase<Stub *,&DoNothing<Stub *>,&StubRelease<Stub>,2>,0,&CompareDefault<Stub *>,2>+0xfa 1c93ef64 79208dda 1d1a1468 1c93f1f8 1b7affe0 clr!COMToCLRWorkerBody+0xb4 1c93efbc 792098c9 1d1a1468 1c93f1f8 1b7affe0 clr!COMToCLRWorkerDebuggerWrapper+0x34 1c93f1cc 02b3a1aa 1d1a1468 1c93f1f8 a65adfcd clr!COMToCLRWorker+0x614 1c93f1e0 69f5aa4f 00000001 028038c8 00000000 0x2b3a1aa 1c93f544 69f5ab4a 028038c8 69f5aae2 1c93f56c webengine4!HttpCompletion::ProcessRequestInManagedCode+0x1cd 1c93f554 69f5aafe 028038c8 00000000 00000000 webengine4!HttpCompletion::ProcessCompletion+0x4a 1c93f56c 792078af 028038c8 ed47c90d 0000ffff webengine4!CorThreadPoolWorkitemCallback+0x1c 1c93f5bc 79206c5f 1c93f61f 1c93f61e ed47ca9d clr!UnManagedPerAppDomainTPCount::DispatchWorkItem+0x195 1c93f62c 792084c5 00000000 ed47ca25 00000000 clr!ThreadpoolMgr::NewWorkerThreadStart+0x20b 1c93f694 792f76e0 00000000 fff91c00 00000002 clr!ThreadpoolMgr::WorkerThreadStart+0x3d1 1c93ffb8 7d4dfb97 00247430 00000000 00000000 clr!Thread::intermediateThreadProc+0x4b 1c93ffec 00000000 792f7698 00247430 00000000 kernel32!BaseThreadStart+0x34但後來我注意到了一些有趣的事情。通過使用該
!eestack -ee -short命令，我看到執行緒 35 和 40（禁用 PreEmptive GC 的執行緒）都在同一個目前幀上：Current frame: (MethodDesc 798ee360 +0xab System.Collections.Generic.Dictionary`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int32))這就是導致我寫這篇文章的原因，讓我覺得我肯定找到了問題所在。但不幸的是，在使用堆棧追溯程式碼之後，有問題的字典不是靜態的——所以我猜這不會是問題所在。
我現在幾乎沒有想法 - 我不是分析轉儲文件的專家（事實上我昨天才開始：D）所以如果有人對我接下來應該做什麼以找出問題的原因有任何指示會很好。
更新
執行
~*ekbBrian 建議的命令後，我找到了啟動垃圾收集的執行緒，因為它在堆棧中有GarbageCollectGeneration。1e61e54c 7d4d8c9e 000003c4 00000000 00000000 ntdll_7d600000!NtWaitForSingleObject+0x15 1e61e5bc 791897da 000003c4 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xac 1e61e5f0 7918981b 000003c4 ffffffff 00000000 clr!CLREvent::CreateManualEvent+0xf6 1e61e640 791896f1 00000000 efb5da31 0019f8a8 clr!CLREvent::CreateManualEvent+0x137 1e61e680 79189712 ffffffff 00000000 00000000 clr!CLREvent::WaitEx+0x126 1e61e694 792a05cc ffffffff 00000000 00000000 clr!CLREvent::Wait+0x19 1e61e6b8 792a04e5 ffffffff 00000000 0019f8f0 clr!SVR::gc_heap::wait_for_gc_done+0x6f **1e61e6e0 792a424b 00000000 00000001 001bc600 clr!SVR::GCHeap::GarbageCollectGeneration+0x14f** 1e61e714 79229fd2 0019f8f0 00000040 00000000 clr!SVR::gc_heap::try_allocate_more_space+0x184 1e61e730 7922a080 0019f8f0 00000040 00000000 clr!SVR::gc_heap::allocate_more_space+0x30 1e61e750 79188f33 0019f8f0 00000040 00000000 clr!SVR::GCHeap::Alloc+0x55 1e61e76c 7915dd44 00000040 00000000 00000000 clr!Alloc+0x8d 1e61e7ac 7915dd84 0000001a 79169a39 79166166 clr!SlowAllocateString+0x42 1e61e7b4 79169a39 79166166 00000019 efb5d4c9 clr!UnframedAllocateString+0x12 1e61e7b8 79166166 00000019 efb5d4c9 00001f3e clr!StringObject::NewString+0x13 1e61e878 79ac139e 00000000 0019f8a8 0515fcd0 clr!COMNlsInfo::InternalChangeCaseString+0x128 1e61e88c 79ac51b4 0515fcd0 1e61e900 20e59f26 mscorlib_ni+0x24139e 1e61e898 20e59f26 1e61e900 08ce6208 050fd8e8 mscorlib_ni+0x2451b4我還應該提到我們的應用程序在 64 位伺服器上以 32 位模式執行。不幸的是，當它上次沒有響應時，我們忘記了 32 位的轉儲，這意味著當我們在 WinDbg 中載入轉儲文件時，我們需要執行
!wow64exts.sw命令進行分析。不知道這有多大區別（也許這就是為什麼我看不到 ‘(GC)’ 執行緒），但我們似乎無法讓 `!clrstack’ 命令工作。我們目前正在等待它再次無響應，以便我們可以在 32 位中進行轉儲。
所以我們最終找到了問題的根源。原來是我原來的問題中提到的兩篇文章的組合：
- 有兩個執行緒試圖訪問同一個通用字典
- GC 無法完成，因為兩個執行緒已將 PreEmptive GC 設置為禁用。
更詳細一點：
雖然這兩個執行緒處於某種死鎖狀態，但第三個執行緒加入了想要在堆上分配一些記憶體的一方。這會觸發新的 GC，但 GC 無法完成，因為這兩個執行緒的 PreEmptive GC 設置為禁用。由於 GC 無法完成，IIS 程序仍處於無法為請求生成新工作執行緒的狀態，這意味著任何後續請求都將排隊。隊列繼續增長，在應用程序池被回收之前不會返回任何響應。
正如我在最初的問題中提到的 - 我們將字典追溯到程式碼，它不是靜態字典，所以我們認為這一定是紅鯡魚；兩個執行緒怎麼能訪問同一個對象？事實證明這是可能的，因為字典儲存在 InProc 會話中。
預設情況下，ASP.NET 會阻止對同一會話 ID 的並發請求。這是通過在每個請求的會話上放置一個排他鎖來實現的，旨在防止這種確切的情況。然而，這是一個使用舊 AjaxPro 框架的“遺留”應用程序，並且已配置為繞過此鎖定。這允許同一會話的並發 AjaxRequest 訪問同一會話對象。
事實證明，我們最近在 JavaScript 中引入了一個錯誤，它多次觸發同一個 AjaxPro 請求，從而導致了這個問題。