Duration is out of dual 32-bit range

[xav12358]

Hello,

I use ROS noetic on ubuntu 20.04.

I run that launch file :

<?xml version="1.0" ?>
<launch>
  <arg name="robot_ip" />

  <include file="$(find panda_moveit_config)/launch/franka_control.launch">
    <arg name="robot_ip" value="$(arg robot_ip)" />
  </include>

</launch>

After one or two moveit execution, I get that error:

[ INFO] [1650017555.624464339]: Controller 'position_joint_trajectory_controller' successfully finished
[ INFO] [1650017555.707375009]: Completed trajectory execution with status SUCCEEDED ...
[ INFO] [1650017555.714236078]: Received event 'stop'
[ INFO] [1650017555.812988489]: Received request to compute Cartesian path
[ INFO] [1650017555.813370991]: Attempting to follow 2 waypoints for link 'panda_link8' using a step of 0.010000 m and jump threshold 0.000000 (in global reference frame)
[ INFO] [1650017555.813802012]: Computed Cartesian path with 3 points (followed 100.000000% of requested trajectory)
[ INFO] [1650017555.814520703]: Execution request received
[ INFO] [1650017556.041427698]: Controller 'position_joint_trajectory_controller' successfully finished
[ INFO] [1650017556.140868267]: Completed trajectory execution with status SUCCEEDED ...
[ INFO] [1650017556.140992920]: Execution completed: SUCCEEDED
[ INFO] [1650017557.674071654]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[ INFO] [1650017557.674226121]: Planning attempt 1 of at most 1
[ INFO] [1650017557.675771675]: Planner configuration 'panda_arm' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[ INFO] [1650017557.676177264]: panda_arm/panda_arm: Starting planning with 1 states already in datastructure
[ INFO] [1650017557.699567260]: panda_arm/panda_arm: Created 5 states (2 start + 3 goal)
[ INFO] [1650017557.699626543]: Solution found in 0.023645 seconds
[ INFO] [1650017557.716953937]: SimpleSetup: Path simplification took 0.017239 seconds and changed from 4 to 2 states
[ WARN] [1650017557.917534940]: FrankaHW: 
	panda_joint4: 48.052401 degrees to joint limits (limits: [-3.071800, -0.069800] q: -2.233127) 
[ INFO] [1650017560.191609366]: Controller 'position_joint_trajectory_controller' successfully finished
[ INFO] [1650017560.274275395]: Completed trajectory execution with status SUCCEEDED ...
[ INFO] [1650017560.281329970]: Received event 'stop'
[ INFO] [1650017560.340796921]: Combined planning and execution request received for MoveGroup action. Forwarding to planning and execution pipeline.
[ INFO] [1650017560.340938019]: Planning attempt 1 of at most 1
[ INFO] [1650017560.341766800]: Planner configuration 'panda_arm' will use planner 'geometric::RRTConnect'. Additional configuration parameters will be set when the planner is constructed.
[ INFO] [1650017560.341938683]: panda_arm/panda_arm: Starting planning with 1 states already in datastructure
[ INFO] [1650017560.357619875]: panda_arm/panda_arm: Created 5 states (2 start + 3 goal)
[ INFO] [1650017560.357657397]: Solution found in 0.015800 seconds
[ INFO] [1650017560.390585205]: SimpleSetup: Path simplification took 0.032877 seconds and changed from 4 to 2 states
[ WARN] [1650017562.918474636]: FrankaHW: 
	panda_joint4: 47.972937 degrees to joint limits (limits: [-3.071800, -0.069800] q: -2.234514) 
[ INFO] [1650017563.157946778]: Controller 'position_joint_trajectory_controller' successfully finished
[ INFO] [1650017563.240689409]: Completed trajectory execution with status SUCCEEDED ...
[ INFO] [1650017563.247838920]: Received event 'stop'
[ INFO] [1650017563.342252969]: Received request to compute Cartesian path
[ INFO] [1650017563.342370025]: Attempting to follow 2 waypoints for link 'panda_link8' using a step of 0.010000 m and jump threshold 0.000000 (in global reference frame)
[ INFO] [1650017563.342754963]: Computed Cartesian path with 3 points (followed 100.000000% of requested trajectory)
[ INFO] [1650017563.343340847]: Execution request received
terminate called after throwing an instance of 'std::runtime_error'
  what():  Duration is out of dual 32-bit range
================================================================================REQUIRED process [franka_control-3] has died!
process has died [pid 139304, exit code -6, cmd /home/fff/dev/catkin_ws/devel/lib/franka_control/franka_control_node __name:=franka_control __log:=/home/fff/.ros/log/8a163c10-bca4-11ec-b7e8-f91b2a3bdfbe/franka_control-3.log].
log file: /home/fff/.ros/log/8a163c10-bca4-11ec-b7e8-f91b2a3bdfbe/franka_control-3*.log
Initiating shutdown!
================================================================================
[rviz_fff_139214_966731689332244255-10] killing on exit
[move_group-9] killing on exit
[virtual_joint_broadcaster_0-8] killing on exit
[controller_spawner-7] killing on exit
[joint_state_publisher-6] killing on exit
[robot_state_publisher-5] killing on exit
[state_controller_spawner-4] killing on exit
[franka_control-3] killing on exit
[franka_gripper-2] killing on exit
[INFO] [1650017563.645560]: Shutting down spawner. Stopping and unloading controllers...
[INFO] [1650017563.645870]: Shutting down spawner. Stopping and unloading controllers...
[INFO] [1650017563.647024]: Stopping all controllers...
[INFO] [1650017563.647739]: Stopping all controllers...
[WARN] [1650017563.649646]: Controller Spawner error while taking down controllers: unable to connect to service: [Errno 111] Connection refused
[WARN] [1650017563.650208]: Controller Spawner error while taking down controllers: unable to connect to service: [Errno 111] Connection refused
[rosout-1] killing on exit
[master] killing on exit
shutting down processing monitor...
... shutting down processing monitor complete

Unfortunatly there is no franka_control-3.log file. Is there a way to get it?

And then, I don't really no where the problem comes. Can someone help me to solve this?

[xav12358]

I try to add debug mode like this:

RLException: Roslaunch got a 'No such file or directory' error while attempting to run:

xterm -e gdb --args /home/fff/dev/catkin_ws/devel/lib/franka_control/franka_control_node __name:=franka_control __log:=/home/fff/.ros/log/19f6fe8e-bfc8-11ec-b7e8-f91b2a3bdfbe/franka_control-3.log

Please make sure that all the executables in this command exist and have
executable permission. This is often caused by a bad launch-

I modify the launch file like this:

<?xml version="1.0" ?>
<launch>
  <arg name="robot_ip" />
  <arg name="load_gripper" default="true" />

  <param name="robot_description" command="$(find xacro)/xacro $(find franka_description)/robots/panda_arm.urdf.xacro hand:=$(arg load_gripper)" />

  <include file="$(find franka_gripper)/launch/franka_gripper.launch" if="$(arg load_gripper)">
    <arg name="robot_ip" value="$(arg robot_ip)" />
  </include>

  <node name="franka_control" pkg="franka_control" type="franka_control_node" output="screen" required="true" launch-prefix="xterm -e gdb --args">
    <rosparam command="load" file="$(find franka_control)/config/franka_control_node.yaml" />
    <param name="robot_ip" value="$(arg robot_ip)" />
  </node>

  <rosparam command="load" file="$(find franka_control)/config/default_controllers.yaml" />
  <node name="state_controller_spawner" pkg="controller_manager" type="spawner" respawn="false" output="screen" args="franka_state_controller"/>
  <node name="robot_state_publisher" pkg="robot_state_publisher" type="robot_state_publisher" output="screen"/>
  <node name="joint_state_publisher" type="joint_state_publisher" pkg="joint_state_publisher" output="screen">
    <rosparam if="$(arg load_gripper)" param="source_list">[franka_state_controller/joint_states, franka_gripper/joint_states] </rosparam>
    <rosparam unless="$(arg load_gripper)" param="source_list">[franka_state_controller/joint_states] </rosparam>
    <param name="rate" value="30"/>
  </node>
</launch>

Do I made something wrong?

Edit:

I modify the argument with :
launch-prefix="gdb -ex run --args"

I get that error:

[ INFO] [1650363502.788109479]: Completed trajectory execution with status TIMED_OUT ...
[ INFO] [1650363502.793309900]: Received event 'stop'
ere
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff7711859 in __GI_abort () at abort.c:79
#2  0x00007ffff799a911 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff79a638c in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007ffff79a63f7 in std::terminate() () from /lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007ffff79a66fd in __cxa_rethrow () from /lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x00007ffff7f89054 in franka::ControlLoop<franka::JointPositions>::operator()() () from /home/fff/dev/libfranka/build/libfranka.so.0.9
#7  0x00007ffff7fa5e6d in franka::Robot::control(std::function<franka::JointPositions (franka::RobotState const&, franka::Duration)>, franka::ControllerMode, bool, double) ()
   from /home/fff/dev/libfranka/build/libfranka.so.0.9
#8  0x00007ffff7e755a6 in std::_Function_handler<void (franka::Robot&, std::function<bool (franka::RobotState const&, franka::Duration)>), franka_hw::FrankaHW::setRunFunction(franka_hw::ControlMode const&, bool, double, franka::ControllerMode)::{lambda(franka::Robot&, std::function<bool (franka::RobotState const&, franka::Duration)>)#2}>::_M_invoke(std::_Any_data const&, franka::Robot&, std::function<bool (franka::RobotState const&, franka::Duration)>&&) () from /home/fff/dev/catkin_ws/devel/lib/libfranka_hw.so
#9  0x00007ffff7e700dc in franka_hw::FrankaHW::control(std::function<bool (ros::Time const&, ros::Duration const&)> const&) () from /home/fff/dev/catkin_ws/devel/lib/libfranka_hw.so
#10 0x00005555555817c6 in main ()
(gdb) 

Edit 2:
I recompile on debug libfranka:

here
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007ffff74bd859 in __GI_abort () at abort.c:79
#2  0x00007ffff7746911 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007ffff775238c in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007ffff77523f7 in std::terminate() () from /lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007ffff77526fd in __cxa_rethrow () from /lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x00007ffff7f89054 in franka::ControlLoop<franka::JointPositions>::operator()() () from /home/fff/dev/libfranka/build/libfranka.so.0.9
#7  0x00007ffff7fa5e6d in franka::Robot::control(std::function<franka::JointPositions (franka::RobotState const&, franka::Duration)>, franka::ControllerMode, bool, double) ()
   from /home/fff/dev/libfranka/build/libfranka.so.0.9
#8  0x00007ffff7df4ed9 in franka_hw::FrankaHW::<lambda(franka::Robot&, Callback)>::operator()(franka::Robot &, franka_hw::FrankaHW::<lambda(franka::Robot&, Callback)>::Callback) const (
    __closure=0x7fffdc002ce0, robot=..., ros_callback=...) at /home/fff/dev/catkin_ws/src/franka_ros/franka_hw/src/franka_hw.cpp:455
#9  0x00007ffff7df85bc in std::_Function_handler<void(franka::Robot&, std::function<bool(const franka::RobotState&, franka::Duration)>), franka_hw::FrankaHW::setRunFunction(const franka_hw::ControlMode&, bool, double, franka::ControllerMode)::<lambda(franka::Robot&, Callback)> >::_M_invoke(const std::_Any_data &, franka::Robot &, std::function<bool(const franka::RobotState&, franka::Duration)> &&) (
    __functor=..., __args#0=..., __args#1=...) at /usr/include/c++/9/bits/std_function.h:300
#10 0x00007ffff7e05af5 in std::function<void (franka::Robot&, std::function<bool (franka::RobotState const&, franka::Duration)>)>::operator()(franka::Robot&, std::function<bool (franka::RobotState const&, franka::Duration)>) const (this=0x7fffffffd930, __args#0=..., __args#1=...) at /usr/include/c++/9/bits/std_function.h:688
#11 0x00007ffff7df23b4 in franka_hw::FrankaHW::control(std::function<bool (ros::Time const&, ros::Duration const&)> const&) (this=0x7fffffffb360, ros_callback=...)
    at /home/fff/dev/catkin_ws/src/franka_ros/franka_hw/src/franka_hw.cpp:234
#12 0x00005555555fa3d4 in main (argc=1, argv=0x7fffffffda78) at /home/fff/dev/catkin_ws/src/franka_ros/franka_control/src/franka_control_node.cpp:141
(gdb) 

[alexswerner]

Same issue here, also seems to be random. ROS noetic on Ubuntu 20.04 (in a docker), libfranka 0.9.0-2focal.20220328.144759.

[rpapallas]

We also have the same issue. Any update on this, please?

[marcbone]

There is an issue for the same problem in libfranka. You can try out the "solution" that was mentioned there, but I doubt that it will really fix your problem. Honestly, there is not much I can do for you as I cannot reproduce it 😕

[xav12358]

@marcbone Are my debug logs enough. Do you need other trace ? I can generated it for you.

[HumbertoE]

We also have had this error for some months:

[ INFO] [1648537848.852719572]: FrankaHW: Prepared switching controllers to joint_position with parameters limit_rate=1, cutoff_frequency=100, internal_controller=joint_impedance
[ INFO] [1648537848.855927422]: franka_control, main loop
terminate called after throwing an instance of 'std::runtime_error'
  what():  Duration is out of dual 32-bit range
================================================================================REQUIRED process [franka_control-1] has died!
process has died [pid 239, exit code -6, cmd /catkin_ws/devel/lib/franka_control/franka_control_node __name:=franka_control __log:=/root/.ros/log/a1ad6386-af2e-11ec-abea-902e16d1ae42/franka_control-1.log].
log file: /root/.ros/log/a1ad6386-af2e-11ec-abea-902e16d1ae42/franka_control-1*.log
Initiating shutdown!
================================================================================
[controller_spawner_visual_servoing-6] killing on exit

Scenario

• We switch between 2 controllers, position_joint_trajectory_controller and a custom controller that uses hardware_interface::VelocityJointInterface

• Most of the time it works. It switches controllers, moves the robot and everything is nice, but once and then we get the error.

• Most of the time the error appears after the first time we switch controllers and switch back. We do the following:

  1. Start with the position_joint_trajectory_controller
  2. Successfully move the robot with it
  3. Change to our custom controller
  4. Successfully move the robot with it
  5. Change back to the position_joint_trajectory_controller
  6. Succesfully plan the next move, but when executing it, the error happens

• We switch controllers by calling the service controller_manager/switch_controller and even when the error appears, the service returns success.

• First we added a small wait of 0.2s after switching back to position_joint_trajectory_controller and before moving (or even planning) and seemed to help a bit, but not much. Now we got rid of this wait.

• We now have a check before switching back to position_joint_trajectory_controller that reads the state of the robot from the /joint_states topic to make sure the change is done after the robot is not moving (we had an error involving a "velocity discontinuity" that was caused by this). This seems to decrease the frequency of appearance of the error, but it still appears.

• We also tried just switching controllers very fast (at 20 Hz, but maybe we also tried faster, I don't remember) and the service always said the switch was successful.

• The error also happened when the controllers were not being switch, in between movements with the position_joint_trajectory_controller, but this has happened just 2 or 3 times.

• The error most of the time appears when the ROS master together with the franka-ros nodes are created. After they have been running for some time, the error rarely appears

• We run the ROS master and most of our nodes on one computer, and franka control and control manager in a different, real time PC

What the problem could be

rhaschke stated in #232 (and a few days ago checked that the error was still there) that when the start of a controller actually failed, the ControllerManager thinks that controller switching succeeded.

Maybe our switch is not successful and we don't know it. But he also mentioned that this raises a ROS error, so I'm not sure if we would see this.

Any comments on our thoughts or ideas of what to try are welcome.

[xav12358]

@HumbertoE I try a 'solution' since o,e week. I found on Ros forum that moveit Can create that keep of problem if the package is not updated.

So I update Moveit and ROS and it seems to solve my trouve.

[HumbertoE]

@xav12358 could you share the ROS forum question or issue if you still have it open? We can try this, thanks. I will comment here if this solves the issue for us

[HumbertoE]

@xav12358 what version of Moveit are you using? Or if installed from source, what commit of the Moveit repository are you at?

We are installing it from source and are in commit 7949bd6ea776e1268b8ff9e2015cad5cb695b829 that was done on August 16 (one week before you started testing I think) and we still got the error.

I will update moveit to the latest state in the master branch and test in the robot in a couple of days and inform if this solves the issue for us.

[xav12358]

@HumbertoE in fact I use the Ubuntu 20.04 Moveit package. Why do you need to install moveit from source package ?

[HumbertoE]

So the release 1.1.5 maybe? I will try that one then and see if the duration error disappears. Thank you

We had to do some custom changes to one package moveit depends on for our application. The changes are not fixes, so we didn't make any pull request. I will also check that this package is compatible to that release

[HumbertoE]

We changed to the 1.1.5 release version on Moveit and we still have the same error.

We also changed to libfranka version 0.9.2 and franka ros 0.9.1 (before we had both at 0.9.0) and still we get the duration error.

In some point we also got another error of the controller not executing commands even when the controller manager said it was ok and running. I manually changed to another controller and then back to the position_joint_trajectory_controller and then it worked.

My theory is that when we change controllers, it fails but the controller manager reports it doesn't or it reports it was successful before it finishes (the controller switch service returns success after between 5 and 7 ms) and then when it receives some commands for the controller that is reported as loaded, it fails.

The problem here of the failure in changing controllers could be in our implementation, but if the controller switch is reported as successful when it is not, it is very hard to debug.

[HumbertoE]

Now the problem seems to be solved for us. It hasn't appeared in more than a month, even when we try to provoke it.

We were running the ROS core in one computer and the ROS control node in another one with a different version of ROS. Now we have the same version of ROS and this solved the problem.

[Maverobot]

It seems to be unrelated to franka_ros but is caused by ABI incompability in the workspace/installed packages. See:

• Duration is out of dual 32-bit range moveit/moveit#1062
• https://answers.ros.org/question/302654/time-is-out-of-dual-32-bit-range/

I will close it for now.