gperftools inexactitudes with CPUPROFILE_FREQUENCY

Question

I have a task for which gprof seems that cannot be used. Callgrind is helping a lot here, but when found a solution more gprof-like, i. e., gperftools, dove into them to try.

So I wrote a dummy program and did several trials like these:

0:10:1386682334:user@host:~$ time gcc test.c -o test -lprofiler -Lgperftools-2.
1/.libs/ -g

real    0m0.085s
user    0m0.048s
sys     0m0.032s
0:11:1386682357:user@host:~$ time CPUPROFILE_FREQUENCY=50 CPUPROFILE=~
/test_profile LD_LIBRARY_PATH=~/gperftools-2.1/.libs/ ./test && ~/gperftools-2.
1/src/pprof test test_profile --text

PROFILE: interrupts/evictions/bytes = 14/0/216

real    0m7.157s
user    0m0.008s
sys     0m0.672s
Using local file test.
Using local file test_profile.
Removing killpg from all stack traces.
Removing do_system from all stack traces.
Total: 14 samples
      14 100.0% 100.0%       14 100.0% do_system
       0   0.0% 100.0%       14 100.0% __libc_start_main
       0   0.0% 100.0%       14 100.0% _start
       0   0.0% 100.0%        2  14.3% bar
       0   0.0% 100.0%       14 100.0% foo
       0   0.0% 100.0%       14 100.0% main
0:12:1386682465:user@host:~$ time CPUPROFILE_FREQUENCY=50000 CPUPROFIL
E=~/test_profile LD_LIBRARY_PATH=~/gperftools-2.1/.libs/ ./test && ~/gperftools
-2.1/src/pprof test test_profile --text

PROFILE: interrupts/evictions/bytes = 80/0/520

real    0m7.199s
user    0m0.016s
sys     0m0.704s
Using local file test.
Using local file test_profile.
Removing killpg from all stack traces.
Total: 80 samples
      78  97.5%  97.5%       79  98.8% do_system
       1   1.2%  98.8%        1   1.2% __find_specmb
       1   1.2% 100.0%        1   1.2% __libc_waitpid
       0   0.0% 100.0%        1   1.2% _IO_vfprintf_internal
       0   0.0% 100.0%       80 100.0% __libc_start_main
       0   0.0% 100.0%        1   1.2% __printf
       0   0.0% 100.0%       80 100.0% _start
       0   0.0% 100.0%       27  33.8% bar
       0   0.0% 100.0%       79  98.8% foo
       0   0.0% 100.0%       80 100.0% main

CPUPROFILE_FREQUENCY is documented here to be defaulted at 100 and being How many interrupts/second the cpu-profiler samples. Am estranged at setting it to 50 on a 7 seconds dummy program is sampling only 14 times, and at setting it to 50000 is sampling only 80 times.

I would want to know whether when needed more precision can be get with this simple environment change, and whether is CPUPROFILE_FREQUENCY broken in gperftools.

Answer 1

Your program only had between 0.008s and 0.048s user execution time. The profiler only profiles time spent in user space executing, and so I think your results are expected.

Try running a dummy program that spends 7 seconds doing actual computation. For example, compute Ackermann's function.