Profiling info

[Daniel Gates]

Greetings all,

I have been working out some profiling issues with TreEvo even though
it still gets caught up when I try running it. I used Rprof() for this
profiling info as profR was not working well for me. I have saved
the .Rdata file here: https://github.com/danjgates/TreEvo-Profiling/blob/master/Rprof.Rdata

Looking through it I'm not entirely sure how to interpret what I'm
seeing and I'm not sure that the results from this will even be that
relevant because I think most of the time spent in this run was spent
after the program got hung up (perhaps it may be informative as to
what's causing the hang ups when I run it). I'll try something like
this later on our lab computer that seems capable of running TreEvo
without hitting the errors that my comps do and I'll try to get that
posted tomorrow

Cheers!
-Dan

[Derrick Zwickl]

Hi Dan,

All Rprof does is check what the current call stack is (what function is
currently being executed, and what called it, etc.) every fraction of a
second, and write that to file (as text). That information is then
analyzed by summaryRprof to get information such as how much time is
being spent (how many samples have been taken) in given functions.

In general the basic info your get from any profiling will be
-the "self" time, the time spent in the given function itself
-the "total" time, the time spent in the given function plus everything
downstream of it (time in functions that it calls)

The other info that one typically wants (but summaryRprof does not give,
as far as I can tell) is what the call hierarchy and the number of times
each function is called. Based on what is written to file by Rprof it
isn't possible to extract the latter, but the call hierarchy is easy
enough. I wrote a python script to do it (attached), but there may be a
better R package that I haven't found yet. Or you could write one in
R. The call hierarchy is important. Obviously it is good to know the
program flow and who is calling what, but it can also be good to know
whether a particular function is being called from multiple places.
Speeding up loops and particular functions is great, but making higher
level structural changes that reduce the number of times a function is
called can also be very helpful.

It will also be good to note how much time is being spent in R library
functions. You obviously won't be able to optimize them directly, so
avoiding extra calls is your only hope.

Let me know if this all makes sense.

Cheers,
Derrick

[dga...@huskers.unl.edu]

Hi Derrick,

Thanks for the info on Rprof. I'm not exactly sure how I should pass info through your python script just from looking at the code, it seems like when I just try to define and load the functions it hits a system error and exits. It's been a while since I've done much with python so if you could give me a refresher that would be great!

Thanks
-Dan
________________________________________
From: treevo-...@googlegroups.com [treevo-...@googlegroups.com] on behalf of Derrick Zwickl [dzw...@gmail.com]
Sent: Wednesday, May 16, 2012 5:58 PM
To: treevo-...@googlegroups.com
Subject: Re: Profiling info

[Derrick Zwickl]

It's simpler than that ;-). Its just a shell script, so just create the
Rprof output file, then from the command line

./parseRprof.py your_output_file

That should do it.

Derrick