Increase in thread usage - find where the demand is

Question

I have a windows wcf web application and in the service side, we create stateful sessions. When the number of sessions exceed a certain threshold, new requests get queued up in the .net level. We figured that it's because of some .net bug where .net is unable to issue threads fast enough when there is a sudden burst of demand for .net default threadpool threads. So new requests are queued until .net recovers from the hang and issues thradpool threads to accept the incoming requests.

We are trying to figure out where the sudden demand for the thread is coming from. I took a dump of the w3wp process when the thread count started increasing.

I ran !uniqstack command in windbg and I notice the below stack common for close to 400 threads. What does this stack mean? Is it all waiting for some IO to complete? Are these 400 threads IO Completion Port threads?

.561  Id: c504.ce10 Suspend: 0 Teb: 00000038`f6d90000 Unfrozen
      Start: clr!Thread::intermediateThreadProc (00007ff9`d1bbc150)
      Priority: 0  Priority class: 32  Affinity: fff
 # Child-SP          RetAddr           Call Site
00 00000038`f997f068 00007ff9`dfbabcff ntdll!ZwRemoveIoCompletion+0x14 [d:\rs1.obj.amd64fre\minkernel\ntdll\daytona\objfre\amd64\usrstubs.asm @ 251]
01 00000038`f997f070 00007ff9`d1ccea3c KERNELBASE!GetQueuedCompletionStatus+0x3f [d:\rs1\minkernel\kernelbase\error.c @ 844]
02 00000038`f997f0d0 00007ff9`d1bbc1cf clr!ThreadpoolMgr::CompletionPortThreadStart+0x210 [f:\dd\ndp\clr\src\vm\win32threadpool.cpp @ 3770]
03 00000038`f997f170 00007ff9`e1c184d4 clr!Thread::intermediateThreadProc+0x86 [f:\dd\ndp\clr\src\vm\threads.cpp @ 2872]
04 00000038`f997fb30 00007ff9`e285e8b1 kernel32!BaseThreadInitThunk+0x14 [d:\rs1\base\win32\client\thread.c @ 64]
05 00000038`f997fb60 00000000`00000000 ntdll!RtlUserThreadStart+0x21 [d:\rs1\minkernel\ntdll\rtlstrt.c @ 997]

But the number of IO Completion port thread is only few as per below command.

0:000> !threadpool
CPU utilization: 3%
Worker Thread: Total: 492 Running: 492 Idle: 0 MaxLimit: 32767 MinLimit: 360
Work Request in Queue: 1
    AsyncTimerCallbackCompletion TimerInfo@000001e7a14ffcd0
--------------------------------------
Number of Timers: 1
--------------------------------------
Completion Port Thread:Total: 3 Free: 3 MaxFree: 24 CurrentLimit: 3 MaxLimit: 1000 MinLimit: 12

Answer 1

Since you have WinDbg ;-) I'm no expert but have cobbled together a few useful commands, like two:

Search for wildcard function from loaded stuff, this will give the exact name for setting breakpoints at functions:

x *!*CreateThread*

Set tracepoint at function, log callstack at depth:

bp ntdll!ZwCreateThreadEx "k 10; gc"

Maybe this will give some insights about what is triggering the creation of new threads, perhaps adding threads to the existing pool.

There's also many nice reference sites for WinDbg strategies, like http://www.windbg.info/ that is the limits of my scant knowledge.

There's also the reference source for WCF, but that is rather large, would really help if you have some call stack context and know what to search for in the source.

Answer 2

Tess Ferrandez, a former Microsoft Escalation Engineer, seems to list exactly your case as one of the things to ignore. On her website If broken it is, fix it you should , it's mentioned like this:

Idle CLR Completion Port/IO Thread

14 Id: efc.11c8 Suspend: 1 Teb: fff8e000 Unfrozen
ChildEBP RetAddr Args to Child 
0209fe7c 7d50664c 00000234 0209fee8 0209fec0 ntdll!NtRemoveIoCompletion+0x15
0209fea8 79f795de 00000234 0209feec 0209fee8 kernel32!GetQueuedCompletionStatus+0x29
0209ff14 79f7997f 00000000 00000000 00000000 mscorwks!ThreadpoolMgr::CompletionPortThreadStart+0x11a
0209ffb8 7d4dfff1 0019c440 00000000 00000000 mscorwks!ThreadpoolMgr::intermediateThreadProc+0x49
0209ffec 00000000 79f79939 0019c440 00000000 kernel32!BaseThreadStart+0x34

I can't tell why !threadpool would not recognize them.