x86_64: gprof reports run times much longer than reality

[Jeremy Buhler]

PROBLEM:
On all of my Linux x86_64 systems, when I build code instrumented for 
profiling with gcc -pg, the running times reported for the code by gprof 
are many times the actual runtime of the program.  This problem is 
specific to x86_64; the times for the same code are correct on 32-bit 
x86 Linux.  The problem on x86_64 occurs independently of whether I 
compile with -m32 or -m64, and independently of the optimization level 
of the compilation.

A simple example is the following program "braindead.c":

unsigned int x;

void do_something()
{
  unsigned int j;
  for (j = 0; j < (1U << 31); j++)
    {
      x = (j * j + j)/ 10000;
    }
}

int main()
{
  do_something();
  return 0;
}

Here's what I see:

> gcc -O2 -pg braindead.c
> time a.out
5.030u 0.001s 0:05.03 100.0%    0+0k 0+0io 0pf+0w
> gprof a.out
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total
 time   seconds   seconds    calls   s/call   s/call  name
101.33     50.97    50.97        1    50.97    50.97  do_something
[...]
ndex % time    self  children    called     name
               50.97    0.00       1/1           main [2]
[1]    100.0   50.97    0.00       1         do_something [1]
-----------------------------------------------
                                                 <spontaneous>
[2]    100.0    0.00   50.97                 main [2]
               50.97    0.00       1/1           do_something [1]
-----------------------------------------------

PLATFORM:
Linux 2.6.x x86_64 (x86_64-uknown-linux-gnu)
(observed with RedHat 2.6.9 and 2.6.10 kernels)
(observed on both AMD Opteron and Intel Pentium D)

TOOLCHAIN:
gcc 4.1.1 (same observed with gcc 3.4.5)
binutils nightly 0621 (same observed with older releases)
glibc 2.3.4

                                                         Jeremy

smime.p7s
Description: S/MIME Cryptographic Signature