Exploring C++11, part 1 (Time)

I was playing around with C++11 the other day – being inspired and all by the 2012 Going Native videocasts. So far I have only seen the keynote by Stroustrup but that was enough to get me inspired :)

Anyhow,.. I decided to put down some random pieces of code and thoughts that were running through my head in the past,. maybe a code snippet or two is useful to you as well?

The code snippets can also be found at: http://ideone.com/LA2FC

1. Time

OK, so with C++11 we get this whole nice feature to deal with time in different ways. Previously this was not cross-platform standardized and even thread unsafe for the ANSI functions. Time and time again (pun intended) we allways run into the task of measuring the time between two points,. and sometimes, just sometimes, it is nice to force a “wait/sleep” either for fun or for testing. This would be easy to do with C++11 but due to its very verbose syntax it can be confusing to get it right. Perhaps these snippets might help?

Check out in my artificial examples, like the silly_sleep_ms(…) and you will see what I mean

#include <iostream>
#include <chrono>
#include <thread>
void silly_sleep_ms(unsigned int ms)
{
using std::chrono::high_resolution_clock;
using std::chrono::milliseconds;
auto t0 = high_resolution_clock::now();
std::this_thread::sleep_for(milliseconds(ms));
auto t1 = high_resolution_clock::now();
milliseconds total_ms = std::chrono::duration_cast<milliseconds>(t1 - t0);

std::cout <<"this_thread_sleep (" << ms <<") milliseconds: "
<< total_ms.count() << "ms\n";
}

Running silly_sleep_ms(50) three times yield:
this_thread_sleep 50 milliseconds: 52ms
this_thread_sleep 50 milliseconds: 51ms
this_thread_sleep 50 milliseconds: 51ms

On my ancient PC (Intel Core 2-CPU 6400 @ 2.13GHz) running Windows7 it is usually slightly worse performance than when I boot up for Ubuntu. But on windows7 this seemed to be typical with a couple of milliseconds difference. No big deal, right?.

Of course repeating all the typedefs and template arguments all the time is kind of tedious. A simple StopWatch utility makes things easier,. so with an attempt at refactoring it.

namespace whatever // formatted for blog readability
{
  typedef std::chrono::high_resolution_clock clock;
  typedef std::chrono::microseconds microseconds;
  typedef std::chrono::milliseconds milliseconds;

  clock::time_point now(){return clock::now();}

  microseconds intervalUs(const clock::time_point& t1, const clock::time_point& t0)
 {
    return std::chrono::duration_cast<microseconds>(t1 - t0);
 }

  milliseconds intervalMs(const clock::time_point& t1,const clock::time_point& t0)
 {
    return std::chrono::duration_cast<milliseconds>(t1 - t0);
 }

class StopWatch
{
   clock::time_point start_;
 public:
   StopWatch() : start_(clock::now()){}
   clock::time_point restart() { start_ = clock::now(); return start_;}
   microseconds elapsedUs()    { return intervalUs(now(), start_);}
   milliseconds elapsedMs()    { return intervalMs(now(), start_);}
};

} // whatever

This cuts down the verbose syntax needed for the silly_sleep_ms(…) function

void silly_sleep_ms(unsigned int ms)
{
 using namespace whatever;
   StopWatch measure;
   std::this_thread::sleep_for(g2::milliseconds(ms));

   std::cout <<" 2this_thread_sleep (" << ms <<") milliseconds: "
             << measure.elapsedMs().count() << "ms\n";
}

Running it instead for microseconds (us) the overhead is proportionally much higher (not as bad if running on Linux).

void silly_sleep_us(unsigned int us)
{
 using namespace whatever;
    StopWatch measure;
    std::this_thread::sleep_for(microseconds(us));

    std::cout <<" this_thread_sleep (" << us <<") microseconds: "
              << measure.elapsedUs().count() << "us\n";
}

Running silly_sleep_us(50) three times yield:
this_thread_sleep (50) microseconds: 1792us
this_thread_sleep (50) microseconds: 1151us
this_thread_sleep (50) microseconds: 1921us

Whoa. The overhead just went from some meager 4% overhead to 38 times the expected time and actually getting closer to 2 milliseconds for some calls. Repeating this even more times just confirms that this result was not unusual but what is to be expected!

Being Windows rusty and all and doing this a late night last year together with packing (for paternal leave in the USA) made my sleepy brain more befuddled than usual.

Mental note to self:
Do not try to do snippet programming examples and pack at the same time

For some reason I actually thought I had seen a bug since I tested the same code on Linux and the overhead was not nearly as high. In a temporary state of confusion I emailed Anthony Williams (creator of just::thread and the chrono library that I use). He very nicely replied to my email explaining that
… the smallest timer tick granularity on Windows is 1 millisecond, so it is hard to sleep for less than that, and the standard says that sleep_for sleeps for *at least* the specified time.”

Duh! Reading it on the plane made me feel more than a little silly. Of course. Anthony was even so nice as to suggest a snipped for shorter sleep. Using this_thread::yield in a loop with the high_resolution_clock would get better result. The tradeoff being that the operation on Windows would in itself be a time consuming operation,. maybe even yielding as bad result as before.

template<typename Duration>
void short_sleep(Duration d) // thanks to Anthony Williams for the suggestion of short_sleep
{
   clock::time_point const start=clock::now(), stop=start+d;
   do{
       std::this_thread::yield();
     } while(clock::now()<stop);
}

// ... updated for using the new sleep utility
void silly_improved_short_sleep_us(unsigned int us)
{
  using namespace whatever;
  StopWatch measure;
  short_sleep(microseconds(us));
  auto elapsed_us = measure.elapsedUs().count();

  std::cout <<"this_thread_sleep (" << us <<") microseconds: "
            << elapsed_us << "us\n";
}

Running a modified version of the silly_sleep_us, using the short_sleep gave for three tries
this_thread_sleep (50) microseconds: 51us
this_thread_sleep (50) microseconds: 295us
this_thread_sleep (50) microseconds: 51us

Running it even more times show that the result is more inconsistent then what I first expected. Just like Anthony suggested using the high_resolution_clock is sometimes as fickle as the original this_thread_sleep.

So way better than before but still shaky. Shaky is still better than always way out there I suppose. But what is better is naturally the improved syntax with or without the StopWatch. Instead of writing very verbose like as shown before:

typedef std::chrono::high_resolution_clock clock;
typedef std::chrono::milliseconds milliseconds;

  clock::time_point t0 = clock::now();
  // ... some operation to time estimate
  clock::time_point t1 = clock::now();

  milliseconds total_ms = std::chrono::duration_cast<milliseconds>(t1 - t0);

All you need to do is to use a StopWatch or similar grouped functionality and you cut it down to

StopWatch measure;
// ... some operation to time estimate

auto elapsed_us = measure.elapsedUs().count();

Or just using the namespace whatever as used above

clock::time_point t0 = now();
// ... some operation to time estimate
clock::time_point t1 = now();

auto elapsed_ms = intervalMs(t1, t0).count();

There you go, with C++11 it is a snap to pin down elapsed time no matter if you are on Windows or on Linux. Unfortunately we have this verbose template syntax that will scare away many newcomers and till it gets simpler I suggest you to use something like the StopWatch or the whatever functionality above.

About these ads

About kjellkod

Software Engineer by trade, (former?) Martial Artist and Champion by strong will and small skill... and a Swede by nationality :)
This entry was posted in C++. Bookmark the permalink.

8 Responses to Exploring C++11, part 1 (Time)

  1. kjellkod says:

    Cut and paste of this code (+ some extras) to ideone.com (online compiler) http://ideone.com/LA2FC
    Unfortunately ideone.com does not yet support std::thread so it won’t compile online but this is basically the code I used above

  2. idoin says:

    I most strongly advise any person interested in such problems to read line after line Chapter 5, sections 5.6 and 5.7 in The C++ Standard Library, A Tutorial and Reference, SECOND EDITION, by Nicolaï Josuttis.

  3. kjellkod says:

    @idoin, that is a great suggestion. As it turns out you do not have to buy the book for those two chapters (although you probably should) since he has given out the chapters 5.6 and 5.7 Clock and Timers for free. http://www.informit.com/articles/article.aspx?p=1881386&seqNum=2

    So, while I am waiting for the book to arrive (thanks for the suggestion idoin) I have at least read through 5.7 Clock and Timers. Apart from one important area I think the chapter is a good read and explains a lot in the area of C++11 Time.

    I was disappointed however when I noticed Josuttis’s use of the old, thread unsafe and race hazard C-API with ctime and localtime without even mentioning it. A word of warning would be the least to expect from an expert of his magnitude ….

  4. Pingback: Exploring C++11, part 2 (localtime and time again) | Kjellkod's Blog

  5. Tama McGlinn says:

    Thanks for your post, it was very clear and to the point.
    However, I had two problems using your first snippit:
    - ‘typedef std::chrono::high_resolution_clock clock’ redeclared as different kind of symbol
    - ‘std::this_thread’ has not been declared

    I solved the first problem by changing typedefs to;
    using std::chrono::high_resolution_clock;
    using std::chrono::milliseconds;
    I feel this is better anyway. The second statement actually lets you use milliseconds just as before, and the first only makes the clock type slightly longer. I think it is clearer this way, because a novice could read that part of my code, copy paste “high_resolution_clock” into google and find out what it is.

    The second problem is the omission of:
    #include

    I hope you will integrate this to improve the snippit.

    • Tama McGlinn says:

      woops. What’s missing is
      #include

      • Tama McGlinn says:

        Ah. It was not my mistake. Your blog cannot handle the less than or greater than signs. Anyway, just include thread

    • kjellkod says:

      Thanks for the help Tama.

      I have updated the example and am using auto to make it a little bit easier to read
      #include
      #include
      #include
      void silly_sleep_ms(unsigned int ms)
      {
      using std::chrono::high_resolution_clock;
      using std::chrono::milliseconds;
      auto t0 = high_resolution_clock::now();
      std::this_thread::sleep_for(milliseconds(ms));
      auto t1 = high_resolution_clock::now();
      milliseconds total_ms = std::chrono::duration_cast(t1 - t0);

      std::cout <<"this_thread_sleep (" << ms <<") milliseconds: "
      << total_ms.count() << "ms\n";
      }

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s