Debugging 100% CPU Use

[Woof]

Hello all,

I have a pure .NET (C# .net framework 3.5 [all latest updates installed]) Windows Service which listens for connections via UDP and TCP, queues messages, and then interacts via LDAP and Exchange Web Services to perform tasks. This includes a WCF listener which receives thousands of EWS messages per hour.

After a period of time, typically 3 hours, the service goes to 100% CPU usage, yet is still fully responsive and appears to be working just fine. I have logged metrics which show all the processes still performing as expected, sending responses to other devices as expected and without delay. If the task manager didn't show 100% CPU usage then I would be under the impression all was fine. Memory usage is not increasing.

At 100% CPU usage there are no individual threads maxed out, rather an ever changing (2-4) group of threads which, between them, add up to 100%. The percentage for each thread continually varies and the threads appear to end as expected.

I've built in the ability to kill individual class instances (all the main queues, udp and tcp listeners, plus the WCF server) at will, but doing this causes no difference. The service still runs at 100% CPU, fully responsive. Network load appears no different to the pre 100% CPU load.

I'm having a heck of a time finding out what is going on, especially as disposing of and recreating all the main class instances makes no difference.

If anyone could give me a nudge in the right direction to find the cause I'd be very grateful.

Many thanks.

[sknake]

Why don't you fire visual studio up and attach a debugger to it and see what is going on? Also depending on how you have written your service you should split it out to a command or form application so you can debug the code more easily. For my services I write all of the service code in another assembly and develop it with a windows form app then reference the assembly in a service when I am completed with testing.... but it may be too late for that so a debugger is fine too.

[monalin]

Why don't you fire visual studio up and attach a debugger to it and see what is going on? Also depending on how you have written your service you should split it out to a command or form application so you can debug the code more easily. For my services I write all of the service code in another assembly and develop it with a windows form app then reference the assembly in a service when I am completed with testing.... but it may be too late for that so a debugger is fine too.

I do this as well. I typically build my source code for my services into an assembly so that I can test it in just a simple windows console app. Try running a debugger find out which code is running. If it always bugs out after three hours of running it makes sense that it would be some type of resource that's causing the problem, you said memory was fine and threads are normal, what about TCP UDP connections? Are messages being put in the queue faster than they're being processed?

Are each of the 2-4 threads running the same code? Or do they all have different jobs like one listens for messages and adds them to the queue, another waits for messages to be put on the queue and sends them out to other services etc...

[Arjay]

I perform a similar technique for debugging services; however, I don't put the service code inside an assembly. Instead I abstract the service implementation from the derived ServiceBase code. That way I just modify the program.cs file when I want to debug.

staticvoid Main( string[ ] args )
{
  //
  // DEBUG MODE (uncomment to run code as an exe)
  //
 
  // MyServiceImpl myServiceImpl = MyServiceImpl.Create( );
  // myServiceImpl.OnStart( args );
  // Thread.Sleep( 10000000 ); // DEBUG SLEEP
  //
  // SERVICE MODE
  //


  try
  {
    MyService myService = new MyService( );

    ServiceBase[ ] servicesToRun = new ServiceBase[ ] { myService };
    ServiceBase.Run( servicesToRun );
  }
  catch( Exception e )
  {
    myService.EventLog.WriteEntry( e.Message, EventLogEntryType.Error );
  }
}

The MyService code just creates an instance of MyServiceInstance and delegates the OnStart, OnStop, etc. to it.

[monalin]

Very interesting Arjay. I'll have to try this out.

[Woof]

Thanks for the responses guys. I agree completely with your separate assembly approach. In hindsight, given that this is a reasonable complex project I would do exactly that.

I had already attached a debugger but did not get any meaningful results. I cannot see thread info until I interrupt the service running (not sure if this is expected behaviour or me just not knowing the debugger properly), and everything seems to be running fine.

The only unknown that I am aware of right now is this service is running on a VMware virtual machine. I've not been able to take that out of the equation just yet.

Finally, I my logging is pretty extensive and I am including Thread.CurrentThread.ManagedThreadId and Thread.CurrentThread.Name in the logs but these bear no resemblance to the thread id's given in VS debugger or task manager. I guess I need to improve my skills here somewhat.

Networking appears normal by the way, and metrics for message processing shows that they are all being handled timely, hence why I'm rather confused. As I mentioned, if the task manager wasn't showing 100% CPU then I would have no indication that there was a problem.

My client application allows me to kill / reinstantiate all the main objects used, including the TCP / UDP listeners, but once in 100%CPU state, even killing all of these makes no difference. Only restartnig the complete service helps.

Cheers

[vcdebugger]

strange problem.

looks like you are not closing some of the opened calls( eg: timers, loopbacks, new threads opened..etc..) - they may pile up more and after 3 hrs they reach the peak and cpu is utilized 100% but your things might be working properly as expected.my suggestion is just do a thorough code walk thr and see if there is any loophole in the code regarding cleaning up some things in all your thread/process.

one more thing - try opening some other applications on your machines when it reached 100% CPU and see if those applications slow down to open or even they too work fine !!

[monalin]

It may not help but i'm curious if the CPU usage goes up over time or its like a switch. Does it go from 10% or something to 100% in a matter of seconds or progressively work its way up to 100% over three hours?

[Woof]

vcdebugger - will do, thanks.

monalin - 0-2% with the odd spike and very stable, then 100%, so like switch to use your analogy.

I've added a significant amount of metrics logging of the past few days to try and get a better idea of what is happening (or not!).

Cheers.

[monalin]

monalin - 0-2% with the odd spike and very stable, then 100%, so like switch to use your analogy.

Yeah that makes a lot of sense based on the other information you've provided us. Typically if it was some type of "leak" in the resources the CPU would take more of a gradual incline to 100% as the resources were used up.

Sounds to me like something is causing your application to get into a loop at some point that it never exits. Next time it goes to 100% CPU usage see if you can set it to trip a breakpoint in the code and then take a look at the call stack and look for any kind of loop. If it is a loop you'll see the same function show up quite a few times in the call stack.

If that doesn't work, look for any places this might be possible in your code and put some traces in those loops to see if any of them are getting called excessively. Once it hits 100% CPU usage it might be a lot more obvious whats going on if you have some traces in your code.

[Woof]

Finally found the issue. It was the constant use of new buffers for the tcp.beginreceive calls. It looks like garbage collection was never able to keep up when the server was busy. I'm now using the newer receiveasync method with a pool of reusable buffers (as per the example in the .net 3.5 sdk and all is well.

Thanks all for the pointers.

[monalin]

Nice! Glad you finally figured it out. Quite an elusive bug you had on your hands hah.