speed of check_not_nan

[Daniel Lee]

I'm not convinced that check_not_nan is slow. Although it looks like 5% of the time is spent in check_not_nan() in Michael's profiled code, I think that might be artificial and introduced by setting up the profiler.

I ran src/models/basic_distributions/normal.stan. I compiled it using clang++, O=3. I compiled 2 versions. The first was with what's in the develop branch. In the second, I changed check_not_nan() to return true without testing. Here are the timing results for 5 runs:

Develop, no modifications
0m39.863s
0m40.985s
0m40.834s
0m40.300s
0m40.530s

check_not_nan() returns true always
0m42.330s
0m40.906s
0m41.796s
0m39.764s
0m40.032s

The two executables are indeed different (different sizes). If check_not_nan() was taking 5%, I'd expect the times to be a little faster for the second run, but I'm not seeing it.

I ran each for 10 million iterations, refresh at 10 million, seed set to 1. The commands I used to run the models:

time ./normal --seed=1 --iter=10000000 --refresh=10000000
time ./normal_no_nan_check --seed=1 --iter=10000000 --refresh=10000000

I know this isn't the same model Michael ran. Perhaps in that model, check_not_nan() is throwing an exception?

Daniel

On Fri, May 31, 2013 at 12:03 PM, Michael Betancourt <betan...@gmail.com> wrote:

v1.3.0 Time    New Time     Name

3 %                11.3 %         szone_free_definite_size

6 %                9.4 %           grad_log_prob

6 %                9.4 %           chain()

6 %                7.5 %           free

3 %                7.5 %           tiny_malloc_from_free_list

9%                 5.6%            check_not_nan

NA                 3.7%            ps_point(ps_point const&)

...
Also, why is check_not_nan so slow?

[Bob Carpenter]

On 6/5/13 1:30 PM, Daniel Lee wrote:
> I'm not convinced that check_not_nan is slow. Although it looks like 5% of the time is spent in check_not_nan() in
> Michael's profiled code, I think that might be artificial and introduced by setting up the profiler.
>
> I ran src/models/basic_distributions/normal.stan. I compiled it using clang++, O=3. I compiled 2 versions. The first was
> with what's in the develop branch. In the second, I changed check_not_nan() to return true without testing. Here are the
> timing results for 5 runs:
>
> Develop, no modifications
> 0m39.863s
> 0m40.985s
> 0m40.834s
> 0m40.300s
> 0m40.530s
>
> check_not_nan() returns true always
> 0m42.330s
> 0m40.906s
> 0m41.796s
> 0m39.764s
> 0m40.032s
>
> The two executables are indeed different (different sizes). If check_not_nan() was taking 5%, I'd expect the times to be
> a little faster for the second run, but I'm not seeing it.

That'd translate into about 2s if the return true is
compiled away.

> I ran each for 10 million iterations, refresh at 10 million, seed set to 1. The commands I used to run the models:
> time ./normal --seed=1 --iter=10000000 --refresh=10000000
> time ./normal_no_nan_check --seed=1 --iter=10000000 --refresh=10000000
>
> I know this isn't the same model Michael ran. Perhaps in that model, check_not_nan() is throwing an exception?

That sounds possible.

I was running the Rats example from BUGS. And also
using clang++. I wonder how different the compilers
are in their profiles. I only really care about -O3.

I'll look in the profiler to see if I can see an exception
being thrown. Or if it makes a difference in this model
for some reason.

- Bob

[Michael Betancourt]

I was running most of my profiling on Gaussians, so there shouldn't have been any exceptions.

> --
> You received this message because you are subscribed to the Google Groups "stan development mailing list" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to stan-dev+u...@googlegroups.com.
> For more options, visit https://groups.google.com/groups/opt_out.
>
>

[Daniel Lee]

Can anyone show using O3 and no -g and no profiling that check_not_nan actually takes time? If not, I'd like to table the discussion and suggest we use error checking wherever appropriate.


Daniel

[Bob Carpenter]

On 6/18/13 5:03 PM, Daniel Lee wrote:

> Can anyone show using O3 and no -g and no profiling that check_not_nan
> actually takes time? If not, I'd like to table
> the discussion and suggest we use error checking wherever appropriate.

I just closed the issue.

I was never suggesting to get rid of error checking! I just
suspected an issue with the check_not_nan() implementation.

I'll be more careful to measure functions
independently before submitting another issue based on
profiling an involved function. No idea why the profiler showed
so much time in is_nan().

I couldn't measure a difference (meaning that the between-run
differences were larger than the code differences) between:

1. stan::math::check_not_nan<double,double>("fun",x,"x");

2. if (x != x) return std::numeric_limits<double>::quiet_NaN();

The timing is also the same with x = NaN and x = 0.01.

I also couldn't measure a difference between clang++ and g++.

Then I thought it might all be branch prediction and then checked
every other iteration adding NaN and 0.01, which defeats branch
prediction. That did have an effect. It's about 5% slower under
g++ and 10% slower under clang++. (So in this case, there was
a difference between clang++ and g++.)

I'll append the test code.

- Bob

-------------------
#include <stan/math/error_handling/check_not_nan.hpp>
#include <iostream>
#include <limits>

inline double fun(double x) {
if (x != x) return std::numeric_limits<double>::quiet_NaN();
// stan::math::check_not_nan<double,double>("fun",x,"x");
return x;
}

int main() {
double outer_sum = 0;
for (int m = 0; m < 10000; ++m) {
double sum = 0;
for (int n = 0; n < 1000000; ++n)
sum += fun(std::numeric_limits<double>::quiet_NaN());
// sum += fun(0.001);
// sum += fun(n % 2 == 0 ? 0.01 : std::numeric_limits<double>::quiet_NaN());
outer_sum += sum;
}
std::cout << "outer_sum=" << outer_sum << std::endl;
}
------------------

[Marcus Brubaker]

As I just noted on the github issue, there is also no difference between (x!=x) and boost::math::isnan(x).  I'd suggest that we use boost::math::isnan() in the future to make the code clearer.

--
You received this message because you are subscribed to the Google Groups "stan development mailing list" group.

To unsubscribe from this group and stop receiving emails from it, send an email to stan-dev+unsubscribe@googlegroups.com.

[Bob Carpenter]

On 6/19/13 3:28 PM, Marcus Brubaker wrote:
> As I just noted on the github issue, there is also no difference between (x!=x) and boost::math::isnan(x). I'd suggest
> that we use boost::math::isnan() in the future to make the code clearer.

I think that would be a good change.

So I wrote a quick Java program to test and here
are the only three instances I found:

File=/Users/carp/stan/src/stan/mcmc/hmc/base_hmc.hpp
Line Num=67
Line= if (h != h) h = std::numeric_limits<double>::infinity();

File=/Users/carp/stan/src/stan/mcmc/hmc/base_hmc.hpp
Line Num=85
Line= if (h != h) h = std::numeric_limits<double>::infinity();

File=/Users/carp/stan/src/stan/mcmc/hmc/nuts/base_nuts.hpp
Line Num=199
Line= if (h != h) h = std::numeric_limits<double>::infinity();

- Bob

P.S. Thanks to Mitzi for help with the regex syntax. Given it only
found single-char matches, we added some test cases with longer
ones and the regex found them.

[Michael Betancourt]

Already done in the feature/fix_static_hmc pull request.

> --
> You received this message because you are subscribed to the Google Groups "stan development mailing list" group.

> To unsubscribe from this group and stop receiving emails from it, send an email to stan-dev+u...@googlegroups.com.

[Marcus Brubaker]

Awesome, thanks Mike.

Cheers,

Marcus