Debugging slow functions in C programs (built by gcc)

Question

Having source like this:

void foo() {
    func1();
    if(qqq) {
        func2();
    };
    func3();
    func4();
    for(...) {
        func5();
    }
}

I want to obtain info like this:

               void foo() {
5  ms; 2 times;    func1();
0  ms; 2 times;    if(qqq) {
0  ms; 0 times;        func2();
0  ms; 2 times;    };
20 ms; 2 times;    func3();
5  s ; 2 times;    func4();
0  ms; 60 times;   for(...) {
30 ms; 60 times;       func5();
0  ms; 60 times;   }
                }

I.e. information about how long in average it took to execute this line (real clock time, including waiting in syscalls) and how many times is it executed.

What tools should I use?

I expect the tool to instrument each function to measure it's running time, which is used by instrumentation inside calling function that writes log file (or counts in memory and then dumps).

Answer 1

gprof is pretty standard for GNU built (gcc, g++) programs: http://www.cs.utah.edu/dept/old/texinfo/as/gprof_toc.html

Here is what the output looks like: http://www.cs.utah.edu/dept/old/texinfo/as/gprof.html#SEC5

Answer 2

Take a trial run of Zoom. You won't be disappointed.

P.S. Don't expect instrumentation to do the job. For either line-level or function-level information, a wall-time stack sampler delivers the goods, assuming you don't absolutely need precise invocation counts (which have little relevance to performance).

---

ADDED: I'm on Windows, so I just ran your code with LTProf. The output looks like this:

  void foo(){
 5  func1();
    if(qqq){
 5    func2();
    }
 5  func3();
 5  func4();
    // I made this 16, not 60, so the total time would be 20 sec.
    for(int i = 0; i < 16; i++){
80    func5();
    } 
  }

where each func() does a Sleep(1000) and qqq is True, so the whole thing runs for 20 seconds. The numbers on the left are the percent of samples (6,667 samples) that have that line on them. So, for example, a single call to one of the func functions uses 1 second or 5% of the total time. So you can see that the line where func5() is called uses 80% of the total time. (That is, 16 out of the 20 seconds.) All the other lines were on the stack so little, comparatively, that their percents are zero.

I would present the information differently, but this should give a sense of what stack sampling can tell you.

Answer 3

Either Zoom or Intel VTune.