Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix integer overflow for oneshot timers. #1382

Merged
merged 3 commits into from
May 10, 2018

Conversation

achim-k
Copy link
Contributor

@achim-k achim-k commented May 1, 2018

I noticed that the robot_state_publisher node takes a significant of cpu time although it's basically doing nothing (urdf with only fixed joints). After debugging a bit, I noticed that the cpu consumption stems from a ros::Timer with oneshot = true:

Interestingly, when stopping the oneshot timer after its callback has been called, almost no cpu is consumed. This I could verify by creating two simple nodes, one that stops the timer and one that doesn't, and comparing their consumed cpu time:

Timer is stopped:

// Stops the oneshot timer after callback execution. No significant cpu usage.
ros::Timer timer;
timer = nh.createTimer(ros::Duration(0.1), [&timer](const ros::TimerEvent&) {
  timer.stop();
}, true /* oneshot */);

Timer is not stopped:

// Oneshot timer not stopped, significant higher cpu usage (~10times as much).
ros::Timer timer;
timer = nh.createTimer(ros::Duration(0.1), [&timer](const ros::TimerEvent&) {
  ;  // no op
}, true /* oneshot */);

Long story short: The reason for the higher cpu usage was an integer overflow for oneshot timers in

int32_t remaining_time = std::max((int32_t)((sleep_end - current).toSec() * 1000.0f), 1);
timers_cond_.timed_wait(lock, boost::posix_time::milliseconds(remaining_time));

with my debug values:

ros::Time sleep_end(2147483647, 999999999);
ros::Time current(1525190218, 443312022);

std::max((int32_t)((sleep_end - current).toSec() * 1000.0f), 1); /*
+                 +|                           |          +    +
|                 +-----    622293429.55    ---+          |    |
|                 |                                       |    |
|                 +-----    -476828920 (overflow)     ----+    |
|                                                              |
+--------------------------   1     ---------------------------+
*/

So it was always sleeping for 1ms, although it could have slept much longer.

@@ -584,7 +584,7 @@ void TimerManager<T, D, E>::threadFunc()
{
// On system time we can simply sleep for the rest of the wait time, since anything else requiring processing will
// signal the condition variable
int32_t remaining_time = std::max((int32_t)((sleep_end - current).toSec() * 1000.0f), 1);
int64_t remaining_time = std::max((int64_t)((sleep_end - current).toSec() * 1000.0f), (int64_t)1);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IMO the second cast should not be required in order for std::max to do the right thing.

Can you also use static_cast vs a c-style cast, please?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

IMO the second cast should not be required in order for std::max to do the right thing.

Gave me the following error in that case: deduced conflicting types for parameter ‘const _Tp’ (‘long int’ and ‘int’). Explicitly templating std::max<int64_t>(...) would probably have been better than casting both arguments. With my latest commit it's a static_cast<int64_t>(std_max<double>(...))

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there something which prevents doing std::max<int64_t>? That does indeed seem better than doing the max against a floating point value that's then cast back to an integer.

@ros ros deleted a comment from achim-k May 10, 2018
@mikepurvis
Copy link
Member

Looks great, thanks for figuring this out and iterating on it!

@mikepurvis mikepurvis merged commit 862105d into ros:melodic-devel May 10, 2018
dirk-thomas pushed a commit that referenced this pull request Aug 9, 2018
* Template std::max instead of casting explicitly.
dirk-thomas pushed a commit that referenced this pull request Aug 20, 2018
* Template std::max instead of casting explicitly.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants