c++ g++ llvm-clang compiler profiling

Question

Note, my question is not: how do I tell my compiler to compile with profiling on.

I want to profile my compiles process. For each file, I'd like to know how much time is spent on each line of the program.

I'm working on a project, some files have huge compile times, I'm trying to figure out why.

Is there anyway to do this with g++ or llvm-clang?

Thanks!

Output of -v -ftime-report (what oes it mean)?

In the following, is "parser" or "expand" the use of templates?

Execution times (seconds)
  callgraph construction:   0.06 ( 2%) usr   0.00 ( 0%) sys   0.09 ( 2%) wall    3181 kB ( 1%) ggc
  callgraph optimization:   0.05 ( 2%) usr   0.00 ( 0%) sys   0.05 ( 1%) wall    5243 kB ( 2%) ggc
  cfg cleanup           :   0.02 ( 1%) usr   0.00 ( 0%) sys   0.02 ( 0%) wall      11 kB ( 0%) ggc
  df live regs          :   0.01 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 0%) wall       0 kB ( 0%) ggc
  df reg dead/unused notes:   0.03 ( 1%) usr   0.00 ( 0%) sys   0.03 ( 1%) wall    1993 kB ( 1%) ggc
  register information  :   0.04 ( 1%) usr   0.00 ( 0%) sys   0.04 ( 1%) wall       0 kB ( 0%) ggc
  alias analysis        :   0.01 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 0%) wall     450 kB ( 0%) ggc
  rebuild jump labels   :   0.03 ( 1%) usr   0.00 ( 0%) sys   0.03 ( 1%) wall       0 kB ( 0%) ggc
  preprocessing         :   0.12 ( 4%) usr   0.06 (12%) sys   1.46 (27%) wall    2752 kB ( 1%) ggc
  parser                :   0.67 (21%) usr   0.15 (29%) sys   0.89 (16%) wall   91749 kB (36%) ggc
  name lookup           :   0.15 ( 5%) usr   0.12 (24%) sys   0.24 ( 4%) wall   14384 kB ( 6%) ggc
  inline heuristics     :   0.03 ( 1%) usr   0.00 ( 0%) sys   0.03 ( 1%) wall       0 kB ( 0%) ggc
  tree gimplify         :   0.06 ( 2%) usr   0.01 ( 2%) sys   0.09 ( 2%) wall   15992 kB ( 6%) ggc
  tree eh               :   0.02 ( 1%) usr   0.01 ( 2%) sys   0.03 ( 1%) wall    4405 kB ( 2%) ggc
  tree CFG construction :   0.01 ( 0%) usr   0.01 ( 2%) sys   0.03 ( 1%) wall    6636 kB ( 3%) ggc
  tree CFG cleanup      :   0.02 ( 1%) usr   0.01 ( 2%) sys   0.02 ( 0%) wall      15 kB ( 0%) ggc
  tree find ref. vars   :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.00 ( 0%) wall    1870 kB ( 1%) ggc
  tree SSA rewrite      :   0.01 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 0%) wall    2357 kB ( 1%) ggc
  tree SSA other        :   0.00 ( 0%) usr   0.01 ( 2%) sys   0.00 ( 0%) wall      37 kB ( 0%) ggc
  tree operand scan     :   0.01 ( 0%) usr   0.04 ( 8%) sys   0.06 ( 1%) wall    6340 kB ( 2%) ggc
  tree SSA to normal    :   0.05 ( 2%) usr   0.00 ( 0%) sys   0.05 ( 1%) wall      95 kB ( 0%) ggc
  dominance computation :   0.04 ( 1%) usr   0.00 ( 0%) sys   0.04 ( 1%) wall       0 kB ( 0%) ggc
  expand                :   0.60 (18%) usr   0.03 ( 6%) sys   0.71 (13%) wall   45557 kB (18%) ggc
  varconst              :   0.02 ( 1%) usr   0.00 ( 0%) sys   0.02 ( 0%) wall    3532 kB ( 1%) ggc
  jump                  :   0.00 ( 0%) usr   0.00 ( 0%) sys   0.00 ( 0%) wall    1745 kB ( 1%) ggc
  mode switching        :   0.01 ( 0%) usr   0.00 ( 0%) sys   0.01 ( 0%) wall       0 kB ( 0%) ggc
  integrated RA         :   0.35 (11%) usr   0.00 ( 0%) sys   0.35 ( 6%) wall    5259 kB ( 2%) ggc
  reload                :   0.29 ( 9%) usr   0.01 ( 2%) sys   0.31 ( 6%) wall    6490 kB ( 3%) ggc
  thread pro- & epilogue:   0.10 ( 3%) usr   0.01 ( 2%) sys   0.13 ( 2%) wall    4832 kB ( 2%) ggc
  final                 :   0.19 ( 6%) usr   0.01 ( 2%) sys   0.21 ( 4%) wall    2985 kB ( 1%) ggc
  symout                :   0.25 ( 8%) usr   0.01 ( 2%) sys   0.26 ( 5%) wall   27322 kB (11%) ggc
  TOTAL                 :   3.25             0.51             5.49             256741 kB

Answer 1

Try these command line options with g++

-v -ftime-report

That should give you more information on the compiling process. The culprit is usually templates though.

Answer 2

For preprocessing line a bit longer suggestion:

" 0.12 ( 4%) usr 0.06 (12%) sys 1.46 (27%) wall " - this line says, that preprocessing was to do small job on CPU itself (0.12), but is uses system calls rather heavy (0.06 or 50% of user CPU time) and the most time was wasted not on CPU (1.46 real time >> 0.18 s cpu time). So This time was wasted in waiting an I/O operation OR waiting for CPU on busy system. Was this run the only working program on the machine?

For I/O you can do: add noatime to fs to lower number of I/O reqs, buy faster (in terms of lower seek time or higher IO rate) HDD, move clang sources to SSD or even RAM-drive (loop-device). And you can't do a defragment, because it is linux.

For meaning of eash pass, use http://gcc.gnu.org/onlinedocs/gccint/Passes.html#Passes