ros2 / rmw_fastrtps

Implementation of the ROS Middleware (rmw) Interface using eProsima's Fast RTPS.
Apache License 2.0
157 stars 117 forks source link

ROS2 examples_rclcpp_minimal_client test fail #677

Open zhukao opened 1 year ago

zhukao commented 1 year ago

Bug report

Required Info:

Steps to reproduce issue

terminal 1 ``` ros2 run examples_rclcpp_minimal_service service_main ``` terminal 2,run bash test.sh ``` #test.sh #!/bin/bash for i in {1..35} do echo $i ros2 run examples_rclcpp_minimal_client client_main & done ``` #### Expected behavior run `bash test.sh` success and recved '[minimal_client]: result of 41 + 1 = 42' 35 times. #### Actual behavior recved '[minimal_client]: result of 41 + 1 = 42' about 15 times and terminal flushs with log: ``` [INFO] [1675664776.051358218] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664776.104662718] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664776.728668135] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664776.752090969] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664776.796690594] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.072884094] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.181419719] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.377985302] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.558767969] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.788203469] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664777.976998553] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664778.138286303] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664778.670482970] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664778.847479511] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664778.972767011] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664779.085595803] [minimal_client]: waiting for service to appear... [INFO] [1675664779.113969636] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664779.127767970] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664779.430923803] [minimal_client]: waiting for service to appear... [INFO] [1675664779.467639887] [minimal_client]: waiting for service to appear... [INFO] [1675664779.664464220] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664779.696623053] [minimal_client]: waiting for service to appear... [INFO] [1675664779.824583137] [minimal_client]: waiting for service to appear... [INFO] [1675664780.027541720] [minimal_client]: waiting for service to appear... [INFO] [1675664780.087177429] [minimal_client]: waiting for service to appear... [INFO] [1675664780.287833012] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.351804679] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.357385345] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.374538095] [minimal_client]: waiting for service to appear... [INFO] [1675664780.410529929] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.431850679] [minimal_client]: waiting for service to appear... [INFO] [1675664780.468385970] [minimal_client]: waiting for service to appear... [INFO] [1675664780.493101429] [minimal_client]: waiting for service to appear... [INFO] [1675664780.500369845] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.514093220] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664780.697583387] [minimal_client]: waiting for service to appear... [INFO] [1675664781.033561679] [minimal_client]: waiting for service to appear... [INFO] [1675664781.087894096] [minimal_client]: waiting for service to appear... [INFO] [1675664781.111166096] [minimal_client]: result of 41 + 1 = 42 [INFO] [1675664781.348420512] [minimal_client]: waiting for service to appear... [INFO] [1675664781.432698929] [minimal_client]: waiting for service to appear... [INFO] [1675664781.469277471] [minimal_client]: waiting for service to appear... [INFO] [1675664781.493870971] [minimal_client]: waiting for service to appear... [INFO] [1675664781.698428513] [minimal_client]: waiting for service to appear... [INFO] [1675664781.871443346] [minimal_client]: waiting for service to appear... [INFO] [1675664781.908048138] [minimal_client]: waiting for service to appear... [INFO] [1675664782.033915138] [minimal_client]: waiting for service to appear... [INFO] [1675664782.080632055] [minimal_client]: waiting for service to appear... [INFO] [1675664782.088659388] [minimal_client]: waiting for service to appear... [INFO] [1675664782.349358680] [minimal_client]: waiting for service to appear... [INFO] [1675664782.433491138] [minimal_client]: waiting for service to appear... [INFO] [1675664782.469945680] [minimal_client]: waiting for service to appear... [INFO] [1675664782.494180805] [minimal_client]: waiting for service to appear... [INFO] [1675664782.698763305] [minimal_client]: waiting for service to appear... [INFO] [1675664782.872066555] [minimal_client]: waiting for service to appear... [INFO] [1675664782.908621972] [minimal_client]: waiting for service to appear... [INFO] [1675664783.034666097] [minimal_client]: waiting for service to appear... [INFO] [1675664783.081224555] [minimal_client]: waiting for service to appear... [INFO] [1675664783.088986305] [minimal_client]: waiting for service to appear... [INFO] [1675664783.349666930] [minimal_client]: waiting for service to appear... [INFO] [1675664783.434136847] [minimal_client]: waiting for service to appear... [INFO] [1675664783.470589180] [minimal_client]: waiting for service to appear... [INFO] [1675664783.494500014] [minimal_client]: waiting for service to appear... [INFO] [1675664783.699889639] [minimal_client]: waiting for service to appear... [INFO] [1675664783.872641597] [minimal_client]: waiting for service to appear... [INFO] [1675664783.908922264] [minimal_client]: waiting for service to appear... ``` #### Additional information If I switch dds to cyclonedds with cmd `export RMW_IMPLEMENTATION=rmw_cyclonedds_cpp`, test.sh runs OK! ---- ## Feature request #### Feature description

Implementation considerations

fujitatomoya commented 1 year ago

related to https://github.com/ros2/rmw_fastrtps/issues/392, service discovery is the known issue. I confirmed that this can be observed with https://github.com/ros2/ros2/commit/036eb0b4e3d144227c30e787cfa5469d8eabf831.

fujitatomoya commented 1 year ago

The problem here is some participants cannot even find the service which is available and response the result as following. some service requesters are stuck in state just to wait until the service is ready. (which is ready)

root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 run examples_rclcpp_minimal_service service_main
[INFO] [1679415531.831507848] [minimal_service]: request: 41 + 1
...
root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 run examples_rclcpp_minimal_client client_main
[INFO] [1679415531.832655212] [minimal_client]: result of 41 + 1 = 42
root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 node list
/minimal_service
root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 service list
/add_two_ints
/minimal_service/describe_parameters
/minimal_service/get_parameter_types
/minimal_service/get_parameters
/minimal_service/list_parameters
/minimal_service/set_parameters
/minimal_service/set_parameters_atomically
root@tomoyafujita:~/ros2_ws/colcon_ws# cat test.sh
#!/bin/bash

for i in {1..35}
do
    echo $i
    ros2 run examples_rclcpp_minimal_client client_main --ros-args -r __node:=my_client_$i &
done

root@tomoyafujita:~/ros2_ws/colcon_ws# ./test.sh
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
root@tomoyafujita:~/ros2_ws/colcon_ws# [INFO] [1679415726.001189401] [my_client_11]: result of 41 + 1 = 42
[INFO] [1679415726.033860994] [my_client_13]: result of 41 + 1 = 42
[INFO] [1679415726.044011517] [my_client_10]: result of 41 + 1 = 42
[INFO] [1679415726.044482451] [my_client_29]: result of 41 + 1 = 42
[INFO] [1679415726.045010030] [my_client_15]: result of 41 + 1 = 42
[INFO] [1679415726.104026266] [my_client_5]: result of 41 + 1 = 42
[INFO] [1679415726.343552874] [my_client_26]: result of 41 + 1 = 42
[INFO] [1679415726.366641854] [my_client_34]: result of 41 + 1 = 42
[INFO] [1679415726.432906268] [my_client_22]: result of 41 + 1 = 42
[INFO] [1679415726.442957139] [my_client_12]: result of 41 + 1 = 42
[INFO] [1679415726.455768454] [my_client_9]: result of 41 + 1 = 42
[INFO] [1679415726.455944256] [my_client_17]: result of 41 + 1 = 42
[INFO] [1679415726.482988199] [my_client_24]: result of 41 + 1 = 42
[INFO] [1679415726.492443702] [my_client_28]: result of 41 + 1 = 42
[INFO] [1679415726.499117249] [my_client_30]: result of 41 + 1 = 42
[INFO] [1679415726.499828156] [my_client_8]: result of 41 + 1 = 42
[INFO] [1679415726.511567688] [my_client_21]: result of 41 + 1 = 42
[INFO] [1679415726.512058944] [my_client_18]: result of 41 + 1 = 42
[INFO] [1679415726.513173598] [my_client_1]: result of 41 + 1 = 42
[INFO] [1679415726.514267817] [my_client_3]: result of 41 + 1 = 42
[INFO] [1679415726.516096605] [my_client_35]: result of 41 + 1 = 42
[INFO] [1679415726.522424238] [my_client_32]: result of 41 + 1 = 42
[INFO] [1679415726.523221009] [my_client_7]: result of 41 + 1 = 42
[INFO] [1679415726.523299414] [my_client_25]: result of 41 + 1 = 42
[INFO] [1679415726.537680232] [my_client_20]: result of 41 + 1 = 42
[INFO] [1679415726.551778461] [my_client_19]: result of 41 + 1 = 42
[INFO] [1679415726.592722411] [my_client_16]: result of 41 + 1 = 42
[INFO] [1679415727.020505285] [my_client_23]: waiting for service to appear...
[INFO] [1679415727.040310150] [my_client_2]: waiting for service to appear...
[INFO] [1679415727.059856848] [my_client_6]: waiting for service to appear...
[INFO] [1679415727.371524989] [my_client_27]: waiting for service to appear...
...<snip>

root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 node list
/minimal_service
/my_client_14
root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 service list
/add_two_ints
/minimal_service/describe_parameters
/minimal_service/get_parameter_types
/minimal_service/get_parameters
/minimal_service/list_parameters
/minimal_service/set_parameters
/minimal_service/set_parameters_atomically
/my_client_14/describe_parameters
/my_client_14/get_parameter_types
/my_client_14/get_parameters
/my_client_14/list_parameters
/my_client_14/set_parameters
/my_client_14/set_parameters_atomically
/my_client_2/describe_parameters
/my_client_2/get_parameter_types
/my_client_2/get_parameters
/my_client_2/list_parameters
/my_client_2/set_parameters
/my_client_2/set_parameters_atomically
/my_client_27/describe_parameters
/my_client_27/get_parameter_types
/my_client_27/get_parameters
/my_client_27/list_parameters
/my_client_27/set_parameters
/my_client_27/set_parameters_atomically
/my_client_33/describe_parameters
/my_client_33/get_parameter_types
/my_client_33/get_parameters
/my_client_33/list_parameters
/my_client_33/set_parameters
/my_client_33/set_parameters_atomically
/my_client_4/describe_parameters
/my_client_4/get_parameter_types
/my_client_4/get_parameters
/my_client_4/list_parameters
/my_client_4/set_parameters
/my_client_4/set_parameters_atomically

root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 run examples_rclcpp_minimal_client client_main
[INFO] [1679415754.492335377] [minimal_client]: result of 41 + 1 = 42
fujitatomoya commented 1 year ago

CC: @iuhilnehc-ynos @MiguelCompany