views:

831

answers:

4

Some loading routines in my program takes to long to complete. I want a quick small snippet for checking how long a function took to execute. By small I mean "preferably without 3rd party libraries".

Maybe something as simple as taking the system time?

start = current_system_time()
load_something()
delta = current_system_time()-start
log_debug("load took "+delta)

Edit: Target OS in question is Windows.

+2  A: 

This is a quick and dirty way to time a block of C/C++ code. You need to #include <sys/time.h>, which should be a standard header...

struct timeval start, end;
gettimeofday(&start, NULL);
// benchmark code
gettimeofday(&end, NULL);
long long time =   (end.tv_sec * (unsigned int)1e6 +   end.tv_usec) - 
                 (start.tv_sec * (unsigned int)1e6 + start.tv_usec);

This should give 1-2µs resolution on modern Linux systems (what OS are you using?), which means that it's not well suited to learning much for items taking of <10µs. However, you don't seem to be in that situation.

Update: Based on specified OS... Windows implementation of gettimeofday()

jvasak
+4  A: 

Your answer: Yes

Caveat: That WON'T work in multihtreaded code or multiple core machines, you need a robust wall-clock timer. So I recommend you use omp's wallclock. OMP is included with VC and GCC, and most compilers and its a standard you don't need to worry about disappearing

#include <omp.h>

// Starting the time measurement
double start = omp_get_wtime();
// Computations to be measured
...
// Measuring the elapsed time
double end = omp_get_wtime();
// Time calculation (in seconds)
Robert Gould
+2  A: 
#if defined(_WIN32) || defined(__WIN32__) || defined(WIN32)

namespace win32 {
    #include <windows.h>
}

class timer
{
    win32::LARGE_INTEGER start_time_;
public:
    timer() { QueryPerformanceCounter( &start_time_ ); }
    void   restart() { QueryPerformanceCounter( &start_time_ ); }
    double elapsed() const
    {
        win32::LARGE_INTEGER end_time, frequency;
        QueryPerformanceCounter( &end_time );
        QueryPerformanceFrequency( &frequency );
        return double( end_time.QuadPart - start_time_.QuadPart )
            / frequency.QuadPart;
    }
};

#else

#include <ctime>

class timer
{
    clock_t _start_time;
public:
    timer() { _start_time = clock(); }
    void   restart() { _start_time = clock(); }
    double elapsed() const
    {
        return double(clock() - _start_time) / CLOCKS_PER_SEC;
    }
};

#endif

template< typename Func >
double measure_time( Func f )
{
    timer t;
    f();
    return t.elapsed();
}
Vadim Ferderer
A: 

I use a class for this, its designed to measure the time taken to execute a function and write that to a uth-16le text file (I need to update this to use a new class i made for this... but nm).

Create a new instance at the top of a function, e.g. jProfiler(L"myFunction") and the cleanup at the end of the function will do the rest, if you want to be sure though new and delete it yourself. Its a bit overkill for a small test, but might help:

// start header

/* jProfiler class by Semi Essessi
 *
 * (class description goes here)
 *
 */

#ifndef __JPROFILER_H
#define __JPROFILER_H

#include <stdio.h>
#include <windows.h>

class jProfiler
{
private:
    wchar_t*   str;
    LARGE_INTEGER start;
    LARGE_INTEGER tps;
    LARGE_INTEGER buf;

    static FILE* f;
    static int  instCount;

    static void  Initialise();
    static void  Shutdown();
public:
    jProfiler(const wchar_t* msg);
    ~jProfiler();
};

#endif

// - end header

/* jProfiler class by Semi Essessi
 *
 * (class description goes here)
 *
 */

#include "jProfiler.h"

#include <windows.h>

FILE* jProfiler::f = 0;
int jProfiler::instCount = 0;

jProfiler::jProfiler(const wchar_t* msg)
{
    // constructor code for menuVar
    int i = (int)wcslen(msg)+1;
    str = new wchar_t[i];
    memcpy(str, msg, sizeof(wchar_t)*i);
    str[i-1] =  0;

    QueryPerformanceFrequency(&tps);
    QueryPerformanceCounter(&start);

    instCount++;
    Initialise();
}

jProfiler::~jProfiler()
{
    // destructor code for menuVar
    QueryPerformanceCounter(&buf);
    // work out change in time
    double dt=((float)buf.QuadPart - (float)start.QuadPart)/(float)tps.QuadPart;
    fwprintf(f, L"%s : %.20f\r\n", str, dt);

    if(str) delete[] str;
    instCount--;
    Shutdown();
}

void jProfiler::Initialise()
{
    if(!f)
    {
     f = _wfopen(L"profilerlog.txt", L"wb");
     unsigned short a = 0xFEFF;
     fwrite(&a, sizeof(unsigned short), 1, f);
    }
}

void jProfiler::Shutdown()
{
    if(instCount==0) if(f) fclose(f);
}
jheriko