ASP.NET航 - 通用字典的併發問題引起GC僵局

在上個月的ASP.NET Web應用程序已停止響應的要求，我們不得不重新設置應用程序池把它找回來了。ASP.NET航 - 通用字典的併發問題引起GC僵局

我們有麻煩確定問題的確切原因，因爲有在服務器的事件日誌中沒有錯誤。該網站只是停止響應。

所以我們一直使用WinDbg的嘗試和分析採取了內存轉儲時，該網站未與苔絲Ferrandez的博客條目幫助響應：GC Hangs & High CPU Hang

通過運行!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

根據苔絲在杭的博客文章，這表明我們是停留在一個垃圾收集的中間（的東西，通常採用的納米秒鐘的事），因爲該處理器顯示81％這是什麼.NET框架，將其設置爲同時它的垃圾回收。它被設置爲這個，因爲當這個值大於80％時不會產生新的線程。此外 - 你可以看到有1930個請求在隊列中，即使只有10個工作線程出一個可能的400

的通過運行!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）」線程 - 觸發了垃圾收集線程？

但無論如何，因爲兩個線程設置爲禁用，我認爲這是問題，並且苔絲的掛起博客將繼續告訴我確切的原因&解決方案。但不幸的是它暗示對該問題進行了「mixed DLLloading problem」這看着堆殘疾人線程後，無論是要加載的DLL。例如，這裏是線程40的kb：

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（那些與殘疾人搶佔GC）均在同一當前幀：

Current frame: (MethodDesc 798ee360 +0xab System.Collections.Generic.Dictionary`2[[System.Int32, mscorlib],[System.__Canon, mscorlib]].FindEntry(Int32))

這是促使我this後&讓我覺得我肯定會發現這個問題。但不幸的是，使用堆棧追溯代碼後，該字典的問題不是靜態的 - 所以我猜這不可能是問題。

我現在幾乎沒有想法 - 我不是分析轉儲文件的專家（事實上我只是在昨天開始：D），所以如果任何人有任何指示我應該做下一步以確定原因這個問題很好。

UPDATE

運行~*ekb命令由Brian建議後，我發現，開始垃圾收集線程，因爲它有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

我還要提到的是我們的應用程序在32位模式下運行，在64位服務器上。不幸的是，當它最後變得沒有響應時，我們忘記了在32位轉儲，這意味着當我們在WinDbg中加載轉儲文件時，我們需要運行!wow64exts.sw命令來分析。不知道這有多大的差異（也許這就是爲什麼我看不到'（GC）'線程），但我們似乎無法讓`！clrstack'命令工作。我們目前正在等待它再次無響應，因此我們可以將轉儲轉換爲32位。

來源

2013-02-12 David Masters

我覺得有趣的是，沒有任何線程被標記爲做GC。您可以使用'〜* ekb'枚舉調用堆棧，並查找GC相關的方法以確定其中一個線程是否位於集合中間。 – 2013-02-12 19:35:01

@BrianRasmussen我發現線程做我的更新GC，但不知道如何獲得該命令的線程號？ – 2013-02-12 21:51:24

因此，我們最終陷入了問題的底部。原來，在我原來的問題中提到的兩篇文章的組合：

有兩個線程試圖訪問相同的通用字典
GC不能完成，因爲兩個線程都搶先GC設置爲禁用。

在一些詳細信息：

雖然兩個線程都處於某種僵局，第三螺紋聯接希望在堆上分配一些內存的一方。這會觸發一個新的GC，但GC無法完成，因爲這兩個線程的PreEmptive GC設置爲禁用狀態。由於GC無法完成，因此IIS進程仍處於不能爲請求派生新的工作線程的狀態，這意味着任何後續請求都會排隊。隊列繼續增長，直到應用程序池被回收後纔會返回響應。

正如我在我原來的問題中提到的 - 我們將字典追溯到代碼，它不是一個靜態字典，所以我們認爲這必須是一個紅色的鯡魚;兩個線程如何能夠訪問同一個對象？那麼事實證明，這是可能的，因爲字典存儲在一個InProc會話。

默認情況下，ASP.NET會阻止同一個會話ID的併發請求。這是通過對每個請求的會話進行排它鎖來實現的，旨在防止出現這種情況。但是，這是一個'傳統'應用程序，它使用舊的AjaxPro框架，並且已被配置爲繞過此鎖定。這允許同一個會話的併發AjaxRequests訪問同一會話對象。

事實證明，我們最近在JavaScript中引入了一個錯誤，它多次觸發相同的AjaxPro請求，從而導致該問題。

來源

2013-02-14 15:29:44

感謝您的更新。 – 2013-02-14 17:37:24

這可能是完全出於左場，但在一片轉儲信息，我注意到了這一點：

1c93eeac 79208c9b 67935cc0 6726b530 0ac4ea6c clr!COMToCLRDispatchHelper+0x28

這COMToCLRDispatchHelper電話使我不知道，如果應用程序在調用一個32位的COM組件，可有點爲你混濁水？

來源

2013-02-12 17:18:36

我認爲這是一個正常的調用堆棧，當從IIS調用CLR時，但是，就像您一樣，由於我沒有在幾年內調試IIS轉儲，所以我可能會出現在左側字段:) – 2013-02-12 17:20:21

就我而言意識到，我們的應用程序不使用任何COM組件。我只是假設這是與IIS調用我們託管的CLR應用程序有關...... – 2013-02-12 17:24:15

ASP.NET航 - 通用字典的併發問題引起GC僵局

回答

相關問題