Comparison between calling ROS1 and ROS2 services with rosbridge

[csimon-be]

Description

We are currently migrating ROS Noetic code to ROS2 Humble and we are facing some weird behavior with rosbridge server. The testing case is the following: we have a simple service server node returning a boolean status called from rosbridge server. The response time is considerably increased in ROS2 comparing to ROS.

If we are missing something, do not hesitate to correct us please.

ROS

Average response time by calling the service directly (without rosbridge): 0.01s (quite stable)
Average response time by calling the service via rosbridge (using the attached web socket script): 0.04s (quite stable)

• Library Version: 0.11.16
• ROS Version: 1 Neotic
• Python version: 3.6
• Platform / OS: linux based

ROS2

Average response time by calling the service directly in a client node (without rosbridge): 0.01s (quite stable)
Average response time by calling the service via rosbridge (using the attached web socket script):0.02s to 0.7s (increasing)

• Library Version: 1.3.1
• ROS Version: 2 Humble
• Python version: 3.10
• Platform / OS: linux based

Steps To Reproduce

We are calling the rosbridge server with "--call_services_in_new_thread" and "true" arguments but it does not make a great difference. The nodes are launched with ros2 run command (one in its own terminal).

1. Launch file

from launch import LaunchDescription
from launch_ros.actions import Node


def generate_launch_description():
    ld = LaunchDescription()

    rosbridge_node = Node(
        package="rosbridge_server",
        executable="rosbridge_websocket",
        name="rosbridge_server_node",
        arguments=["--port", "9090", "--call_services_in_new_thread", "true"],
    )

    ld.add_action(rosbridge_node)

    return ld

2. SRV file

---
bool status

3. Service server file

#!/usr/bin/env python3

import rclpy
from rclpy.node import Node
from rclpy.callback_groups import MutuallyExclusiveCallbackGroup
from rclpy.executors import MultiThreadedExecutor

from std_msgs.msg import Bool
from x_interfaces.srv import GetPauseStatus


class PauseNode(Node):
    def __init__(self):
        super().__init__("pause_node")
        self.in_pause = Bool(data=False)

        self.pause_service = self.create_service(
            GetPauseStatus,
            "get_pause_status",
            self.handle_get_pause_status,
            callback_group=MutuallyExclusiveCallbackGroup(),
        )
        self.get_logger().info("Pause node started!")


def main(args=None):
    # init the node
    rclpy.init(args=args)
    pause_node = PauseNode()
    executor = MultiThreadedExecutor()
    executor.add_node(pause_node)

    try:
        pause_node.get_logger().info("Beginning client, shut down with CTRL-C")
        executor.spin()
    except KeyboardInterrupt:
        pause_node.get_logger().info("Keyboard interrupt, shutting down.\n")
    pause_node.destroy_node()
    rclpy.shutdown()


if __name__ == "__main__":
    main()

4. Service client file

#!/usr/bin/env python3
import rclpy
from rclpy.node import Node
from functools import partial

from otto_interfaces.srv import GetPauseStatus

import time


class GetPauseStatusClientNode(Node):
    def __init__(self):
        super().__init__("get_pause_status_client")
        self.times = []
        self.timer = self.create_timer(0.5, self.call_get_pause_status)


    def call_get_pause_status(self):
        client = self.create_client(GetPauseStatus, "get_pause_status")
        while not client.wait_for_service(1.0):
            self.get_logger().warn("Waiting for Server GetPauseStatus...")
        
        self.tic = time.perf_counter()
        request = GetPauseStatus.Request()

        future = client.call_async(request)
        future.add_done_callback(
            partial(self.callback_call_get_pause_status))

    def callback_call_get_pause_status(self, future):
        try:
            response = future.result()
            toc = time.perf_counter()
            self.get_logger().info(str(response.status))
            self.get_logger().info(f"pause status in {toc - self.tic:0.4f} seconds")
        except Exception as e:
            self.get_logger().error("Service call failed %r" % (e,))


def main(args=None):
    rclpy.init(args=args)
    node = GetPauseStatusClientNode()
    rclpy.spin(node)
    rclpy.shutdown()


if __name__ == "__main__":
    main()

5. Websocket script

from websocket import create_connection
import time



def call_pause_service():
    tic = time.perf_counter()
    
    # advertise_service_msg = '{"op": "advertise_service", "type": GetPauseStatus, "service": "get_pause_status"}'
    # ws.send(advertise_service_msg)

    service_call_msg = '{"op": "call_service", "id": "test_service", "service": "get_pause_status"}'
    ws.send(service_call_msg)

    print(ws.recv())

    # unadvertise_service_msg = '{"op": "unadvertise_service", "service": "get_pause_status"}'
    # ws.send(unadvertise_service_msg)

    toc = time.perf_counter()
    print(f"get move mode in {toc - tic:0.4f} seconds")

ws = create_connection(url="ws://localhost:9090/")

i = 0
while i < 500:
    call_pause_service()
    time.sleep(0.25)
    i += 1
    
ws.close()

Expected Behavior

Similar and stable response time in ROS2 using rosbridge

Actual Behavior

Increasing and higher response time in ROS2 comparing to ROS