0

I am looking into an issue at work with a WindowsService that is taking 100% CPU on a machine with 16 CPU's.

The service is hosting a self-hosted .NET WCF service.

I have received a crash dump which I have loaded up in windbg, in order to look for clues.

So what I have tried:

  • !threads :

    ThreadCount: 646
    UnstartedThread: 0
    BackgroundThread: 643
    PendingThread: 0
    DeadThread: 2
    Hosted Runtime: no

    642 of the threads were Threadpool workers as following:
    8 29 2a34 000000002068b510 3029220 Preemptive 0000000000000000:0000000000000000 0000000000563f50 0 MTA (Threadpool Worker)

  • ~29s -> !CLRStack

    000000003c66eb70 00000000770512fa [GCFrame: 000000003c66eb70]
    000000003c66ec40 00000000770512fa [GCFrame: 000000003c66ec40]
    000000003c66ec78 00000000770512fa [HelperMethodFrame: 000000003c66ec78]
    System.Threading.Monitor.Enter(System.Object)
    000000003c66ed70 000007fef7af1c9c System.Threading.TimerQueueTimer.Fire()
    000000003c66ede0 000007fef7a6c2f3 System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
    000000003c66ee30 000007fef7a6c92a System.Threading.ThreadPoolWorkQueue.Dispatch()
    000000003c66f388 000007fef8d57d33 [DebuggerU2MCatchHandlerFrame: 000000003c66f388]

  • ~29s -> K

    000000003c66e858 000007fefd7010dc ntdll!NtWaitForSingleObject+0xa
    000000003c66e860 000007fef8d049bf KERNELBASE!WaitForSingleObjectEx+0x79
    000000003c66e900 000007fef8d04977 clr!CLREventBase::WaitEx+0x16c
    000000003c66e940 000007fef8d048f8 clr!CLREventBase::WaitEx+0x103
    000000003c66e9a0 000007fef8e9c5de clr!CLREventBase::WaitEx+0x70
    000000003c66ea30 000007fef8dc5a34 clr!WKS::GCHeap::WaitUntilGCComplete+0x2b
    000000003c66ea60 000007fef8d0c4f4 clr!Thread::RareDisablePreemptiveGC+0x176
    000000003c66eaf0 000007fef8dd1f3d clr!GCCoop::GCCoop+0x3d
    000000003c66eb20 000007fef8e898cf clr!AwareLock::Contention+0x137
    000000003c66ebe0 000007fef7af1c9c clr!JITutil_MonContention+0xaf
    000000003c66ed70 000007fef7a6c2f3 mscorlib_ni+0x521c9c
    000000003c66ede0 000007fef7a6c92a mscorlib_ni+0x49c2f3
    000000003c66ee30 000007fef8d57d33 mscorlib_ni+0x49c92a
    000000003c66eef0 000007fef8d556e6 clr!CallDescrWorkerInternal+0x83
    000000003c66ef30 000007fef8d557af clr!CallDescrWorkerWithHandler+0x4a
    000000003c66ef70 000007fef8eda2c9 clr!MethodDescCallSite::CallTargetWorker+0x2e6
    000000003c66f120 000007fef8ee51b0 clr!QueueUserWorkItemManagedCallback+0x2a
    000000003c66f200 000007fef8ee513e clr!DebuggerU2MCatchHandlerFrame::DebuggerU2MCatchHandlerFrame+0xa0
    000000003c66f240 000007fef8ee50b5 clr!ManagedPerAppDomainTPCount::DispatchWorkItem+0x38e
    000000003c66f340 000007fef8ee51eb clr!ManagedPerAppDomainTPCount::DispatchWorkItem+0x2bd
    000000003c66f3d0 000007fef8eda224 clr!ManagedPerAppDomainTPCount::DispatchWorkItem+0x23b
    000000003c66f430 000007fef8ee6baf clr!ManagedPerAppDomainTPCount::DispatchWorkItem+0xb4
    000000003c66f5c0 000007fef8ee6ab3 clr!ThreadpoolMgr::ExecuteWorkRequest+0x4c
    000000003c66f5f0 000007fef8eda8a6 clr!ThreadpoolMgr::WorkerThreadStart+0xf3
    000000003c66f6b0 0000000076c9652d clr!Thread::intermediateThreadProc+0x7d
    000000003c66f7f0 000000007702c541 kernel32!BaseThreadInitThunk+0xd
    000000003c66f820 0000000000000000 ntdll!RtlUserThreadStart+0x1d

Im having a hard time interpreting the stacktraces since they dont hit any of my applicationcode. Are they all just idle threadworkers, waiting for work?

3
  • What does !runaway report? If it shows a threads on top that are not a threadpool workers, it might give you the offender. Otherwise, look at why you have so many threads -- 646 is too many.
    – seva titov
    Oct 23, 2014 at 20:22
  • Use ProcessExplorer from SysInternals (Microsoft) and you can open the process details and see a list of threads and how much CPU the threads are taking. It can also load symbols and show you the entrypoint of the thread in question. Figure out which threads are using the CPU then debug those specific threads.
    – lordjeb
    Oct 23, 2014 at 23:04
  • have you tried xperf/WPA? Oct 27, 2014 at 19:02

5 Answers 5

1

Threads with WaitForSingleObject are not critical, since they are waiting and not consuming CPU time. But be aware that your dump is only a snapshot and you might have had bad luck when taking the snapshot.

For a performance analysis with WinDbg you'd need several dumps during high CPU and compare them. If they all have similar stack traces, that's fine and you can conclude something. If they are all very different, it's almost useless.

The command !runaway seems more interesting here, since it lists CPU times consumed per thread, so you can identify the one(s) which are on high CPU. Again: having two snapshots that you can compare is helpful, because the main thread may still have consumed more CPU time in total than some short-living 100% threads.

If you can't use a performance profiler, SysInternals Procdump can generate a series of dumps (-n) for you on high CPU (-c). Use -s to set the time between dumps. For .NET, don't forget -ma for full memory.

Other than that, 646 threads sounds a lot to me. The OS itself could be quite busy scheduling them.

0

Sounds like the issue could be related to GC. Since this is a self-hosted service, it will use the Workstation GC by default, unless you enable the server GC manually:

http://msdn.microsoft.com/en-us/library/ms229357(v=vs.110).aspx

Have you tried that and see if it makes any difference?

3
  • Is this really an answer? Sounds more like a comment. Oct 23, 2014 at 19:03
  • It's an educated guess, based on seeing a fairly significant number of self-hosted WCF services suffering from the same issue, and the fact that the stack trace shown clearly indicates the thread is waiting for GC to complete (if you're allocating a lot of objects, then the workstation GC will impact you heavily on a 16-proc machine). I could certainly be wrong, but it's worth a try.
    – tomasr
    Oct 23, 2014 at 21:51
  • Sounds very plausible - I am switching to server gc, and are awaiting a deployment to see if it changes anything! Nov 21, 2014 at 9:05
0

Perfview from Microsoft may be helpful. From the link:

http://blogs.msdn.com/b/dotnet/archive/2012/10/09/improving-your-app-s-performance-with-perfview.aspx

"Late last year, Vance Morrison, who is currently an architect on the .NET Framework Performance team, released PerfView, which is a new performance tool for .NET developers. PerfView helps you discover and investigate performance hotspots in .NET Framework apps, and enables you to deliver consistently high-performance apps to your customers.

Using PerfView, you can perform complex CPU performance analyses to solve hard-to-detect performance problems. PerfView's revolutionary grouping and folding features are what makes it possible to grasp and solve these difficult problems."

0

use WPRUI.exe to capture a trace and analyze the CPU usage with WPA.exe.

enter image description here

Microsoft explained how to analyze the created trace in the following video:

Defrag Tools: #42 - WPT - CPU Analysis
http://channel9.msdn.com/Shows/Defrag-Tools/Defrag-Tools-42-WPT-CPU-Analysis

-1

Collect ETW with Perfview and follow the big % numbers.

try run in windbg ~*e!clstack => call stacks of all threads look for repeatable code.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.