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

Change next_call_time computation of rcl_timer to always result in a future timestamp #1089

Merged
merged 1 commit into from
Oct 12, 2023

Conversation

kohrt
Copy link
Contributor

@kohrt kohrt commented Aug 15, 2023

In the current implementation next_call_time can be equal to now after the timer has been called. This can lead to consecutive callback calls with the same timestamp when using sim time.

With this change next_call_time will always be greater than now after the timer has been called.

rcl/src/rcl/timer.c Show resolved Hide resolved
rcl/src/rcl/timer.c Show resolved Hide resolved
@kohrt
Copy link
Contributor Author

kohrt commented Aug 17, 2023

I think, I didn't make it clear in the beginning. We have the issue that timer callbacks of our nodes get called twice with the same timestamp regularly when used in simulation with use_sim_time set to true. I tracked down the problem and tried to create a minimal change that fixes it.

@fujitatomoya
Copy link
Collaborator

I think, I didn't make it clear in the beginning. We have the issue that timer callbacks of our nodes get called twice with the same timestamp regularly when used in simulation with use_sim_time set to true. I tracked down the problem and tried to create a minimal change that fixes it.

@kohrt thanks for sharing the issue. is that possible to share the reproducible test project? that would be helpful to understand details and do further debug.

@kohrt
Copy link
Contributor Author

kohrt commented Aug 18, 2023

Here is the example project: https://github.com/cellumation/timer_test.git

Compile and run ros2 launch timer_test timer_test.yaml. It will output if calls with the same timestamps occure:

[timer_test-1] [WARN] [1692347432.710947829] [timer_test]: same timestamp: 2600000000
[timer_test-1] [WARN] [1692347432.810938363] [timer_test]: same timestamp: 2700000000
[timer_test-1] [WARN] [1692347432.910990966] [timer_test]: same timestamp: 2800000000
[timer_test-1] [WARN] [1692347433.011015172] [timer_test]: same timestamp: 2900000000
[timer_test-1] [WARN] [1692347433.111107161] [timer_test]: same timestamp: 3000000000
[timer_test-1] [WARN] [1692347433.211355448] [timer_test]: same timestamp: 3100000000
[timer_test-1] [WARN] [1692347439.224457634] [timer_test]: same timestamp: 9110000000

Copy link
Collaborator

@fujitatomoya fujitatomoya left a comment

Choose a reason for hiding this comment

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

@kohrt thanks for providing the test project, that really helped me to understand.

i did some experimental check and left a couple of comments, could you share your thought?

CC: @ros2/team

rcl/src/rcl/timer.c Show resolved Hide resolved
rcl/src/rcl/timer.c Show resolved Hide resolved
fujitatomoya added a commit to fujitatomoya/ros2_test_prover that referenced this pull request Aug 20, 2023
…future timestamp

  ros2/rcl#1089

Signed-off-by: Tomoya Fujita <Tomoya.Fujita@sony.com>
@fujitatomoya
Copy link
Collaborator

My local test project, see fujitatomoya/ros2_test_prover@544e615

with the following commands, we can reproduce the problem.

> colcon build --symlink-install --packages-select prover_rclcpp

### Terminal-1
> ros2 run prover_rclcpp rcl_1089 --ros-args -p use_sim_time:=true --ros-args --log-level debug

### Terminal-2
> ros2 run prover_rclcpp sim_clock_publisher 

@clalancette clalancette self-assigned this Aug 31, 2023
rcl/src/rcl/timer.c Show resolved Hide resolved
@clalancette
Copy link
Contributor

and run CI

Actually, that won't work because we've added some APIs in the meantime. @kohrt Can you please go ahead and rebase this? Once that is done I'll run CI.

…r_call.

If next_call_time equals now, consecutive callback calls with the same timestamp can occur when using sim time.

Signed-off-by: Thiemo Kohrt <t.kohrt@cellumation.com>
@kohrt
Copy link
Contributor Author

kohrt commented Oct 12, 2023

Should be rebased now. Thanks for the review @fujitatomoya and @clalancette

@clalancette
Copy link
Contributor

CI:

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Windows Build Status

@clalancette clalancette merged commit 45fc952 into ros2:rolling Oct 12, 2023
3 checks passed
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.

3 participants