23  Profiling R Code

R comes with a profiler to help you optimize your code and improve its performance. Better to get all the bugs out first, then focus on optimizing.

Of course, when it comes to optimizing code, the question is what should you optimize? Well, clearly should optimize the parts of your code that are running slowly, but how do we know what parts those are?

Profiling is a systematic way to examine how much time is spent in different parts of a program.

23.1 system.time()

The system.time() function computes the time (in seconds) needed to execute an expression and if there’s an error, gives the time until the error occurred. Using system.time() allows you to test certain functions or code blocks to see if they are taking excessive amounts of time.

The function returns an object of class proc_time which contains two useful bits of information:

  • user time: time charged to the CPU(s) for this expression.

  • elapsed time: “wall clock” time, the amount of time that passes for you as you’re sitting there.

The elapsed time may be greater than the user time if the CPU spends a lot of time waiting around. The elapsed time may be smaller than the user time if your machine has multiple cores/processors (and is capable of using them).

Here’s an example of where the elapsed time is greater than the user time:

## Elapsed time > user time 
system.time(readLines("http://www.amazon.com")) 
   user  system elapsed 
   0.00    0.00    0.38

You can time longer expressions by wrapping them in curly braces within the call to system.time().

system.time({ 
  ## expression or loop or function
  })

23.2 The R Profiler

system.time() assumes that you already know where the problem is and can call system.time() on that piece of code. What if you don’t know where to start? This is where the profiler comes in handy.

In conjunction with Rprof(), we will use the summaryRprof() function which summarizes the output from Rprof().

Rprof() keeps track of the function call stack at regularly sampled intervals and tabulates how much time is spent inside each function.

The profiler is started by calling the Rprof() function:

Rprof()  ## Turn on the profiler

Once you call the Rprof() function, everything that you do from then on will be measured by the profiler. Therefore, you usually only want to run a single R function or expression once you turn on the profiler and then immediately turn it off.

The profiler can be turned off by passing NULL to Rprof():

Rprof(NULL)  ## Turn off the profiler
summaryRprof()

The summaryRprof() function tabulates the R profiler output and calculates how much time is spend in which function. There are two methods for normalizing the data:

  • “by.total”: divides the time spend in each function by the total run time.
  • “by.self”: does the same as “by.total” but first subtracts out time spent in functions above the current function in the call stack.

The final bit of output that summaryRprof() provides is the sampling interval and the total runtime.

$sample.interval

[1] 0.02

$sampling.time

[1] 7.41