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).

Can you consider a slightly different expectation? When a line of code is active, it is on the stack, so if you know the total time, and the fraction of time a line is on the stack, you know how much time it is responsible for. You can get that info from stack samples, and that tells which lines of code (and functions, if you like) would provide the most benefit if optimized. — Mike Dunlavey, Oct 21 '10 at 00:40

score 2 · Answer 1 · answered Oct 20 '10 at 19:43

2

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

answered Oct 20 '10 at 19:43

kanaka

70,845
23
144
140

2

Annotated source example: http://sourceware.org/binutils/docs/gprof/Annotated-Source.html – kanaka Oct 20 '10 at 21:28
Can it calculate real delays (for example, waiting for some input), not just how much times each thing is called? I've tried it on simple program that calls usleep(10000), but gprof fails to detect delays at all. – Vi. Oct 20 '10 at 22:20
1

@Vi: That's one of the basic issues with gprof: http://stackoverflow.com/questions/1777556/alternatives-to-gprof/1779343#1779343 – Mike Dunlavey Oct 20 '10 at 23:57

Mike Dunlavey · Accepted Answer · 2010-10-22T02:45:38.463

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.

score 0 · Answer 3 · answered Oct 21 '10 at 00:04

0

Either Zoom or Intel VTune.

answered Oct 21 '10 at 00:04

Eugene Smith

9,126
6
36
40

Debugging slow functions in C programs (built by gcc)

3 Answers3