Why Rcpp::warning() is slower than R warning?

Question

Consider the following functions foo and bar (differs only in printing warning) and their R equivalents fooR and barR:

cppFunction('
void foo () {
  int i = 0;
  while (i < 1e3) {
    i++;
  }
  return;
}')

cppFunction('
void bar () {
  int i = 0;
  while (i < 1e3) {
    i++;
    Rcpp::warning("hello world!");
  }
  return;
}')

fooR <- function() {
  i = 0;
  while (i < 1e3) {
    i = i+1;
  }
}

barR <- function() {
  i = 0;
  while (i < 1e3) {
    i = i+1;
    warning("hello world!")
  }
}

Obviously, printing warnings makes function slower, but the difference between R and Rcpp is huge (200 times slower vs 5000 times slower!):

> benchmark(foo(), bar())
   test replications elapsed relative user.self sys.self user.child sys.child
2 bar()          100   5.156     5156     5.156        0          0         0
1 foo()          100   0.001        1     0.000        0          0         0
There were 50 or more warnings (use warnings() to see the first 50)

> benchmark(fooR(), barR())
    test replications elapsed relative user.self sys.self user.child sys.child
2 barR()          100  11.102    213.5    11.104        0          0         0
1 fooR()          100   0.052      1.0     0.052        0          0         0
There were 50 or more warnings (use warnings() to see the first 50)

Why is it so? Can it be prevented?

Apparently Rcpp has to do more work to send the warning to R's stderr stream. You could look at the source code to investigate this. However, why are you concerned by this? Do you have a use case where so many warnings are common? — Roland
@Roland I need to check input values for exceptions and return warnings in each case -- this is how I noticed that there seems to be this slowdown. — Tim
Hundreds of warnings are not very useful. I'd try to avoid that and use a function for input validation that combines these many warnings into one or very few warnings or possibly even returns an error. — Roland
@Roland agree, but I want to be consistent with base R in what I'm doing and this is a behavior of functions like e.g. dpois that throws warnings for each non-integer etc. — Tim
Are you sure the compiler isn't just optimizing out the entire for loop within foo()? — Kevin Ushey

coatless coatless · Accepted Answer · 2016-06-07T14:03:02

I'm not sure if you realize from your benchmark that Rcpp is:

11.102/5.156 = 2.15322 times faster in throwing a warning
0.052/0.001 = 52 times faster in the pure loop case.

Now, when you are throwing a warning, in both Rcpp and base R, the following is occurring:

Stream to STDERR is opened. (Hence, red text instead of STDOUT's black)
Write message
Close STDERR
Continue instructions.

In Rcpp, the low-level reference helps lower the total amount of time it takes to repeat the above procedure and return control to the loop vs. R's handler that sits higher up on the stack.

Again, the time it takes to complete this with Rcpp is normal as it has to cede control of the process back to R, print the message, then return to the loop. The best way to think about the loss of speed from the pure loop case is you decided to call an R based function in a C++ loop instead of an R loop expecting a speedup.

To be honest, I'm a bit amazed that Rcpp was able to be 2x faster than the R equivalent.

Why Rcpp::warning() is slower than R warning?

1 Answers