3 Measuring and comparing execution times

The first step before optimizing a code is to measure its execution time, in order to compare timings between different implementations.

For this section and the following we refer to the book Advanced R by Hadley Wickham ², freely available online.

3.1 Measuring execution times with system.time()

To measure the execution time of an command, you can use the native system.time() function like this:

obs <- matrix(rep(1.96, 2), nrow=2, ncol=1)
system.time(mvnpdf(x=obs, Log=FALSE))

##    user  system elapsed 
##   0.001   0.001   0.002

The problem that appears in this example is that the execution is so fast that system.time() displays 0 (or a very close value) that will be impossible to compare to an hopefully faster implementation. Also, we see that there is some variability when we run the command several times.

Thus if we want to compare our code with the mvtnorm::dmvnorm() function, we can’t use system.time():

obs <- rep(1.96, 2)
system.time(mvtnorm::dmvnorm(obs))

##    user  system elapsed 
##   0.002   0.001   0.004

We could imagine that we need to increase the complexity of our calculation to be able to compare them, but there is actually a better way: the use of the microbenchmark package!

NB: It can be convenient to add an .R file in your package folder to add those commands (or testing your functions more generally), but do not forget to ignore it from the package building and also optionnally from the git. For that, your can use usethis::use_build_ignore("name_of_file.R") and usethis::use_git_ignore("name_of_file.R").

3.2 Compare execution times with microbenchmark()

As its name indicates, this package allows to compare execution times even when they are very fast. Moreover, each benchmarked expression will be repeatedly evaluated several times, thus stabilizing its timing estimations.

library(microbenchmark)
mb <- microbenchmark(mvtnorm::dmvnorm(rep(1.96, 2)),
                     mvnpdf(x = matrix(rep(1.96,2)), Log = FALSE),
                     times = 1000)

## Warning in microbenchmark(mvtnorm::dmvnorm(rep(1.96, 2)), mvnpdf(x =
## matrix(rep(1.96, : less accurate nanosecond times to avoid potential integer
## overflows

mb

## Unit: microseconds
##                                           expr    min      lq     mean median
##                 mvtnorm::dmvnorm(rep(1.96, 2)) 10.414 11.3980 12.73325 12.341
##  mvnpdf(x = matrix(rep(1.96, 2)), Log = FALSE)  9.799 10.7215 12.88388 11.480
##       uq      max neval
##  13.3865   38.827  1000
##  12.4640 1023.688  1000

Both mvnpdf() and dmnvorm() functions being able to take a matrix as input, we can also compare their speeds in this setting:

n <- 100
mb <- microbenchmark(mvtnorm::dmvnorm(matrix(1.96, nrow = n, ncol = 2)),
                     mvnpdf(x=matrix(1.96, nrow = 2, ncol = n), 
                            Log=FALSE),
                     times=100)
mb

## Unit: microseconds
##                                                       expr     min       lq
##         mvtnorm::dmvnorm(matrix(1.96, nrow = n, ncol = 2))  15.703  17.3840
##  mvnpdf(x = matrix(1.96, nrow = 2, ncol = n), Log = FALSE) 135.546 140.0355
##       mean   median       uq     max neval
##   19.08468  18.2450  19.5775  66.994   100
##  148.45977 146.3085 154.7340 190.732   100

Something happened… And we will find out what exactly is causing this issue in what comes next.