C program output analysis

Question

A simple C program run on windows 10.(Visual Studio 2013)

#include <time.h>

void hello(){
    printf("hello world");
}

int _tmain(int argc, _TCHAR* argv[])
{
    clock_t t;
    for (int i = 0; i<50; i++){
        t = clock();
        hello();
        t = clock() - t;
        double time_taken = ((double)t) / CLOCKS_PER_SEC; // in seconds

        printf("hello() took %f ms to execute \n", time_taken * 1000);
    }
    getchar();
    return 0;
}

Output:

hello worldhello() took 0.000000 ms to execute(35times)
hello worldhello() took 17.000000 ms to execute
hello worldhello() took 3.000000 ms to execute
hello worldhello() took 2.000000 ms to execute
hello worldhello() took 0.000000 ms to execute(5 times)
hello worldhello() took 15.000000 ms to execute
hello worldhello() took 0.000000 ms to execute(4 times)
hello worldhello() took 16.000000 ms to execute
hello worldhello() took 0.000000 ms to execute

some lines are 0.000000 and some lines are 15.000000-17.000000

those outputs may not be exactly same as outputs of second run. but in the second/third.. run there must be some lines containing 0.000000ms and 15.000000-17.000000ms.

0ms to 16ms (is it for process CPU time ?). Would you please explain what is the actual reason.
If I want to avoid this kind of change and get uniform output like 0-1 ms, then how can I change my code. (Loop running for 50 times but if I run it for 100 or 1000 times then time effect can easily be understood.)

Possible duplicate of [How can I get the Windows system time with millisecond resolution?](https://stackoverflow.com/questions/3729169/how-can-i-get-the-windows-system-time-with-millisecond-resolution). Windows timestamps and timers have a resolution of 16ms, unless you use `timeBeginPeriod(1)`. For timing, you should be using `QueryPerformanceCounter` anyway. If you are using Windows 8 or newer and need precise current time, use `GetSystemTimePreciseAsFileTime`. — vgru, Aug 31 '17 at 10:10
I don't think `clock()` is very accurate. Try `struct/time.h` — cs95, Aug 31 '17 at 10:10
I expect your computer is performing other housekeeping tasks before returning from `printf()`. — r3mainer, Aug 31 '17 at 10:14
your thread not execute all time. periodically windows suspend it to give time to another threads. as result and this peaks - when thread was interrupted in loop. when he run without interrupt - you got 0 ms — RbMm, Aug 31 '17 at 13:31
Thanks to all for sharing your important concept and solution :) — Razin Bashar, Sep 26 '17 at 02:20

Jean-François Fabre · Accepted Answer · 2017-08-31T10:27:14.297

your code is too short and clock() has not the required accuracy to measure precisely execution time. Add to system overhead to perform the clock measure, and you get random results.

To get a better measure, loop 1 million times on your function, then clock & divide by 1 million to get the average execution time.

For more complex programs, using a code profiler could be a better solution (it is specialized in fine-grain clocking of functions & measuring execution time of the current function instructions, not a trivial task)

score 1 · Answer 2 · answered Aug 31 '17 at 10:18

1) This is due to the frequency of the process which is not constant.

So when you print through a loop it depennds directly of the frequency of the processor.

2) To avoid this behavior, you can check the clock value to be exactly more than 1 ms or 1 s to print exactly at this time. (in infinite loop)

score 1 · Answer 3 · answered Aug 31 '17 at 10:31

I agree with what Jean-François Fabre and Benjamin Audet.

You can use google_benchmark to benchmark the performance of a certain piece of code. It will perform a loop, in order to account for run time differences. The mean value an deviation are displayed.

C program output analysis

3 Answers3