Triggering the Result Callback in an Action Client

I’m struggling to find out if I’m correctly triggering the get_result_callback in my action client. I’m not sure if I’m not correctly publishing the information within the server, or if I’m not correctly calling it in the client. In my action client, I have these callbacks:

    def send_goal(self):
        goal_msg = OdomRecord.Goal()
        self._action_client.wait_for_server()
        self._send_goal_future = self._action_client.send_goal_async(goal_msg, feedback_callback=self.feedback_callback)
        self._send_goal_future.add_done_callback(self.goal_response_callback)

    def goal_response_callback(self, future):
        goal_handle = future.result()
        if not goal_handle.accepted:
            self.get_logger().info('Goal rejected :(')
            return

        self.get_logger().info('Goal accepted :)')
        self._get_result_future = goal_handle.get_result_async()
        self.get_logger().info('Waiting for result..."%s"' % str(self._get_result_future))
        self._get_result_future.add_done_callback(self.get_result_callback)

    def get_result_callback(self, future):
        lapresult = future.result().result
        self.get_logger().info('Result: {0}'.format(lapresult.current_total))
        self.get_logger().info('1 Lap Completed. Stopping Robot')        
        self.movement.angular.z = 0.0
        self.movement.linear.x = 0.0
        self.pubisher_.publish(self.movement)
        rclpy.shutdown()

    def feedback_callback(self, feedback_msg):
        feedback = feedback_msg.feedback
        self.get_logger().info('Dist: {0:.4f}'.format(feedback.current_total))

If I understand correctly, within the goal_response_callback, the ‘add_done_callback’ should trigger when goal_handle.get_result_async() has succeeded. This should then call get_result_callback, but I’ve never gotten that far. I think these callbacks are written correctly, so I thought that I was publishing that information incorrectly within the server. here is my execute_callback and the method it references within (just in case that matters, but I don’t think its relevant).

def execute_callback(self, goal_handle):
        self.get_logger().info('Executing goal...')
        self.execute_goal = True
        self.total_distance = 0.0
        self.first_odom = Point()
        self.last_odom = Point()
        self.odom_record = []
        self.stored_init_meas = False
        while self.execute_goal is True:
            time.sleep(1)
            self.dist_calc()
            goal_handle.publish_feedback(self.feedback_msg)
        #self.get_logger().info('Exited while loop in Execute Callback')
        goal_handle.succeed()
        self.get_logger().info('goal_handle"%s"' % str(goal_handle.succeed))
        result = OdomRecord.Result()
        result.list_of_odoms = self.odom_record
        self.get_logger().info('result"%s"' % str(result))
                
        return result


    def dist_calc(self):
        if len(self.odom_record) >= 2:
            dist_p1_p2 = ((self.odom_record[-1].x - self.odom_record[-2].x) ** 2 + (self.odom_record[-1].y - self.odom_record[-2].y) ** 2) ** 0.5
            self.total_distance += dist_p1_p2

        dist_to_start = (((self.odom_record[-1].x - self.first_odom.x) ** 2 + (self.odom_record[-1].y - self.first_odom.y) ** 2) ** 0.5)

        if dist_to_start < 0.1 and len(self.odom_record) >= 180:
            self.get_logger().info('Robot has returned to the initial position.')
            self.execute_goal = False
            self.stored_init_meas = False
            
        #self.get_logger().info(
        #    f"self.odom_record list length: {len(self.odom_record)}, "
        #    f"total_distance: {self.total_distance:.3f}, "
        #    f"dist_to_start: {dist_to_start:.3f}"
        #)
               
        self.feedback_msg.current_total = self.total_distance
        self.distance_publisher.publish(Float64(data=self.total_distance))

I don’t think the action server is telling the action client that the goal is complete so get_result_callback is never called. What am I missing?

Hi,

To be sure the action server is good, I may use ros2 cli to trigger the action server.

ros2 action send_goal …

https://docs.ros.org/en/foxy/Tutorials/Beginner-CLI-Tools/Understanding-ROS2-Actions/Understanding-ROS2-Actions.html#ros2-action-send-goal

Péter

To clarify, there are no issues sending the goal, executing the goal, or publishing feedback.

Hi @pharva,

I think it is because you are not calling goal_handle.publish_result at the end of your execute_callback.

Here an example of that method being called, and some logs to help you better debug it:

def execute_callback(self, goal_handle):
    self.get_logger().info('Executing goal...')
    self.execute_goal = True
    self.total_distance = 0.0
    self.first_odom = Point()
    self.last_odom = Point()
    self.odom_record = []
    self.stored_init_meas = False

    while self.execute_goal:
        time.sleep(1)
        self.dist_calc()
        goal_handle.publish_feedback(self.feedback_msg)
        self.get_logger().info('Feedback published...')

    self.get_logger().info('Exited while loop in Execute Callback')
    goal_handle.succeed()
    self.get_logger().info('Goal succeeded...')
    
    result = OdomRecord.Result()
    result.list_of_odoms = self.odom_record
    self.get_logger().info('Result prepared...')
    goal_handle.publish_result(result)
    self.get_logger().info('Result published...')

    return result

Please let us know how your tests go after these changes.

Hi @ralves thanks for your reply. Unfortunately, that did not work.

odom_recorder-3] [INFO] [1711123136.196489446] [odom_action_server]: Robot has returned to the initial position.
[odom_recorder-3] [INFO] [1711123136.198758172] [odom_action_server]: Goal succeeded...
[odom_recorder-3] [INFO] [1711123136.199585995] [odom_action_server]: Result prepared...
[odom_recorder-3] [ERROR] [1711123136.200585893] [odom_action_server]: Error raised in execute callback: 'ServerGoalHandle' object has no attribute 'publish_result'

It did not recognize the goal_handle.publish_result command. I thought goal_handle.succeed() was supposed to publish the goal result. Is that right?

Hi @pharva,

I think it may be a logic error in your code.

In the execute_callback method we see that it will run until execute_goal is set to False.

The question now is: Is execute_goal ever being set to False?

I see in the dist_calc that depending on some conditions, the execute_goal is set to False, but we are not sure if those conditions are ever met.

I would suggest you modify the dist_calc method.

You currently have this:

if dist_to_start < 0.1 and len(self.odom_record) >= 180:
    self.get_logger().info('Robot has returned to the initial position.')
    self.execute_goal = False
    self.stored_init_meas = False

I would add an else clause there:

if dist_to_start < 0.1 and len(self.odom_record) >= 180:
    self.get_logger().info('Robot has returned to the initial position.')
    self.execute_goal = False
    self.stored_init_meas = False
else:
    self.get_logger().info('CONDITIONS NOT MET. KEEP GOING....')
    self.get_logger().info(f'LEN: {len(self.odom_record)}')
    self.get_logger().info(f'DIST_TO_START: {dist_to_start}')


If you see CONDITIONS NOT MET. KEEP GOING… printed, you know that either:

  • dist_to_start < 0.1 is false
    or
  • len(self.odom_record) >= 180 is false.

To help you identify where exactly is the error, just check the values of those variables, printed after “CONDITIONS NOT MET. KEEP GOING.

@ralves You are correct: execute_goal is set to False inside of the dist_calc method. The purpose is so that when the robot has completed a lap and returns to the start position, the while loop inside of execute_callback will be exited and goal_handle.succeed() is issued.

dist_calc method runs with no issue and the loggers that I have here

        while self.execute_goal is True:
            time.sleep(1)
            self.dist_calc()
            goal_handle.publish_feedback(self.feedback_msg)
        #self.get_logger().info('Exited while loop in Execute Callback')
        goal_handle.succeed()self.get_logger().info('goal_handle"%s"' % str(goal_handle.succeed))
        result = OdomRecord.Result()
        result.list_of_odoms = self.odom_record
        self.get_logger().info('result"%s"' % str(result))

are only published when the while loop is exited, as expected. This is also shown in my previous reply with the messages printed in the console (these loggers were inserted based on your suggestion):

[odom_recorder-3] [INFO] [1711123136.196489446] [odom_action_server]: Robot has returned to the initial position.
[odom_recorder-3] [INFO] [1711123136.198758172] [odom_action_server]: Goal succeeded...
[odom_recorder-3] [INFO] [1711123136.199585995] [odom_action_server]: Result prepared...
[odom_recorder-3] [ERROR] [1711123136.200585893] [odom_action_server]: Error raised in execute callback: 'ServerGoalHandle' object has no attribute 'publish_result'

Further, dist_to_start and len(self.odom_record) used to be printed along with the current_total distance while I was testing the code. I have removed that logger since I confirmed that they were working correctly. However, to be thorough, I have reinserted that logger.

[odom_recorder-3] [INFO] [1711156362.877279439] [odom_action_server]: self.odom_record list length: 208, total_distance: 5.603, dist_to_start: 0.175
[wall_following-2] [INFO] [1711156362.880808426] [wall_hugger_node]: Current Dist. Traveled: 5.6028
[odom_recorder-3] [INFO] [1711156363.879382948] [odom_action_server]: self.odom_record list length: 209, total_distance: 5.630, dist_to_start: 0.148
[wall_following-2] [INFO] [1711156363.882347458] [wall_hugger_node]: Current Dist. Traveled: 5.6303
[odom_recorder-3] [INFO] [1711156364.881133335] [odom_action_server]: self.odom_record list length: 210, total_distance: 5.659, dist_to_start: 0.119
[wall_following-2] [INFO] [1711156364.884148030] [wall_hugger_node]: Current Dist. Traveled: 5.6589
[odom_recorder-3] [INFO] [1711156365.884403702] [odom_action_server]: Robot has returned to the initial position.
[odom_recorder-3] [INFO] [1711156365.884880385] [odom_action_server]: self.odom_record list length: 211, total_distance: 5.685, dist_to_start: 0.093
[odom_recorder-3] [INFO] [1711156365.885927047] [odom_action_server]: Goal succeeded...
[odom_recorder-3] [INFO] [1711156365.886437158] [odom_action_server]: Result prepared...
[odom_recorder-3] [ERROR] [1711156365.887235502] [odom_action_server]: Error raised in execute callback: 'ServerGoalHandle' object has no attribute 'publish_result'
[wall_following-2] [INFO] [1711156365.887496259] [wall_hugger_node]: Current Dist. Traveled: 5.6854

Here we can see that as the robot approaches the starting point, dist_to_start in approaching 0.1 and len(self.odom_record) is greater than 180. When dist_to_start is <= to 0.1, the while loop exits and the expected loggers are published.

For clarity, I have posted the full code for my action server below:

odom_recorder.py

import rclpy
from rclpy.action import ActionServer
from rclpy.node import Node
from rclpy.qos import ReliabilityPolicy, QoSProfile
from odom_interface.action import OdomRecord
from nav_msgs.msg import Odometry
from geometry_msgs.msg import Point
from geometry_msgs.msg import Twist
from std_msgs.msg import Float64
import time
from rclpy.executors import MultiThreadedExecutor

class OdomActionServer(Node):
    def __init__(self):
        super().__init__('odom_action_server')
        self._action_server = ActionServer(self, OdomRecord, 'record_odom_as', self.execute_callback)
        self.distance_publisher = self.create_publisher(Float64, 'total_distance', 10)
        self.subscriber = self.create_subscription(Odometry, '/odom', self.odom_callback, QoSProfile(depth=10, reliability=ReliabilityPolicy.RELIABLE))
        self.execute_goal = False
        self.stored_init_meas = False
        self.first_odom = Point()
        self.last_odom = Point()
        self.odom_record = []
        self.total_distance = 0.0
        self.last_x = 0.0
        self.last_y = 0.0
        self.timer_odom_record = self.create_timer(1.0, self.update_odom_record)  # make the update_odom_record update only every 1 second
        self.feedback_msg = OdomRecord.Feedback()
        
    def odom_callback(self, msg):
        if self.stored_init_meas == False and self.execute_goal is True:
            self.first_odom.x = msg.pose.pose.position.x
            self.first_odom.y = msg.pose.pose.position.y
            self.odom_record.append(Point(x=self.first_odom.x, y=self.first_odom.y, z=0.0))
            self.stored_init_meas = True
           
        self.last_odom.x = msg.pose.pose.position.x
        self.last_odom.y = msg.pose.pose.position.y

    def update_odom_record(self):
        if self.execute_goal is True:
            self.odom_record.append(Point(x=self.last_odom.x, y=self.last_odom.y, z=0.0))
        

    def execute_callback(self, goal_handle):
        self.get_logger().info('Executing goal...')
        self.execute_goal = True
        self.total_distance = 0.0
        self.first_odom = Point()
        self.last_odom = Point()
        self.odom_record = []
        self.stored_init_meas = False
        while self.execute_goal is True:
            time.sleep(1)
            self.dist_calc()
            goal_handle.publish_feedback(self.feedback_msg)
        #self.get_logger().info('Exited while loop in Execute Callback')
        goal_handle.succeed()
        self.get_logger().info('Goal succeeded...')
    
        result = OdomRecord.Result()
        result.list_of_odoms = self.odom_record
        self.get_logger().info('Result prepared...')
        goal_handle.publish_result(result)
        self.get_logger().info('Result published...')

        return result


    def dist_calc(self):
        if len(self.odom_record) >= 2:
            dist_p1_p2 = ((self.odom_record[-1].x - self.odom_record[-2].x) ** 2 + (self.odom_record[-1].y - self.odom_record[-2].y) ** 2) ** 0.5
            self.total_distance += dist_p1_p2

        dist_to_start = (((self.odom_record[-1].x - self.first_odom.x) ** 2 + (self.odom_record[-1].y - self.first_odom.y) ** 2) ** 0.5)

        if dist_to_start < 0.1 and len(self.odom_record) >= 180:
            self.get_logger().info('Robot has returned to the initial position.')
            self.execute_goal = False
            self.stored_init_meas = False
            
        self.get_logger().info(
           f"self.odom_record list length: {len(self.odom_record)}, "
           f"total_distance: {self.total_distance:.3f}, "
           f"dist_to_start: {dist_to_start:.3f}"
        )
               
        self.feedback_msg.current_total = self.total_distance
        self.distance_publisher.publish(Float64(data=self.total_distance))
       
                

def main(args=None):
    rclpy.init(args=args)
    odom_action_server = OdomActionServer()
    executor = MultiThreadedExecutor(num_threads=4)
    executor.add_node(odom_action_server)
    try:
        executor.spin()
    finally:
        executor.shutdown()
        odom_action_server.destroy_node()
    rclpy.shutdown()

if __name__ == '__main__':
    main()

Hi @pharva,

Good news!

Thank you for sharing the code of your Action Server, class OdomActionServer(Node)

Your Action Server is correct. The problem is in the Action Client.

On your client feedback, this is the code you sent us:

def get_result_callback(self, future):
    lapresult = future.result().result
    self.get_logger().info('Result: {0}'.format(lapresult.current_total))
    self.get_logger().info('1 Lap Completed. Stopping Robot')        
    self.movement.angular.z = 0.0
    self.movement.linear.x = 0.0
    self.pubisher_.publish(self.movement)
    rclpy.shutdown()

On the penultimate line, you have:

self.pubisher_

I think there is a misspelling there. It should be “publisher_” instead of “pubisher_”, right?

This is an error but it is not the main error here.

The get_result_callback is being called. You can check that by printing a logger message before any other code, and adding a logger message between every valid code. Example:

def get_result_callback(self, future):
    self.get_logger().info('[SUCCESS].0 get_result_callback() called')
    lapresult = future.result().result
    self.get_logger().info('[SUCCESS].1 get_result_callback() after result')

    from pprint import pprint 
    pprint(lapresult)

    self.get_logger().info('[SUCCESS].2')

    #   self.get_logger().info('Result: {0}'.format(lapresult.current_total))
    self.get_logger().info('Result: {0}'.format(lapresult.list_of_odoms))
    self.get_logger().info('[SUCCESS].3')
    self.get_logger().info('1 Lap Completed. Stopping Robot')        
    self.movement.angular.z = 0.0
    self.movement.linear.x = 0.0
    # self.pubisher_.publish(self.movement)
    self.publisher_.publish(self.movement)
    rclpy.shutdown()

Please, check the code above and note that I replaced:

self.get_logger().info('Result: {0}'.format(lapresult.current_total))

with

self.get_logger().info('Result: {0}'.format(lapresult.list_of_odoms))

That was the only error.

If you put self.get_logger().info(‘Result: {0}’.format(lapresult.current_total)) back, you will see that the last log message printed is [SUCCESS].2.

So, the main problem is that you are calling lapresult.current_total, but current_total is not a field in the result message, and it gets stuck there for some reason, instead of raising an error.

Using “pprint” as in my example, you can see all the fields of the result message.
In the end, it’s going to be something like this:

odom_interface.action.OdomRecord_Result(
	list_of_odoms=[
		geometry_msgs.msg.Point(x=0.017476935425936316, y=0.5639423945682094, z=0.0), 
		geometry_msgs.msg.Point(x=-0.000763198888377083, y=0.5653908715287039, z=0.0), 
		geometry_msgs.msg.Point(x=-0.025194636210564215, y=0.5665243393352062, z=0.0), 
		geometry_msgs.msg.Point(x=-0.0506627621540793, y=0.567739495765675, z=0.0), 
		geometry_msgs.msg.Point(x=-0.07714774804400157, y=0.568879108892567, z=0.0), 
		geometry_msgs.msg.Point(x=-0.10364598812339251, y=0.5699479755982219, z=0.0), 
		geometry_msgs.msg.Point(x=-0.12911157999629566, y=0.57068765692352, z=0.0), 
		geometry_msgs.msg.Point(x=-0.15461887368383256, y=0.5714974060315241, z=0.0)
	]
)

Please check again your OdomRecord.action to identify the feedback and result fields. In the ROS2 Basics in 5 Days (python) course, on Unit 7 we have the following, when showing the fields on a .action file. :

Tips while testing

  1. In the Action Server code, we see in the logs that “goal_handle.publish_result(result)” is causing errors. You can safely remove that line.
  2. If you have to wait many minutes until there are 180 items on odom_record, it may take some time to debug your system. To make things faster, you can use a code similar to the following:
def execute_callback(self, goal_handle):
    self.get_logger().info('Executing goal...')
    self.execute_goal = True
    self.total_distance = 0.0
    self.first_odom = Point()
    self.last_odom = Point()
    self.odom_record = []
    self.stored_init_meas = False

    count = 1
    while self.execute_goal is True and count < 8:
        count += 1 
        time.sleep(1)
        self.dist_calc()
        goal_handle.publish_feedback(self.feedback_msg)
    #self.get_logger().info('Exited while loop in Execute Callback')
    goal_handle.succeed()
    self.get_logger().info('Goal succeeded...')
    
    result = OdomRecord.Result()
    result.list_of_odoms = self.odom_record
    self.get_logger().info('Result prepared...')

    from pprint import pprint 
    pprint(result)
    self.get_logger().info("ODOM RECORD")
    pprint(self.odom_record)
    self.get_logger().info('Result PRINTED...')

    return result
  1. Note that I just added some log messages, and used pprint to better understand the structure of the result message. Also, note that I added the count variable to make the loop break after 7 seconds instead of 180 interactions, making it faster to debug.

  2. When trying to find a bug, just as I did on get_result_callback, add logs in every line. This is what I (Ruben) personally do when trying to find bugs that are really difficult to find. With log messages, I can clearly identify where the error is and where it is not.

  3. When debugging, it is better to run every ROS node in a terminal, rather than running all nodes using a launch file. Using each terminal for each node is easier to find where the error is.

That was hard to find, but Thank God, we finally smashed that snake (error).

1 Like

You are absolutely correct. lapresult.current_total is not defined as a result of OdomRecord, and is instead a feedback of OdomRecord. What a great catch! I can’t believe something so small was causing the error. Thank you so much for finding that.

I kept thinking that the get_result_callback was never being called because I never saw the first logger displayed, but that logger was exactly what was causing the error.

I’ve spent a lot of time pouring over the examples provided in the ROS2 Basics in 5 Days and comparing it to my code trying to find the discrepancy. I really appreciate your help with finding this error.

1 Like

This topic was automatically closed 5 days after the last reply. New replies are no longer allowed.