Re: [Bug gprof/2776] New: Strange profiling results

[Nick Clifton]

Hi Dmitry,

> void f (int n) 
> {
>       rdtscll (t);

> void g (int n) 
> {
>       gettimeofday (&tv, 0);

> int main (int argc, char *argv[])
> { 
>   int n;
>
>   for (n = 0; n < 200; n++) {
>     if (n % 2)
>       f (n);
>     else
>       g (n);

> My typical results are:
>
> $ gcc -O2 -g -pg -o test test.c                        
> $ gprof test | head -n 10                            
> Flat profile:
>
> Each sample counts as 0.01 seconds.
>   %   cumulative   self              self     total           
>  time   seconds   seconds    calls  ms/call  ms/call  name    
>  95.85      0.40     0.40      100     4.03     4.03  f
>   4.79      0.42     0.02      100     0.20     0.20  g

Have you checked the assembler output of the compiler ?  Perhaps it is 
being clever.  Maybe it knows that all but the calls to gettimeofday are 
redundant ?

What about main(), is any time spent in that function ?

Also it appears that the two percentages above add up to more than 100%.

The most likely though is that bad profiling data is being generated. 
ie it is not gprof's fault but either gcc's (for not inserting the calls 
to the profiling hooks correctly) or else the run time C library's (for 
not implementing the profiling hooks correctly).  Check you version of 
gcc.  If it is an old one, then try updating it.  If it is a new one, 
then try using an older one and see if the problem goes away.

Cheers
  Nick