Thursday, February 17, 2011

Simple C++ scope timing module

OK--I've been busy and tied down. And I've been trying to post an update on a weekly basis, so far so good this year. Except this is another short one. A longer posting is coming for next week though...

I've been using this little snippet of C++ code for ages, but it's nice to have the relatively simple source located at an easy to get location. Just uses the scope to determine the elapsed time in elapsed microseconds.

As you can see just requires a declaration that looks like:

Timer t("my time');

Which can be further simplified with a macro:

#define T Timer t(__PRETTY_FUNCTION__)

to:

T;

The implementation can (and has) been fancier. A static can be used to track nested or re-entry into blocks of code for easier consumption. That's great, however for multithreaded code a mutex needs to be thrown on the static which then perturbs the timing itself--so it's better to avoid unneeded complexity.

The header:
class Timer
{
public:
Timer(std::string id);
~Timer();

private:
struct timeval _start_time;
std::string _id;
};

The Source:
Timer::Timer(string id) : _id(id)
{
gettimeofday(&_start_time,NULL);
}

Timer::~Timer()
{
struct timeval end_time;
gettimeofday(&end_time,NULL);

unsigned long usecs = abs(_start_time.tv_usec - end_time.tv_usec);
unsigned long secs = end_time.tv_sec - _start_time.tv_sec;
if (_start_time.tv_usec >= end_time.tv_usec) {
secs = secs - 1;
usecs = 1000000 - usecs;
}

char buf[512];
sprintf(buf,"elapsed sec %d, usec %d",secs,usecs);
string msg = "timer(" + _id + "): " + buf;
string cmd = "echo '" + msg + "' >> /tmp/timer";
system(cmd.c_str());
}

Time printed is in elapsed time within the scope of the measurement. Obviously, this doesn't work well for scopes that are called multiple times, but is useful for outer scope timing. This can be easily modified to accumulate time though, at the expense of being thread unsafe.

No comments:

Post a Comment