Execution time of a function in C++

Question

I want to use several functions that declare the same array but in different ways (statically, on the stack and on the heap) and to display the execution time of each functions. Finally I want to call those functions several times.

I think I've managed to do everything but for the execution time of the functions I'm constantly getting 0 and I don't know if it's supposed to be normal. If somebody could confirm it for me. Thanks Here's my code

#include "stdafx.h"
#include <iostream>
#include <time.h>
#include <stdio.h>
#include <chrono>

#define size 100000
using namespace std;

void prem(){
  auto start = std::chrono::high_resolution_clock::now();
  static int array[size];
  auto finish = std::chrono::high_resolution_clock::now();
  std::chrono::duration<double> elapsed = finish - start;

  std::cout << "Elapsed timefor static: " << elapsed.count() << " s\n";
}

void first(){
  auto start = std::chrono::high_resolution_clock::now();
  int array[size];
  auto finish = std::chrono::high_resolution_clock::now();
  std::chrono::duration<double> elapsed = finish - start;
  std::cout << "Elapsed time on the stack: " << elapsed.count() << " s\n";
}

void secon(){
  auto start = std::chrono::high_resolution_clock::now();
  int *array = new int[size];
  auto finish = std::chrono::high_resolution_clock::now();
  std::chrono::duration<double> elapsed = finish - start;
  std::cout << "Elapsed time dynamic: " << elapsed.count() << " s\n";

  delete[] array;
}

int main()
{
  for (int i = 0; i <= 1000; i++){
    prem();
    first();
    secon();
  }
  return 0;
}

Answer 1

prem() - the array is allocated outside of the function
first() - the array is allocated before your code gets to it

You are looping over all 3 functions in a single loop. Why? Didn't you mean to loop for 1000 times over each one separately, so that they (hopefully) don't affect each other? In practice that last statement is not true though.

My suggestions:

1. Loop over each function separately
2. Do the now() call for the entire 1000 loops: make the now() calls before you enter the loop and after you exit it, then get the difference and divide it by the number of iterations(1000)
3. Dynamic allocation can be (trivially) reduced to just grabbing a block of memory in the vast available address space (I assume you are running on 64-bit platform) and unless you actually use that memory the OS doesn't even need to make sure it is in RAM. That would certainly skew your results significantly
4. Write a "driver" function that gets function pointer to "test"

Possible implementation of that driver() function:

void driver( void(*_f)(), int _iter, std::string _name){
  auto start = std::chrono::high_resolution_clock::now();
  for(int i = 0; i < _iter; ++i){
    *_f();
  }
  auto finish = std::chrono::high_resolution_clock::now();
  std::chrono::duration<double> elapsed = finish - start;
  std::cout << "Elapsed time " << _name << ": " << elapsed.count() / _iter << " s" << std::endl;
}

That way your main() looks like that:

void main(){
  const int iterations = 1000;
  driver(prem, iterations, "static allocation");
  driver(first, iterations, "stack allocation");
  driver(secon, iterations, "dynamic allocation");
}

Answer 2

Do not do such synthetic tests because the compiler will optimize out everything that is not used.

As another answer suggests, you need to measure the time for entire 1000 loops. And even though, I do not think you will get reasonable results.

Let's make not 1000 iterations, but 1000000. And let's add another case, where we just do two subsequent calls to chrono::high_resolution_clock::now() as a baseline:

#include <iostream>
#include <time.h>
#include <stdio.h>
#include <chrono>
#include <string>
#include <functional>

#define size 100000
using namespace std;

void prem() {
    static int array[size];
}

void first() {
    int array[size];
}

void second() {
    int *array = new int[size];
    delete[] array;
}

void PrintTime(std::chrono::duration<double> elapsed, int count, std::string msg)
{
    std::cout << msg << elapsed.count() / count << " s\n";
}

int main()
{
    int iterations = 1000000;
    {
        auto start = std::chrono::high_resolution_clock::now();
        auto finish = std::chrono::high_resolution_clock::now();
        PrintTime(finish - start, iterations, "Elapsed time for nothing: ");
    }
    {
        auto start = std::chrono::high_resolution_clock::now();
        for (int i = 0; i <= iterations; i++)
        {
            prem();
        }
        auto finish = std::chrono::high_resolution_clock::now();
        PrintTime(finish - start, iterations, "Elapsed timefor static: ");
    }
    {
        auto start = std::chrono::high_resolution_clock::now();
        for (int i = 0; i <= iterations; i++)
        {
            first();
        }
        auto finish = std::chrono::high_resolution_clock::now();
        PrintTime(finish - start, iterations, "Elapsed time on the stack: ");
    }
    {
        auto start = std::chrono::high_resolution_clock::now();
        for (int i = 0; i <= iterations; i++)
        {
            second();
        }
        auto finish = std::chrono::high_resolution_clock::now();
        PrintTime(finish - start, iterations, "Elapsed time dynamic: ");
    }
    return 0;
}

With all optimisations on, I get this result:

Elapsed time for nothing: 3.11e-13 s
Elapsed timefor static: 3.11e-13 s
Elapsed time on the stack: 3.11e-13 s
Elapsed time dynamic: 1.88703e-07 s

That basically means, that compiler actually optimized out prem() and first(). Even not calls, but entire loops, because they do not have side effects.