ROS2 timer callback stops working after a few hours

asked 2018-07-11 07:16:15 -0500

brantolsen gravatar image

I have created a Node class that creates a service (for input), timer (for cleanup), and publisher (for output).

def __init__(self):
   self.srv = self.create_service(SRV_CLASS, 'my_service', self.service_callback)
   self.tmr = self.create_timer(1.0, self.timer_callback)
   self.pub = self.create_publisher(MSG_CLASS, 'my_message')

def timer_callback(self):
    logging.debug(f"Timer: is_cancelled={self.tmr.is_canceled()}, time_since_last_called={self.tmr.time_since_last_call()}, time_until_next_call={self.tmr.time_until_next_call()}, timer_handle={self.tmr.timer_handle}, timer_pointer={self.tmr.timer_pointer}.")
    try:
        expiring = self.get_expired_list()
        for expired in expiring:
            msg = PublishMessage()
            msg.text = "Expiriing"
            self.pub.publish(msg)
    except Exception as e:
        logging.error(e)

The node is run with the following:

rclpy.init(args=args)
node = MyNode()
rclpy.spin(node)

For a few hours with only the timer_callback being called, I get nice output like the following:

[2018-07-10 17:14:08,040][DEBUG] Timer: is_cancelled=False, time_since_last_called=9557, time_until_next_call=999988736, timer_handle=<capsule object "rcl_timer_t" at 0x000001B7AEB090C0>, timer_pointer=1888422158736.
[2018-07-10 17:14:09,041][DEBUG] Timer: is_cancelled=False, time_since_last_called=9557, time_until_next_call=999988736, timer_handle=<capsule object "rcl_timer_t" at 0x000001B7AEB090C0>, timer_pointer=1888422158736.
[2018-07-10 17:14:10,041][DEBUG] Timer: is_cancelled=False, time_since_last_called=10240, time_until_next_call=999988053, timer_handle=<capsule object "rcl_timer_t" at 0x000001B7AEB090C0>, timer_pointer=1888422158736.

Then the timer_callback stops being called. If manually checked, I get the following output:

[2018-07-10 18:43:52,894][DEBUG] Timer: is_cancelled=False, time_since_last_called=18446743157075998461, time_until_next_call=917633551449, timer_handle=<capsule object "rcl_timer_t" at 0x000001B7AEB090C0>, timer_pointer=1888422158736.
[2018-07-11 05:52:50,171][DEBUG] Timer: is_cancelled=False, time_since_last_called=18446739218955848859, time_until_next_call=4855753701392, timer_handle=<capsule object "rcl_timer_t" at 0x000001B7AEB090C0>, timer_pointer=1888422158736.

It does not look like the handle has been garbage collected and it has not been canceled. Is there something I am doing wrong? Or is there something else I can do to debug this? Or should I not use a timer for this logic?

edit retag flag offensive close merge delete

Comments

Can you reproduce the problem with the latest release (ROS 2 Bouncy)? If yes, please create an issue in https://github.com/ros2/rclpy - preferable with a reproducible example which doesn't take a few hours. Thanks.

Dirk Thomas gravatar image Dirk Thomas  ( 2018-08-02 18:22:46 -0500 )edit