Benchmarking Rcpp code with RcppClock

Microbenchmarking Rcpp code

Benchmarking is awesome. It’s rewarding to find bottlenecks in code, piece apart the trouble-makers, and put together an amazingly fast bit of code.

The microbenchmark R package is my go-to for any R functions, but there isn’t a really nice equivalent for benchmarking in Rcpp. True, there is the internal Rcpp timer, but it’s very rudimentary and especially leaves a lot to be desired on the R side of things.

So I wrote up a new Rcpp package called RcppClock.

• On the Rcpp side you can measure the execution of functions using the std::chrono::high_resolution_clock features. Just call .tick(std::string ticker_label) to start a timer, and .tock(std::string ticker_label) to stop that timer. When you call .stop(std::string R_var_name), the class writes to a global variable in the R environment (no need to wrap or return a clock class from a function).
• On the R side, you’ll magically get a global variable containing timing results at runtime, and you can easily print it to the console (just like a data.frame), or plot it with ggplot2.

A simple example

First, install RcppClock from CRAN.

# install.packages("RcppClock")
library(RcppClock)

Then in your .cpp file, link the RcppClock header with //[[Rcpp::depends(RcppClock)]] (and link to it in your DESCRIPTION file if this is an R package).

//[[Rcpp::depends(RcppClock)]]
#include <RcppClock.h>
#include <thread>

//[[Rcpp::export]]
void sleepy(){
  Rcpp::Clock clock;
  
  clock.tick("both_naps");
  
  clock.tick("short_nap");
  std::this_thread::sleep_for(std::chrono::milliseconds(10));  
  clock.tock("short_nap");
  
  clock.tick("long_nap");
  std::this_thread::sleep_for(std::chrono::milliseconds(100));  
  clock.tock("long_nap");

  clock.tock("both_naps");
  
  // send the times to the R global environment variable, named "naptimes"
  clock.stop("naptimes");
}

.tick(std::string) starts a new timer. Provide a name to record what is being timed.

.tock(std::string) stops a timer. It is important to use the same name as declared in .tick().

.stop(std::string) calculates the duration between all .tick() and .tock() timing results, and creates an object in the R environment with the name provided.

On the R end, we can now do stuff with the “naptimes” variable that was created in the above Rcpp function:

sleepy()
# global variable "naptimes" is now created in the environment
naptimes

## Unit: milliseconds 
##     ticker  mean sd   min   max neval
##  both_naps 128.2 NA 128.2 128.2     1
##   long_nap 109.9 NA 109.9 109.9     1
##  short_nap  18.3 NA  18.3  18.3     1

Timing fibonacci sequences

Here’s a nice example showing how it can be useful to time replicates of a calculation.

Note that if a .tick() with the same name is called multiple times, RcppClock automatically groups the results. On the other hand, it is a bad idea to specify a .tick() without a correspondingly named .tock() – it won’t work.

The following code reproduces the ?fibonacci function example included in the RcppClock package:

int fib(int n) {
  return ((n <= 1) ? n : fib(n - 1) + fib(n - 2));
}

//[[Rcpp::export]]
void fibonacci(std::vector<int> n, int reps = 10) {
  Rcpp::Clock clock;
  
  while(reps-- > 0){
    for(auto number : n){
      clock.tick("fib" + std::to_string(number));
      fib(number);
      clock.tock("fib" + std::to_string(number));
    }
  }
  clock.stop("clock");
}

On the R end, we’ll get an object named “clock”:

fibonacci(n = 25:35, reps = 10)
# global variable "clock" is created in the R global environment
summary(clock, units = "ms")

##    ticker     mean         sd     min     max neval
## 1   fib25  0.29785 0.47960160  0.0000  0.9983    10
## 2   fib26  0.29639 0.47730010  0.0000  0.9980    10
## 3   fib27  0.69853 0.48203219  0.0000  1.0001    10
## 4   fib28  0.99483 0.01664098  0.9681  1.0265    10
## 5   fib29  1.49545 0.53196206  0.9675  2.0229    10
## 6   fib30  2.49632 0.52858752  1.9941  3.0200    10
## 7   fib31  4.18293 0.42422221  3.9610  4.9877    10
## 8   fib32  6.88482 0.73182249  5.9823  7.9801    10
## 9   fib33 11.47170 1.35929765  9.9660 12.9947    10
## 10  fib34 17.80497 1.18372117 16.9205 19.9173    10
## 11  fib35 29.43125 2.67395255 27.9230 34.9051    10

plot(clock)