23.2 Profiling

library(profvis)
library(bench)

The tool to use is a profiler, it allows for sampling the code performance through stopping the execution of code every few milliseconds and recording all the steps.

Example:

f <- function() {
  pause(0.1)
  g()
  h()
}
g <- function() {
  pause(0.1)
  h()
}
h <- function() {
  pause(0.1)
}

Profile the execution of f():

profvis::pause() is used instead of Sys.sleep()
profile f(), with utils::Rprof()

tmp <- tempfile()
Rprof(tmp, interval = 0.1)
f()
#> NULL
Rprof(NULL)
writeLines(readLines(tmp))
#> sample.interval=100000
#> "f" "eval" "eval" "withVisible" "withCallingHandlers" "eval" "eval" "with_handlers" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "withRestarts" "evaluate::evaluate" "evaluate" "in_dir" "in_input_dir" "eng_r" "block_exec" "call_block" "process_group" "withCallingHandlers" "xfun:::handle_error" "process_file" "knitr::knit" "rmarkdown::render" "render_cur_session" "bookdown::render_book" 
#> "pause" "g" "f" "eval" "eval" "withVisible" "withCallingHandlers" "eval" "eval" "with_handlers" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "withRestarts" "evaluate::evaluate" "evaluate" "in_dir" "in_input_dir" "eng_r" "block_exec" "call_block" "process_group" "withCallingHandlers" "xfun:::handle_error" "process_file" "knitr::knit" "rmarkdown::render" "render_cur_session" "bookdown::render_book" 
#> "pause" "h" "g" "f" "eval" "eval" "withVisible" "withCallingHandlers" "eval" "eval" "with_handlers" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "withRestarts" "evaluate::evaluate" "evaluate" "in_dir" "in_input_dir" "eng_r" "block_exec" "call_block" "process_group" "withCallingHandlers" "xfun:::handle_error" "process_file" "knitr::knit" "rmarkdown::render" "render_cur_session" "bookdown::render_book" 
#> "pause" "h" "f" "eval" "eval" "withVisible" "withCallingHandlers" "eval" "eval" "with_handlers" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "doWithOneRestart" "withOneRestart" "withRestartList" "withRestarts" "evaluate::evaluate" "evaluate" "in_dir" "in_input_dir" "eng_r" "block_exec" "call_block" "process_group" "withCallingHandlers" "xfun:::handle_error" "process_file" "knitr::knit" "rmarkdown::render" "render_cur_session" "bookdown::render_book"

Visualising profiles

Makes easier to build up a mental model of what you need to change:

profvis::profvis()
utils::summaryRprof()

source("scripts/profiling-example.R")
profvis(f())

Memory profiling and the garbage collector

Profiling a loop that modifies an existing variable:

profvis::profvis({
  x <- integer()
for (i in 1:1e4) {
  x <- c(x, i)
}
})

You can figure out what is the source of the problem by looking at the memory column. In this case, copy-on-modify acts in each iteration of the loop creating another copy of x.

Limitations

• Profiling does not extend to C code
• Anonymous functions are hard to figure out
• Arguments are evaluated inside another function

23.2.1 Exercise

profvis::profvis({
  f <- function(n = 1e5) {
  x <- rep(1, n)
  rm(x)
}
},torture = TRUE)

?rm()

solution