fprintf in subroutine and runtime

[OakRand]

This may be a well-known phenomenon, but I've only just noticed it and am not sure why it happens.

I've got a basic little subroutine called from main that runs two nested for loops and takes 13 realtime seconds to run. If I include an fprintf at the end of the routine, after complettion of the for loops, it takes nearly 4 minutes. If I include an fprintf at the end of main, runtime is again 13s.

Can anyone explain to me why this is?

[joeprogrammer]

Maybe it's got some issues dumping the stack after running fprintf.

[grumpy]

I/O is pretty slow compared with other things done by the computer. For example, times to seek, read, and write data to disk are typically measured in milliseconds whereas times for completion of machine instructions and accessing data in RAM are measured in microseconds (or even smaller units).

[Tonto]

>> Maybe it's got some issues dumping the stack

What is 'dumping the stack'?

[Salem]

http://cboard.cprogramming.com/showt...tf+performance
My guess is, adding the printf() is actually printing a variable which was otherwise unused, and the compiler had optimised it out.

By printing it (and hence using it), it forced the compiler to include a whole bunch of expensive code which was otherwise optimised out.

[OakRand]

My guess is, adding the printf() is actually printing a variable which was otherwise unused, and the compiler had optimised it out..

That's what it was. Thanks. I should have realized it.

[grumpy]

http://cboard.cprogramming.com/showt...tf+performance
My guess is, adding the printf() is actually printing a variable which was otherwise unused, and the compiler had optimised it out.

By printing it (and hence using it), it forced the compiler to include a whole bunch of expensive code which was otherwise optimised out.

While the phenomenon you describe (adding I/O operations changing how effectively a compiler does optimisation) can have some effect, those effects are rarely of the order of those described in the original post.

The more likely reason is that I/O is slower than many other operations on a machine, and doing many I/O operations consumes both CPU time and actual (clock) time.

It is a pretty fair bet that

#include <stdio.h>

int main()
{
    int i, j;
    for (int i = 0; i < 10000; ++i)
   {
        for (int j = 0; j < 10000; ++j)
        {
             some_complex_calculations();
        }
   }

   print_results_of_calculations();
}

will run noticeably more quickly on most systems than;

#include <stdio.h>

int main()
{
    int i, j;
    for (int i = 0; i < 10000; ++i)
   {
        for (int j = 0; j < 10000; ++j)
        {
             some_complex_calculations();

             fprintf(stdout, "%s\n", "Hello");   /* only addition */
        }
   }

   print_results_of_calculations();
}

[Salem]

> While the phenomenon you describe
Read the OP - the number of printfs didn't change - they simply moved the single printf from the end of the function to main to get the huge difference.

For sure putting printf inside a nested loop will make a difference.