Great job José. Thanks for making it available to all of us!

I just wanted to let you know that this script just saved me hours of deciphering the Python profiler's output. Thanks!

excellent work!! thanks a lot!

Excellent python profiling result viewer. I'm using inkscape as an SVG visualization tool (couldn't find easily a dot viewer on Windows).

It's just what I was looking for. Thanks.

Very nice. There's a small problem when there are more than 10000 functions. At least some versions of gprof have a bug where the initial function index loses the closing bracket for indices > 10000. I just added a '?' to the initial closing bracket in the cg_primary_re and cg_cycle_header_re regexps to fix this.

Here is an example of the gprof bug:

-----------------------------------------------
                0.00    0.00    3778/3778        timing::ClockDef::~ClockDef() [3176]
[9999]   0.0    0.00    0.00    3778         timing::ClockEdge::~ClockEdge() [9999]
-----------------------------------------------
                0.00    0.00      14/3657        timing::BaseTranList::handleUserTransitions(clkdb::SmartPointerTP<circuit::Port>, bool) [836]
                0.00    0.00    3643/3657        timing::AllClockDefs::skipClockPropDueToInactiveClock(clkdb::SmartPointerTP<timing::ClockDef>) [2467]
[10000   0.0    0.00    0.00    3657         timing::ClockDef::getMasterSourceClock() const [10000]
-----------------------------------------------
                0.00    0.00    3503/3503        circuit::name::FindNameBaseTraverser::addFoundName(clkdb::SmartPointerTP<circuit::name::NameIFC>, clkdb::SmartPointerTP<clkdb::PersistentObject>) [2984]
[10001   0.0    0.00    0.00    3503         circuit::name::FindNameContainer<clkdb::ObjectContainer>::push_back(clkdb::SmartPointerTP<clkdb::PersistentObject>) [10001]
-----------------------------------------------

jkuzeja,

Commited. Thanks.

Very nice, thanks!

/Johan Eker

It would be very nice to have an option to colour nodes according to exclusive time rather than inclusive - having the main red hotspot "main" for every profile is not always helpful

Really quality tools man...

thanks.

This is a life saver....great job.

This is an excellent program. Thank you very much for your hard work.

Amazing, I finally find the tool I needed:) Is it possible to let user specify the function to output? I think it would be better if user can specify one function so to see the process flow of a specific function. For example,one program has 2 steps one is compressing and the following is decompressing,so the user can choose to draw only the work flow of decompressing.

Comment by jon.x.hill, May 22, 2009 It would be very nice to have an option to colour nodes according to exclusive time rather than inclusive - having the main red hotspot "main" for every profile is not always helpful

I think you can achive this by simply copy it to another one say,gprof2dot2.py and then goto line 1898,modify it as below actually changing PRUNE_RATION to TIME_RATIO, hope the author will give one option for this:)

try:

weight = functionTIME_RATIO?

except UndefinedEvent?:

weight = 0.0

label = '\n'.join(labels) self.node(function.id,

label = label, color = self.color(theme.node_bgcolor(weight)), fontcolor = self.color(theme.node_fgcolor(weight)), fontsize = "%.2f" % theme.node_fontsize(weight),

)

for call in function.calls.itervalues():

callee = profile.functions[call.callee_id]

labels = for event in TOTAL_TIME_RATIO, CALLS:

if event in call.events:

label = event.format(callevent?) labels.append(label)

try:

weight = callTIME_RATIO?

except UndefinedEvent?:

try:

weight = calleeTIME_RATIO?

except UndefinedEvent?:

weight = 0.0

Is there any chance for valgrind callgrind support? These graphs are much nicer than some of KCacheGrind's.

All,

Has any one ever tried generating dot file / call graph using the output from Shark? I m trying to use "gprof2dot" to make call graphs using the profiling info from Shark. I can't figure that out yet.

I tried this below with no luck:

$ ./gprof2dot.py -f shark shark_report1 | dot -Tpng -o output.png

I get the errors:

#-------------------------------------

Traceback (most recent call last): File "./gprof2dot.py", line 2192, in <module> Main().main() File "./gprof2dot.py", line 2117, in main self.profile = parser.parse() File "./gprof2dot.py", line 1348, in parse raise ParseError?('failed to parse', line) main.ParseError?: failed to parse: '+ 79.0%, thread_start, libSystem.B.dylib'

#------------------------------------- Thanks, Ad.

All,

I found a solution to my question above. Tom, provided me with a patch. The line #1339, on the gprof2dot.py script should be changed to:

match = re.compile(r'(?P<prefix>[|+\- ])(?P<samples>\d+), (?P<symbol>[^,]+), (?P<image>.)')

i.e. for it to work with all Apple Shark outputs.

Also mke sure your Shark output e.g. shark_report1 above uses "samples counts" NOT "percentages".

I hope this helps,

Adolph,

Hi,

I tried using the gprof2dot script with my attached output and I got an error below.

i.e. I did this on Fedora:

$.my_exec param1 param2 $ gprof my_exec | gprof2dot.py | dot -Tpng -o output.png

I got:

Error: <stdin>:1: syntax error near line 1 context: >>> Command <<< not found.

Any ideas on what I did wrong? I am running Fedora 12 virtualized on my OS X (leopard). Any ideas will be appreciated,

Ad.

All,

When I run it as below, I do get some graph output, I wonder if this is a correct graph. I am using -pg option in my CFLAGS and LDFLAGS options.

i.e. I did:

$ gprof my_exec > gprof_out.txt $ ./gprof2dot.py -f prof gprof_out.txt | dot -Tpng -o goutput.png This gives me a viewable goutput.png graph but I am wondering if there could be a "prof vs. gprof" confusion in my commandline, that makes this illegitimate.

Thanks, Ad.

would you please update the documentation for processing sysprof results? Thanks!

Hi,

thanks for your work! its very useful.

Here is a patch with an color theme for printing (black text; nodes are not filled). I thought it might be of some use.

--- a/gprof2dot.py	2010-06-13 23:52:16.370554491 +0200
+++ b/gprof2dot.py	2010-06-14 00:05:12.055554359 +0200
@@ -2135,6 +2135,8 @@
             mincolor = (0.0, 0.0, 0.0),
             maxcolor = (0.0, 0.0, 1.0),
             fontname = "Arial",
+            fontcolor = "white",
+			nodestyle = "filled",
             minfontsize = 10.0,
             maxfontsize = 10.0,
             minpenwidth = 0.5,
@@ -2145,6 +2147,8 @@
         self.mincolor = mincolor
         self.maxcolor = maxcolor
         self.fontname = fontname
+        self.fontcolor = fontcolor
+        self.nodestyle = nodestyle
         self.minfontsize = minfontsize
         self.maxfontsize = maxfontsize
         self.minpenwidth = minpenwidth
@@ -2158,6 +2162,9 @@
     def graph_fontname(self):
         return self.fontname
 
+    def graph_fontcolor(self):
+        return self.fontcolor
+
     def graph_fontsize(self):
         return self.minfontsize
 
@@ -2165,11 +2172,17 @@
         return self.color(weight)
 
     def node_fgcolor(self, weight):
-        return self.graph_bgcolor()
+        if self.nodestyle == "filled":
+            return self.graph_bgcolor()
+        else:
+            return self.color(weight)
 
     def node_fontsize(self, weight):
         return self.fontsize(weight)
 
+    def node_style(self):
+        return self.nodestyle
+
     def edge_color(self, weight):
         return self.color(weight)
 
@@ -2272,6 +2285,16 @@
     maxpenwidth = 8.0,
 )
 
+WB_COLORMAP = Theme(
+    minfontsize = 18.0,
+    maxfontsize = 30.0,
+	fontcolor = "black",
+	nodestyle = "solid",
+    mincolor = (0.0, 0.0, 0.0), # black
+    maxcolor = (0.0, 0.0, 0.0), # black
+    minpenwidth = 0.1,
+    maxpenwidth = 8.0,
+)
 
 class DotWriter:
     """Writer for the DOT language.
@@ -2288,9 +2311,11 @@
         self.begin_graph()
 
         fontname = theme.graph_fontname()
+        fontcolor = theme.graph_fontcolor()
+        nodestyle = theme.node_style()
 
         self.attr('graph', fontname=fontname, ranksep=0.25, nodesep=0.125)
-        self.attr('node', fontname=fontname, shape="box", style="filled", fontcolor="white", width=0, height=0)
+        self.attr('node', fontname=fontname, shape="box", style=nodestyle, fontcolor=fontcolor, width=0, height=0)
         self.attr('edge', fontname=fontname)
 
         for function in profile.functions.itervalues():
@@ -2434,6 +2459,7 @@
             "pink": PINK_COLORMAP,
             "gray": GRAY_COLORMAP,
             "bw": BW_COLORMAP,
+            "wb": WB_COLORMAP,
     }
 
     def main(self):
@@ -2461,9 +2487,9 @@
             help="profile format: prof, callgrind, oprofile, sysprof, shark, sleepy, aqtime, pstats, or xperf [default: %default]")
         parser.add_option(
             '-c', '--colormap',
-            type="choice", choices=('color', 'pink', 'gray', 'bw'),
+            type="choice", choices=('color', 'pink', 'gray', 'wb', 'bw'),
             dest="theme", default="color",
-            help="color map: color, pink, gray, or bw [default: %default]")
+            help="color map: color, pink, gray, wb or bw [default: %default]")
         parser.add_option(
             '-s', '--strip',
             action="store_true",

I added the following line to the PstatsParser?.parse method in order to print summaries information, in particular the cpu time. Maybe maybe it could be useful to someone else...

print >> sys.stderr, "%s function calls" % (self.stats.total_calls), if self.stats.total_calls != self.stats.prim_calls:

print >> sys.stderr, "(%d primitive calls)" % self.stats.prim_calls,

print >> sys.stderr, "in %.3f CPU seconds" % self.stats.total_tt

1. elf.stats.print_stats()
2. elf.stats.print_callees()

etc...

It could be nice to include summaries information in the output image.

I'm getting the "unexpected end of file" error with "gprof myapp.exe | gprof2dot.py | dot -Tpng -o output.png".

Everything works fine except gprof2dot.py. Some help would be appreciated as there are is probably no other profiler support for gcc on Win.

Ok, seems like I got over it by using "gprof2dot.py gprof.txt -f prof | dot -Tpng -o output.png" where gprof.txt is output of "gprof myapp.exe".

Thank you very much for the tool. I tried it for Python and it is great; hope it handle oProfile output the same good.

a wonderful tool

Nice job of programming, but this kind of gprof-style stuff gives me a stomach ache, because I use the random-pause method of locating "bottlenecks". Gprof floods you with data, of which 95+% is irrelevant. For example, I worked through that gmon.out data and simulated 10 random stack samples. After sorting them, they look like this:

main ...
main read_all_makefiles ...
main read_all_makefiles eval_makefile eval ...
main read_all_makefiles eval_makefile eval ...
main read_all_makefiles eval_makefile eval ...
main read_all_makefiles eval_makefile eval ...
main update_goal_chain ...
main update_goal_chain try_implicit_rule ...
main update_goal_chain try_implicit_rule pattern_search ...
main update_goal_chain try_implicit_rule pattern_search file_impossible_p find_directory ...

The ... is because I couldn't follow the gmon.out data far enough to simulate a full stack trace. Any routine on X% of these samples is responsible for about X% of the time. Examples:

eval_makefile 40%
eval 40%
try_implicit_rule 30%
pattern_search 20%

What's more the exact lines of code responsible for the time are also on the samples, not just functions. This a small amount of data, and it is rich in information about what code is responsible for the time. It doesn't spend a lot of clutter on stuff that doesn't matter. What's more, gprof is blind to I/O, so it is skewed to CPU-only time, not wall time.

MikeDunlavey?,

This is a tool to help visualize "gprof-style stuff". I never intended to advocate nor evangelize gprof (which I actually stopped many years ago), any particular profiling tool, or even a particular profiling technique. This tool, like any tool, it is merely is a mean to an end, and is not implicitly good or bad. If this tool doesn't fit your needs then you can simply be kind to your stomach and not use it.

Yes, the results will be blind to I/O if the profiler is blind to I/O. But this is not the case with all profilers (e.g., Very Sleepy will capture I/O times when profiling a single thread). Tools like xperf and linux perf can actually put a maginifying glass on events such as I/O or context switches.

Yes, gprof and similar profilers will flood you with a lot of data. But guess what -- reducing the data and higlighting the most interesting bits is precisely the point of this tool. Actually, if you look at the output, and follow the hot red color down you'll get precisely the call path that "random-pause" most frequently would give (assuming load is CPU based or the tool captures I/O times) if there is one. If there is not single hot path, you still perceive informatiom without doing many "random-pauses" (which, if done too often, end up being nothing more than a poor man sampling profiler).

One thing which you hint at, and that I agree that could be done better here is to take in account the full stack traces. Unlike old gprof, new tools such as linux perf and Very Sleepy capture the full stack traces, however gprof2dot ends up ignoring the high order correlations, which ends up biasing (actually more like tends to averaging out) the cumulative values.

There is some challenge though, as stack traces are some times truncated, so a mixed approach will be necessary. Also, this only makes a significant difference when there are dispatch functions, i.e., single functions with many callers and many callees, that dispatch to a particular callee depending on argument input.

hi, i tested gprof on c++ code, but in the call graph are value for % time--self--children = ZERO, do you know where is problem ? for example: index % time self children called name

9 quicksort(int, int, int) 2?

0.00 0.00 1/1 main 2248?

9 quicksort(int, int, int) 2?

thx. V.