.net - .netアプリケーションがハングしています。奇妙なクラッシュダンプ

Question

本番サーバーには24時間365日稼働するアプリケーションがあり、CPUの50％近くを消費し始めることがあります。ローカルで再現することはできませんでしたが、adplusを使用してメモリダンプを実行しました。サーバーには、Windows 2008 Server 64ビット、.NET3.5が搭載されています。アプリケーションはMSMQをリッスンし、操作を実行するためのスレッドプールを持っています。メモリダンプを実行したとき、何も実行されていないはずでしたが、それでもCPUを消費していました。

以下はダンプです。何が起こっているのか知っていますか？遅いスレッドがGCDisabledと言っているのは奇妙です！あれは何でしょう？

同じサーバーにASP.NETアプリがあるのは奇妙なことで、同じことが起こることもあります。

0:000> !threads
ThreadCount: 23
UnstartedThread: 0
BackgroundThread: 6
PendingThread: 0
DeadThread: 5
Hosted Runtime: no
                                              PreEmptive                                                Lock
       ID OSID        ThreadOBJ     State   GC     GC Alloc Context                  Domain           Count APT Exception
   0    1 1ec0 0000000000249c10      a020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
   2    2  84c 0000000000253470      b220 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA (Finalizer)
   3    3 10b8 0000000019d0f900    80a220 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA (Threadpool Completion Port)
   5    4 2184 0000000019d4a550   880b220 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA (Threadpool Completion Port)
   6    6 14a0 0000000019d602a0   180b220 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA (Threadpool Worker)
   8    7  490 0000000019d7db70   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
   9    8 2164 0000000019dae680   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  10    9  ac0 0000000019db4740   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  11    a 24cc 0000000019db51f0   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  12    b 1fb4 0000000019db5ca0   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  13    c 2408 0000000019db1520   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  14    d 1b44 0000000019db1fd0   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  15    e 1280 0000000019db2a80   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  16    f 206c 0000000019db8780   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  17   10 1ff8 0000000019db9230   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  18   11 2548 0000000019dc2120   200b020 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA
  20   18 2588 0000000019dc49d0   180b220 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 MTA (Threadpool Worker)
  21   1a 20a0 0000000019dc5570      b220 Disabled 0000000001653d88:0000000001655978 00000000002410b0     1 MTA
XXXX   26    0 0000000019dc89c0      9820 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 Ukn
XXXX   2c    0 0000000019dc5b40      9820 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 Ukn
XXXX   2b    0 0000000019dc3290      9820 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 Ukn
XXXX    5    0 0000000019dc8f90      9820 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 Ukn
XXXX   27    0 0000000019dc7850      9820 Enabled  0000000000000000:0000000000000000 00000000002410b0     0 Ukn

 0:000> !runaway
 User Mode Time
  Thread       Time
  **21:20a0      0 days 0:27:21.718**
   6:14a0      0 days 0:00:01.921
  18:2548      0 days 0:00:01.015
   2:84c       0 days 0:00:00.890
   (18 more....)

0:000> ~21s
*** WARNING: Unable to verify checksum for System.ni.dll
mscorwks!JIT_WriteBarrier_Fast+0x3:
000007fe`f88de5c3 4881fa607f4701  cmp     rdx,1477F60h

0:021> !clrstack
OS Thread Id: 0x20a0 (21)
*** WARNING: Unable to verify checksum for mscorlib.ni.dll
Child-SP         RetAddr          Call Site
000000001b05f090 000007fef651b1ba System.Net.TimerThread+TimerNode..ctor(Callback, System.Object, Int32, System.Object)
000000001b05f0d0 000007fef69a0c3f System.Net.TimerThread+TimerQueue.CreateTimer(Callback, System.Object)
000000001b05f180 000007fef651b73e System.Net.ConnectionPool.CleanupCallbackWrapper(Timer, Int32, System.Object)
000000001b05f1d0 000007fef651b560 System.Net.TimerThread+TimerNode.Fire()
000000001b05f2a0 000007fef64e6388 System.Net.TimerThread+TimerQueue.Fire(Int32 ByRef)
000000001b05f330 000007fef271175b System.Net.TimerThread.ThreadProc()
000000001b05f400 000007fef27a95fd System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000001b05f450 000007fef88e1552 System.Threading.ThreadHelper.ThreadStart()
0:021> kb
RetAddr           : Args to Child      : Call Site
000007fe`f6a1b87e : 00000000 (Edited) : mscorwks!JIT_WriteBarrier_Fast+0x3
000007fe`f651b1ba : 00000000 (Edited) : System_ni+0x70b87e
000007fe`f69a0c3f : 00000000 (Edited) : System_ni+0x20b1ba
000007fe`f651b73e : 000007fe (Edited) : System_ni+0x690c3f
000007fe`f651b560 : 00000000 (Edited) : System_ni+0x20b73e
000007fe`f64e6388 : 00000000 (Edited) : System_ni+0x20b560
000007fe`f271175b : 00000000 (Edited) : System_ni+0x1d6388
000007fe`f27a95fd : 00000000 (Edited) : mscorlib_ni+0x2f175b
000007fe`f88e1552 : 00000000 (Edited) : mscorlib_ni+0x3895fd
000007fe`f877e5e3 : 00000000 (Edited) : mscorwks!CallDescrWorker+0x82
000007fe`f878c83f : 00000000 (Edited) : mscorwks!CallDescrWorkerWithHandler+0xd3
000007fe`f887ae8d : 00000000 (Edited) : mscorwks!MethodDesc::CallDescr+0x24f
000007fe`f8839374 : 00000000 (Edited) : mscorwks!ThreadNative::KickOffThread_Worker+0x191
000007fe`f8732045 : 00000000 (Edited) : mscorwks!TypeHandle::GetParent+0x5c
000007fe`f8846139 : 00000000 (Edited) : mscorwks!SVR::gc_heap::make_heap_segment+0x155
000007fe`f8700e15 : 00000000 (Edited) : mscorwks!ZapStubPrecode::GetType+0x39
000007fe`f8700ae7 : 00000000 (Edited) : mscorwks!ThreadNative::KickOffThread+0x401
000007fe`f88614fc : 00000002 (Edited) : mscorwks!ThreadNative::KickOffThread+0xd3
00000000`76bdbe3d : 00000000 (Edited) : mscorwks!Thread::intermediateThreadProc+0x78
00000000`76d16a51 : 00000000 (Edited) : kernel32!BaseThreadInitThunk+0xd

Answer 1

私はここでは断然専門家ではありませんが、役立つかもしれないいくつかの情報があります。

• これによると、GCスレッドはCLRの起動時に、少なくともサーバーGCの場合は作成されるため、GCの実行に十分なスレッドがない可能性はありません;-)

• スレッド21の「GC」列の「Disabled」は、最終的なGC操作によって想定されないことを決定したことを意味します。これは、スレッド上のコードが、GCによって妨害されるべきではない重要な操作（ロードやアセンブリ、したがって融合など）を実行していると判断した場合に発生します。

• 「kb」コマンドの出力から、実際にサーバーGCを使用していると思います（スタックフレーム「mscorwks！SVR :: gc_heap :: make_heap_segment」、ワークステーションGCにはクラス/名前空間「WKS」が含まれます）。これは「サーバーオペレーティング」システムのデフォルトであるため、予期しないことではありません。これについては、「！eeversion」コマンドを使用して確認する必要があります。
  さらに、サーバーGCが実行されると、同じ数のスレッド（論理/物理コアごとに1つ）が使用されるため、コアの数を確認する必要があります。

タイマーがかなり頻繁に起動しているか、前のタイマーが終了するよりも速くなっている可能性があります。「！ThreadPool」コマンドを使用して、スレッドプールスレッドの使用法の概要を取得できます。

また、メソッドとローカル（！clrstack -a）および/またはスタック上の現在のオブジェクト（！dso）への実際の引数を確認することもできます。多分それはもう少し光を当てることができます。

大げさな推測として、「System.Net.ConnectionPool.CleanupCallbackWrapper」をグーグルで検索すると、次のリンクが生成されます。これが問題になる可能性がありますか？

• 高いCPU使用率のデバッグ
• SmtpClientは、メッセージの送信後にセッションを閉じません
• 負荷のないWebアプリでのCPU使用率が高い問題