search

Yaskawa-Global / motoros2

ROS 2 (rcl, rclc & micro-ROS) node for MotoPlus-compatible Yaskawa Motoman robot controllers
95 stars 16 forks source link

`/start_traj_mode` failed incorrectly #114

Closed ted-miller closed 6 months ago

ted-miller commented 1 year ago

I was in an error state created by an estop. I tried to start traj mode. It failed due to the error state. But, the job did start and the drives came on.

Eventually servo-sleep mode kicked in with the job still running.

I then call /reset_error to clear the previous error state.

When I call start_traj_mode, the servos woke back up and the job was restarted. But the service returned result_code=motoros2_interfaces.msg.MotionReadyEnum(value=109), message='INFORM job is not on a WAIT command. Check the format of INIT_ROS')

I'm wondering if it was due to the servo-sleep or my error-reset situation.

A second call to /start_traj_mode worked ok.

ted-miller commented 1 year ago

A second call to /start_traj_mode worked ok.

Well maybe not. It indicated success. But when I tried to submit a goal, I got control_msgs.action.FollowJointTrajectory_Result(error_code=-100208, error_string='Must call start_traj_mode service.')

yai-rosejo commented 6 months ago

I tried replicating this bug. This first instance I got the bug to occur I hit the e-stop right after sending the /start_traj_mode.

[2024-02-16 14:11:48.790752] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:11:49.258552] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:11:49.270952] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:11:49.270952] [192.168.1.31:59487]: Ros_MotionControl_ActiveTrajMode = 1
[2024-02-16 14:11:49.271152] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: activated
[2024-02-16 14:11:49.383952] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:11:52.678152] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:11:58.177352] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:11:58.177552] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: The controller is in E-Stop (103)
[2024-02-16 14:12:16.451032] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:12:16.914232] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:12:16.987032] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:12:16.987232] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: INFORM job is not on a WAIT command. Check the format of INIT_ROS (109)

The second instance I was in e-stop, sent /start_traj_mode, cleared e-stop, sent /reset_error, sent /start_traj_mode, hit e-stop, cleared e-stop, waited 2 minutes, then sent a /start_traj_mode.

[2024-02-16 14:22:03.100478] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:22:03.368678] [192.168.1.31:59487]: Can't turn on servo because: 'Unspecified reason' (0x3450)
[2024-02-16 14:22:03.368878] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:22:03.368878] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: The controller is in E-Stop (103)
[2024-02-16 14:22:15.550731] [192.168.1.31:59487]: reset: attempting to reset controller
[2024-02-16 14:22:15.550731] [192.168.1.31:59487]: reset: success
[2024-02-16 14:22:20.841852] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:22:21.311852] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:22:21.312052] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:22:21.312052] [192.168.1.31:59487]: Ros_MotionControl_ActiveTrajMode = 1
[2024-02-16 14:22:21.312052] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: activated
[2024-02-16 14:22:21.436252] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:24:10.655491] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 14:24:11.153891] [192.168.1.31:59487]: Robot job is ready for ROS commands.
[2024-02-16 14:24:11.204291] [192.168.1.31:59487]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 14:24:11.204291] [192.168.1.31:59487]: Ros_ServiceStartTrajMode_Trigger: INFORM job is not on a WAIT command. Check the format of INIT_ROS (109)
[2024-02-16 14:24:11.267691] [192.168.1.31:59487]: Robot job is ready for ROS commands.

I have tried both of these order of operations again and it isn't repeating

yai-rosejo commented 6 months ago

Found a sequence that makes this message appear and is repeatable: e-stop -> turn off e-stop -> send reset_error -> send start_traj_mode -> wait till energy save mode turns on -> send fjt command -> inform error

[2024-02-16 19:34:21.624265] [192.168.1.31:65119]: reset: attempting to reset controller
[2024-02-16 19:34:21.624265] [192.168.1.31:65119]: reset: success
[2024-02-16 19:34:30.722604] [192.168.1.31:65119]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 19:34:31.211004] [192.168.1.31:65119]: Robot job is ready for ROS commands.
[2024-02-16 19:34:31.311004] [192.168.1.31:65119]: Robot job is ready for ROS commands.
[2024-02-16 19:34:31.367204] [192.168.1.31:65119]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 19:34:31.367204] [192.168.1.31:65119]: Ros_MotionControl_ActiveTrajMode = 1
[2024-02-16 19:34:31.367204] [192.168.1.31:65119]: Ros_ServiceStartTrajMode_Trigger: activated
[2024-02-16 19:35:54.783605] [192.168.1.31:65119]: Trajectory contains 61 points
[2024-02-16 19:35:54.783805] [192.168.1.31:65119]: Energy saving function is active. Re-enabling the robot.
[2024-02-16 19:35:54.783805] [192.168.1.31:65119]: Ros_MotionControl_StartMotionMode: enter
[2024-02-16 19:35:55.753405] [192.168.1.31:65119]: Robot job is ready for ROS commands.
[2024-02-16 19:35:55.753605] [192.168.1.31:65119]: Ros_MotionControl_StartMotionMode: exit
[2024-02-16 19:35:55.753605] [192.168.1.31:65119]: Ros_MotionControl_ActiveTrajMode = 1
[2024-02-16 19:35:55.753605] [192.168.1.31:65119]: Ros_ServiceStartTrajMode_Trigger: activated
[2024-02-16 19:35:55.753805] [192.168.1.31:65119]:
[2024-02-16 19:35:55.855605] [192.168.1.31:65119]: Robot has been re-enabled.
[2024-02-16 19:35:55.855605] [192.168.1.31:65119]: FollowJointTrajectory - Goal request rejected
[2024-02-16 19:35:55.855605] [192.168.1.31:65119]: The trajectory will be accepted and then immediately aborted
[2024-02-16 19:35:55.855805] [192.168.1.31:65119]: INFORM job is not on a WAIT command. Check the format of INIT_ROS
[2024-02-16 19:35:55.870405] [192.168.1.31:65119]: Robot job is ready for ROS commands.
control_msgs.action.FollowJointTrajectory_Result(error_code=-100109, error_string='INFORM job is not on a WAIT command. Check the format of INIT_ROS')