1% File src/library/utils/man/Rprof.Rd 2% Part of the R package, https://www.R-project.org 3% Copyright 1995-2018 R Core Team 4% Distributed under GPL 2 or later 5 6\name{Rprof} 7\alias{Rprof} 8\title{Enable Profiling of R's Execution} 9\description{ 10 Enable or disable profiling of the execution of \R expressions. 11} 12\usage{ 13Rprof(filename = "Rprof.out", append = FALSE, interval = 0.02, 14 memory.profiling = FALSE, gc.profiling = FALSE, 15 line.profiling = FALSE, filter.callframes = FALSE, 16 numfiles = 100L, bufsize = 10000L) 17} 18\arguments{ 19 \item{filename}{ 20 The file to be used for recording the profiling results. 21 Set to \code{NULL} or \code{""} to disable profiling. 22 } 23 \item{append}{ 24 logical: should the file be over-written or appended to? 25 } 26 \item{interval}{ 27 real: time interval between samples. 28 } 29 \item{memory.profiling}{logical: write memory use information to the file?} 30 \item{gc.profiling}{logical: record whether GC is running?} 31 \item{line.profiling}{logical: write line locations to the file?} 32 \item{filter.callframes}{logical: filter out intervening call frames 33 of the call tree. See the filtering out call frames section.} 34 \item{numfiles, bufsize}{integers: line profiling memory allocation} 35} 36\details{ 37 Enabling profiling automatically disables any existing profiling to 38 another or the same file. 39 40 Profiling works by writing out the call stack every \code{interval} 41 seconds, to the file specified. Either the \code{\link{summaryRprof}} 42 function or the wrapper script \command{R CMD Rprof} can be used to 43 process the output file to produce a summary of the usage; use 44 \command{R CMD Rprof --help} for usage information. 45 46 How time is measured varies by platform: 47 \describe{ 48 \item{On Windows:}{ 49 Exactly what the time interval measures is subtle: it is time that the 50 \R process is running and executing an \R command. It is not however just 51 CPU time, for if \code{readline()} is waiting for input, that counts 52 (on Windows, but not on a Unix-alike). 53 54 Note that the timing interval cannot be too small, for the time spent 55 in each profiling step is added to the interval. What is feasible is 56 machine-dependent, but 10ms seemed as small as advisable on a 1GHz machine. 57 } 58 \item{On Unix-alikes}{it is the CPU 59 time of the \R process, so for example excludes time when \R is waiting 60 for input or for processes run by \code{\link{system}} to return. 61 62 Note that the timing interval cannot usefully be too small: once the 63 timer goes off, the information is not recorded until the next timing 64 click (probably in the range 1--10 ms). 65 } 66 } 67 68 Functions will only be recorded in the profile log if they put a 69 context on the call stack (see \code{\link{sys.calls}}). Some 70 \link{primitive} functions do not do so: specifically those which are 71 of \link{type} \code{"special"} (see the \sQuote{R Internals} manual 72 for more details). 73 74 Individual statements will be recorded in the profile log if 75 \code{line.profiling} is \code{TRUE}, and if the code being executed 76 was parsed with source references. See \code{\link{parse}} for a 77 discussion of source references. By default the statement locations 78 are not shown in \code{\link{summaryRprof}}, but see that help page 79 for options to enable the display. 80} 81 82\section{Filtering Out Call Frames}{ 83 Lazy evaluation makes the call stack more complex because intervening 84 call frames are created between the time arguments are applied to a 85 function, and the time they are effectively evaluated. When the call 86 stack is represented as a tree, these intervening frames appear as 87 sibling nodes. For instance, evaluating \code{try(EXPR)} produces the 88 following call tree, at the time \code{EXPR} gets evaluated: 89 90\preformatted{ 911. +-base::try(EXPR) 922. | \-base::tryCatch(...) 933. | \-base:::tryCatchList(expr, classes, parentenv, handlers) 944. | \-base:::tryCatchOne(expr, names, parentenv, handlers[[1L]]) 955. | \-base:::doTryCatch(return(expr), name, parentenv, handler) 966. \-EXPR 97} 98 99 Lines 2 to 5 are intervening call frames, the last of which finally 100 triggered evaluation of \code{EXPR}. Setting \code{filter.callframes} 101 to \code{TRUE} simplifies the profiler output by removing all sibling 102 nodes of intervening frames. 103 104 The same kind of call frame filtering is applied with \code{eval()} 105 frames. When you call \code{eval()}, two frames are pushed on the 106 stack to ensure a continuity between frames. Say we have these 107 definitions: 108 109\preformatted{ 110calling <- function() evaluator(quote(called()), environment()) 111evaluator <- function(expr, env) eval(expr, env) 112called <- function() EXPR() 113} 114 115 \code{calling()} calls \code{called()} in its own environment, via 116 \code{eval()}. The latter is called indirectly through 117 \code{evaluator()}. The net effect of this code is identical to just 118 calling \code{called()} directly, without the intermediaries. However, 119 the full call stack looks like this: 120 121 122\preformatted{ 1231. calling() 1242. \-evaluator(quote(called()), environment()) 1253. \-base::eval(expr, env) 1264. \-base::eval(expr, env) 1275. \-called() 1286. \-EXPR() 129} 130 131 When call frame filtering is turned on, the true calling environment 132 of \code{called()} is looked up, and the filtered call stack looks like 133 this: 134 135\preformatted{ 1361. calling() 1375. \-called() 1386. \-EXPR() 139} 140 141 If the calling environment is not on the stack, the function called by 142 \code{eval()} becomes a root node. Say we have: 143 144\preformatted{ 145calling <- function() evaluator(quote(called()), new.env()) 146} 147 148 With call frame filtering we then get the following filtered call 149 stack: 150 151\preformatted{ 1525. called() 1536. \-EXPR() 154} 155 156} 157\note{ 158 \describe{ 159 \item{On Unix-alikes:}{ 160 Profiling is not available on all platforms. By default, 161 support for profiling is compiled in if possible -- configure \R with 162 \option{--disable-R-profiling} to change this. 163 164 As \R profiling uses the same mechanisms as C profiling, the two 165 cannot be used together, so do not use \code{Rprof} in an executable 166 built for C-level profiling. 167 } 168 \item{On Windows:}{ 169 \code{filename} can be a UTF-8-encoded filepath that cannot be translated to 170 the current locale. 171 } 172 } 173 174The profiler interrupts R asynchronously, and it cannot allocate 175memory to store results as it runs. This affects line profiling, 176which needs to store an unknown number of file pathnames. The 177\code{numfiles} and \code{bufsize} arguments control the size of 178pre-allocated buffers to hold these results: the former counts the 179maximum number of paths, the latter counts the numbers of bytes in 180them. If the profiler runs out of space it will skip recording the 181line information for new files, and issue a warning when 182\code{Rprof(NULL)} is called to finish profiling. 183} 184\seealso{ 185 The chapter on \dQuote{Tidying and profiling R code} in 186 \sQuote{Writing R Extensions} (see the \file{doc/manual} subdirectory 187 of the \R source tree). 188 189 \code{\link{summaryRprof}} to analyse the output file. 190 191 \code{\link{tracemem}}, \code{\link{Rprofmem}} for other ways to track 192 memory use. 193} 194\examples{ 195\dontrun{Rprof() 196## some code to be profiled 197Rprof(NULL) 198## some code NOT to be profiled 199Rprof(append = TRUE) 200## some code to be profiled 201Rprof(NULL) 202## ... 203## Now post-process the output as described in Details 204}} 205\keyword{utilities} 206