1

I'm trying to use valgrind --tool=callgrind to profile my C++ program on Ubuntu. Here is my code:

#include <iostream>
int main()
{
    std::cout<<"hello world"<<std::endl;
    return 0;
}

Compile it: g++ main.cpp -g

valgrind: valgrind --tool=callgrind ./a.out

Then I get a file named callgrind.out.1153.

Then I use the tool gprof2dot and the command dot:

python gprof2dot.py -f callgrind -n10 -s callgrind.out.1153 > valgrind.dot
dot -Tpng valgrind.dot -o valgrind.png

However, this png is like this:

enter image description here

For me this is really hard to read.

So is it possible to make callgrind more human readable? For example, can it show me only the execution time of each function of my code or the execution time of my code line by line?

4
  • Have you tried KCachegrind? Commented Jul 18, 2019 at 8:18
  • @user6556709 I can't because my working PC is not allowed to install KCachegrind.
    – Yves
    Commented Jul 18, 2019 at 8:21
  • Valgrind comes with command line tool cg_annotate . It is able to output execution time per line. Commented Jul 18, 2019 at 8:34
  • First of all, the ___grind profilers only do CPU time, not I/O time. Second, a "hello world" program is almost totally I/O. The smaller-than-miniscule time it spends in CPU is almost totally spent in the I/O library functions, as you can see, and, even if you understood them, you can't change them, so how can this help you? Commented Jul 18, 2019 at 13:19

1 Answer 1

3

It's not super user-friendly, but I think this does what the OP wants:

callgrind_annotate --tree=both --inclusive=yes --auto=yes --show-percs=yes callgrind.out.${pid} > tree.${pid}

This creates a text file with two sections. The first section is a summary of profiled functions, sorted by the time spent in each. Example of one function:

 3,090,761,742,907 (22.39%)  < /home/me/proj/src/dir0/file0.cpp:caller0() (79,173,695x) [/home/me/proj/build/reldbg/lib/libzero.so]
   768,380,030,255 ( 5.57%)  < /home/me/proj/src/dir0/file1.cpp:caller1(unsigned int) (19,814,000x) [/home/me/proj/build/reldbg/lib/libzero.so]
 3,861,537,817,283 (27.97%)  *  /home/me/proj/src/dir0/Abc.cpp:Abc::Abc() [/home/me/proj/build/reldbg/lib/libzero.so]
 2,458,035,862,297 (17.80%)  >   /home/me/proj/src/dir1/file2.h:callee0() (99,049,427x) [/home/me/proj/build/reldbg/lib/libone.so]
 1,378,046,252,252 ( 9.98%)  >   /home/me/proj/src/dir0/file3.cpp:callee1() (99,049,427x) [/home/me/proj/build/reldbg/lib/libzero.so]

The profiled function has the asterisk, its callers have less-than, the functions it calls have greater-than.

The second section is annotated source code, with the amount of time allocated on each line. For example:

--------------------------------------------------------------------------------
-- Auto-annotated source: /home/me/proj/src/dir0/file1.cpp
--------------------------------------------------------------------------------
Ir                      

-- line 37 ----------------------------------------
 7,822,093,316 ( 0.06%)          for (uint32 i = 0; i < VEC_SIZE; i++)
             .                   {
21,018,143,872 ( 0.15%)              data[i].reset();
110,822,940,416 ( 0.80%)  => /home/me/proj/src/dir0/abc.cpp:Abc::reset() (1,910,740,352x)
             .                   }

Not the answer you're looking for? Browse other questions tagged or ask your own question.