ray_speed test running super slow, boost thinking its in debug?

[Tibonium]

Compiling the test without debug turned on from CMake, the test will hang for ad infinitum and must be aborted.

According to Sean, the issue is most likely boost, thinking that it is running in debug mode and shouldn't be.

[campreilly]

I am trying to use uBLAS benhmarks to untangle this problem. First, I downloaded a new copy of Boost 1.52.0 that I'l build from source to the ~/Projects/testlib directory.

• ./bootstrap.sh --prefix=/home/sreilly/Projects/testlib
• ./b2 install

Then I'll build the uBLAS bench1 test using both debug and release options

• cd libs/numeric/ublas/bench1
• ../../../../bjam variant=debug
• ../../../../bjam variant=release

I chose bench1, because it has published times in the uBLAS documentation. Their bench1 example was compiled with GCC 4.0 and run on an Athlon 64 3000+. My test uses g++ 4.6 on an Intel Core i5-2540M running at 2.60 GHz. The times for the product of two 100x100 matrix (fast) elements (using bench1 100) are

• published = 0.76 s, 749 Mflops
• release = 0.34 s, 1674.54 Mflops
• debug = 17.06 s, 33.373 Mflops

Conclusion, my release version is about 2x as fast as the original test and about 50x as fast as the debug version on the same machine.

I then used "-d+2 -n -a" options on bjam to see the options that it used during the compilation:

• release = -ftemplate-depth-128 -O3 -finline-functions -Wno-inline -Wall -fPIC -DBOOST_ALL_NO_LIB=1 -DNDEBUG
• debug = -ftemplate-depth-128 -O0 -fno-inline -Wall -g -fPIC -DBOOST_ALL_NO_LIB=1

I'll investigate each of these options to see what difference they make with our ray_speed application.

[campreilly]

I don't think we need the BOOST_ALL_NO_LIB option. From the boost/config/user.hpp file we have this documentation

// BOOST_ALL_NO_LIB: Tells the config system not to automatically select 
// which libraries to link against.  
// Normally if a compiler supports #pragma lib, then the correct library 
// build variant will be automatically selected and linked against, 
// simply by the act of including one of that library's headers.  
// This macro turns that feature off.

[campreilly]

I think that the -Wno-inline may not be necessary. From the GCC documentation we have:

-Winline Warn if a function that is declared as inline cannot be inlined. Even with this option, the compiler does not warn about failures to inline functions declared in system headers. The compiler uses a variety of heuristics to determine whether or not to inline a function. For example, the compiler takes into account the size of the function being inlined and the amount of inlining that has already been done in the current function. Therefore, seemingly insignificant changes in the source program can cause the warnings produced by -Winline to appear or disappear.

[campreilly]

Next step is to ensure that the problem actually lies in uBLAS optimization and not our code:

• Stub out all of the functionality in ray_speed except the for calculation of ray paths. This eliminates the contributions from environment interpolation and eigenray finding. Ray tracing is the part the relies the most heavily on uBLAS optimization.
• Increase the propagation time to 600 seconds. Set BOOST_ROOT = /home/sreilly/Projects/testlib before configuring CMake to ensure that we are using Boost 1.52 version.
• Re-run ray speed
  • Debug = 151 sec.
  • Release = 10 sec.

The fact that there is a 15:1 speed-up when debugging is turn on, strongly suggests that uBLAS optimization is, in fact, working. And that the problem lies in our code. Or perhaps, there really is not a problem, per se.

[campreilly]

Including or excluding either -ftemplate-depth=x or -finline-functions appears to have no impact on the speed of the Release version. Neither does using static or shared libraries.

[Tibonium]

Upon updating logic for edge_limit and reflection gazing angle, ray_speed now runs for approx 47sec and then crashes again. The crash occurs upon attempting to calculate the rayleigh impedance.

[Tibonium]

Ran stack trace and received the following details regarding latest issue:

0 0xb7f5b559 std::complex::operator/=(this=0xbffff098, __z=...)(/usr/include/c++/4.6/complex:1327)

1 0xb7f5b242 std::operator/(x=..., y=...) (/usr/include/c++/4.6/complex:414)

2 0xb7f5ab2b usml::ocean::reflect_loss_rayleigh::impedence(this=0x80ed8e8, density=1900, speed=1650.0000000000002, attenuation=0.014658711977588555, angle=0.51774960901559475, cosA=0xbffff078) (/home/david/usml/ocean/reflect_loss_rayleigh.cc:127)

3 0xb7f5a513 usml::ocean::reflect_loss_rayleigh::reflect_loss(this=0x80ed8e8, location=..., frequencies=..., angle=0.51774960901559475, amplitude=0xbffff3d0, phase=0xbffff3dc) (/home/david/usml/ocean/reflect_loss_rayleigh.cc:93)

4 0x8069694 usml::ocean::boundary_model::reflect_loss(this=0x80ed4c0, location=..., frequencies=..., angle=0.51774960901559475, amplitude=0xbffff3d0, phase=0xbffff3dc) (/home/david/usml/../usml/ocean/boundary_model.h:120)

5 0xb7f66c55 usml::waveq3d::reflection_model::bottom_reflection(this=0x808a0c0, de=7, az=7, depth=27.505162413232028) (/home/david/usml/waveq3d/reflection_model.cc:109)

6 0xb7f6e238 usml::waveq3d::wave_queue::detect_reflections_bottom(this=0xbffff5f4, de=7, az=7) (/home/david/usml/waveq3d/wave_queue.cc:240)

7 0xb7f6dfb5 usml::waveq3d::wave_queue::detect_reflections(this=0xbffff5f4) (/home/david/usml/waveq3d/wave_queue.cc:203)

8 0xb7f6ddc1 usml::waveq3d::wave_queue::step(this=0xbffff5f4) (/home/david/usml/waveq3d/wave_queue.cc:159)

9 0x8066ffa main(argc=1, argv=0xbffff924) (/home/david/usml/studies/ray_speed/ray_speed.cc:107)

It appears that the test is having a math error, however the error is not an error that would be obvious. (no divide by zero or anything of that sort)

[campreilly]

Suggest that you add a debugging print to see the values of c, density, sinA, cosA, and *cosA. The angle of 30 degrees (0.5235 radians) is right around the spot where the bottom loss for sand goes to almost zero.

[Tibonium]

Added print statement to reflect_loss_rayleigh and ran test again. Test passed without errors. Removed print statement, then test began to fail again. Created a new reflect_loss_test with the parameters that supposedly are creating the crash and found that the test case passes with the provided restrictions.

[Tibonium]

After changing reflect_loss from boundary_grid default to a constant_reflect_loss model, the tests run to completion and within a reasonable time period.

[Tibonium]

Latest run and test of ray_speed shows that this issue has been resolved. Further machine testing is required to verify that this is no longer an issue but it appears that after the changes and clean rebuild of usml resolved the issue.

[Tibonium]

This appears to have resurfaced again.

[Tibonium]

The sound speed for rays close to the boundary of the rayfan are returning NANs. This is independent of using profile_grid or profile_grid_fast. These NAN errors only appear when using these two profile_models, when using profile_linear, the NAN errors are not present.

[Tibonium]

fill_missing() does not function on release build on my system (David), but functions as expected in a debug build.

boost::math::isnan() function is not working properly in release mode using boost 1.51.0. When the code boost::math::isnan() is changed to isnan(), the code does what is expected and fills in the missing numbers, replacing all NaNs.

Also, in order to check this issue, all isnan functions were replaced with code that utilized the fact that NaN == NaN is always false, this code worked within the context of fill_missing(), but would not work appropriately during the constructor of netcdf_profile.

Changing all instances of boost::math::isnan() to isnan(), resolves this issue and ray_speed runs at faster then real time again. The reason why boost::math::isnan() does not work in release mode has yet to be determined.

[campreilly]

Replacing all instances of boost::math::isnan() with std::isnan() has fixed this problem.