Click here to Skip to main content
15,351,508 members
Articles / Programming Languages / C#
Posted 6 Mar 2012

Tagged as


19 bookmarked

Measure time with LogTimer

Rate me:
Please Sign up or sign in to vote.
4.38/5 (6 votes)
4 May 2012CPOL3 min read
How to measure time and find bottleneck points of an application with LogTimer

Image 1


In my last project, I needed to check what slows my application. To identify the bottleneck points of the misbehaved application I needed to measure the execution's times of several code blocks.

While System.Diagnostics.StopWatch is the obvious solution to this problem, it lacks some features I wanted:

  • Measuring samples - sample is the interval between Start() and its sequential Stop().
  • Retrieving the duration of the last sample - While System.Diagnostics.StopWatch allows to measure the duration of all samples (the duration of all Start and Stop intervals) you can not retrieve the duration of the last sample (the last Start and its sequential Stop interval).
  • Retrieving the total execution's time - The total execution's time may have one of the following meanings:
    • The time passed since the first Start() and the last Stop()
    • The time passed since the first Start() and the current time
  • Retrieving the percent of measured time of sampels from total execution's time
  • Retrieving the number of samples(Start and Stop intervals) and query the average of execution time of a sample.

The Demo Program

The demo program demonstrate how to use LogTimer. We will measure the execution's time of DoSomeWork(int timeout) which simply sleep for timeout milliseconds. The timer data will be displayed on the console after each step, the time is displayed as number of milliseconds.
public class LogTimerDemo {
  public static void Main(string[] args) {
    LogTimerDemo demo = new LogTimerDemo();
    LogTimer timer = new LogTimer();

    // Stage 1 : Let measure the exectution time of DoSomeWork(2000)
    timer.Start(); demo.DoSomeWork(2000); timer.Stop();
    // Stage 2 - Let wait 3 seconds. Note the influence of AllFromNow property
    timer.AllFromNow = false; demo.Display(timer,"2");
    timer.AllFromNow = true;  demo.Display(timer,"3");
    // Stage 4 : Let measure the exectution time of DoSomeWork(5000)
    timer.Start(); demo.DoSomeWork(5000); timer.Stop();
    // Stage 4 : Let measure the exectution's time of calling DoSomeWork(100)
    // 100 times in sequence and check the average time DoSomeWork(100). Note
    // that we use AddSample() that is more accurate than calling Stop() and
    // Start() in sequence.
    for (int ii = 0;ii > 100;ii++) {
  public void DoSomeWork(int ms) {
  public void Display(LogTimer timer,string perfix) {
    System.Console.WriteLine("{6} => All: {0:D5} , Value: {1:D5} , Current: {2:D5}, Stats: {3,3}%, Average ; {4:D5} [{5} samples]",timer.All.Ms(),timer.Value.Ms(),timer.Current.Ms(),timer.PercentAll,timer.Average.Ms(),timer.Count,perfix);

Here the program output on my machine:

Image 2

Using LogTimer

  • You can start a new sample (start to measure time) by calling Start().You can also start the timer immediately while creating a new timer by invoking the constructor with true. While calling Start() when the timer is running(measuring time) is allowed, it will be ignored by the timer.
  • You can end sample (stop measuring time) by calling Stop(). The return value of this is last sample's time (the time measured since last valid Start()). This sample's time is also added to total measured time. After the timer has stopped you can call Start() to measure other event in later time. While calling Stop() when the timer is not running(measuring time) is allowed, it will be ignored by the timer.
  • You can add a new sample by callling AddSample. This is the same effect of calling Stop() and Start in sequence but it is more accurate.
  • You can reset the timer by Calling Reset(). You can also start the timer immediately if called with true or by calling Restart().
  • You can use Value property to retrieve the total measured time (All samples' times). If the property invoked while the timer is running, the value will be the measured time at the property invocation.
  • You can use Current property to retrieve the time of the last sample (The interval between last Start()and Stop()). If the property invoked while the timer is running, the value will be the measured time at the property invocation.
  • You can use All property to retrieve the total execution's time. the actual meaning of this measurement depends on the value of AllFromNow property. If the property is true the value will be the time the time passed since the first call to Start() after last Reset() and the current time, Otherwise the value will be the time passed since the first call to Start() after last Reset() and last call to Stop(). If the property invoked while the timer is running, the value will be the measured time at the property invocation.
  • You can use Count property to retrieve the number of Start() and Stop() intervals. The Average property is average duration of the interval. (Value/Count)


  • Version 3 - Add AllFromNow and Restart
  • Version 2 - Explain the differances between System.Diagnostics.StopWatch and LogTimer.
  • Version 1


This article, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)


About the Author

Software Developer
Israel Israel

I have been developing professionally since 2002.

I developed desktop applications in C++ and C#. Now developing web applications and sites in PHP.

Visit Panboza.

Comments and Discussions

GeneralMy vote of 3 Pin
Joe Sonderegger7-May-12 20:14
MemberJoe Sonderegger7-May-12 20:14 
GeneralThe Console.WriteLine is for demonstration only ;) Pin
panboza7-May-12 23:29
Memberpanboza7-May-12 23:29 
QuestionDateTime.Now precision Pin
Jcmorin7-May-12 5:22
MemberJcmorin7-May-12 5:22 
AnswerRe: DateTime.Now precision Pin
panboza7-May-12 23:21
Memberpanboza7-May-12 23:21 
SuggestionRe: DateTime.Now precision Pin
Jcmorin8-May-12 1:40
MemberJcmorin8-May-12 1:40 
It's not recommended either because it's not more precice AND the 32 bit roll over in a few days....[^]

Environment.TickCount is based on GetTickCount() WinAPI function. It's in milliseconds But the actual precision of it is about 15.6 ms. So you can't measure shorter time intervals (or you'll get 0)

DateTime.Ticks is based on GetSystemTimeAsFileTime() WinAPI function. It's in 100s nanoseconds (tenths of microsoconds). The actual precision of DateTime.Ticks depends on the system. On XP, the increment of system clock is about 15.6 ms, the same as in Environment.TickCount. On Windows 7 its precision is 1 ms (while Environemnt.TickCount's is still 15.6 ms)

Stopwatch is based on QueryPerformanceCounter() WinAPI function (but if high-resolution performance counter is not supported by your system, DateTime.Ticks is used)
QuestionI'm confused Pin
hvasilev6-Mar-12 6:55
Memberhvasilev6-Mar-12 6:55 
AnswerThe Differences : Pin
panboza6-Mar-12 19:42
Memberpanboza6-Mar-12 19:42 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    Praise Praise    Rant Rant    Admin Admin   

Use Ctrl+Left/Right to switch messages, Ctrl+Up/Down to switch threads, Ctrl+Shift+Left/Right to switch pages.