Easily measure elapsed time

Question

I am trying to use time() to measure various points of my program.

What I don't understand is why the values in the before and after are the same? I understand this is not the best way to profile my program, I just want to see how long something take.

printf("**MyProgram::before time= %ld\n", time(NULL));

doSomthing();
doSomthingLong();

printf("**MyProgram::after time= %ld\n", time(NULL));

I have tried:

struct timeval diff, startTV, endTV;

gettimeofday(&startTV, NULL); 

doSomething();
doSomethingLong();

gettimeofday(&endTV, NULL); 

timersub(&endTV, &startTV, &diff);

printf("**time taken = %ld %ld\n", diff.tv_sec, diff.tv_usec);

How do I read a result of **time taken = 0 26339? Does that mean 26,339 nanoseconds = 26.3 msec?

What about **time taken = 4 45025, does that mean 4 seconds and 25 msec?

Solution 1

//***C++11 Style:***
#include <chrono>

std::chrono::steady_clock::time_point begin = std::chrono::steady_clock::now();
std::chrono::steady_clock::time_point end = std::chrono::steady_clock::now();

std::cout << "Time difference = " << std::chrono::duration_cast<std::chrono::microseconds>(end - begin).count() << "[µs]" << std::endl;
std::cout << "Time difference = " << std::chrono::duration_cast<std::chrono::nanoseconds> (end - begin).count() << "[ns]" << std::endl;

Solution 2

0 - Delta

Use a delta function to compute time differences:

auto start = std::chrono::steady_clock::now();
std::cout << "Elapsed(ms)=" << since(start).count() << std::endl;

since accepts any timepoint and produces any duration (milliseconds is the default). It is defined as:

template <
    class result_t   = std::chrono::milliseconds,
    class clock_t    = std::chrono::steady_clock,
    class duration_t = std::chrono::milliseconds
>
auto since(std::chrono::time_point<clock_t, duration_t> const& start)
{
    return std::chrono::duration_cast<result_t>(clock_t::now() - start);
}

Demo

1 - Timer

Use a timer based on std::chrono:

Timer clock; // Timer<milliseconds, steady_clock>

clock.tick();
/* code you want to measure */
clock.tock();

cout << "Run time = " << clock.duration().count() << " ms\n";

Demo

Timer is defined as:

template <class DT = std::chrono::milliseconds,
          class ClockT = std::chrono::steady_clock>
class Timer
{
    using timep_t = typename ClockT::time_point;
    timep_t _start = ClockT::now(), _end = {};

public:
    void tick() { 
        _end = timep_t{}; 
        _start = ClockT::now(); 
    }
    
    void tock() { _end = ClockT::now(); }
    
    template <class T = DT> 
    auto duration() const { 
        gsl_Expects(_end != timep_t{} && "toc before reporting"); 
        return std::chrono::duration_cast<T>(_end - _start); 
    }
};

As Howard Hinnant pointed out, we use a duration to remain in the chrono type-system and perform operations like averaging or comparisons (e.g. here this means using std::chrono::milliseconds). When we just do IO, we use the count() or ticks of a duration (e.g. here number of milliseconds).

2 - Instrumentation

Any callable (function, function object, lambda etc.) can be instrumented for benchmarking. Say you have a function F invokable with arguments arg1,arg2, this technique results in:

cout << "F runtime=" << measure<>::duration(F, arg1, arg2).count() << "ms";

Demo

measure is defined as:

template <class TimeT  = std::chrono::milliseconds
          class ClockT = std::chrono::steady_clock>
struct measure
{
    template<class F, class ...Args>
    static auto duration(F&& func, Args&&... args)
    {
        auto start = ClockT::now();
        std::invoke(std::forward<F>(func), std::forward<Args>(args)...);
        return std::chrono::duration_cast<TimeT>(ClockT::now()-start);
    }
};

As mentioned in (1), using the duration w/o .count() is most useful for clients that want to post-process a bunch of durations prior to I/O, e.g. average:

auto avg = (measure<>::duration(func) + measure<>::duration(func)) / 2;
std::cout << "Average run time " << avg.count() << " ms\n";

---

^{+This is why the forwarded function call.}

^{+The complete code can be found here}

^{+My attempt to build a benchmarking framework based on chrono is recorded here}

^{+Old demo}

Solution 3

As I can see from your question, it looks like you want to know the elapsed time after execution of some piece of code. I guess you would be comfortable to see the results in second(s). If so, try using difftime() function as shown below. Hope this solves your problem.

#include <time.h>
#include <stdio.h>

time_t start,end;
time (&start);
.
.
.
<your code>
.
.
.
time (&end);
double dif = difftime (end,start);
printf ("Elasped time is %.2lf seconds.", dif );

Solution 4

Windows only: (The Linux tag was added after I posted this answer)

You can use GetTickCount() to get the number of milliseconds that have elapsed since the system was started.

long int before = GetTickCount();

// Perform time-consuming operation

long int after = GetTickCount();

Solution 5

time(NULL) returns the number of seconds elapsed since 01/01/1970 at 00:00 (the Epoch). So the difference between the two values is the number of seconds your processing took.

int t0 = time(NULL);
doSomthing();
doSomthingLong();
int t1 = time(NULL);

printf ("time = %d secs\n", t1 - t0);

You can get finer results with getttimeofday(), which return the current time in seconds, as time() does and also in microseconds.

View more solutions

Comments

[hap497]

I am using it on linux. So I can't use the GetTickCount() function.

[CoreModule]

already never mind ;) Thanks for updating the tag of your post

[Matt Joiner]

I don't know why someone downvoted, but your answer isn't entirely correct. For starters it doesn't return the date time, and it won't always be different.

[Kev]

Whilst your answer is appreciated, we do prefer a pre-amble containing a brief description of the code. Thanks.

[utnapistim]

Nice; I have something similar in my code, but use a different interface to the class: I have a class (code_timer) that takes the start time (std::chrono::system_clock::now();) in the constructor, a method code_timer::ellapsed that measures the difference between a new now() call and the one in the constructor, and a code_timer::reset method that resets the start time to a new now() result. To measure the execution of a functor in my code, I use a free function, outside the class. This allows for measuring time from the construction of an object, to the finish of an asynch call.

[Nikos Athanasiou]

@utnapistim Thnx, I've asked a review on this code, you can check it here. If you have the time, there you could also elaborate a bit more on your design, it sounds great.

[Baum mit Augen]

Watch out for compiler optimization! I've tried something like this before and the compiler optimized the call to func away since it did not have side effects and the return value was not used.

[Nikos Athanasiou]

@BaummitAugen You misread the comments on that. It's when using inlined timer machinery (as in Edward's answer) that non observable behaviour gets optimized away. The function call placed as is won't be moved by the compiler.

[JonnyJD]

This is not the elapsed time, but the processor time.

[sodiumnitrate]

This always gives me integer seconds. Is that supposed to happen?

[Howard Hinnant]

<nitpick>: Don't escape out of the chrono system until you have to (avoid use of .count()). Let the client call .count() when forced to (say for I/O, which is indeed unfortunate). The client may want to post-process a bunch of durations prior to I/O (e.g. average) and that is best done within the chrono system.

[user1234567]

Thanks, it's cool! But: code from Update2 does not compile on VS2013 with auto return type of duration(..). I get error "C3551: expected a trailing return type". It works only if I replace auto with typename TimeT.

[user1234567]

also Update2 code doesn't compile when a function has default values of parameters, in case when such arguments are omitted in a call. Can anyone explain, why?

[Nikos Athanasiou]

@user3241228 1. VS2013 does not support auto return types (just trailing return types - it's a c++14 feature not available yet). 2. I believe this is the reason but I asked a q just to be sure

[Nikos Athanasiou]

@user3241228 Sorry, scratch point 2; this is the reason

[DeepDeadpool]

time will always only return seconds, so it can't be used for sub second measurements.

[Ruchir]

It works and gives the real time, not the CPU time. I tested it by placing SleepEx(5000,0) in place of //Perform time-consuming operation and difference of after and before was almost 5 sec.

[Andriy Tylychko]

why you didn't use high_resolution_clock instead of system_clock? I understand they can be the same on many systems, but I'd expect high_resolution_clock can be more precise on systems where they are not the same thing

[Andriy Tylychko]

When measuring performance we run the test multiple times to get rid of noise. Wouldn't it be more appropriate to use min in your example for duration function usage? not a big deal of course

[Nikos Athanasiou]

@AndyT Nice points. As you know high_resolution_clock may be a typedef to either system_clock or steady_clock. In the linked blog post, the timers "let" the user choose the clock type and use steady_clock as a default clock since it ticks at a uniform rate. To me this should be the default but a case should be made for "freedom of choice". Also therein I develop a "lab" environment for multiple experiment executions, so (to me) the noise removal should be done that way (in a more "in the box" fashion) ... alas that was too much to elaborate on in SO

[oliora]

Why not std::forward<F>(func)?

[Nikos Athanasiou]

@oliora It's the same thing. I prefer std::forward<decltype(func)>(func) because it can apply to arguments of generic lambdas (auto&& func) where F is not syntactically there and it's easy to abstract in a utility macro #define fw(arg) std::forward<decltype(arg)>(arg) which I do in my benchmark library (so it's a syntactic left over on which I don't elaborate much in the answer)

[oliora]

I would suggest to use a steady clock only. In my code I do it with using perf_clock = std::conditional< std::chrono::high_resolution_clock::is_steady, std::chrono::high_resolution_clock, std::chrono::steady_clock >::type; (you can see this much better formatted in my answer below)

[Nikos Athanasiou]

@oliora Yes, it's a typical type switch, I've seen it around a lot (I'll comment on your answer about this typeswitch). In my benchmarking library I give the user the freedom to choose which clock type she prefers. I believe this is the correct way to go (even though even there I default to steady_clock, check the benchmark class ... I'll edit this answer, just to write that)

[Nikos Athanasiou]

On this typeswitch : Typically high_resolution_clock is a typedef for either system_clock or steady_clock. So to trace that std::conditional if the is_steady part is true, then you pick the high_resolution_clock which is (a typedef to) the steady_clock. If it's false then you pick the steady_clock again. Just use steady_clock from the beginning ...

[oliora]

@nikos-athanasiou I completely agree with the comment from 5gon12eder that "typical" case is not required by the standard so some STL may be implemented in a different way. I prefer to have my code to be more generic and not related on implementation details.

[Nikos Athanasiou]

It's not required but explicitly stated in 20.12.7.3 : high_resolution_clock may be a synonym for system_clock or steady_clock. The reason is this : high_resolution_clock represents clocks with the shortest tick period, so whatever the implementation, it has two choices, being steady or not. Whatever choice we make, saying that the implementation will differ from the other two clocks is like saying we have a better implementation for a steady (or not) clock that we choose not to use (for steady or not clocks). Knowing how is good, knowing why is better

[oliora]

@nikos-athanasiou I would prefer to be 100% safe especially when this cost me no runtime overhead and undetectable compile time overhead. You may rely on "may" and assamptions if you want.

[Nikos Athanasiou]

au contraire my friend, it's you that relies on "may", but suit yourself. If you want to be 100% sure and keep writing this then, you should also find a way, for you and users of your code, to avoid non-portably mixing time points of different clocks (if ever this type switch acquires a meaning, it'll behave differently on different platforms). Have fun!

[oliora]

@NikosAthanasiou as you can see, no time_point escapes the function. The return type is a floating seconds duration which is clock independent. So no user code will depend on actual clock that chosen by the condition. To be honest I don't see any point to continue this discussion.

[SajithP]

So bad I cannot use <chrono> as it's not approved by google standards. stackoverflow.com/questions/33653326/…

[Antonello]

To run this you have to add the #include <chrono> directive and I would change the reporting time as: std::cout << "Time difference (sec) = " << (std::chrono::duration_cast<std::chrono::microseconds>(end - begin).count()) /1000000.0 <<std::endl; (and do not forget the C++11 flag when compiling: -std=c++11 )

[cylus]

@RestlessC0bra According to the docs on cppreference, "This clock is not related to wall clock time (for example, it can be time since last reboot), and is most suitable for measuring intervals."

[Admin]

@NikosAthanasiou If possible, with your permission, I would like to use some of your ideas for my project. Unfortunately, I could not find any licensing information in the github repository and/or your blog.

[Nikos Athanasiou]

@user1391279 As with all Stack Overflow code I believe it falls under creativecommons license

[Admin]

@NikosAthanasiou Thank you for your comment. However, I was referring to the code that I found through the links in your answer. Would it be acceptable for me to use it for non-commercial purposes? Was the code released under the terms of any particular license?

[Nikos Athanasiou]

@user1391279 A simple mention (even as a comment in the code) would do. Stay tuned though cause I'll be posting updates

[Admin]

@NikosAthanasiou Thank you for letting me know. It would be useful if you could provide licensing information for your repository/repositories. I believe that the default license is not open source (link).

[Axel Rietschin]

@Antonello - You should look more closely at std::chrono::duration_cast, and in particular at std::chrono::seconds if you want the duration to be returned in terms of seconds.

[rayryeng]

@AxelRietschin That would only return the time in seconds. Antonello's suggestion also provides fractional time (i.e. 2.15315 seconds as opposed to just 2 seconds).

[einpoklum]

With the second function (duration()) you can simplify the first function and avoid some code duplication: return duration(std::forward<F>(func), std::forward<Args>(args)...).count();

[sqp_125]

What data type is this?std::chrono::duration_cast<std::chrono::microseconds>(e‌​nd - begin).count()

[Stavros Avramidis]

How can this work with a function that has templates as arguments ?

[Stavros Avramidis]

Never mind I got it you need to specify the non-type argument, either with a typedef or a cast when passing it

[kelalaka]

One can find the types from chrono duration docs

[RobinAtTech]

@Nikos Athanasiou I have a class member function with no arguments and return type is void. Can somebody let me know how to use this mechanism?

[Howard Hinnant]

I like your print statement with the units. What would it take to port your code to gcc and clang? (wandbox.org)

[Admin]

@HowardHinnant: thanks for addressing, I updated the code for gcc and clang as well.

[zanbri]

@sqp_125 It seems to be std::chrono::microseconds::rep

[val is still with Monica]

In SDL there is a portable function doing the same thing: SDL_GetTicks(). It measures time since SDL initialization and not system startup.

[Lucas Sousa]

Seems the smartest way and it is very similar to Java. Btw, shouldn't this be stored in a long type?

[SubMachine]

this answer use full types instead of "auto" which make it easier to understand

[otto]

@sqp_125 long int

[If_You_Say_So]

How is std::invoke related here?

[Sneftel]

This is not a good approach. Because it uses a global variable by default, it’s not reentrant. An inner function using the same interface could screw up the timing of the outer interface.