A lesson in not leaping to conclusions

Gadgets

 

I have a pretty decent quad-core PC at home with 8GB RAM and performance generally isn’t an issue for me. This spec is more than adequate to run the occasional virtual machine for testing and evaluation purposes as well as handle standard business applications such as word processing, email, video conferencing etc.

 

At the moment, my performance counters are reasonably healthy; under normal use, I typically use between 10-25% of my processing capacity and about 2/3 of my available memory. This is normal for me and has been consistent for more than 12 months. The only exception to this tends to be when I edit HD videos or do other things such as saving recorded TV shows to DVD using media centre.

 

 

The problem
I work as an application performance tester which means that I’m pretty inquisitive when it comes to how computers perform. This may be the reason that I tend to leave Windows Gadgets on my desktop reporting CPU and memory use in real-time.

For some time, I’d been noticing that the third core of my quad core processor (an Intel i5 750) was busier than the other cores. I thought that I’d have a look at Windows Task Manager to see what was using my CPU cycles. When I looked at Task Manager I was surprised to see that the total amount of CPU in use was consistently less than that shown by my desktop gadget.

 

I tried the usual tricks, including choosing “show processes from all users” to see whether a system account was using CPU.

 

In short I was stumped…..

 

 

Diagnosis

I decided that perhaps I should dig a little deeper, so I installed Process Explorer.

Process Explorer shows you more detailed information about currently running processes and I was pleased to see that it showed me the increased activity on core 3. As well as showing me this extra activity it also showed that the bulk of activity was down to interrupts, rather than context switches or deferred procedure calls.

Process Explorer showing large number of interrupts

15-17% of all CPU activity was handling hardware interrupts so one core was almost fully occupied.

Process Explorer - CPU chart, core 3 busy

The (wrong) conclusion

I knew that I shouldn’t have any hardware device generating this large number of interrupts, so I thought that I’d work out what was causing the problem by a process of elimination. I decided to check external devices first because this was easier and I suspected that these devices were more likely to be faulty. I disconnected the scanner, printer, external USB hub, speakers, drawing pad etc. but the problem remained.

This meant that the problem had to be inside the PC, so I started to disconnect internal components such as my DVD drive, after disconnecting everything that I could, I rechecked and the problem still remained. Because my graphics card passed a diagnostic check and I was running out of other options, I decided that it must be my hard drive.

This was both right AND wrong.

The (correct) conclusion

After replacing my hard drive at first the problem seemed to have resolved itself. I’m not sure how this problem seemed to be fixed for a short while, but after a couple of days the problem came back.

I decided to overhaul the PC from a software perspective. I performed a Windows update to upgrade any drivers that were out of date, and then I decided to check for new drivers for my hard disk.
In device manager I right-clicked on the hard disk and chose the option to “Update Driver Software”. I didn’t really expect this to work but after a reboot the problem had gone.

Device Manager - showing option to update driver software

After several months, I’m happy to report that my PC is still working normally.

All cores have similar utilisation levels.

Process Explorer - showing four cores with similar utilisation

Interrupts is no longer visible in the top of the list of active processes.

Process Explorer

 

If only I checked for updated drivers before I spent the best part of £80 on a new drive.
Ah well, at least I learnt something new, and I now have a spare hard drive for backups!

 

 

Creating uniquely named log files with details of running processes (TASKLIST)

Thanks to Scott Moore (at LoadTester.com) for the idea behind this article and to the owners of DOStips.com for their article on DOS string manipulation which I used to get the string concatenation right.

When running performance tests or any kind of performance analysis it can be useful to know the processes running on a PC or server which are consuming resources. The Windows command TASKLIST gives a list of currently running processes (basically a text based version of what the Task Manager process tab shows you).

TASKLIST screenshot

By piping the output of this file to a text file you can save details of the running processes for later analysis.

Scott’s article described a batch file which you could run before and after certain events such as batch processing or performance tests to create uniquely named log files containing the TASKLIST information. I had some difficulty getting his time and date stamps to work, possibly due to the timezone settings in Windows which “regionalise” the date and time environment variables. I’ve modified his original batch file to this one below which seems to work on UK PCs running Windows 7, Windows Vista and Windows XP.

Sample Code

for /f “tokens=1-3 delims=/ ” %%d in (“%date%”) do set d=%%d-%%e-%%f

for /f “tokens=1-3 delims=:” %%d in (“%time%”) do set t=%%d%%e

set timestr=%d:~6,4%%d:~3,2%%d:~0,2%-%t:~0,2%%t:~2,2%

tasklist /FO CSV > TASKLIST_Logfile_%timestr%.csv

 

This creates a CSV file named TASKLIST_Logfile_YYYYMMDD-HHMM.csv formatted like the sample below.


Sample Output

“Image Name”,”PID”,”Session Name”,”Session#”,”Mem Usage”

“System Idle Process”,”0″,”Services”,”0″,”24 K”

“System”,”4″,”Services”,”0″,”95,672 K”

“smss.exe”,”272″,”Services”,”0″,”64 K”

“csrss.exe”,”408″,”Services”,”0″,”2,484 K”

“csrss.exe”,”484″,”Console”,”1″,”73,224 K”

“wininit.exe”,”496″,”Services”,”0″,”172 K”

“avgchsva.exe”,”508″,”Services”,”0″,”25,816 K”