Why is the execution time 0ms?

Pages: 123
Finally a question for @Chervil:
What do you want to say with your last posted message? :)
Have you found a way to calculate the execution time with cpp in Windows?

Yes. That is what I am saying. The Windows function GetProcessTimes() does that.
https://msdn.microsoft.com/en-us/library/windows/desktop/ms683223(v=vs.85).aspx

The code I posted was a quick attempt to simplify the process of calling that raw function.

 
    CPUTimer cputimer; // defines the timer object and sets the start time. 

Put the processing to be timed here.

 
    cputimer.stop(); // sets the end time 


 
    cputimer.CPU() // returns the user-mode processing time in seconds, as a double 


There is another figure for the kernel-mode processing time. I wasn't sure what to do with this, its value is usually zero but some websites say it should be added to the user-mode processing time to give a total.
Using boost::timer::auto_cpu_timer:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
#include <iostream>
#include <ctime>
#include <chrono>
#include <thread>
#include <boost/timer/timer.hpp>

volatile long long v = 0 ;

int main()
{
    constexpr int N = 1024*1024*128 ;

    using namespace std::chrono ;
    const auto timepoint_start = steady_clock::now() ;
    const auto clock_start = std::clock() ;

    {
        // auto_timer: destructor prints elapsed time statistics
        // http://www.boost.org/doc/libs/1_65_0/libs/timer/doc/cpu_timers.html#Class-auto_cpu_timer
        boost::timer::auto_cpu_timer auto_timer( 3, " boost:  processor %t seconds\n"
                                                    " boost: wall clock %w seconds\n"
                                                    " boost:  CPU usage %p%\n\n" ) ;

        for( int i=0 ; i < N ; ++i ) v += 1 ;

        // simulate the processor not being available to our program for two seconds
        // for example, this could happer if our timeslice expired after the first loop
        //                                and there is contention for processor time
        std::this_thread::sleep_for( seconds(2) ) ;

        for( int i=0 ; i < N ; ++i ) v += 1 ;
    }

    const auto clock_end = std::clock() ;
    const auto timepoint_end = steady_clock::now() ;

    std::cout << " clock:  processor " << double(clock_end-clock_start) / CLOCKS_PER_SEC << " seconds.\n" ;
    std::cout << "chrono: wall clock " << duration_cast<milliseconds>(timepoint_end-timepoint_start).count() / 1000.0 << " seconds.\n" ;
}

 boost:  processor 0.710 seconds
 boost: wall clock 2.709 seconds
 boost:  CPU usage 26.2%

 clock:  processor 0.709087 seconds.
chrono: wall clock 2.709 seconds.

http://coliru.stacked-crooked.com/a/cde5b4e87887f9fb
@puertas12

Specifically for my factiorial implementation:
.....
There is no way to measure the execution time with std::clock() because this execution takes less than one clock tick :(

No - put your factorial calculation in a loop to do it, say, 5000 (or whatever) times with the clock starting and ending outside that loop. When you have got the time taken to do it 5000 times (enough to make it a decent number of clock ticks) ... then just divide by 5000 to get the time to do it once.

Keep any input/output outside the timing loop as they are intrinsically slower than numerical calculations (and might be buffered).



I'm very confused by all these clocks! Am I right in thinking that:

(a) std::clock() is supposed to measure the time actually spent by the processor;
chrono::steady_clock() is supposed to measure the time on my office wall;

(b) if all was correctly implemented then std::clock() is a better way of timing numerical processes and chrono::steady_clock() is a better way of timing a 100m race;

(c) Microsoft has deliberately chosen not to correctly implement std::clock(), but @Chervil's CPUtimer class, or Boost's cpu timer would do the job properly;

(d) I might be better going out and buying a sun-dial.

Or (as is highly possible) am I completely wrong?





Last edited on
closed account (48T7M4Gy)
@lastchance

std::clock measures processor time in clock ticks. http://www.cplusplus.com/reference/ctime/clock/ the trouble is it doesn't have the resolution to time a small/fast program. This one that OP has takes about 1-3 clock ticks on the cpp shell and/or my machine. So when you do the sums it comes out as zero processor time. The conversion factor of CLOCKS_PER_SECOND and 1000 'destroy any value'.

That's why I went to <chrono> because even though it's measuring wall clock time it has a higher resolution. (I'm not trying to sell <chrono>)

The added problem is there are guaranteed to be other processes using up processor time 'simultaneously' so the timings with <chrono> ar guaranteed to be exaggerated. But for a small program that gets knocked over quickly it doesn't matter because the only non boost alternative is to use <ctime> which doesn't have the resolution.

The highlight of the show is using sleep(). It doesn't use any significant processor time so all it does is bulk out any sort of timing (other than processor time).

Because this OP effort is a short program that's why <chrono> gets the same result once the sleep line is discarded. The idea to use sleep is OK to show how times differ but it's actually not all that realistic. What would be realistic is where a longer running program is being timed and where other processes are competing for the processor resource. <chrono> doesn't differentiate.

My timing purpose is to look at relative differences between alternatives and the external conditions are conveniently for me about the same, so <chrono> does the job for even though it's a wall clock. And is better than a sundial because I can work at night. Perhaps not for others - but there you go. :)
Hi @Kemort,

That's why I went to <chrono> because even though it's measuring wall clock time it has a higher resolution.
....
My timing purpose is to look at relative differences between alternatives and the external conditions are conveniently for me about the same


Yes, I agree - for the reasons I have taken the liberty of putting in bold above. Usually, we aren't interested in the precise times taken by two approaches, but which is the faster and by how much. Most of the figures where there is a distinction show the processor time being consistently about a quarter of the wall time ...

... which brings me to my (hopefully) final grouse: what on earth is that processor doing taking 75% of its time away from dealing with my program?! Maybe that's why Microsoft doesn't want us to have too accurate a std::clock().
Last edited on
closed account (48T7M4Gy)
hi @lastchance

Maybe there's a smart way via threads and core allocation, way beyond me, that enables your program to totally commandeer a (timeable) processor resource. But as we agree it doesn't get you much.

Again, not hard sell, but this video might be useful as far as <chrono> is concerned if you haven't seen it before. There's an interesting snippet on timing very fast things in the opening minutes :)

https://www.youtube.com/watch?v=P32hvk8b13M



Last edited on
lastchance wrote:
Yes, I agree - for the reasons I have taken the liberty of putting in bold above. Usually, we aren't interested in the precise times taken by two approaches, but which is the faster and by how much. Most of the figures where there is a distinction show the processor time being consistently about a quarter of the wall time ...

... which brings me to my (hopefully) final grouse: what on earth is that processor doing taking 75% of its time away from dealing with my program?! Maybe that's why Microsoft doesn't want us to have too accurate a std::clock().

Maybe it depends on what sort of program it is that you are timing. Some tasks are intensively heavy on CPU processing usage, others may do a lot of I/O and less processing. It may also depend on what else is running on the machine.

In some of the tests I've done, for example using a very inefficient recursive fibonacci function show processor and wall clock timings almost the same.

On a Windows system you can find out where the system is allocating CPU resources between different tasks using Sysinternals Process Explorer. Useful too for looking in detail at an individual process.
https://docs.microsoft.com/en-gb/sysinternals/downloads/process-explorer
> (a) std::clock() is supposed to measure the time actually spent by the processor;
> chrono::steady_clock() is supposed to measure the time on my office wall;

Yes.


> (b) if all was correctly implemented then std::clock() is a better way of timing numerical processes

Yes, if the purely numerical operation is single-threaded.
If there are multiple concurrent threads of execution, both measures would be of interest.


> and chrono::steady_clock() is a better way of timing a 100m race;

Or a process that is primarily i/o bound.


> (c) Microsoft has deliberately chosen not to correctly implement std::clock(),
> but @Chervil's CPUtimer class, or Boost's cpu timer would do the job properly;

Yes.


> (d) I might be better going out and buying a sun-dial.

The resolution of std::clock() is usually good enough. POSIX specifies that CLOCKS_PER_SEC == 1'000'000;
though the the actual resolution provided by implementations can be lower than this.
In a typical Linux implementation std::clock() does appear to tick one million times a second.
http://coliru.stacked-crooked.com/a/a23191c1a9e4b576

If higher precision is required, place the code to be timed in a loop that executes several times (say, a thousand times) and then compute the average.
closed account (48T7M4Gy)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
#include <iostream>
#include <ctime>
#include <iomanip>

#include "stopwatch.h"

using namespace std;

int main() {
    double fac = 0, tmp1;
    double duration;
    
    cout << "fac              Iterations      Av Exe Tm  Av S/watch Tm\n";
    Stopwatch sw;
    
    for(int limit = 1; limit <= 10000000; limit *= 10)
    {
        sw.reset();
        clock_t c_start = clock();
        
        for(int i = 0; i < limit; ++i)
        {
            fac =100;
            
            tmp1 = fac-1;
            
            while (tmp1>0){
                fac*=tmp1;
                tmp1--;
            }
        }
        clock_t c_end=clock();
        
        duration= 1000.0*(c_end - c_start) / CLOCKS_PER_SEC;
        
        
        cout
        << setw(10) << fac
        << setw(15) << limit
        << setw(15) << duration/limit
        <<setw(15)<< sw.getTime()/limit
        << '\n';
    }
}


fac              Iterations      Av Exe Tm  Av S/watch Tm
9.33262e+157              1          0.002          18832
9.33262e+157             10         0.0003            811
9.33262e+157            100         0.0003            344
9.33262e+157           1000       0.000304            314
9.33262e+157          10000      0.0002883            290
9.33262e+157         100000     0.00030632            306
9.33262e+157        1000000    0.000303465            304
9.33262e+157       10000000    0.000291497            291
Program ended with exit code: 0
closed account (48T7M4Gy)
It's probably flogging a dead horse but timings are interesting.

Using a 'combined' Stopwatch and a processor load routine the relative timings between the two functions become clearer. With the large iterations these times become very sensitive to other uses the machine is put to but the similarity between the two remains about the same.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
#include <chrono>
#include <ctime>

using namespace std::chrono;

class Stopwatch
{
private:
    steady_clock::time_point start_chrono_clock;
    clock_t start_ctime_clock;
public:
    Stopwatch(){
        reset();
    }
    
    ~Stopwatch(){}
    
    // Start the clocks
    void reset(){
        start_chrono_clock = steady_clock::now();
        start_ctime_clock = clock();
    }
    
    // Read time elapsed in nanoseconds
    int64_t getTime_chrono(){
        return (steady_clock::now() - start_chrono_clock).count();
    }
    
    // Read time elapsed in milliseconds
    double getTime_ctime(){
        return 1000.0 * (clock() - start_ctime_clock)/CLOCKS_PER_SEC;
    }
};



1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
#include <iostream>
#include <ctime>
#include <iomanip>

#include <cmath>

#include "stopwatch.h"

int main() {
    double fac = 0, tmp1;
    
    std::cout
    << "fac              Iterations      Av ctime       Av chrono\n"
    << "                                (Times are in milliseconds)\n";
    
    Stopwatch sw;
    
    for(int limit = 1; limit <= 10000000; limit *= 10)
    {
        sw.reset();
        
        for(int i = 0; i < limit; ++i)
        {
            fac = 100;
            
            tmp1 = fac-1;
            while (tmp1>0){
                fac*=tmp1;
                tmp1--;
            }
            
            // PROVIDE SOME PROCESSOR LOAD
            for(int i = 0; i < 1000; i++)
                double x = sin(i) + cos(i);
            
        }
        
        std::cout
        << std::scientific << std::setprecision(5)
        << std::setw(10) << fac
        
        << std::fixed << std::setprecision(7)
        << std::setw(15) << limit
        << std::setw(15) << sw.getTime_ctime()/limit
        << std::setw(15) << sw.getTime_chrono()/limit/1000000.0
        << '\n';
    }
}



fac              Iterations      Av ctime       Av chrono
                                (Times are in milliseconds)
9.33262e+157              1      0.0850000      0.0891060
9.33262e+157             10      0.0468000      0.0491970
9.33262e+157            100      0.0416400      0.0417340
9.33262e+157           1000      0.0419580      0.0422120
9.33262e+157          10000      0.0423668      0.0425300
9.33262e+157         100000      0.0395159      0.0395450
9.33262e+157        1000000      0.0397168      0.0397410
9.33262e+157       10000000      0.0401500      0.0401670
Program ended with exit code: 0
Hi all :)!

Thank you for your answers.

I would like to play with the boost CPU timers and I had a look at the website suggested by JLBorges:
http://www.boost.org/doc/libs/1_65_0/libs/timer/doc/cpu_timers.html
However I haven't seen an entry where download the binaries to set up them.
@JLBorges Where have you downloaded them?
The Getting Started guide link seems also broken.

According with what kemort said:
So when you do the sums it comes out as zero processor time. The conversion factor of CLOCKS_PER_SECOND and 1000 'destroy any value'

This sounds logical but what I had experienced is more what lastchance said:
If it's less than one clock interval then the discrete result will be 0


For the moment I don't want to mess up with the <chrono> solution because preferably I would like to code smth I can implement using C++98.

Finally I decided to iterate the execution in a huge loop and I started to obtain execution time results different than 0:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
#include <iostream>

using namespace std;

//Prototypes
double calculoFactorialRecursividad(double, const double);

//Global variables
int loop_it=10000000;


int main() {
	double fac,fac1, tmp1, tmp2;
	double duration;

	fac=100;
	fac1=fac;

	tmp1 = fac-1;
	tmp2 = tmp1;

	cout<< "Fac iterative code" <<endl;

	clock_t c_start = clock();

	for (int i=0; i<loop_it; i++){
		while (tmp1>0){
			fac*=tmp1;
			tmp1--;
			//cout << " #####fac: " <<fac;
		}
	}

	clock_t c_end=clock();

	duration= c_end-c_start;
	cout<< "Factorial value: " <<fac <<endl;
	cout.precision(4);
	cout.setf(ios::fixed, ios::floatfield);
	cout<<"Execution time: "<<(1000.0*duration)/(loop_it*CLOCKS_PER_SEC)<< "ms"<<endl;

	cout<<endl;
	cout<< "Fac recursively code" <<endl;

	clock_t time2 =clock();

	for (int i=0; i<loop_it; i++){
		while (tmp2>0){
			fac1 = calculoFactorialRecursividad(fac1,tmp2);
			tmp2--;
		}
	}

	duration = (clock() - time2); // tiempo de ejecucion en ms

	cout.setf(ios::scientific, ios::floatfield);
	cout<< "Factorial value: " <<fac <<endl;
	cout.setf(ios::fixed, ios::floatfield);

	cout<< "Execution time: " <<(1000.0*duration)/(loop_it*CLOCKS_PER_SEC) <<"ms" <<endl;

	return 0;
}


double calculoFactorialRecursividad(double fac1, const double tmp2){
	fac1*=tmp2;
	//cout<< " #####fac1: " <<fac1;
	return fac1;
}



However the results I obtain are not reliable i.e: change every time:

First execution:
Fac iterative code
Factorial value: 9.33262e+157
Execution time: 0.0304ms

Fac recursively code
Factorial value: 9.3326e+157
Execution time: 0.0380ms

Second execution:
Fac iterative code
Factorial value: 9.33262e+157
Execution time: 0.0836ms

Fac recursively code
Factorial value: 9.3326e+157
Execution time: 0.0836ms

Third execution:
Fac iterative code
Factorial value: 9.33262e+157
Execution time: 0.0912ms

Fac recursively code
Factorial value: 9.3326e+157
Execution time: 0.0760ms


Furthermore I've been told that iterative code should execute faster than recursively code. Why is this not confirmed in my code? Why do my execution time changes every time?

@kemort: Do you experience the same problem in your examples?
Last edited on
closed account (48T7M4Gy)
@puertas12

Running your program 10 times I get the following ctime timings which reflects the variability in timings clearly.

Run  0 Iter: 9.33262e+157    16.902 Rec: 9.33262e+157    17.828
Run  1 Iter: 9.33262e+157    15.731 Rec: 9.33262e+157    15.919
Run  2 Iter: 9.33262e+157     17.17 Rec: 9.33262e+157    18.509
Run  3 Iter: 9.33262e+157    16.079 Rec: 9.33262e+157    15.605
Run  4 Iter: 9.33262e+157    17.476 Rec: 9.33262e+157    17.671
Run  5 Iter: 9.33262e+157     15.76 Rec: 9.33262e+157    17.053
Run  6 Iter: 9.33262e+157    16.006 Rec: 9.33262e+157    15.327
Run  7 Iter: 9.33262e+157    15.215 Rec: 9.33262e+157    16.709
Run  8 Iter: 9.33262e+157    15.881 Rec: 9.33262e+157    15.877
Run  9 Iter: 9.33262e+157    15.215 Rec: 9.33262e+157    15.501
Program ended with exit code: 0


As was already mentioned the processor is being used by many and varied (system at least) processes at the same time so there is going to be variation.

I wouldn't conclude from these clock timings that there is any significant difference between the two methods of calculation you have devised. And, keep in mind that modelling the algorithms mathematically is often a better way of determining the relative efficiency of options.

(BTW, and again I'm not selling <chrono>, the timings there are about the same)



> However the results I obtain are not reliable i.e: change every time
> Why do my execution time changes every time?

If the time that we are trying to measure is not an integral multiple of the period between clock ticks, there would me measurement errors. (Note that the tick interval can be larger than what is indicated by CLOCKS_PER_SEC).

For instance, if the time taken is between two and three tick intervals, this may be the result:
                           tick                  tick                  tick                  tick
                            |                     |                     |                     |                     |
run 1: three clock ticks    |                 <---|---------------------|---------------------|---->                |                     |
                            |                     |                     |                     |                     |
                            |                     |                     |                     |                     |
run 2: two clock ticks      |        <------------|---------------------|---------------->    |                     |                     |
                            |                     |                     |                     |                     |
                           tick                  tick                  tick                  tick


In addition, each time that the program is run, there may be differences in memory access times (eg. the cache may or may not have been flushed/overwritten) between successive runs.

In general, to get reasonably reliable results, the loop that is being timed should take at least a few dozen milliseconds.
Thanks for your answers.

I would like to play with the boost CPU timers and I had a look at the website suggested by JLBorges. I downloaded the cpp libraries from here:
http://www.boost.org/users/download/
I "untared" the archive and then looked for the "timer.hpp" library.
Finally I included it into my source code:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
#include <iostream>
#include </media/DATA/OSsOFTWAREyDRIVERS/CppLibraries/boost_1_65_0/boost/timer/timer.hpp>

using namespace std;

//Prototypes
double calculoFactorialRecursividad(double, const double);

//Global variables
int loop_it=10000000;


int main() {
	double fac,fac1, tmp1, tmp2;
	double duration;
...


When I add this include my program is not running anymore:
"Launching <project> has encountered a problem.
The problem file specified in the launch
configuration does not exist"


@JLBorges Did you have the same problem?
Does anybody know the root-cause of the problem?
Boost.Timer is implemented as a separately compiled library, so you must install binaries in a location that can be found by your linker. If you followed the Boost Getting Started instructions http://www.boost.org/doc/libs/release/more/getting_started/index.html , that's already done for you
http://www.boost.org/doc/libs/1_65_0/libs/timer/doc/cpu_timers.html

Once the libraries are built, link with the libboost_timer library. For example, with the GNU tool chain:
g++ -std=c++14 -Wall -Wextra -pedantic-errors -O2 -pthread main.cpp -lpthread -lboost_timer && ./a.out
http://coliru.stacked-crooked.com/a/cde5b4e87887f9fb
@JLBorges Thanks for your answer

I followed the Getting Started Guide. I build and installed the boost cpp libraries under /usr/local/bin/boostCppLib

I linked the lboost_timer library in Eclipse:
Right click on the project-> Properties-> C/C++ Build-> GCC C++ Linker-> Add-> /usr/local/bin/boostCppLib/lib/libbost_timer

I also added the include in my program:
1
2
3
4
5
6
7
8
9
10
#include <iostream>
#include </usr/local/bin/boostCppLib/include/boost/timer/timer.hpp>
using namespace std;

//Prototypes
double calculoFactorialRecursividad(double, const double);

//Global variables
int loop_it=10000000;
...


However when I execute the program the following error is shown:

In file included from ../src/funcionFactorialIteracionVsRecursividad.cpp:10:0:
/usr/local/bin/boostCppLib/include/boost/timer/timer.hpp:11:44: fatal error: boost/config/warning_disable.hpp: No existe el archivo o el directorio
#include <boost/config/warning_disable.hpp>


I think the linker cannot find the include warning_disable.hpp
@JLBorger How can I provide the boost includes to the program? What I did wrong?
> How can I provide the boost includes to the program?

Add the boost include directory to the directories to search for header files.
See: https://gcc.gnu.org/onlinedocs/gcc/Directory-Options.html#Directory-Options

In your case, the compiler option would be: -I /usr/local/bin/boostCppLib/include
There must be way to do this from within the IDE in Eclipse, though I do not know what it is.

Then in your program, to include the boost header: #include <boost/timer/timer.hpp>
This header would then find the other boost headers that it requires.
Thank you @JLBorges.

I added the include directory in eclipse doing the following:
1.- I added the iclude path in the Include paths (-l) field:
* Right click on the project -> Properties -> C/C++ Build -> GCC C++ Compiler -> Includes

However when I compile I receive the following error:
/usr/bin/ld: cannot find -lboost_timer


The compiler does not find the library.
In my environment the library is here:
/usr/local/bin/boostCppLib/lib/libboost_timer.so

I found a thread here about this problem:
https://stackoverflow.com/questions/16710047/usr-bin-ld-cannot-find-lnameofthelibrary

Following this thread I did the following:
1.- Add the library directory in the Include paths (-l) field
2.- Add the library "boost_timer" in the Libraries (-l) field:
* Right click on the project-> Properties-> C/C++ Build-> GCC C++ Linker-> Libraries

But still the library is not found. Does anybody know why?
> 1.- Add the library directory in the Include paths (-l) field

No.
Add the library directory to the search path for libraries -L (upper case L)
The option would be: -L/usr/local/bin/boostCppLib/lib

I do not know how to do his from within Eclipse IDE; from what you posted, it could be something like:
Right click on the project -> Properties -> C/C++ Build -> Linker ->


> 2.- Add the library "boost_timer" in the Libraries (-l) field:

Yes.
Thank you @JLBorges.

I had to link several libraries. But it looks like they have been found.
However now another error is displayed:
/home/victor/.dropbox-workspace/Dropbox/funcionFactorialIteracionVsRecursividad/Debug/funcionFactorialIteracionVsRecursividad: error while loading shared libraries: libboost_timer.so.1.65.0: cannot open shared object file: No such file or directory


It looks like the dynamic linker is not finding libboost_timer.so.1.65.0.
This library is also in /usr/local/bin/boostCppLib/lib/

I've been reading about dynamic linking and I understood that I've to include the path /usr/local/bin/boostCppLib/lib/ in the environmet variable LD_LIBRARY_PATH

So I did the following:
Right click on the project -> Properties -> C/C++ -> Build Variables -> LD_LIBRARY_PATH and included the path the in the environment variable.
Last edited on
Pages: 123