Using RATTV3 to Analyze the DPC Problem
Despite SoCal’s high winds and raging fires Gibbs stays on the hunt for the cause of why his processor utilization is being consumed by DPCs.
Faithful readers will know I’m still on the hunt for what is causing Deferred Procedure Calls to drive wild swings in processor utilitization on my Windows XP machine. I rebooted the box but the DPC utilization of around 40% returned for most of Tuesday and lasted through to Wednesday when it magically settled back down to around 2%.
Before I elaborate on that let me note I am lucky my computers are running at all. I live in Southern California and on Saturday the Santa Ana from hell blew in (actually, it was really more like an explosion). I spent much of the day picking up things that blew over and battening down the hatches on the Good Ship Gibbs in 50 mph gusts and 90 degree heat.
Sunday was when things went from bad to worse. My wife’s PC wouldn’t start and it was then we noticed the house lights were rather dim. I measured the voltage and found we had a whopping 60 volts! The chance of damaging equipment under such conditions is high.
We’ve had occasional, short-lived brownouts in high winds in the past, but this one lasted 18 hours. Edison followed that up the next day with a complete outage until midday when we got power back and, to my surprise and relief, all was well with the electronics.
That was when I restarted my PC and found the high DPC utilization was back. Last week I mentioned that Microsoft’s Mark Russinovich suggested I try the Kernrate sample profiling tool, which tracks how CPU time is spent for both kernel and user mode processes.
At about the same time reader Sean Fischer (Cheshire, Conn.) wrote: “We had a similar problem with wireless laptops at a major hospital where I was implementing a new Cisco lightweight enterprise WLAN (approximately 300 access points). A small number of Windows XP clients would become extremely sluggish at times. Task manager would show 100% CPU utilization, but the individual tasks did not add up to 100%. We used Process Explorer to trace it to DPCs.” Ah, this sounds familiar!
Fischer says they diagnosed the problem using another Microsoft tool, RATTV3. This utility is less complex and looked easier to use than Kernrate so I decided to try it first.
RATTV3 consists of two programs: RATT, which does the performance sampling using Event Tracing for Windows, and CSWA, which analyzes the collected data.
RATT runs as a system tray application and samples kernel activity for three minutes then calls CSWA to process the data.
The data is a record of the time spent in Interrupt Service Routines, DPCs and DPC Timers (a mechanism for timing out execution of procedures for things like preventing performance problems).
The output of CSWA is a little tricky to interpret as it divides timing into “buckets” — for example, from 4.00us to 4.99us, so an event that takes 4.54us would add one to that bucket. Note that the buckets are smaller for the shorter events (1.00 to 1.99us) than for the longer events (940.00us to 949.99us).
Of course, when you look at the results you really have to multiply the number of events in each bucket by the median duration of the bucket to get the real execution time.
Next week: What did I find? Send your output to gearhead@gibbs.com.
