ROS2 Actions publish status messages that get exponentially more expensive

edit

I am creating a graphical user interface with PySide6 for my ROS2 Application.

To test it, I am using the GUI to send goals to the examples_rclpy_minimal_action_server server_single_goal server.

In my GUI plumbing, there is a class that wraps the ROS2 ClientGoalHandle called QActionGoal(QObject). This QActionGoal has a property called status and status_str that can be used to get the int and string versions of the status enum. In order for QML to know when to redraw controls that use status and status_str, a signal needs to be emitted. Unfortunately, ClientGoalHandle does not have a on_status_changed_callback, so I have had to subscribe to the hidden topic: See code below:

class QActionGoal(QObject):
    def __init__(self):
        super().__init__()
        self.__handle: Optional[ClientGoalHandle] = None

    def set_handle(self, handle: ClientGoalHandle):
        self.__handle = handle
        cli: ActionClient = self.__handle._action_client
        node: Node = cli._node
        topic_name = cli._action_name + '/_action/status'
        node.create_subscription(GoalStatusArray, topic_name, self.__status_callback, 1)
        retry = 0
        while node.count_publishers(topic_name) == 0:
            if retry > 10:
                raise Exception(f'publisher for {topic_name} not ready')
            retry += 1
            time.sleep(0.1)
        get_logger('action_goal').info(f'subscriber for {topic_name} ready') #TODO change to debug

    def get_status(self) -> int:
        if self.__handle is None:
            return 0
        return self.__handle.status

    def get_status_str(self) -> str:
        return GOAL_STATUS.ENUM(self.get_status()).name

    def __status_callback(self, msg: GoalStatusArray):
        #TODO change to debug
        get_logger('action_goal').info(f'status callback: {[s.status for s in msg.status_list]}')
        current_status: GoalStatus = msg.status_list[-1]
        self.status_changed.emit(current_status.status)

    status_changed = Signal(int)
    status = Property(int, fget=get_status, notify=status_changed)
    status_str = Property(str, fget=get_status_str, notify=status_changed)

The bit to pay attention to is the:

get_logger('action_goal').info(f'status callback: {[s.status for s in msg.status_list]}') in the subscription callback.

When sending the first goal, this prints (as expected):

[INFO action_goal] status callback: [2]
[INFO action_goal] status callback: [4]

Because the goal status first changes to executing, and then to succeeded. But the next time a goal is sent, it prints:

[INFO action_goal] status callback: [4, 2]
[INFO action_goal] status callback: [4, 2]
[INFO action_goal] status callback: [4, 4]
[INFO action_goal] status callback: [4, 4]

4 Messages instead of two, and each of length 2. Why is it both republishing old statuses, and including the history of the status in each message?

This grows exponentially worse The full log after a few action calls is:

[INFO qt_node] Goal accepted for action /fibonacci
[INFO action_goal] subscriber for /fibonacci/_action/status ready
[INFO action_goal] status callback: [2]
[INFO action_goal] status callback: [4]
[INFO qt_node] Calling with {order: 5}
[INFO qt_node] Goal accepted for action /fibonacci
[INFO action_goal] subscriber for /fibonacci/_action/status ready
[INFO action_goal] status callback: [4, 2]
[INFO action_goal] status callback: [4, 2]
[INFO action_goal] status callback: [4, 4]
[INFO action_goal] status callback: [4, 4]
[INFO qt_node] Calling with {order: 5}
[INFO qt_node] Goal accepted for action /fibonacci
[INFO action_goal] subscriber for /fibonacci/_action/status ready
[INFO action_goal] status callback: [4, 4, 2]
[INFO action_goal] status callback: [4, 4, 2 ...