Thursday, May 20, 2010

Timing a section of code in C++

Sometimes it's useful to measure how long a certain part of your C++ code takes to execute. Here's a little utility class that makes this extremely easy. It can be used like this:

void foo() {
    TimedSection s("foo()");
    // do some long operation...
}

Calling foo() will print something like this to stderr:

foo()   336.856127 ms

As you may have guessed, a TimedSection records the time between its construction and its destruction. Since C++ has no garbage collection, destructors are called at a deterministic moment: when the local object (called s above) goes out of scope. If you want to time a section that is not a scope by itself, you can introduce a pair of braces to scope the object. If the section is even more complex (e.g. spanning multiple functions), you can use new and delete, but that destroys the elegant simplicity of TimedSection's usage.

The implementation is rather simple as well:

#include <iostream>
#include <ctime>

class TimedSection {
    char const *d_name;
    timespec d_start;
    public:
        TimedSection(char const *name) :
            d_name(name)
        {
            clock_gettime(CLOCK_REALTIME, &d_start);
        }
        ~TimedSection() {
            timespec end;
            clock_gettime(CLOCK_REALTIME, &end);
            double duration = 1e3 * (end.tv_sec - d_start.tv_sec) +
                              1e-6 * (end.tv_nsec - d_start.tv_nsec);
            std::cerr << d_name << '\t' << std::fixed << duration << " ms\n"; 
        }
};
I hereby release this little code snippet into the public domain. Enjoy!

2 comments:

Eamon Nerbonne said...

It might be nice to know boost's progress_timer.

http://www.boost.org/doc/libs/1_43_0/libs/timer/timer.htm#Class%20progress_timer

It's not quite as handy: it prints using seconds rather ms, and prints to cout by default, and doesn't have that nice labelling option, but it is simple...

For more precise things, you might also want to use clock_gettime(CLOCK_PROCESS_CPUTIME_ID, ptr_to_timespec) or clock_gettime(CLOCK_REALTIME, ptr_to_timespec) from unistd.h on unix or their win32 counterparts QueryPerformanceCounter(ptr_to_LARGE_INTEGER) or GetSystemTime(ptr_to_SYSTEMTIME)

(I've never quite figured out what exactly cpu time is supposed to mean to these functions, but they're extremely highres, which can be nice...)

Thomas ten Cate said...

I'm already using clock_gettime(CLOCK_REALTIME, ...) above. Mainly because CPUTIME is indeed a tricky concept.

I didn't check clock_getres, but the resolution of clock_gettime is high enough indeed. When I forgot to actually declare a TimedSection variable (creating a temporary instead), it measured a nonzero time between construction and destruction.