# Multiple Performance Timer

By , 2 Jan 2003

## Introduction

This article contains one file MultiTimer.h which allows you to easily time parts of your code. It accumulates times on multiple calls and produces an output summary with all the totals and number of calls for each timer. There are many similar articles here and elsewhere, I thought it worthwhile to add this article though, as I think my timer class adds a few extra features and is very easy to use.

## Example

void testfun()
{
printf("Hello World!\n");
}

int main(int argc, char* argv[])
{
for (int i = 0; i < 10; i++)
testfun();

return 0;
}

This isn't the best example of code to time, but it is a good example to show how the timing code is used. See the usage guidelines below for ideas on how to time your code.

The following steps are needed to add timing code:

• Add #include "MultiTimer.h"
• Add timing macros to the code you want to time
• Call TIMER_DUMP or similar macros to display the results

After adding some test timing code, the above example looks like this:

#include "MultiTimer.h"

void testfun()
{
TIME_LINE(printf("Hello World!\n");)
}

int main(int argc, char* argv[])
{
{
TIME_SCOPE("total test")
for (int i = 0; i < 10; i++)
TIME_FUN(testfun())
}
TIMER_DUMP("c:\\times.txt", SORT_CALLORDER)

return 0;
}

This produces the following output file:

-----------------------------------------------------------------
Timings at 10:41:56 Friday, January 03, 2003
-----------------------------------------------------------------
total test took 606.80 micro secs (called 1 time)
testfun() took 591.42 micro secs (called 10 times)
printf("Hello World!\n"); took 561.52 micro secs (called 10 times)

The results are pretty straightforward. If you download the demo code, you will see further code which breaks down the times for the testfun() calls. Here is a sample output from this code:

Total: 668.20 micro secs
Minimum: 39.39 micro secs
Maximum: 302.55 micro secs
Average: 66.82 micro secs

-----------------------------------------------------------------
testfun() at 10:22:06 Friday, January 03, 2003
-----------------------------------------------------------------
Sample  1 = 302.55 micro secs
Sample  2 = 58.11 micro secs
Sample  3 = 55.87 micro secs
Sample  4 = 41.63 micro secs
Sample  5 = 42.46 micro secs
Sample  6 = 41.07 micro secs
Sample  7 = 42.46 micro secs
Sample  8 = 39.39 micro secs
Sample  9 = 50.29 micro secs
Sample 10 = 43.02 micro secs

You can see from this that the first printf takes a lot longer on Windows 2000, I guess some initialization is going on.

## Macros

From the above example, you can see that this timing code is largely macro driven, here is a list of the macros used:-

### TIMER_SETUP

This needs to be included in one of the .cpp files in a project, at a global scope. It sets up the storage for the timing code.

### TIME_SCOPE(name)

Place this in your code to time from that point to the end of the current scope. name is a string, which is used in the output to identify these times.

### TIME_FUN(fun())

Replace a function call, fun(), with this macro to time the call.

### TIME_LINE(line)

Wrap any line with this macro to time it. Avoid declaring any variables in the line, as this macro puts the line in a separate scope.

### TIMER_START(name) and TIMER_STOP(name)

These macros allow you to start and stop timers manually. See the demo for an example.

### TIMER_DUMP(dest, sort)

Dump the current times. If dest is a file name, then the output is written to this file. Otherwise it can be:

• OUT_MSGBOX - Display output in a message box
• OUT_TRACE - Send the output to the trace window
• OUT_CONSOLE - Send the output to stdout

The output can be sorted in 3 ways:

• SORT_TIMES - The longest time is displayed first, down to the smallest
• SORT_CALLORDER - The times are displayed in the order the timers were called
• SORT_NAMES - The output is sorted alphabetically

### TIMER_DUMP_FILE(dest, sort, mode)

This allows 3 extra mode values:

• FILE_NEW - Create a new file each time
• FILE_APPEND - Add each output to the end of the file
• FILE_PREPEND - Add each output to the start of the file

This is useful if you want to compare several test runs.

### TIMER_DUMP_CSV(dest, sort, mode)

This is the same as TIMER_DUMP_FILE but the output is in comma separated format.

### TIMER_DUMP_SAMPLES*(timer, ...)

The TIMER_DUMP_SAMPLES macros dump all the samples for a specified timer, this can be it's name or a CHiFreqTimer object. See the demo for an example.

There are 3 TIMER_DUMP_SAMPLES macros which correspond to the TIMER_DUMP macros, except there is no sort argument - the samples are dumped in ascending order.

### GET_TIMER(name)

Return a CHiFreqTimer object for timer name. Further statistics can then be used, see the demo for an example.

### T2S(time)

Converts a time returned from a CHiFreqTimer call to a meaningful string, see the demo for examples.

### CLEAR_TIMERS

Removes all timers.

## Disabling timing code

At the top of MultiTimer.h is a #define USE_TIMERS. Commenting this out will compile out any timing code you may have added.

## Timing multiple files

You can put timing code in more than one file. Every file needs to include multitimer.h and all but the first must put the following line before the #include:

#define ANOTHER_TIMER_FILE

## Clock ticks

It is sometimes useful to know how many clock ticks a piece of code took. I've added some macros which convert the time taken to clock cycles, first you must uncomment the #define _CLOCKTICKS line at the top of multitimer.h file. They are:-

### T2C(time)

Converts a time to a string containing the number of clock cycles taken.

### T2S_WITHCYCLES(time)

Converts a time to a string containing the time and the number of cycles.

### CLOCK_SPEED

This is an int which represents your machine speed, e.g.. 733. This figure is accurate to 1 or 2 of your specific machine speed.

## Usage guidelines

The idea of this type of code is to identify slow parts of your projects. If a part of your project is slow, it should help you to narrow down which bit of your code is causing the problem. You should avoid timing very quick statements - the timings are likely to be inaccurate. Also don't time all of your code, focus on areas that are slow and need to be sped up. It can also be helpful to know how many times a particular line or function is called, as this is often difficult to find out from the code alone.

Ideally release code should always be used to get accurate timings, the extra checking and lack of optimizations in debug code can cause misleading results. Other running processes can also affect times, for example virus scanners can skew file access times.

Any code added to time a file will itself take some time. This code tries to compensate for this but with very large number of timers and/or timing calls, a small loss of accuracy may result.

The QueryPerformanceCounter() call is used to time things. This is only supported on Pentiums. If you're running on an older machine, upgrading will probably speed things up...

## Change History

• 6/11/02
• General improvements to MultiTimer.h file
• TIMER_DUMP_FILE macro added
• 7/11/02
• Added TIMER_START + TIMER_STOP macros
• Added USE_TIMERS #define
• 3/1/03
• Sorted out TIMER_START and TIMER_STOP manual timers
• Added TIMER_DUMP_CSV macro
• Added TIMER_DUMP_SAMPLES, TIMER_DUMP_SAMPLES_FILE and TIMER_DUMP_SAMPLES_CSV macros
• Removed TIMER_SETUP macro

 Jon Software Developer United Kingdom Member
No Biography provided

Votes of 3 or less require a comment

 Search this forum Profile popups    Spacing RelaxedCompactTight   Noise Very HighHighMediumLowVery Low   Layout Open AllThread ViewNo JavascriptPreview   Per page 102550
 First PrevNext
 execution time mrt85 18 Feb '08 - 4:45
 Hi; Firstly,thank you for this useful and good project.I want to calculate my program's execution time with miliseconds or microseconds in c++,borland. What should I do? Can you give me some tipps for this? Thank you! Sign In·View Thread·Permalink
 Re: execution time Jon 18 Feb '08 - 4:54
 Look at the example, the "totaltest" timer is for the whole of the program. I've not used Borland C++, but it should work... Sign In·View Thread·Permalink
 License for use? Paul Gregory 9 Jun '05 - 6:45
 Hi,   Really, really like this article, I'd like to use the implementation pretty much as it is, with a couple of small tweaks in an Open Source project (http://www.aqsis.com). I can't immediately find any licensing details on this site, can you tell me what license this code is under?   Of course I will give due credit for it's use if I am able to use it.   Cheers   PaulG Sign In·View Thread·Permalink
 Re: License for use? Steve Maier 9 Jun '05 - 7:20
 Here is a snippet from the "submit your code" page.   "Note that we do not accept time limited, shareware contributions or binary-only contributions. All code that is available from our site must be available for use without registration or licence fees and without time restrictions, and all applications or binaries submitted must contain source code. CodeProject is a place to share source code, not applications or components."   Steve Maier, MCSD MCAD Sign In·View Thread·Permalink
 Re: License for use? Jon 13 Jun '05 - 11:34
 Hi Paul,   Steve's right - everything on this site is free to be used as you like.   You could add a comment saying you got the code from here, but to be honest I don't mind. Just happy you find the code useful.   Jon Sign In·View Thread·Permalink
 compile error with 'log10' manhatman 7 May '05 - 6:49
 Why do I get this compiling your demo? d:\My Documents\Visual Studio Projects\TimerDemo\TimerDemo\TimerDemo\MultiTimer.h(582) : error C2668: 'log10' : ambiguous call to overloaded function            c:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\include\math.h(614): could be 'long double log10(long double)'            c:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\include\math.h(566): or         'float log10(float)'            c:\Program Files\Microsoft Visual Studio .NET 2003\Vc7\include\math.h(194): or         'double log10(double)'            while trying to match the argument list '(unsigned int)' Sign In·View Thread·Permalink
 Re: compile error with 'log10' manhatman 7 May '05 - 7:08
 Fix for MultiTimer.hchange    //int width = (int)log10(numSamples) + 1;to   int width = (int)log10((double)numSamples) + 1; also, if using console application, fix for TimerDemo.CPPchange   //TIMER_DUMP(OUT_MSGBOX, SORT_CALLORDER)to   TIMER_DUMP(OUT_CONSOLE, SORT_CALLORDER) Sign In·View Thread·Permalink
 Try our tool, auto display time stamp. autodebug 5 Apr '04 - 14:52
 exit(0) Thomas Haase 4 Apr '03 - 1:50
 You have some exit(0) calls in your code. I would prefer to have some more relaxed error handling. Couldn't you add a special dummy timer into your list, that you can return on error case?   Thomas Haase Sign In·View Thread·Permalink
 Re: exit(0) Jon 4 Apr '03 - 1:58
 The exit(0) code is only if things go really wrong, e.g. if the timing isn't supported.   The code isn't supposed to error at all   Jon Sign In·View Thread·Permalink
 Last Visit: 31 Dec '99 - 18:00     Last Update: 23 May '13 - 20:08 Refresh 123 Next »