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?

Answer 1

#include<time.h> // for clock
#include<math.h> // for fmod
#include<cstdlib> //for system
#include <stdio.h> //for delay

using namespace std;

int main()
{


   clock_t t1,t2;

   t1=clock(); // first time capture

   // Now your time spanning loop or code goes here
   // i am first trying to display time elapsed every time loop runs

   int ddays=0; // d prefix is just to say that this variable will be used for display
   int dhh=0;
   int dmm=0;
   int dss=0;

   int loopcount = 1000 ; // just for demo your loop will be different of course

   for(float count=1;count<loopcount;count++)
   {

     t2=clock(); // we get the time now

     float difference= (((float)t2)-((float)t1)); // gives the time elapsed since t1 in milliseconds

    // now get the time elapsed in seconds

    float seconds = difference/1000; // float value of seconds
    if (seconds<(60*60*24)) // a day is not over
    {
        dss = fmod(seconds,60); // the remainder is seconds to be displayed
        float minutes= seconds/60;  // the total minutes in float
        dmm= fmod(minutes,60);  // the remainder are minutes to be displayed
        float hours= minutes/60; // the total hours in float
        dhh= hours;  // the hours to be displayed
        ddays=0;
    }
    else // we have reached the counting of days
    {
        float days = seconds/(24*60*60);
        ddays = (int)(days);
        float minutes= seconds/60;  // the total minutes in float
        dmm= fmod(minutes,60);  // the rmainder are minutes to be displayed
        float hours= minutes/60; // the total hours in float
        dhh= fmod (hours,24);  // the hours to be displayed

    }

    cout<<"Count Is : "<<count<<"Time Elapsed : "<<ddays<<" Days "<<dhh<<" hrs "<<dmm<<" mins "<<dss<<" secs";


    // the actual working code here,I have just put a delay function
    delay(1000);
    system("cls");

 } // end for loop

}// end of main 

Answer 2

C++ std::chrono has a clear benefit of being cross-platform. However, it also introduces a significant overhead compared to POSIX clock_gettime(). On my Linux box all std::chrono::xxx_clock::now() flavors perform roughly the same:

std::chrono::system_clock::now()
std::chrono::steady_clock::now()
std::chrono::high_resolution_clock::now()

Though POSIX clock_gettime(CLOCK_MONOTONIC, &time) should be same as steady_clock::now() but it is more than x3 times faster!

Here is my test, for completeness.

#include <stdio.h>
#include <chrono>
#include <ctime>

void print_timediff(const char* prefix, const struct timespec& start, const 
struct timespec& end)
{
    double milliseconds = (end.tv_nsec - start.tv_nsec) / 1e6 + (end.tv_sec - start.tv_sec) * 1e3;
    printf("%s: %lf milliseconds\n", prefix, milliseconds);
}

int main()
{
    int i, n = 1000000;
    struct timespec start, end;

    // Test stopwatch
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i) {
        struct timespec dummy;
        clock_gettime(CLOCK_MONOTONIC, &dummy);
    }
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("clock_gettime", start, end);

    // Test chrono system_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::system_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::system_clock::now", start, end);

    // Test chrono steady_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::steady_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::steady_clock::now", start, end);

    // Test chrono high_resolution_clock
    clock_gettime(CLOCK_MONOTONIC, &start);
    for (i = 0; i < n; ++i)
        auto dummy = std::chrono::high_resolution_clock::now();
    clock_gettime(CLOCK_MONOTONIC, &end);
    print_timediff("chrono::high_resolution_clock::now", start, end);

    return 0;
}

And this is the output I get when compiled with gcc7.2 -O3:

clock_gettime: 24.484926 milliseconds
chrono::system_clock::now: 85.142108 milliseconds
chrono::steady_clock::now: 87.295347 milliseconds
chrono::high_resolution_clock::now: 84.437838 milliseconds

Answer 3

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.

Answer 4

I usually use the following:

#include <chrono>
#include <type_traits>

using perf_clock = std::conditional<
    std::chrono::high_resolution_clock::is_steady,
    std::chrono::high_resolution_clock,
    std::chrono::steady_clock
>::type;

using floating_seconds = std::chrono::duration<double>;

template<class F, class... Args>
floating_seconds run_test(Func&& func, Args&&... args)
{
   const auto t0 = perf_clock::now();
   std::forward<Func>(func)(std::forward<Args>(args)...);
   return floating_seconds(perf_clock::now() - t0);
} 

It's the same as @nikos-athanasiou proposed except that I avoid using of a non-steady clock and use floating number of seconds as a duration.

Answer 5

On linux, clock_gettime() is one of the good choices. You must link real time library(-lrt).

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

#define BILLION  1000000000L;

int main( int argc, char **argv )
  {
    struct timespec start, stop;
    double accum;

    if( clock_gettime( CLOCK_REALTIME, &start) == -1 ) {
      perror( "clock gettime" );
      exit( EXIT_FAILURE );
    }

    system( argv[1] );

    if( clock_gettime( CLOCK_REALTIME, &stop) == -1 ) {
      perror( "clock gettime" );
      exit( EXIT_FAILURE );
    }

    accum = ( stop.tv_sec - start.tv_sec )
          + ( stop.tv_nsec - start.tv_nsec )
            / BILLION;
    printf( "%lf\n", accum );
    return( EXIT_SUCCESS );
  }

Answer 6

The values printed by your second program are seconds, and microseconds.

0 26339 = 0.026'339 s =   26339 µs
4 45025 = 4.045'025 s = 4045025 µs