Node seems to unwantedly automatically unsubcribe from topic

asked 2019-12-10 10:31:33 -0500

Chubb gravatar image

updated 2019-12-13 07:39:27 -0500

Hi,

Note: Edits have been made and I found a workaround , see EDIT 5, 6 and 7 below.

General information and context: WIndows 8.1 64-bit running Virtual Box VM: Ubuntu 16.04.6 LTS with ROS Kinetic. I'm running a setup where a Husarion Rosbot 2.0 is driving around in the generic maze world, publishing /odom, /scan and listening to /cmd_vel among other things. The published odometry and laserscan are used by the obstacle_detector package made by tysik (github. This all working fine.

The following is where the issue is: I have written two nodes in python, the first is called obstacle_visualisation and it subscribes to the /obstacles topic that the obstacle_detector is publishing, as well as the /odom topic from Gazebo. It filters on range and reclassifies moving obstacles as agents, then publishes this to the /sfmmpdm_obstacles topic.

rostopic echo /sfmmpdm_obstacles continuously shows filtered obstacle data so this seems to be running correct as well.

The second node is called sfm_mpdm and it subscribers to the /sfmmpdm_obstacles topic as well as the /odom topic. In the callback methods for these subscriptions I have a print statement writing either 'callbackOdom' or 'callbackSFMObs'. The /odom continues to work, but somehow the /sfmmpdm_obstacles topic gets unsubscribed without me telling it to.

The rqt_graph while everything is working looks like:https://imgur.com/V5ooPo3

And when it breaks down it looks like:https://imgur.com/DhPiIgs

Sequentially the printed 'callbackSFMObs' also stop at that moment.

I subscribe to the topics using the following python code:

#!/usr/bin/env python

import rospy;
import numpy as np
import pygame

from obstacle_detector.msg import SFMObstacles
from nav_msgs.msg import Odometry
from geometry_msgs.msg import Twist
from tf.transformations import euler_from_quaternion

def main_loop():
    # Initialize node, publisher and subscribers.
    rospy.init_node('sfm_mpdm')
    rospy.Subscriber("sfmmpdm_obstacles", SFMObstacles, callbackSFMObs)
    rospy.Subscriber("odom", Odometry, callbackOdom)
    pub = rospy.Publisher('cmd_vel', Twist, queue_size = 1)

    # Loop at 'rate' times per second.
    elapsed = 0                 # Initialize in game delta time
    step_count = 0                  # Initialize forward simulation counter
    previous_time = rospy.get_rostime() # Get current time 

    rate = rospy.Rate(100)  # 100 Hz
    while not rospy.is_shutdown():
        # --- Time keeping, run at 100 Hz ---
        now = rospy.get_rostime()
        # Calculate elapsed time between loops in nanoseconds (a.k.a. delta time).
        time_difference =(now - previous_time).to_nsec()    
        previous_time = now
        # Calculate delta time from ms to s.
        seconds = elapsed / 1000.0      
        # Calculate from nanoseconds to milliseconds    
        elapsed = time_difference / 1000000.0   
        # Count the amount of steps in the elapsed time. Default is 10 per second.
        step_count += elapsed / 100.0   


        # Other code that runs in this loop, snipped for readability.

        # --- Set up and publish the /cmd_vel topic to the Rosbot. --- 
        twist = Twist()
        twist.linear.x = twist_linear_x
        twist.linear.y = 0
        twist.linear.z = 0
        twist.angular.x = 0
        twist.angular.y = 0
        twist.angular.z = twist_angular_z
        # pub.publish(twist) 
        rate.sleep()

# --- Starting point ---
if __name__ == '__main__':
    try:
        main_loop()
    except rospy.ROSInterruptException:
        pass

pygame.quit()
quit()

Why does is suddenly stop being subscribed to the /sfmmpdm_obstacles topic (the subscription to the /odom topic continues just fine, which ... (more)

edit retag flag offensive close merge delete

Comments

You probably should put those rate/sleep calls back in.

jordan gravatar image jordan  ( 2019-12-10 12:58:55 -0500 )edit

Is there a way for rate or sleep supply a delta time, like the pygame clock.tick does? Because I need that for the remainder of my code in that node (left out for readability).

Chubb gravatar image Chubb  ( 2019-12-10 13:42:47 -0500 )edit

I would also recommend to store the reference to your rospy.Subscriber instances in a local variable. This will prevent them from going out of scope, destroying the objects and deregistering the subscriptions.

Can you explain why you don't store the result of calling the rospy.Subscriber(..) constructor in a variable?

gvdhoorn gravatar image gvdhoorn  ( 2019-12-10 15:21:05 -0500 )edit

To be honest I didn't know you could store the reference to the Subscriber. I added this as such:

sfmobs_subscriber = rospy.Subscriber("sfmmpdm_obstacles", SFMObstacles, callbackSFMObs)
odom_subscriber = rospy.Subscriber("odom", Odometry, callbackOdom)

But the issue still persists; after a while 10~30 seconds sfmmpdm_obstacles is no longer subscribed to. I have yet to implement the rate and sleep instead of the pygame clock.tick. Trying to figure out how to get delta time from it.

Chubb gravatar image Chubb  ( 2019-12-10 15:48:54 -0500 )edit

That appears to be quite a busy loop you have there. What stops it from pegging the cpu? You probably should have some sort of delay/sleep in there. Does the issue go away when you put those rate/sleep calls back in? I see no reason why you can't have both bits of code running at the same time.

jordan gravatar image jordan  ( 2019-12-10 20:14:34 -0500 )edit

I have replaced the pygame time keeping code with ros specific code and added a delta time function to replace the pygame delta time part. It now looks like this:

rate = rospy.Rate(100)          # 100 Hz
    while not rospy.is_shutdown():
        # --- Time keeping, run at 100 Hz ---
        now = rospy.get_rostime()
        time_difference =(now - previous_time).to_nsec()    # Calculate elapsed time between loops in nanoseconds (a.k.a. delta time).
        previous_time = now
        seconds = elapsed / 1000.0          # Calculate delta time from ms to s.
        elapsed = time_difference / 1000000.0   # Calculate from nanoseconds to milliseconds
        step_count += elapsed / 100.0           # Count the amount of steps in the elapsed time. Default is 10 per second.

        # All other code that is in the loop, snipped for readability

        rate.sleep()

However, after a while the node still unsubsribes.

Chubb gravatar image Chubb  ( 2019-12-12 04:25:26 -0500 )edit
1

I would suggest to take a step back.

Create a minimal node that only subscribes, but doesn't really do anything.

Use regular rate.sleep().

Then start it in combination with the rest of your system (but of course not start your 'real node').

Now observe what happens.

If it still 'unsubscribes', we need to look into aspects outside your script perhaps.

If it doesn't, that would seem to give an indication that it's your code that causes this.

Post the code here, describe what happens and then we can start looking for a cause.

Right now there are too many variables -- including the rest of your application -- which we have no insight into which makes diagnosing this really difficult.

Finally: please update the code you show in your OP with the current state. Right now it still shows the incorrect version of the code.

gvdhoorn gravatar image gvdhoorn  ( 2019-12-12 04:56:55 -0500 )edit
1

I would also not use rqt_graph for this. We're probably only interested in the publications and subscriptions for the particular nodes involved here.

rosnode info and rostopic info would be sufficient for this.

gvdhoorn gravatar image gvdhoorn  ( 2019-12-12 04:58:15 -0500 )edit

I've made a new discovery with important information which should hopefully help pinpoint the issue; see EDIT 5 in the main topic.

Chubb gravatar image Chubb  ( 2019-12-13 04:30:40 -0500 )edit