Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

`gprof` time spent in particular lines of code

I've been using the gprof profiler in conjunction with g++.

I have a function in my code which encapsulates several sections of behaviour which are related enough to the primary function that it would not make sense to split them off into their own functions.

I'd like to know how much time is spent in each of these areas of code.

So, if you imagine the code looks like

function(){
    A
    A
    A
    B
    B
    B
    C
    C
    C
}

where A, B, and C represent particular sections of code I'm interested in, is there a way to get gprof to tell me how much time is spent working on those particular sections?

like image 691
Richard Avatar asked Mar 07 '12 20:03

Richard


2 Answers

I know it's a old question, but I have found a interesting answer. As Sam say, the -l option is only for old gcc compiler. But I have found that if you compile and link with -pg -fprofile-arcs -ftest-coverage, run the program, the result of gprof -l is very interesting.

Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  Ts/call  Ts/call  name    
 13.86      0.26     0.26                             main (ComAnalyste.c:450 @ 804b315)
 10.87      0.46     0.20                             main (ComAnalyste.c:386 @ 804b151)
  7.07      0.59     0.13                             main (ComAnalyste.c:437 @ 804b211)
  6.25      0.70     0.12                             main (ComAnalyste.c:436 @ 804b425)
  4.89      0.79     0.09                             main (ComAnalyste.c:283 @ 804a3f4)
  4.89      0.88     0.09                             main (ComAnalyste.c:436 @ 804b1e9)
  4.08      0.96     0.08                             main (ComAnalyste.c:388 @ 804ad95)
  3.81      1.03     0.07                             main (ComAnalyste.c:293 @ 804a510)
  3.53      1.09     0.07                             main (ComAnalyste.c:401 @ 804af04)
  3.26      1.15     0.06                             main (ComAnalyste.c:293 @ 804a4bf)
  2.72      1.20     0.05                             main (ComAnalyste.c:278 @ 804a48d)
  2.72      1.25     0.05                             main (ComAnalyste.c:389 @ 804adae)
  2.72      1.30     0.05                             main (ComAnalyste.c:406 @ 804aecb)
  2.45      1.35     0.05                             main (ComAnalyste.c:386 @ 804ad6d)
  2.45      1.39     0.05                             main (ComAnalyste.c:443 @ 804b248)
  2.45      1.44     0.05                             main (ComAnalyste.c:446 @ 804b2f4)
  2.17      1.48     0.04                             main (ComAnalyste.c:294 @ 804a4e4)
  2.17      1.52     0.04                             main (ComAnalyste.c:459 @ 804b43b)
  1.63      1.55     0.03                             main (ComAnalyste.c:442 @ 804b22d)
  1.63      1.58     0.03                             main (ComAnalyste.c:304 @ 804a56d)
  1.09      1.60     0.02                             main (ComAnalyste.c:278 @ 804a3b3)
  1.09      1.62     0.02                             main (ComAnalyste.c:285 @ 804a450)
  1.09      1.64     0.02                             main (ComAnalyste.c:286 @ 804a470)
  1.09      1.66     0.02                             main (ComAnalyste.c:302 @ 804acdf)
  0.82      1.67     0.02                             main (ComAnalyste.c:435 @ 804b1d2)
  0.54      1.68     0.01                             main (ComAnalyste.c:282 @ 804a3db)
  0.54      1.69     0.01                             main (ComAnalyste.c:302 @ 804a545)
  0.54      1.70     0.01                             main (ComAnalyste.c:307 @ 804a586)
  0.54      1.71     0.01                             main (ComAnalyste.c:367 @ 804ac1a)
  0.54      1.72     0.01                             main (ComAnalyste.c:395 @ 804ade6)
  0.54      1.73     0.01                             main (ComAnalyste.c:411 @ 804aff8)
  0.54      1.74     0.01                             main (ComAnalyste.c:425 @ 804b12a)
  0.54      1.75     0.01                             main (ComAnalyste.c:429 @ 804b19f)
  0.54      1.76     0.01                             main (ComAnalyste.c:444 @ 804b26f)
  0.54      1.77     0.01                             main (ComAnalyste.c:464 @ 804b4a1)
  0.54      1.78     0.01                             main (ComAnalyste.c:469 @ 804b570)
  0.54      1.79     0.01                             main (ComAnalyste.c:472 @ 804b5b9)
  0.27      1.80     0.01                             main (ComAnalyste.c:308 @ 804a5a3)
  0.27      1.80     0.01                             main (ComAnalyste.c:309 @ 804a5a9)
  0.27      1.81     0.01                             main (ComAnalyste.c:349 @ 804a974)
  0.27      1.81     0.01                             main (ComAnalyste.c:350 @ 804a99c)
  0.27      1.82     0.01                             main (ComAnalyste.c:402 @ 804af1d)
  0.27      1.82     0.01                             main (ComAnalyste.c:416 @ 804b073)
  0.27      1.83     0.01                             main (ComAnalyste.c:417 @ 804b0a1)
  0.27      1.83     0.01                             main (ComAnalyste.c:454 @ 804b3ec)
  0.27      1.84     0.01                             main (ComAnalyste.c:461 @ 804b44a)
  0.27      1.84     0.01                             main (ComAnalyste.c:462 @ 804b458)

It's say the time spent per line. It's very interesting result. I don't know the accuracy or the validity of that, but it's quite interesting. Hope it's help

like image 50
Maxime Avatar answered Oct 19 '22 08:10

Maxime


Here's a useful resource for you: gprof line by line profiling.

With older versions of the gcc compiler, the gprof -l argument specified line by line profiling.

However, newer versions of gcc use the gcov tool instead of gprof to display line by line profiling information.

like image 31
Sam DeHaan Avatar answered Oct 19 '22 08:10

Sam DeHaan