search

PilzDE / pilz_robots

PILZ robot manipulator module PRBT 6 in ROS
https://wiki.ros.org/pilz_robots
52 stars 25 forks source link

acceptance_test_speed_monitoring fails when executed on real robot #433

Closed hslusarek closed 4 years ago

hslusarek commented 4 years ago

Commit

9aa67f91c75c1fd240d0562a6ef31a49bb264db9 on melodic-devel

Steps to reproduce

Execute test as described in acceptance_test_speed_monitoring.md until (including) step 2.

Observed behavior

Test fails in T1 at step 2 of acceptance_test_speed_monitoring.md with:

[ROSUNIT] Outputting test results to /home/hslusarek/.ros/test_results/pilz_control/rosunit-acceptance_test_speed_monitoring.xml
[INFO] [1593613437.052367]: Move to start position
[INFO] [1593613447.179552]: Test speed monitoring in T1 mode
[INFO] [1593613447.181057]: Determine target velocity for reaching the speed limit
[INFO] [1593613454.805999]: Move to start position
[Testcase: test_reduced_speed_mode] ... FAILURE!
FAILURE: Speed limit of 0.25[m/s] was violated
  File "/usr/lib/python2.7/unittest/case.py", line 329, in run
    testMethod()
  File "/home/hslusarek/catkin_ws/src/pilz_robots/pilz_control/test/acceptance_test_speed_monitoring.py", line 149, in test_reduced_speed_mode
    self.assertGreater(_SPEED_LIMIT, self._max_frame_speed.get(), 'Speed limit of 0.25[m/s] was violated')
  File "/usr/lib/python2.7/unittest/case.py", line 943, in assertGreater
    self.fail(self._formatMessage(msg, standardMsg))
  File "/usr/lib/python2.7/unittest/case.py", line 410, in fail
    raise self.failureException(msg)
--------------------------------------------------------------------------------
-------------------------------------------------------------
SUMMARY:
 * RESULT: FAIL
 * TESTS: 1
 * ERRORS: 0 []
 * FAILURES: 1 [test_reduced_speed_mode]

Expected behavior

Test should run at real robot without problems.

Logfiles

roslaunch prbt_moveit_config moveit_planning_execution.launch sim:=False pipeline:=pilz_command_planner
... logging to /home/hslusarek/.ros/log/5f3a74ee-bba6-11ea-9122-84a93e5e04ca/roslaunch-titan-20147.log
Checking log directory for disk usage. This may take a while.
Press Ctrl-C to interrupt
Done checking log file disk usage. Usage is <1GB.

xacro: in-order processing became default in ROS Melodic. You can drop the option.
xacro: in-order processing became default in ROS Melodic. You can drop the option.
xacro: in-order processing became default in ROS Melodic. You can drop the option.
xacro: in-order processing became default in ROS Melodic. You can drop the option.
started roslaunch server http://titan:37631/

SUMMARY
========

CLEAR PARAMETERS
 * /prbt/driver/

PARAMETERS
 * /controller_joint_names: ['prbt_joint_1', ...
 * /move_group/allow_trajectory_execution: True
 * /move_group/capabilities: pilz_trajectory_g...
 * /move_group/controller_list: [{'action_ns': 'f...
 * /move_group/disable_capabilities: 
 * /move_group/jiggle_fraction: 0.05
 * /move_group/max_range: 5.0
 * /move_group/max_safe_path_cost: 1
 * /move_group/moveit_controller_manager: moveit_simple_con...
 * /move_group/moveit_manage_controllers: True
 * /move_group/octomap_resolution: 0.025
 * /move_group/planning_plugin: pilz::CommandPlanner
 * /move_group/planning_scene_monitor/publish_geometry_updates: True
 * /move_group/planning_scene_monitor/publish_planning_scene: True
 * /move_group/planning_scene_monitor/publish_state_updates: True
 * /move_group/planning_scene_monitor/publish_transforms_updates: True
 * /move_group/request_adapters: 
 * /move_group/start_state_max_bounds_error: 0.1
 * /move_group/trajectory_execution/allowed_execution_duration_scaling: 1.2
 * /move_group/trajectory_execution/allowed_goal_duration_margin: 0.5
 * /move_group/trajectory_execution/allowed_start_tolerance: 0.01
 * /prbt/driver/bus/device: can0
 * /prbt/driver/defaults/eds_file: config/prbt_0_1.dcf
 * /prbt/driver/defaults/eds_pkg: prbt_support
 * /prbt/driver/name: manipulator
 * /prbt/driver/nodes/prbt_joint_1/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_1/id: 3
 * /prbt/driver/nodes/prbt_joint_2/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_2/id: 4
 * /prbt/driver/nodes/prbt_joint_3/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_3/id: 5
 * /prbt/driver/nodes/prbt_joint_4/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_4/id: 6
 * /prbt/driver/nodes/prbt_joint_5/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_5/id: 7
 * /prbt/driver/nodes/prbt_joint_6/braketest_required: True
 * /prbt/driver/nodes/prbt_joint_6/id: 8
 * /prbt/driver/sync/interval_ms: 10
 * /prbt/driver/sync/overflow: 0
 * /prbt/joint_names: ['prbt_joint_1', ...
 * /prbt/manipulator_joint_state_controller/publish_rate: 50
 * /prbt/manipulator_joint_state_controller/type: joint_state_contr...
 * /prbt/manipulator_joint_trajectory_controller/action_monitor_rate: 10
 * /prbt/manipulator_joint_trajectory_controller/constraints/goal_time: 0.6
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_1/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_1/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_2/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_2/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_3/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_3/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_4/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_4/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_5/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_5/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_6/goal: 0.01
 * /prbt/manipulator_joint_trajectory_controller/constraints/prbt_joint_6/trajectory: 0.157
 * /prbt/manipulator_joint_trajectory_controller/constraints/stopped_velocity_tolerance: 0.05
 * /prbt/manipulator_joint_trajectory_controller/joints: ['prbt_joint_1', ...
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_1/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_1/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_2/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_2/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_3/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_3/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_4/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_4/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_5/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_5/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_6/has_acceleration_limits: True
 * /prbt/manipulator_joint_trajectory_controller/limits/prbt_joint_6/max_acceleration: 4.0
 * /prbt/manipulator_joint_trajectory_controller/required_drive_mode: 7
 * /prbt/manipulator_joint_trajectory_controller/state_publish_rate: 25
 * /prbt/manipulator_joint_trajectory_controller/stop_trajectory_duration: 0.2
 * /prbt/manipulator_joint_trajectory_controller/type: position_controll...
 * /prbt/max_command_silence: 0.5
 * /prbt/pilz_modbus_client_node/modbus_server_ip: 192.168.0.10
 * /prbt/pilz_modbus_client_node/modbus_server_port: 502
 * /prbt/read_api_spec/BRAKETEST_REQUEST: 973
 * /prbt/read_api_spec/OPERATION_MODE: 970
 * /prbt/read_api_spec/RUN_PERMITTED: 974
 * /prbt/read_api_spec/VERSION: 977
 * /prbt/write_api_spec/BRAKETEST_PERFORMED: 982
 * /prbt/write_api_spec/BRAKETEST_RESULT: 983
 * /prbt/write_api_spec/ENABLE_TEMPORARY_MOVEMENT: 979
 * /robot_description: <?xml version="1....
 * /robot_description_kinematics/manipulator/kinematics_solver: prbt_manipulator/...
 * /robot_description_kinematics/manipulator/kinematics_solver_search_resolution: 0.005
 * /robot_description_kinematics/manipulator/kinematics_solver_timeout: 0.005
 * /robot_description_kinematics/manipulator/link_prefix: prbt_
 * /robot_description_planning/cartesian_limits/max_rot_vel: 1.57
 * /robot_description_planning/cartesian_limits/max_trans_acc: 2.25
 * /robot_description_planning/cartesian_limits/max_trans_dec: -5
 * /robot_description_planning/cartesian_limits/max_trans_vel: 1
 * /robot_description_planning/joint_limits/prbt_joint_1/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_1/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_1/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_1/max_velocity: 1.57
 * /robot_description_planning/joint_limits/prbt_joint_2/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_2/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_2/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_2/max_velocity: 1.57
 * /robot_description_planning/joint_limits/prbt_joint_3/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_3/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_3/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_3/max_velocity: 1.57
 * /robot_description_planning/joint_limits/prbt_joint_4/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_4/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_4/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_4/max_velocity: 1.57
 * /robot_description_planning/joint_limits/prbt_joint_5/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_5/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_5/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_5/max_velocity: 1.57
 * /robot_description_planning/joint_limits/prbt_joint_6/has_acceleration_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_6/has_velocity_limits: True
 * /robot_description_planning/joint_limits/prbt_joint_6/max_acceleration: 3.49
 * /robot_description_planning/joint_limits/prbt_joint_6/max_velocity: 1.57
 * /robot_description_semantic: <?xml version="1....
 * /rosdistro: melodic
 * /rosversion: 1.14.6
 * /rviz_titan_20147_8934675460531634154/manipulator/kinematics_solver: prbt_manipulator/...
 * /rviz_titan_20147_8934675460531634154/manipulator/kinematics_solver_search_resolution: 0.005
 * /rviz_titan_20147_8934675460531634154/manipulator/kinematics_solver_timeout: 0.005
 * /rviz_titan_20147_8934675460531634154/manipulator/link_prefix: prbt_

NODES
  /
    move_group (moveit_ros_move_group/move_group)
    pilz_status_indicator_rqt (pilz_status_indicator_rqt/pilz_status_indicator_rqt)
    robot_init (rosservice/rosservice)
    robot_state_publisher (robot_state_publisher/robot_state_publisher)
    rviz_titan_20147_8934675460531634154 (rviz/rviz)
  /prbt/
    brake_test_executor_node (prbt_hardware_support/brake_test_executor_node)
    braketest_adapter_node (prbt_hardware_support/canopen_braketest_adapter_node)
    controller_spawner (controller_manager/spawner)
    driver (canopen_motor_node/canopen_motor_node)
    joint_state_relay (topic_tools/relay)
    modbus_adapter_brake_test_node (prbt_hardware_support/modbus_adapter_brake_test_node)
    modbus_adapter_operation_mode_node (prbt_hardware_support/modbus_adapter_operation_mode_node)
    modbus_adapter_run_permitted_node (prbt_hardware_support/modbus_adapter_run_permitted_node)
    operation_mode_setup_executor_node (prbt_hardware_support/operation_mode_setup_executor_node)
    pilz_modbus_client_node (prbt_hardware_support/pilz_modbus_client_node)
    stop1_executor_node (prbt_hardware_support/stop1_executor_node)
    system_info_node (prbt_support/system_info_node)

auto-starting new master
process[master]: started with pid [20169]
ROS_MASTER_URI=http://localhost:11311

setting /run_id to 5f3a74ee-bba6-11ea-9122-84a93e5e04ca
process[rosout-1]: started with pid [20180]
started core service [/rosout]
process[robot_state_publisher-2]: started with pid [20188]
process[prbt/joint_state_relay-3]: started with pid [20189]
process[prbt/driver-4]: started with pid [20190]
process[prbt/controller_spawner-5]: started with pid [20192]
process[robot_init-6]: started with pid [20202]
process[prbt/pilz_modbus_client_node-7]: started with pid [20208]
process[prbt/modbus_adapter_run_permitted_node-8]: started with pid [20218]
[ INFO] [1593613383.884499788]: Parameters for register range are not set. Will try to determine range from api spec...
process[prbt/stop1_executor_node-9]: started with pid [20224]
[ INFO] [1593613383.894909486]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
process[prbt/modbus_adapter_brake_test_node-10]: started with pid [20232]
[ INFO] [1593613383.903353306]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
process[prbt/braketest_adapter_node-11]: started with pid [20238]
process[prbt/brake_test_executor_node-12]: started with pid [20239]
process[prbt/modbus_adapter_operation_mode_node-13]: started with pid [20250]
[ INFO] [1593613383.935883430]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
process[prbt/operation_mode_setup_executor_node-14]: started with pid [20256]
process[pilz_status_indicator_rqt-15]: started with pid [20257]
[ INFO] [1593613383.960240006]: Using fixed control period: 0.010000000
process[prbt/system_info_node-16]: started with pid [20264]
[ INFO] [1593613383.963658352]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
process[move_group-17]: started with pid [20269]
process[rviz_titan_20147_8934675460531634154-18]: started with pid [20275]
[ INFO] [1593613384.011659755]: Loading robot model 'prbt'...
[ INFO] [1593613384.045155615]: Using link_prefix: 'prbt_'
[ INFO] [1593613384.052842669]: Publishing maintained planning scene on 'monitored_planning_scene'
[ INFO] [1593613384.054762177]: MoveGroup debug mode is OFF
Starting planning scene monitors...
[ INFO] [1593613384.054801743]: Starting planning scene monitor
[ INFO] [1593613384.055894297]: Listening to '/planning_scene'
[ INFO] [1593613384.055923834]: Starting world geometry update monitor for collision objects, attached objects, octomap updates.
[ INFO] [1593613384.056957029]: Listening to '/collision_object'
[ INFO] [1593613384.058570421]: Listening to '/planning_scene_world' for planning scene world geometry
[ERROR] [1593613384.059080956]: Failed to find 3D sensor plugin parameters for octomap generation
[ INFO] [1593613384.062596390]: Listening to '/attached_collision_object' for attached collision objects
Planning scene monitors started.
[ INFO] [1593613384.065675761]: Reading limits from namespace /robot_description_planning
[ INFO] [1593613384.077106036]: rviz version 1.13.12
[ INFO] [1593613384.077347145]: compiled against Qt version 5.9.5
[ INFO] [1593613384.077362830]: compiled against OGRE version 1.9.0 (Ghadamon)
[ INFO] [1593613384.080956187]: Available plugins: pilz::PlanningContextLoaderCIRC pilz::PlanningContextLoaderLIN pilz::PlanningContextLoaderPTP 
[ INFO] [1593613384.080997093]: About to load: pilz::PlanningContextLoaderCIRC
[ INFO] [1593613384.082237167]: Registered Algorithm [CIRC]
[ INFO] [1593613384.082257641]: About to load: pilz::PlanningContextLoaderLIN
[ INFO] [1593613384.083220599]: Registered Algorithm [LIN]
[ INFO] [1593613384.083240136]: About to load: pilz::PlanningContextLoaderPTP
[ INFO] [1593613384.083715094]: Forcing OpenGl version 0.
[ INFO] [1593613384.084287144]: Registered Algorithm [PTP]
[ INFO] [1593613384.084326385]: Using planning interface 'Simple Command Planner'
[ INFO] [1593613384.100940990]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613384.108545133]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.147705703]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.170117019]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613384.194714223]: Initializing...
[ INFO] [1593613384.194835618]: Current state: 1 device error: system:0 internal_error: 0 (OK)
[ INFO] [1593613384.194906911]: Current state: 2 device error: system:0 internal_error: 0 (OK)
[ INFO] [1593613384.202498493]: Stereo is NOT SUPPORTED
[ INFO] [1593613384.202584353]: OpenGl version: 3.1 (GLSL 1.4).
[ INFO] [1593613384.305540740]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613384.312292012]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.352517711]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.373826322]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613384.513866136]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613384.521088375]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.560906972]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.582723265]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613384.718699435]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613384.724747490]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.766936653]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.794135128]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613384.906714550]: Brake Test required.
[ INFO] [1593613384.906735801]: Operation Mode switch: 0 -> 1
[ INFO] [1593613384.931709513]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613384.937502974]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613384.980538140]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613385.004498575]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613385.144772631]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613385.147856488]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613385.194285363]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613385.216958763]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ERROR] [1593613385.243632007]: EMCY received: 83#0000000000000000
[ERROR] [1593613385.249867016]: EMCY received: 84#0000000000000000
[ERROR] [1593613385.253188997]: EMCY received: 85#0000000000000000
[ERROR] [1593613385.256705311]: EMCY received: 86#0000000000000000
[ERROR] [1593613385.261222765]: EMCY received: 87#0000000000000000
[ERROR] [1593613385.265054729]: EMCY received: 88#0000000000000000
[ INFO] [1593613385.265154840]: Initializing successful
[ INFO] [1593613385.359061085]: waitForService: Service [/prbt/run_permitted] has not been advertised, waiting...
[ INFO] [1593613385.360808219]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613385.408702764]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] has not been advertised, waiting...
[ INFO] [1593613385.431967909]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] has not been advertised, waiting...
[ INFO] [1593613385.497197873]: Loading robot model 'prbt'...
[ INFO] [1593613385.503220415]: Monitoring cartesian speed of link prbt_link_1
[ INFO] [1593613385.503238030]: Monitoring cartesian speed of link prbt_link_2
[ INFO] [1593613385.503252901]: Monitoring cartesian speed of link prbt_link_3
[ INFO] [1593613385.503287728]: Monitoring cartesian speed of link prbt_link_4
[ INFO] [1593613385.503317024]: Monitoring cartesian speed of link prbt_link_5
[ INFO] [1593613385.503353213]: Monitoring cartesian speed of link prbt_flange
[ INFO] [1593613385.503380598]: Monitoring cartesian speed of link prbt_tcp
[ INFO] [1593613385.503410786]: Monitoring cartesian speed of link prbt_tool0
[ INFO] [1593613385.506906953]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] is now available.
[ INFO] [1593613385.512667768]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/hold] is now available.
[ INFO] [1593613385.514796805]: waitForService: Service [/prbt/manipulator_joint_trajectory_controller/monitor_cartesian_speed] is now available.
[ INFO] [1593613385.525319426]: waitForService: Service [/prbt/run_permitted] is now available.
[robot_init-6] process has finished cleanly
log file: /home/hslusarek/.ros/log/5f3a74ee-bba6-11ea-9122-84a93e5e04ca/robot_init-6*.log
[ INFO] [1593613385.711121610]: Added FollowJointTrajectory controller for prbt/manipulator_joint_trajectory_controller/
[ INFO] [1593613385.711363063]: Returned 1 controllers in list
[ INFO] [1593613385.715847219]: Recovering...
[ INFO] [1593613385.715963807]: Recovering successful
[ERROR] [1593613385.719388400]: Service: /prbt/manipulator_joint_trajectory_controller/unhold failed with error message:
Could not switch to unhold mode (default mode)
[ INFO] [1593613385.746874614]: Trajectory execution is managing controllers
Loading 'move_group/ApplyPlanningSceneService'...
Loading 'move_group/ClearOctomapService'...
Loading 'move_group/MoveGroupCartesianPathService'...
Loading 'move_group/MoveGroupExecuteTrajectoryAction'...
Loading 'move_group/MoveGroupGetPlanningSceneService'...
Loading 'move_group/MoveGroupKinematicsService'...
Loading 'move_group/MoveGroupMoveAction'...
Loading 'move_group/MoveGroupPickPlaceAction'...
Loading 'move_group/MoveGroupPlanService'...
Loading 'move_group/MoveGroupQueryPlannersService'...
Loading 'move_group/MoveGroupStateValidationService'...
Loading 'pilz_trajectory_generation/MoveGroupSequenceAction'...
[ INFO] [1593613385.801426851]: initialize move group sequence action
[ INFO] [1593613385.806502010]: Reading limits from namespace /robot_description_planning
Loading 'pilz_trajectory_generation/MoveGroupSequenceService'...
[ INFO] [1593613385.818850505]: Reading limits from namespace /robot_description_planning
[ INFO] [1593613385.831320175]: 

********************************************************
* MoveGroup using: 
*     - ApplyPlanningSceneService
*     - ClearOctomapService
*     - CartesianPathService
*     - ExecuteTrajectoryAction
*     - GetPlanningSceneService
*     - KinematicsService
*     - MoveAction
*     - PickPlaceAction
*     - MotionPlanService
*     - QueryPlannersService
*     - StateValidationService
*     - SequenceAction
*     - SequenceService
********************************************************

[ INFO] [1593613385.831385391]: MoveGroup context using planning plugin pilz::CommandPlanner
[ INFO] [1593613385.831398298]: MoveGroup context initialization complete

You can start planning now!

[ INFO] [1593613386.024349508]: Call "get firmware" service for "prbt_joint_1"
[ INFO] [1593613386.042838710]: Call "get firmware" service for "prbt_joint_2"
[ INFO] [1593613386.060141483]: Call "get firmware" service for "prbt_joint_3"
[ INFO] [1593613386.076496326]: Call "get firmware" service for "prbt_joint_4"
[ INFO] [1593613386.094342474]: Call "get firmware" service for "prbt_joint_5"
[ INFO] [1593613386.112522947]: Call "get firmware" service for "prbt_joint_6"
[ INFO] [1593613386.130032146]: Firmware version [prbt_joint_1]: 110 Build:12822 Date:2020-04-28 23:11:51
[ INFO] [1593613386.130141464]: Firmware version [prbt_joint_2]: 110 Build:12822 Date:2020-04-28 23:11:51
[ INFO] [1593613386.130389446]: Firmware version [prbt_joint_3]: 110 Build:12822 Date:2020-04-28 23:11:51
[ INFO] [1593613386.130446037]: Firmware version [prbt_joint_4]: 110 Build:12822 Date:2020-04-28 23:11:51
[ INFO] [1593613386.130507127]: Firmware version [prbt_joint_5]: 110 Build:12822 Date:2020-04-28 23:11:51
[ INFO] [1593613386.130812182]: Firmware version [prbt_joint_6]: 110 Build:12822 Date:2020-04-28 23:11:51
[prbt/system_info_node-16] process has finished cleanly
log file: /home/hslusarek/.ros/log/5f3a74ee-bba6-11ea-9122-84a93e5e04ca/prbt-system_info_node-16*.log
[ INFO] [1593613387.433920987]: Loading robot model 'prbt'...
[ INFO] [1593613387.447955509]: Using link_prefix: 'prbt_'
[ INFO] [1593613387.463420014]: Starting planning scene monitor
[ INFO] [1593613387.464802607]: Listening to '/move_group/monitored_planning_scene'
QObject::connect: Cannot queue arguments of type 'QVector<int>'
(Make sure 'QVector<int>' is registered using qRegisterMetaType().)
QObject::connect: Cannot queue arguments of type 'QVector<int>'
(Make sure 'QVector<int>' is registered using qRegisterMetaType().)
[ INFO] [1593613387.538542927]: Constructing new MoveGroup connection for group 'manipulator' in namespace ''
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
[ INFO] [1593613388.735664539]: Ready to take commands for planning group manipulator.
[ INFO] [1593613388.735715133]: Looking around: no
[ INFO] [1593613388.735734634]: Replanning: no
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
QAbstractItemView::setSelectionModel() failed: Trying to set a selection model, which works on a different model than the view.
[ INFO] [1593613390.141553662]: Halting down...
[ INFO] [1593613390.141628050]: Halting down successful
[ INFO] [1593613393.208521801]: Recovering...
[ERROR] [1593613393.273998748]: EMCY received: 83#0000000000000000
[ERROR] [1593613393.278295822]: EMCY received: 84#0000000000000000
[ERROR] [1593613393.283060810]: EMCY received: 85#0000000000000000
[ERROR] [1593613393.286840231]: EMCY received: 86#0000000000000000
[ERROR] [1593613393.295313747]: EMCY received: 87#0000000000000000
[ERROR] [1593613393.299689084]: EMCY received: 88#0000000000000000
[ INFO] [1593613393.300049691]: Recovering successful
[ INFO] [1593613393.681632375]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[ INFO] [1593613393.682189400]: Planning attempt 1 of at most 1
[ INFO] [1593613393.682524884]: Initialized Point-to-Point Trajectory Generator.
[ INFO] [1593613393.682771572]: Generating PTP trajectory...
[ INFO] [1593613393.688062512]: Disabling trajectory recording
[ INFO] [1593613395.208894865]: Controller prbt/manipulator_joint_trajectory_controller/ successfully finished
[ INFO] [1593613395.250876023]: Completed trajectory execution with status SUCCEEDED ...

[ INFO] [1593613401.621576292]: Halting down...
[ INFO] [1593613401.621636047]: Halting down successful
[ INFO] [1593613407.577709618]: Recovering...
[ERROR] [1593613407.643614772]: EMCY received: 83#0000000000000000
[ERROR] [1593613407.647785947]: EMCY received: 84#0000000000000000
[ERROR] [1593613407.651528545]: EMCY received: 85#0000000000000000
[ERROR] [1593613407.655049547]: EMCY received: 86#0000000000000000
[ERROR] [1593613407.659547048]: EMCY received: 87#0000000000000000
[ERROR] [1593613407.663222472]: EMCY received: 88#0000000000000000
[ INFO] [1593613407.663290191]: Recovering successful
[ INFO] [1593613489.501810698]: Halting down...
[ INFO] [1593613489.501871690]: Halting down successful
martiniil commented 4 years ago

I had a quick look and found something which might cause the failure: #436

martiniil commented 4 years ago

Solved: 7abce15b1dd9676b8abc737aa67265f1ac2ff23c