Thread: Unexplainable performance loss when printing a variable out of a loop

Hi! I hope someone can help me with a (simple but big!) performance problem with a C program.

I'm a computational chemist and I did a C-code which spent much of its time inside a triple loop (few second with the test input data but some day with "real" data).
These loops compute a variable, "sjk", very fast (less than 2 sec.) if I don't put OUT of the loops any instruction like:

printf("%f",sjk);

But, if I try to visualize this variable with a printf, the code runs very much slower (> 1000 sec.).
I tried to rename it out of the loop etc... I always have the same problem.
I discover also that if "sjk" is declared as a global one, the program runs slowly even thoug I don't use printf.
I think the problem could be some optimization option of the compiler (I compile with gcc -fast on MacOsx Tiger, G4) which can not switched on when I try to print "sjk" or I use it as a global variable.
Do anyone know the reason (and possibly a solution) of my problem?
Thank you!

Code:

sjk=0.;
for(i=0;i<natoms;i++){
          for(j=rows_xyz[0][i];j<=rows_xyz[1][i];j++){
              xloc=x[j];
              yloc=y[j];
              zloc=z[j];
            for(k=rows_xyzls[0][i];k<=rows_xyzls[1][i];k++){
              D[0]=xloc-xls[k];
              D[1]=yloc-yls[k];
              D[2]=zloc-zls[k];
              D[0]=D[0]*D[0];
              D[1]=D[1]*D[1];
              D[2]=D[2]*D[2];
              D[2]=D[0]+D[1]+D[2];
              D[2]=sqrt(D[2]);
              if (D[2]!=0.){
                D[2]=1./D[2];
                sjk=sjk+D[2]*lagwj[k];
              }
            }
            sjk=sjk*pinv;
     }
}

/* Here I want to print sjk! */

What does your call to printf look like?

If you place a call to printf() where you have commented in your code, then there really is no reason for a performance loss. If you put the call to printf() inside one of the for loops, then perhaps there would be, but thats not what were talking about doing, right?

Yes, the problem is not in the "slow" printf; in fact I have the same performance loss if I only change the "sjk" variable status from local (to the function which contains the loops) to global variable, without printing anithing.
Thank you! Bye!

> But, if I try to visualize this variable with a printf, the code runs very much slower (> 1000 sec.).
So?
It's called debugging, the only reason to care about intermediate results is when developing the code. Once it's working, and you only care about printing the final result, then everything will happen at full speed.

Compared to a simple arithmetic operation like multiply, printing things is horribly expensive, so you should only really be printing things which you actually need. Outputting to a screen is made worse by the need to say scroll the display, keep a scroll-back buffer and perhaps slug the performance a little down to human readable speed.

Sending output to a file is often much quicker by comparison, eg
myprog.exe > results.txt

> I discover also that if "sjk" is declared as a global one, the program runs slowly even thoug I don't use printf.
The optimiser cannot put global variables into registers, unlike local variables.

Thank you for the delucidation about global variables.
...about printing.....sjk is the final results I need, and it is printed only once because it is computed out of the loops; however this single printing cannot justify a slowdown of the program form 2 second of execution time in computing the loops to more than 1000 seconds of execution time in computing the loops.

Again, lets see your call to printf...

printf("%f", sjk); ....sorry

printf is put where the code is commented

Well that was not as helpful as I had hoped. Is your program really long? Perhaps you could post a little more of it to have a look at?

That seems like a good explanation to me, especially since making it global would have the same "result is used" effect as printing a local would do

Here is the whole program....the problem is in the function big_one_vec.
I added some comment to show where I find the drastic performance loss.
To run the program you need two input files, which are too large as to be posted in the forum...
Thank you!

Reply to nvoigt:

If I print a constant the program is still fast.
The program is still fast also if I print x[ ] or y[ ] or z[ ] (in the same position, out of the loop, where I would like to print sjk)
The program is very slow if I print sjk...

How can the compiler remove an entire loop? I wonder of this...... thank you.

> How can the compiler remove an entire loop?
Because the code has no effect.
The only variable modified by the loop is sjk, so unless you actually use that variable in some way before the function exits, then there is nothing lost by not executing the code, so the compiler removes it.

I've just done the following with your code
$ gcc -S -O2 foo.c
$ cp foo.s foo-1.s
# Now comment out this line
# printf("%f",sjk); /* THIS PRINT IS VERY BAD FOR PERFORMANCE */
$ gcc -S -O2 foo.c
$ ls -l *.s
-rw-rw-r-- 1 18804 Dec 31 17:59 foo-1.s
-rw-rw-r-- 1 17987 Dec 31 17:59 foo.s

That's right, nearly 1K of generated ASM code has simply gone by commenting out that one line.
And if I do a diff on those two files, there's all that code which was previously generated in the old version not in the new version.

Modern optimisers are way smarter than the average programmer.

Wanna try something else?
Remove the printf statement, but declare the variable like this
volatile float sjk;

Now I get
$ ls -l *.s
-rw-rw-r-- 1 18804 Dec 31 17:59 foo-1.s
-rw-rw-r-- 1 18845 Dec 31 18:08 foo.s

Making something volatile basically turns off all optimisation with respect to that variable, so whether you actually use the result or not, the compiler is forced to generate all the code which apparently uses that variable.

Later on, I'll get around to posting some of the bugs in your code.

nvoigt......your reply seems fully reasonable....in fact the problem arise if and only if I try to use that variable out of the loops.....and I never use it and all the other variable D [ ] anywhere in the program....
I didn't think the optimization could lead the compiler to completely avoid the calculation of a variable which is never used in the program, but if you said it is possible, this can really be the reason of my problem...
Thank you everyone for the help!