RFC: watch GCC's per-function processing times

[Josh Stone]

Hi,

The attached is a script that I've been playing with to figure out which
functions in stap's generated C are giving GCC the most grief.  I
haven't looked much at GCC internals before, so I welcome suggestions on
better places to probe and get info.

Example output while compiling para-callgraph.stp on all functions in stap:

10393 cc1: parse   count:2161  sum:0.621380  min:0.000020  avg:0.000287
 max:0.004679
  0.004679  unwind_frame
  0.003738  _stp_vsnprintf
  0.003549  probe_2744
  0.001775  probe_3106
  0.001748  be64_add_cpu
  0.001726  probe_3110
  0.001710  probe_3431
  0.001667  probe_3439
  0.001636  probe_3508
  0.001626  _stp_stat_print_histogram_buf

10393 cc1: expand  count:472   sum:5.247916  min:0.001311  avg:0.011118
 max:0.151588
  0.151588  _stp_vsnprintf
  0.081625  function_trace
  0.077921  _stp_ctl_write_cmd
  0.038044  init_module
  0.035063  probe_2997
  0.030117  probe_2848
  0.027800  probe_3106
  0.027692  probe_3110
  0.027275  __stp_utrace_task_finder_target_syscall_exit
  0.024723  number

The full GCC time in this case was 7 seconds, so I haven't accounted for
everything, but I think it's a pretty good first pass.

The names are also very basic, so in C++ they are missing the class
names, parameters, etc. to help distinguish them.  I can't figure out
how to get at that info just from probing local variables.

I also don't know how to print the file being compiled -- maybe an exec
probe is necessary.

Comments welcome...

Josh
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: gcc-function.stp
URL: <http://sourceware.org/pipermail/systemtap/attachments/20091027/6c6a007b/attachment.ksh>