Introduction

In this two-part post, I will introduce, itimize, a simple library to profile a c++ code. If you are like me, you will find it useful if:

• You need a better resolution/locality for your benchmarks.
• You don't always use a modern IDE (I often draft my code on vim).
• You simply want to add your fingerprint on github :-)

In this part I will show a basic timing class that can be used to time a block. In the second part, I will introduce a singleton class that gives more control on timing possibilities and helps producing statistics on the targeted code.

Block Timing

One of the aspect I wanted to see in Itimize is the ability to time a block easily without having to manually create objects and managing them just for the sake of profiling. In order to achieve this, a common approach is to exploit the implicit call to an object's destructor. Roughly, this can be achieved by:

1. Create a temporary timing object.
2. The constructor of this object starts the timing.
3. When the destructor is called the timing is stopped and the duration is computed.

Truce of blathering, let's have a look at some code. We gonna start by defining types for the time moment and duration:

using TimePoint = std::chrono::time_point<std::chrono::high_resolution_clock>;
using Duration = double; // in ms.

This is very convenient, not only because the new types are more prolix but also makes it easy for future changes. The next thing we need is a function, that when called, returns the time value at the moment of the call:

TimePoint Now()
{
   return std::chrono::high_resolution_clock::now();
}

We are now ready to introduce the skeleton of our main class Ticker , this is where most of the magic happens:

class Ticker
{
  public:
    Ticker(const Ticker&) = delete;

    Ticker(const std::string &label) : label_(label)
  { 
    cout << "Start a stop watch.\n";
  }

    ~Ticker()
    {
      cout << "Stop the stop watch.\n";
    }

  private:
    std::string label_;
};

First thing to notice, we have deleted the copy constructor. The reason behind this it's because a Ticker is meant to be unique in space-time and thus, cloning it has no sens. In this simple skeleton, it is easy to see the lifetime of a Ticker: we record the time moment as soon as the instance is created and we stop measuring when the instance goes out of scope, i.e when the destructor is called. I think it's convenient to label the tickers, doing so will yield a readable summary.

Instead of putting all relevant informations in the Ticker class, I find it clearer to have these info in a separate class. That is the purpose of the struct Entry:

struct Entry
{
  Entry(const std::string &l) : label(l) {}
  Entry(const std::string &l, const TimePoint &s) : label(l), start(s){}

  // Set the endtime and compute the duration.
  void set_endtime(const TimePoint &e)
    { 
     end = e;
     std::chrono::duration<double, std::milli> dur= end - start;
     duration = dur.count();
    }

  std::string label;
  TimePoint   start;
  TimePoint   end;
  Duration    duration;
};

We could have avoided storing the end time since we are mostly interested in the duration, but this will prove to be useful when we would like to produce statistics of the execution times as it will be shown in the second part of this article.

The (temporary) final aspect of the Ticker class, looks now like this:

class Ticker
{
    public:
        Ticker(const Ticker&) = delete;
        Ticker(const std::string &label) : entry_(label, now()) { }

        ~Ticker()
        {
            entry_.set_endtime( now() );
            std::cout << entry_.label << " " << entry_.duration << std::endl;
        }

    private:
        Entry entry_;
};

For this first part, we will simply output on stdin the recorded durations.
There is one last thing remaining in order to make this library handy: a nice macro to facilitate Ticker objects manipulations. Indeed, instead of manually declaring our tickers, we could just add them like item or itime :-) :

#define COMBINE1(X,Y) X##Y 
#define COMBINE(X,Y) COMBINE1(X,Y)

#define LOCATION std::string(__FUNCTION__) +  ":" + STR1(__LINE__)

// Use these macros
#define TIME_NAMED_BLOCK(label) itimize::Ticker COMBINE(_timer_,__LINE__)(std::string(label))
#define TIME_BLOCK() itimize::Ticker COMBINE(_timer_,__LINE__)( LOCATION )

The macro TIME_BLOCK will create a temporary Ticker object whose name is _timer_<line_number>. It's internal label is also a concatenation of the function name and the line number. The macro TIME_NAMED_BLOCK instead, expects an explicit label name.
In the next section, we gonna see some examples using these two macros.

Examples

The simplest way to use itimize is to call one of the macros inside or outside a function call. To time a non recursive function, we can do something like:

int fibonacci(int n)
{
  if( n <= 0 ) return 0;
  if( n == 1 ) return 1;

  return fibonacci(n - 1)  + fibonacci(n - 2); 
}

double func1()
{
  TIME_BLOCK();

  double r = ...
  return r;
}

double func2()
{
  TIME_BLOCK();

  double r = ...
  return r;
}

int main(int , char **)
{

  TIME_NAMED_BLOCK("Main function");

  // Each of these functions call TIME_BLOCK().
  double res1 = func1();
  double res2 = func2();

  // For recursive functions, it is better to create a block 
  // and time outside of the function body. Otherwise, each 
  // recusrive call will create a Ticker object!!
  {
    TIME_NAMED_BLOCK("line " STR1(__LINE__));
    int r = fibonacci(45);
  }

    return 0;
}

Running this program gives on my machine the following output:

$ ./main
func1(line 21): 344.635ms
func2(line 33): 11.7728ms
line 56: 8e-05ms
Main function: 356.508ms

Conclusion

In the next part of this article, I will extend itemize so we can specify a starting and ending point for timing instead of relying on the block logic. I will also introduce a singleton class that will keep track of all timing points and thus, makes it easier to produce statistics like total and average execution times per functions. If you wish to use itimize please clone the complete code form my github repository.

Credits

Although I have been inspecting many projects on github in order to come up with this simple library, I drew most of my inspirations from this vmware gist.