Controller is taking too long to execute trajectory (the expected upper bound for the trajectory execution was 5.804189 seconds). Stopping trajectory.

[wangnan1987]

Description

sudo apt upgrade

ros-humble-desktop-full/jammy,now 0.10.0-1jammy.20221207.083923 amd64

[move_group-2] [ERROR] [1673059767.408024637] [moveit_ros.trajectory_execution_manager]: Controller is taking too long to execute trajectory (the expected upper bound for the trajectory execution was 5.804189 seconds). Stopping trajectory.
[move_group-2] [INFO] [1673059767.408144691] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Cancelling execution for manipulator_controller

Your environment

• ROS Distro: humble
• OS Version: e.g. Ubuntu 22.04
• Binary build
  ros-humble-moveit/jammy,now 2.5.4-1jammy.20221207.093050 amd64

Expected behaviour

e....it worked fine before the upgrade and I don't know if that's the cause of the problem.

Actual behaviour

Tell us what happens instead

Backtrace or Console output

[INFO] [launch]: All log files can be found below /home/dolphin/.ros/log/2023-01-07-11-03-35-003462-dolphin-ubuntu-7329
[INFO] [launch]: Default logging verbosity is set to INFO
Using load_yaml() directly is deprecated. Use xacro.load_yaml() instead.
[INFO] [robot_state_publisher-1]: process started with pid [7330]
[INFO] [move_group-2]: process started with pid [7332]
[INFO] [rviz2-3]: process started with pid [7334]
[INFO] [ros2_control_node-4]: process started with pid [7336]
[INFO] [spawner-5]: process started with pid [7338]
[INFO] [spawner-6]: process started with pid [7340]
[ros2_control_node-4] [INFO] [1673060616.206920018] [resource_manager]: Loading hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.207717958] [resource_manager]: Initialize hardware 'FakeSystem'
[ros2_control_node-4] [WARN] [1673060616.207759814] [mock_generic_system]: Parsing of optional initial interface values failed or uses a deprecated format. Add initial values for every state interface in the ros2_control.xacro. For example:
[ros2_control_node-4] <state_interface name="velocity">
[ros2_control_node-4] 0.0
[ros2_control_node-4] </state_interface>
[ros2_control_node-4] [INFO] [1673060616.207777753] [resource_manager]: Successful initialization of hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.207825965] [resource_manager]: 'configure' hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.207835902] [resource_manager]: Successful 'configure' of hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.207846775] [resource_manager]: 'activate' hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.207854626] [resource_manager]: Successful 'activate' of hardware 'FakeSystem'
[ros2_control_node-4] [INFO] [1673060616.220024262] [controller_manager]: update rate is 100 Hz
[ros2_control_node-4] [INFO] [1673060616.220362634] [controller_manager]: RT kernel is recommended for better performance
[robot_state_publisher-1] The root link base_link has an inertia specified in the URDF, but KDL does not support a root link with an inertia. As a workaround, you can add an extra dummy link to your URDF.
[robot_state_publisher-1] Link base had 0 children
[robot_state_publisher-1] Link link_1 had 1 children
[robot_state_publisher-1] Link link_2 had 1 children
[robot_state_publisher-1] Link link_3 had 1 children
[robot_state_publisher-1] Link link_4 had 1 children
[robot_state_publisher-1] Link link_5 had 1 children
[robot_state_publisher-1] Link link_6 had 1 children
[robot_state_publisher-1] Link tool0 had 0 children
[robot_state_publisher-1] [INFO] [1673060616.355802854] [robot_state_publisher]: got segment base
[robot_state_publisher-1] [INFO] [1673060616.356028360] [robot_state_publisher]: got segment base_link
[robot_state_publisher-1] [INFO] [1673060616.356059876] [robot_state_publisher]: got segment link_1
[robot_state_publisher-1] [INFO] [1673060616.356079170] [robot_state_publisher]: got segment link_2
[robot_state_publisher-1] [INFO] [1673060616.356097170] [robot_state_publisher]: got segment link_3
[robot_state_publisher-1] [INFO] [1673060616.356114636] [robot_state_publisher]: got segment link_4
[robot_state_publisher-1] [INFO] [1673060616.356132333] [robot_state_publisher]: got segment link_5
[robot_state_publisher-1] [INFO] [1673060616.356149776] [robot_state_publisher]: got segment link_6
[robot_state_publisher-1] [INFO] [1673060616.356167066] [robot_state_publisher]: got segment tool0
[move_group-2] [INFO] [1673060616.426659805] [moveit_rdf_loader.rdf_loader]: Loaded robot model in 0.126917 seconds
[move_group-2] [INFO] [1673060616.426821112] [moveit_robot_model.robot_model]: Loading robot model 'kuka_kr16_2'...
[move_group-2] [INFO] [1673060616.426846982] [moveit_robot_model.robot_model]: No root/virtual joint specified in SRDF. Assuming fixed joint
[move_group-2] [INFO] [1673060616.456326506] [kuka_kr16_2_manipulator_ikfast_solver]: Using empty link_prefix.
[move_group-2] [INFO] [1673060616.555648192] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Publishing maintained planning scene on 'monitored_planning_scene'
[move_group-2] [INFO] [1673060616.555956885] [moveit.ros_planning_interface.moveit_cpp]: Listening to 'joint_states' for joint states
[move_group-2] [INFO] [1673060616.557910519] [moveit_ros.current_state_monitor]: Listening to joint states on topic 'joint_states'
[move_group-2] [INFO] [1673060616.559511745] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Listening to '/attached_collision_object' for attached collision objects
[move_group-2] [INFO] [1673060616.559607182] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Starting planning scene monitor
[move_group-2] [INFO] [1673060616.561020975] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Listening to '/planning_scene'
[move_group-2] [INFO] [1673060616.561067331] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Starting world geometry update monitor for collision objects, attached objects, octomap updates.
[move_group-2] [INFO] [1673060616.562495064] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Listening to 'collision_object'
[move_group-2] [INFO] [1673060616.563799623] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Listening to 'planning_scene_world' for planning scene world geometry
[move_group-2] [WARN] [1673060616.565500299] [moveit.ros.occupancy_map_monitor.middleware_handle]: Resolution not specified for Octomap. Assuming resolution = 0.1 instead
[move_group-2] [ERROR] [1673060616.565551106] [moveit.ros.occupancy_map_monitor.middleware_handle]: No 3D sensor plugin(s) defined for octomap updates
[move_group-2] [INFO] [1673060616.570489033] [moveit.ros_planning_interface.moveit_cpp]: Loading planning pipeline 'pilz_industrial_motion_planner'
[move_group-2] [INFO] [1673060616.580086390] [moveit.pilz_industrial_motion_planner.joint_limits_aggregator]: Reading limits from namespace robot_description_planning
[move_group-2] [INFO] [1673060616.598555778] [moveit.pilz_industrial_motion_planner]: Available plugins: pilz_industrial_motion_planner/PlanningContextLoaderCIRC pilz_industrial_motion_planner/PlanningContextLoaderLIN pilz_industrial_motion_planner/PlanningContextLoaderPTP
[move_group-2] [INFO] [1673060616.598616985] [moveit.pilz_industrial_motion_planner]: About to load: pilz_industrial_motion_planner/PlanningContextLoaderCIRC
[move_group-2] [INFO] [1673060616.601837389] [moveit.pilz_industrial_motion_planner]: Registered Algorithm [CIRC]
[move_group-2] [INFO] [1673060616.601899889] [moveit.pilz_industrial_motion_planner]: About to load: pilz_industrial_motion_planner/PlanningContextLoaderLIN
[move_group-2] [INFO] [1673060616.604079616] [moveit.pilz_industrial_motion_planner]: Registered Algorithm [LIN]
[move_group-2] [INFO] [1673060616.604131453] [moveit.pilz_industrial_motion_planner]: About to load: pilz_industrial_motion_planner/PlanningContextLoaderPTP
[move_group-2] [INFO] [1673060616.606124975] [moveit.pilz_industrial_motion_planner]: Registered Algorithm [PTP]
[move_group-2] [INFO] [1673060616.606177091] [moveit.ros_planning.planning_pipeline]: Using planning interface 'Pilz Industrial Motion Planner'
[move_group-2] [INFO] [1673060616.612946150] [moveit.ros_planning_interface.moveit_cpp]: Loading planning pipeline 'ompl'
[move_group-2] [INFO] [1673060616.647370785] [moveit.ros_planning.planning_pipeline]: Using planning interface 'OMPL'
[move_group-2] [INFO] [1673060616.657351422] [moveit_ros.fix_workspace_bounds]: Param 'ompl.default_workspace_bounds' was not set. Using default value: 10.000000
[move_group-2] [INFO] [1673060616.657427828] [moveit_ros.fix_start_state_bounds]: Param 'ompl.start_state_max_bounds_error' was set to 0.100000
[move_group-2] [INFO] [1673060616.657447034] [moveit_ros.fix_start_state_bounds]: Param 'ompl.start_state_max_dt' was not set. Using default value: 0.500000
[move_group-2] [INFO] [1673060616.657480711] [moveit_ros.fix_start_state_collision]: Param 'ompl.start_state_max_dt' was not set. Using default value: 0.500000
[move_group-2] [INFO] [1673060616.657554271] [moveit_ros.fix_start_state_collision]: Param 'ompl.jiggle_fraction' was set to 0.050000
[move_group-2] [INFO] [1673060616.657573638] [moveit_ros.fix_start_state_collision]: Param 'ompl.max_sampling_attempts' was not set. Using default value: 100
[move_group-2] [INFO] [1673060616.657609524] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Add Time Parameterization'
[move_group-2] [INFO] [1673060616.657624034] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Resolve constraint frames to robot links'
[move_group-2] [INFO] [1673060616.657636718] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Workspace Bounds'
[move_group-2] [INFO] [1673060616.657649191] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State Bounds'
[move_group-2] [INFO] [1673060616.657661361] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State In Collision'
[move_group-2] [INFO] [1673060616.657673604] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State Path Constraints'
[move_group-2] [INFO] [1673060616.667946040] [moveit.ros_planning_interface.moveit_cpp]: Loading planning pipeline 'chomp'
[move_group-2] [INFO] [1673060616.681846309] [moveit.ros_planning.planning_pipeline]: Using planning interface 'CHOMP'
[move_group-2] [INFO] [1673060616.689025667] [moveit_ros.fix_workspace_bounds]: Param 'chomp.default_workspace_bounds' was not set. Using default value: 10.000000
[move_group-2] [INFO] [1673060616.689105097] [moveit_ros.fix_start_state_bounds]: Param 'chomp.start_state_max_bounds_error' was set to 0.100000
[move_group-2] [INFO] [1673060616.689124627] [moveit_ros.fix_start_state_bounds]: Param 'chomp.start_state_max_dt' was not set. Using default value: 0.500000
[move_group-2] [INFO] [1673060616.689158674] [moveit_ros.fix_start_state_collision]: Param 'chomp.start_state_max_dt' was not set. Using default value: 0.500000
[move_group-2] [INFO] [1673060616.689176330] [moveit_ros.fix_start_state_collision]: Param 'chomp.jiggle_fraction' was set to 0.050000
[move_group-2] [INFO] [1673060616.689191284] [moveit_ros.fix_start_state_collision]: Param 'chomp.max_sampling_attempts' was not set. Using default value: 100
[move_group-2] [INFO] [1673060616.689225440] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Add Time Parameterization'
[move_group-2] [INFO] [1673060616.689239984] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Resolve constraint frames to robot links'
[move_group-2] [INFO] [1673060616.689253060] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Workspace Bounds'
[move_group-2] [INFO] [1673060616.689265867] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State Bounds'
[move_group-2] [INFO] [1673060616.689278107] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State In Collision'
[move_group-2] [INFO] [1673060616.689290490] [moveit.ros_planning.planning_pipeline]: Using planning request adapter 'Fix Start State Path Constraints'
[ros2_control_node-4] [INFO] [1673060616.816684451] [controller_manager]: Loading controller 'manipulator_controller'
[ros2_control_node-4] [INFO] [1673060616.860796993] [joint_trajectory_controller.interpolation_methods]: No interpolation method parameter was given. Using the default, VARIABLE_DEGREE_SPLINE.
[ros2_control_node-4] [INFO] [1673060616.876550838] [controller_manager]: Loading controller 'joint_state_broadcaster'
[move_group-2] [INFO] [1673060616.897340760] [moveit.plugins.moveit_simple_controller_manager]: Added FollowJointTrajectory controller for manipulator_controller
[move_group-2] [INFO] [1673060616.897641325] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060616.897686852] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060616.899145231] [moveit_ros.trajectory_execution_manager]: Trajectory execution is managing controllers
[move_group-2] [INFO] [1673060616.899193968] [move_group.move_group]: MoveGroup debug mode is ON
[spawner-5] [INFO] [1673060616.909676767] [spawner_manipulator_controller]: Loaded manipulator_controller
[ros2_control_node-4] [INFO] [1673060616.914023041] [controller_manager]: Configuring controller 'manipulator_controller'
[ros2_control_node-4] [INFO] [1673060616.914249488] [manipulator_controller]: No specific joint names are used for command interfaces. Using 'joints' parameter.
[ros2_control_node-4] [INFO] [1673060616.914346078] [manipulator_controller]: Command interfaces are [position] and state interfaces are [position velocity].
[ros2_control_node-4] [INFO] [1673060616.914386525] [joint_trajectory_controller.interpolation_methods]: No interpolation method parameter was given. Using the default, VARIABLE_DEGREE_SPLINE.
[ros2_control_node-4] [INFO] [1673060616.914400815] [manipulator_controller]: Using 'splines' interpolation method.
[ros2_control_node-4] [INFO] [1673060616.918677111] [manipulator_controller]: Controller state will be published at 50.00 Hz.
[ros2_control_node-4] [INFO] [1673060616.924317461] [manipulator_controller]: Action status changes will be monitored at 20.00 Hz.
[spawner-6] [INFO] [1673060616.954792827] [spawner_joint_state_broadcaster]: Loaded joint_state_broadcaster
[move_group-2] [INFO] [1673060616.961141958] [move_group.move_group]:
[move_group-2]
[move_group-2] ********************************************************
[move_group-2] * MoveGroup using:
[move_group-2] * - ApplyPlanningSceneService
[move_group-2] * - ClearOctomapService
[move_group-2] * - CartesianPathService
[move_group-2] * - ExecuteTrajectoryAction
[move_group-2] * - GetPlanningSceneService
[move_group-2] * - KinematicsService
[move_group-2] * - MoveAction
[move_group-2] * - MotionPlanService
[move_group-2] * - QueryPlannersService
[move_group-2] * - StateValidationService
[move_group-2] ********************************************************
[move_group-2]
[move_group-2] [INFO] [1673060616.961239776] [moveit_move_group_capabilities_base.move_group_context]: MoveGroup context using planning plugin ompl_interface/OMPLPlanner
[move_group-2] [INFO] [1673060616.961328899] [moveit_move_group_capabilities_base.move_group_context]: MoveGroup context initialization complete
[move_group-2] Loading 'move_group/ApplyPlanningSceneService'...
[move_group-2] Loading 'move_group/ClearOctomapService'...
[move_group-2] Loading 'move_group/MoveGroupCartesianPathService'...
[move_group-2] Loading 'move_group/MoveGroupExecuteTrajectoryAction'...
[move_group-2] Loading 'move_group/MoveGroupGetPlanningSceneService'...
[move_group-2] Loading 'move_group/MoveGroupKinematicsService'...
[move_group-2] Loading 'move_group/MoveGroupMoveAction'...
[move_group-2] Loading 'move_group/MoveGroupPlanService'...
[move_group-2] Loading 'move_group/MoveGroupQueryPlannersService'...
[move_group-2] Loading 'move_group/MoveGroupStateValidationService'...
[move_group-2]
[move_group-2] You can start planning now!
[move_group-2]
[ros2_control_node-4] [INFO] [1673060616.972864362] [controller_manager]: Configuring controller 'joint_state_broadcaster'
[ros2_control_node-4] [INFO] [1673060616.973002632] [joint_state_broadcaster]: 'joints' or 'interfaces' parameter is empty. All available state interfaces will be published
[spawner-5] [INFO] [1673060616.972966634] [spawner_manipulator_controller]: Configured and activated manipulator_controller
[spawner-6] [INFO] [1673060617.003077072] [spawner_joint_state_broadcaster]: Configured and activated joint_state_broadcaster
[INFO] [spawner-5]: process has finished cleanly [pid 7338]
[INFO] [spawner-6]: process has finished cleanly [pid 7340]
[rviz2-3] [INFO] [1673060618.805099378] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-3] [INFO] [1673060618.805274874] [rviz2]: OpenGl version: 4.6 (GLSL 4.6)
[rviz2-3] [INFO] [1673060618.906588509] [rviz2]: Stereo is NOT SUPPORTED
[rviz2-3] Warning: class_loader.impl: SEVERE WARNING!!! A namespace collision has occurred with plugin factory for class rviz_default_plugins::displays::InteractiveMarkerDisplay. New factory will OVERWRITE existing one. This situation occurs when libraries containing plugins are directly linked against an executable (the one running right now generating this message). Please separate plugins out into their own library or just don't link against the library and use either class_loader::ClassLoader/MultiLibraryClassLoader to open.
[rviz2-3] at line 253 in /opt/ros/humble/include/class_loader/class_loader/class_loader_core.hpp
[rviz2-3] [ERROR] [1673060622.236545847] [moveit_ros_visualization.motion_planning_frame]: Action server: /recognize_objects not available
[rviz2-3] [INFO] [1673060622.285919925] [moveit_ros_visualization.motion_planning_frame]: MoveGroup namespace changed: / -> . Reloading params.
[rviz2-3] [INFO] [1673060622.561717269] [moveit_rdf_loader.rdf_loader]: Loaded robot model in 0.205484 seconds
[rviz2-3] [INFO] [1673060622.561844229] [moveit_robot_model.robot_model]: Loading robot model 'kuka_kr16_2'...
[rviz2-3] [INFO] [1673060622.561879563] [moveit_robot_model.robot_model]: No root/virtual joint specified in SRDF. Assuming fixed joint
[rviz2-3] [INFO] [1673060622.596258897] [kuka_kr16_2_manipulator_ikfast_solver]: Using empty link_prefix.
[rviz2-3] [INFO] [1673060622.692736843] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Starting planning scene monitor
[rviz2-3] [INFO] [1673060622.694849061] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Listening to '/monitored_planning_scene'
[rviz2-3] [INFO] [1673060622.842009445] [interactive_marker_display_94147833552112]: Connected on namespace: /rviz_moveit_motion_planning_display/robot_interaction_interactive_marker_topic
[rviz2-3] The root link base_link has an inertia specified in the URDF, but KDL does not support a root link with an inertia. As a workaround, you can add an extra dummy link to your URDF.
[rviz2-3] Link base had 0 children
[rviz2-3] Link link_1 had 1 children
[rviz2-3] Link link_2 had 1 children
[rviz2-3] Link link_3 had 1 children
[rviz2-3] Link link_4 had 1 children
[rviz2-3] Link link_5 had 1 children
[rviz2-3] Link link_6 had 1 children
[rviz2-3] Link tool0 had 0 children
[rviz2-3] [INFO] [1673060622.859746901] [moveit_ros_visualization.motion_planning_frame]: group manipulator
[rviz2-3] [INFO] [1673060622.859805441] [moveit_ros_visualization.motion_planning_frame]: Constructing new MoveGroup connection for group 'manipulator' in namespace ''
[rviz2-3] [INFO] [1673060622.881795315] [interactive_marker_display_94147833552112]: Sending request for interactive markers
[rviz2-3] [INFO] [1673060622.898439361] [move_group_interface]: Ready to take commands for planning group manipulator.
[rviz2-3] [INFO] [1673060622.900237120] [moveit_ros_visualization.motion_planning_frame]: group manipulator
[rviz2-3] [INFO] [1673060622.919065456] [interactive_marker_display_94147833552112]: Service response received for initialization
[move_group-2] [INFO] [1673060627.904384207] [moveit_move_group_default_capabilities.move_action_capability]: Received request
[rviz2-3] [INFO] [1673060627.904932422] [move_group_interface]: Plan and Execute request accepted
[move_group-2] [INFO] [1673060627.905038495] [moveit_move_group_default_capabilities.move_action_capability]: executing..
[move_group-2] [INFO] [1673060627.912973317] [moveit_move_group_default_capabilities.move_action_capability]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[move_group-2] [INFO] [1673060627.913270416] [moveit_ros.plan_execution]: Planning attempt 1 of at most 1
[move_group-2] [INFO] [1673060627.913308176] [moveit_move_group_capabilities_base.move_group_capability]: Using planning pipeline 'ompl'
[move_group-2] [INFO] [1673060627.915075468] [moveit.ompl_planning.model_based_planning_context]: Planner configuration 'manipulator' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[move_group-2] [INFO] [1673060627.976579647] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060627.976669731] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060627.976782891] [moveit_ros.trajectory_execution_manager]: Validating trajectory with allowed_start_tolerance 0.01
[move_group-2] [INFO] [1673060627.981360954] [moveit_ros.trajectory_execution_manager]: Starting trajectory execution ...
[move_group-2] [INFO] [1673060627.981467865] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060627.981513723] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673060627.981733997] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: sending trajectory to manipulator_controller
[ros2_control_node-4] [INFO] [1673060627.982416858] [manipulator_controller]: Received new action goal
[ros2_control_node-4] [INFO] [1673060627.982543511] [manipulator_controller]: Accepted new action goal
[move_group-2] [INFO] [1673060627.983208448] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: manipulator_controller started execution
[move_group-2] [INFO] [1673060627.983251349] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Goal request accepted!
[ros2_control_node-4] [INFO] [1673060631.310613324] [manipulator_controller]: Goal reached, success!
[move_group-2] [WARN] [1673060632.132194682] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: waitForExecution timed out
[move_group-2] [ERROR] [1673060632.132298091] [moveit_ros.trajectory_execution_manager]: Controller is taking too long to execute trajectory (the expected upper bound for the trajectory execution was 4.148715 seconds). Stopping trajectory.
[move_group-2] [INFO] [1673060632.132352117] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Cancelling execution for manipulator_controller

[AndyZe]

So I see you're using the FakeInterfaces, not real hardware. That should jump to the commanded positions immediately.

I can't think of any reasons off the top of my head. Did you check over in the ros2_control/ros2_controllers repos to see if there are any related issues?

[wangnan1987]

So I see you're using the FakeInterfaces, not real hardware. That should jump to the commanded positions immediately.

I can't think of any reasons off the top of my head. Did you check over in the ros2_control/ros2_controllers repos to see if there are any related issues?

Thanks for your reply!!

I have another computer and it has not been upgraded.

I tried it with the same configuration file and it worked fine.....the version:11.2.3-1jammy.20220913.042554.

so, as you can see,I'm using the FakeInterfaces,not real hardware,

And I know this is a necessary step for a real robot,but i don't need it.I just need it to generate a trajectory for the real controller to execute.

so, how can I close the "waitting for exec...time out" ...this function in "controller yaml" files...if possible?

[AndyZe]

I don't know the answer off the top of my head, but grepping through the codebase, that print statement happens here:

https://github.com/ros-planning/moveit2/blob/b60ee8eb21af6821cee805e923c23ba89b081730/moveit_ros/planning/trajectory_execution_manager/src/trajectory_execution_manager.cpp#L1396

That's enabled by the flag execution_duration_monitoring_ at L1389, which is set from a parameter at L191. So that's a good hint that you need to add a parameter trajectory_execution.execution_duration_monitoring: false. I think that parameter should go here:

https://github.com/ros-planning/moveit_resources/blob/48ec1162b1e6dbbc9586c3b846c3213eabef4de7/panda_moveit_config/config/moveit_controllers.yaml#L5

I'll open a PR to make this more obvious for others in the future 👍

[wangnan1987]

I don't know the answer off the top of my head, but grepping through the codebase, that print statement happens here:

https://github.com/ros-planning/moveit2/blob/b60ee8eb21af6821cee805e923c23ba89b081730/moveit_ros/planning/trajectory_execution_manager/src/trajectory_execution_manager.cpp#L1396

That's enabled by the flag execution_duration_monitoring_ at L1389, which is set from a parameter at L191. So that's a good hint that you need to add a parameter trajectory_execution.execution_duration_monitoring: false. I think that parameter should go here:

https://github.com/ros-planning/moveit_resources/blob/48ec1162b1e6dbbc9586c3b846c3213eabef4de7/panda_moveit_config/config/moveit_controllers.yaml#L5

I'll open a PR to make this more obvious for others in the future +1

Description

[rviz2-3] [INFO] [1673245436.021457027] [moveit_ros_visualization.motion_planning_frame]: group manipulator
[rviz2-3] [INFO] [1673245436.021517141] [moveit_ros_visualization.motion_planning_frame]: Constructing new MoveGroup connection for group 'manipulator' in namespace ''
[rviz2-3] [INFO] [1673245436.041233397] [interactive_marker_display_94449564000704]: Sending request for interactive markers
[rviz2-3] [INFO] [1673245436.055106065] [move_group_interface]: Ready to take commands for planning group manipulator.
[rviz2-3] [INFO] [1673245436.057417806] [moveit_ros_visualization.motion_planning_frame]: group manipulator
[rviz2-3] [INFO] [1673245436.076035164] [interactive_marker_display_94449564000704]: Service response received for initialization
[move_group-2] [INFO] [1673245440.340490295] [moveit_move_group_default_capabilities.move_action_capability]: Received request
[rviz2-3] [INFO] [1673245440.341107733] [move_group_interface]: Plan and Execute request accepted
[move_group-2] [INFO] [1673245440.341119820] [moveit_move_group_default_capabilities.move_action_capability]: executing..
[move_group-2] [INFO] [1673245440.348321744] [moveit_move_group_default_capabilities.move_action_capability]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[move_group-2] [INFO] [1673245440.348595413] [moveit_ros.plan_execution]: Planning attempt 1 of at most 1
[move_group-2] [INFO] [1673245440.348633400] [moveit_move_group_capabilities_base.move_group_capability]: Using planning pipeline 'ompl'
[move_group-2] [INFO] [1673245440.350429243] [moveit.ompl_planning.model_based_planning_context]: Planner configuration 'manipulator' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[move_group-2] [INFO] [1673245440.418579060] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245440.418659739] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245440.418795023] [moveit_ros.trajectory_execution_manager]: Validating trajectory with allowed_start_tolerance 0.05
[move_group-2] [INFO] [1673245440.427854779] [moveit_ros.trajectory_execution_manager]: Starting trajectory execution ...
[move_group-2] [INFO] [1673245440.428038569] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245440.428092855] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245440.428338785] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: sending trajectory to manipulator_controller
[ros2_control_node-4] [INFO] [1673245440.429466132] [manipulator_controller]: Received new action goal
[ros2_control_node-4] [INFO] [1673245440.429662859] [manipulator_controller]: Accepted new action goal
[move_group-2] [INFO] [1673245440.430290461] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: manipulator_controller started execution
[move_group-2] [INFO] [1673245440.430347941] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Goal request accepted!
[ros2_control_node-4] [INFO] [1673245444.237124411] [manipulator_controller]: Goal reached, success!
[move_group-2] [INFO] [1673245444.281109790] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Controller 'manipulator_controller' successfully finished
[move_group-2] [INFO] [1673245444.307895013] [moveit_ros.trajectory_execution_manager]: Completed trajectory execution with status SUCCEEDED ...
[move_group-2] [INFO] [1673245444.318544886] [moveit_move_group_default_capabilities.move_action_capability]: Solution was found and executed.
[rviz2-3] [INFO] [1673245444.320210459] [move_group_interface]: Plan and Execute request complete!
[rviz2-3] [WARN] [1673245445.345379321] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Maybe failed to update robot state, time diff: 0.098s
[move_group-2] [INFO] [1673245454.072666512] [moveit_move_group_default_capabilities.move_action_capability]: Received request
[move_group-2] [INFO] [1673245454.073284387] [moveit_move_group_default_capabilities.move_action_capability]: executing..
[rviz2-3] [INFO] [1673245454.073371620] [move_group_interface]: Plan and Execute request accepted
[move_group-2] [INFO] [1673245454.078074420] [moveit_move_group_default_capabilities.move_action_capability]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[move_group-2] [INFO] [1673245454.078311529] [moveit_ros.plan_execution]: Planning attempt 1 of at most 1
[move_group-2] [INFO] [1673245454.078348999] [moveit_move_group_capabilities_base.move_group_capability]: Using planning pipeline 'ompl'
[move_group-2] [INFO] [1673245454.079393000] [moveit.ompl_planning.model_based_planning_context]: Planner configuration 'manipulator' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[move_group-2] [INFO] [1673245454.153848040] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245454.153937960] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245454.154193582] [moveit_ros.trajectory_execution_manager]: Validating trajectory with allowed_start_tolerance 0.05
[move_group-2] [INFO] [1673245454.158285303] [moveit_ros.trajectory_execution_manager]: Starting trajectory execution ...
[move_group-2] [INFO] [1673245454.158409837] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245454.158469530] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245454.158678280] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: sending trajectory to manipulator_controller
[ros2_control_node-4] [INFO] [1673245454.159443228] [manipulator_controller]: Received new action goal
[ros2_control_node-4] [INFO] [1673245454.159572148] [manipulator_controller]: Accepted new action goal
[move_group-2] [INFO] [1673245454.160014320] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: manipulator_controller started execution
[move_group-2] [INFO] [1673245454.160050957] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Goal request accepted!
[ros2_control_node-4] [INFO] [1673245457.967095766] [manipulator_controller]: Goal reached, success!
[move_group-2] [INFO] [1673245458.010657942] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Controller 'manipulator_controller' successfully finished
[move_group-2] [INFO] [1673245458.037964057] [moveit_ros.trajectory_execution_manager]: Completed trajectory execution with status SUCCEEDED ...
[move_group-2] [INFO] [1673245458.038523546] [moveit_move_group_default_capabilities.move_action_capability]: Solution was found and executed.
[rviz2-3] [INFO] [1673245458.039992667] [move_group_interface]: Plan and Execute request complete!
[rviz2-3] [WARN] [1673245459.076846761] [moveit_ros.planning_scene_monitor.planning_scene_monitor]: Maybe failed to update robot state, time diff: 0.090s
[move_group-2] [INFO] [1673245462.940482814] [moveit_move_group_default_capabilities.move_action_capability]: Received request
[rviz2-3] [INFO] [1673245462.941230616] [move_group_interface]: Plan and Execute request accepted
[move_group-2] [INFO] [1673245462.941251859] [moveit_move_group_default_capabilities.move_action_capability]: executing..
[move_group-2] [INFO] [1673245462.947740055] [moveit_move_group_default_capabilities.move_action_capability]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[move_group-2] [INFO] [1673245462.947891825] [moveit_ros.plan_execution]: Planning attempt 1 of at most 1
[move_group-2] [INFO] [1673245462.947943085] [moveit_move_group_capabilities_base.move_group_capability]: Using planning pipeline 'ompl'
[move_group-2] [INFO] [1673245462.948794966] [moveit.ompl_planning.model_based_planning_context]: Planner configuration 'manipulator' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[move_group-2] [INFO] [1673245463.010142182] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245463.010241481] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245463.010414685] [moveit_ros.trajectory_execution_manager]: Validating trajectory with allowed_start_tolerance 0.05
[move_group-2] [INFO] [1673245463.017839374] [moveit_ros.trajectory_execution_manager]: Starting trajectory execution ...
[move_group-2] [INFO] [1673245463.017956034] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245463.018012051] [moveit.plugins.moveit_simple_controller_manager]: Returned 1 controllers in list
[move_group-2] [INFO] [1673245463.018243464] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: sending trajectory to manipulator_controller
[ros2_control_node-4] [INFO] [1673245463.018824342] [manipulator_controller]: Received new action goal
[ros2_control_node-4] [INFO] [1673245463.018954986] [manipulator_controller]: Accepted new action goal
[move_group-2] [INFO] [1673245463.019440975] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: manipulator_controller started execution
[move_group-2] [INFO] [1673245463.019484521] [moveit.simple_controller_manager.follow_joint_trajectory_controller_handle]: Goal request accepted!
[ros2_control_node-4] [INFO] [1673245466.237073804] [manipulator_controller]: Goal reached, success!

Problem

Hi,I'm sorry to trouble you again...

There is a new problem after I modify the "moveit_controller.yaml" file.
I was devastated.

The console output stopped ...

in rviz:

in c++ move_group_interface

so...what happend?

ps:

it also worked fine with docker...

And docker plug-in version:

ros-humble-moveit/jammy 2.5.3-1jammy.20221108.223459 amd64 [upgradable from: 2.5.3-1jammy.20221026.131039]
ros-humble-moveit/now 2.5.3-1jammy.20221026.131039 amd64 [installed,upgradable to: 2.5.3-1jammy.20221108.223459]

ros-humble-rviz2/jammy 11.2.4-1jammy.20221108.210303 amd64 [upgradable from: 11.2.3-1jammy.20221019.180719]
ros-humble-rviz2/now 11.2.3-1jammy.20221019.180719 amd64 [installed,upgradable to: 11.2.4-1jammy.20221108.210303]

ros-humble-desktop-full/jammy 0.10.0-1jammy.20221109.192604 amd64 [upgradable from: 0.10.0-1jammy.20221101.204035]
ros-humble-desktop-full/now 0.10.0-1jammy.20221101.204035 amd64 [installed,upgradable to: 0.10.0-1jammy.20221109.192604]

[AndyZe]

What you're trying to show from the 2 images is that it worked fine from RViz, but from your move_group program, the program seems to pause or deadlock? Very strange. I guess it is deadlocked on this line:

https://github.com/ros-planning/moveit2/blob/b60ee8eb21af6821cee805e923c23ba89b081730/moveit_ros/planning/trajectory_execution_manager/src/trajectory_execution_manager.cpp#L1411

Have you tried switching to Cyclone middleware? It's a very simple switch:

sudo apt install ros-humble-rmw-cyclonedds-cpp
# You may want to add this to ~/.bashrc to source it automatically
export RMW_IMPLEMENTATION=rmw_cyclonedds_cpp

[wangnan1987]

export RMW_IMPLEMENTATION=rmw_cyclonedds_cpp

Thanks!!!!!!!!!!!!!!!!!!

It's ok now!!!

[SARAWIN-BK-7]

I'm stuck with the same problem. but i tried to improve it The result is still the same. Is there another way? I use moveit 1 noetic.

[TZECHIN6]

I am facing the exact problem in Moveit2 Humble build, i am using real UR5e arm and just want to try out the moveit shown in the example...

I have already install and swtich to cyclonedds, have you also pass any configuration of cyclonedds? as so far switching to cyclone dont solve this for me.

[ycheng517]

I'm using ros2 iron with gazebo and also still running into this issue with both the default RMW and CycloneDDS