Re: [R] interpreting profiling output

From: Luke Tierney <luke_at_stat.uiowa.edu>
Date: Mon 26 Jul 2004 - 22:42:12 EST

On Sun, 25 Jul 2004, Peter Dalgaard wrote:

> Kasper Daniel Hansen <k.hansen@biostat.ku.dk> writes:
>
> > I have some trouble interpreting the output from profiling. I have
> > read the help pages Rprof, summaryRprof and consult the R extensions
> > manual, but I still have problems understanding the output.
> >
> > Basically the output consist of self.time and total.time. I have the
> > understanding that total.time is the time spent in a given function
> > including any subcalls or child functions or whatever the technical
> > term for that activity is. In contrasts self.time is the time spent in
> > the function excluding subcalls.
> >
> > Now, in my understanding basically everything in R is functions. I
> > would then guess that for almost any function (except the "atomic
> > ones") the self.time would be very small as it would spend most of its
> > time calling other functions (again, since almost everything is a
> > function). So how do R determine when a subfunction is called?
> ...brutal snippage...
> > I guess some of the answers would be clear if I had a firm grasp of
> > the inner workings of R :)
>
> In a word, yes...
>
> The profiling keeps track of R's *context stack* which is not quite
> the same as function calls. Essentially, it only counts R functions that
> are actually written in R, but not .Internal, .Primitive, etc. So
> "self" counts the amount of time that a function was at the top of the
> stack. This is done by a periodic poll which dumps out the context
> stack at regular intervals. Seeing cases where the self percentages
> don't add to 100% is, I believe, simply due to truncation of the tails
> -- that is, there is a large number of different functions which each
> are counted a few times, and these are not shown in the summary output.
>
> [Sorry about the late reply, but I was out of town, and noone seems to
> have answered this.]

Just one additional clarification: There are two flavors of .Primitive, 'builtin' and 'special'. You can tell which is which using typeof(). Builtins are things like arithmetic operations and specials include control constructs like `for`. At present profiling does record builtins but not specials. Recording specials is something we would like to do eventually but it requires more changes to the call stack (and dealing with more interections with those changes) so it hasn't happened yet. .Internal is a special, so no .Internal calls are recorded.

luke

-- 
Luke Tierney
University of Iowa                  Phone:             319-335-3386
Department of Statistics and        Fax:               319-335-3017
   Actuarial Science
241 Schaeffer Hall                  email:      luke@stat.uiowa.edu
Iowa City, IA 52242                 WWW:  http://www.stat.uiowa.edu

______________________________________________
R-help@stat.math.ethz.ch mailing list
https://www.stat.math.ethz.ch/mailman/listinfo/r-help
PLEASE do read the posting guide! http://www.R-project.org/posting-guide.html
Received on Mon Jul 26 22:49:57 2004

This archive was generated by hypermail 2.1.8 : Wed 03 Nov 2004 - 22:55:14 EST