Introduction
A common diagnostic task is to measure the performance of your code. To do that, the .NET Framework offers the System.Diagnostics.Stopwatch
class. This, however, is not truly intended for code performance measured, and would return false values in your measuring (explained in the ExecutionStopwatch
vs .NET Stopwatch
paragraph).
The ExecutionStopwatch
delivers an accurate way for measuring your code performance.
ExecutionStopwatch vs .NET Stopwatch
The .NET Framework already contains a time measuring mechanism that could be found in the Stopwatch
class (under System.Diagnostics
). However, the sole purpose of this class is to measure the amount of "real-world" time passed. Meaning, if you will attempt to use the Stopwatch
class in order to measure the execution time of a method, you will also measure time spent by other background threads. Theoretically, you would like to call "Stop()
" each time your OS performs a context switch to another thread, since you are not interested in measuring the time the CPU spent on executing unrelated work.
The ExecutionStopwatch
achieves just that - the amount of time the CPU spent on executing your current thread only. Time spent on executing other system threads will not be counted.
This is done by using the Win32
function GetThreadTimes
that returns time values relating to a particular thread, and not your system's global time (as the Stopwatch
class does).
Demonstration
In order to demonstrate the difference in the behavior between the .NET's original Stopwatch
class and between the ExecutionStopwatch
class, I've come up with the following example:
class Program
{
static void Main()
{
Stopwatch regularSW = new Stopwatch();
ExecutionStopwatch executionSW = new ExecutionStopwatch();
regularSW.Start();
executionSW.Start();
Thread.Sleep(5000);
regularSW.Stop();
executionSW.Stop();
Console.WriteLine("Regular Stopwatch: {0}", regularSW.Elapsed);
Console.WriteLine("Execution Stopwatch: {0}", executionSW.Elapsed);
}
}
The difference can be noticed immediately. While the .NET Stopwatch
measured 4.9 seconds, the ExecutionStopwatch
measured ~0 seconds (Window's time accuracy stands on about 15ms).
While the Stopwatch
measured the total clock time passed, the ExecutionStopwatch
measured the time the CPU spent executing the code.
Source Code
using System;
using System.Collections.Generic;
using System.Text;
using System.Runtime.InteropServices;
namespace DiagnosticsUtils
{
public class ExecutionStopwatch
{
[DllImport("kernel32.dll")]
private static extern long GetThreadTimes
(IntPtr threadHandle, out long createionTime,
out long exitTime, out long kernelTime, out long userTime);
[DllImport("kernel32.dll")]
private static extern IntPtr GetCurrentThread();
private long m_endTimeStamp;
private long m_startTimeStamp;
private bool m_isRunning;
public void Start()
{
m_isRunning = true;
long timestamp = GetThreadTimes();
m_startTimeStamp = timestamp;
}
public void Stop()
{
m_isRunning = false;
long timestamp = GetThreadTimes();
m_endTimeStamp = timestamp;
}
public void Reset()
{
m_startTimeStamp = 0;
m_endTimeStamp = 0;
}
public TimeSpan Elapsed
{
get
{
long elapsed = m_endTimeStamp - m_startTimeStamp;
TimeSpan result =
TimeSpan.FromMilliseconds(elapsed / 10000);
return result;
}
}
public bool IsRunning
{
get { return m_isRunning; }
}
private long GetThreadTimes()
{
IntPtr threadHandle = GetCurrentThread();
long notIntersting;
long kernelTime, userTime;
long retcode = GetThreadTimes
(threadHandle, out notIntersting,
out notIntersting, out kernelTime, out userTime);
bool success = Convert.ToBoolean(retcode);
if (!success)
throw new Exception(string.Format
("failed to get timestamp. error code: {0}",
retcode));
long result = kernelTime + userTime;
return result;
}
}
}
History
- 22nd November, 2008: 1.0 - Original article