action bridge rebased mojin #13

fmessmer · 2023-07-10T15:17:41Z

ref https://github.com/4am-robotics/orga/issues/3731 - see https://github.com/4am-robotics/orga/issues/3731#issuecomment-1629126734

cherry-picked the latest additional commits from ros2#256
which came in later than our branch off in #2

I hope one of the commits fixes our exception in the action_bridge

fmessmer · 2023-07-11T06:59:22Z

what I can say already:

compiles nicely locally (I'll have to fix CI in a separate PR)
works nicely when testing with emulation (probably needs more testing to make sure it doesnt crash anymore)

some observation:
there is a difference in the output depending on the direction of the action_bridge ❗

source_amr_ros_bridge && ros2 run ros1_bridge action_bridge ros1 amr_road_network_msgs ExecuteTransferJob /execute_transferjob_flexbe --ros-args --remap __name:=action_bridge_execute_transferjob_flexbe
ROS_DISTRO was set to 'foxy' before. Please make sure that the environment does not mix paths from different distributions.
ROS_DISTRO was set to 'noetic' before. Please make sure that the environment does not mix paths from different distributions.
ros1 amr_road_network_msgs ExecuteTransferJob /execute_transferjob_flexbe
created action factory
[INFO] [1689058367.717385645] [action_bridge_execute_transferjob_flexbe]: Sending goal
[ INFO] [1689058367.727231530]: Goal [ACTIVE]
[ INFO] [1689058421.615986243]: Goal [WAITING_FOR_RESULT]
[ INFO] [1689058421.616065660]: Goal [DONE]
[ INFO] [1689058421.616771987]: Goal [SUCCEEDED]
[INFO] [1689058433.066171247] [action_bridge_execute_transferjob_flexbe]: Sending goal
[ INFO] [1689058433.179873663]: Goal [ACTIVE]
[ INFO] [1689058498.033534441]: Goal [WAITING_FOR_RESULT]
[ INFO] [1689058498.033959007]: Goal [DONE]
[ INFO] [1689058498.035709510]: Goal [SUCCEEDED]
[INFO] [1689058506.751777264] [action_bridge_execute_transferjob_flexbe]: Sending goal
[ INFO] [1689058506.824741125]: Goal [PENDING]
[ INFO] [1689058506.852753587]: Goal [ACTIVE]

versus

source_amr_ros_bridge && ros2 run ros1_bridge action_bridge ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob --ros-args --remap __name:=action_bridge_execute_transferjob
ROS_DISTRO was set to 'foxy' before. Please make sure that the environment does not mix paths from different distributions.
ROS_DISTRO was set to 'noetic' before. Please make sure that the environment does not mix paths from different distributions.
ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob
created action factory
[INFO] [1689058368.218352717] [action_bridge_execute_transferjob]: Sending goal
[INFO] [1689058378.687480916] [action_bridge_execute_transferjob]: Sending goal
[INFO] [1689058433.369005219] [action_bridge_execute_transferjob]: Sending goal
[INFO] [1689058457.324409427] [action_bridge_execute_transferjob]: Sending goal
[INFO] [1689058507.073843172] [action_bridge_execute_transferjob]: Sending goal
[INFO] [1689058530.607273046] [action_bridge_execute_transferjob]: Sending goal

i.e. I'm missing the Goal Status output on the second bridge - will investigate...

fmessmer · 2023-07-11T09:01:12Z

unfortunately, the exception still occurred with the feature branch - I guess I'm going to merge the launch file as a temporary workaround to buy us some more time #12

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

fmessmer · 2023-07-17T19:00:02Z

what I can see with my additional logging is that the goal of the execute_transferjob action_bridge (ROS1: client, ROS2: server) do not really succeed/finish, but instead get cancelled

( | )fxm@alpamayo:~$ source_amr_ros_bridge && ros2 run ros1_bridge action_bridge ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob --ros-args --remap __name:=action_bridge_execute_transferjob
ROS_DISTRO was set to 'foxy' before. Please make sure that the environment does not mix paths from different distributions.
ROS_DISTRO was set to 'noetic' before. Please make sure that the environment does not mix paths from different distributions.
ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob
created action factory
[INFO] [1689620016.573372008] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1689620016.573665282] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1689620016.577810175] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1689620016.579401999] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1689620016.594986955] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1689620016.595671505] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1689620016.597745356] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1689620016.675522771] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1689620074.047111500] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1689620074.047969908] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1689620074.258056837] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1689620074.258380834] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1689620074.287463400] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1689620074.287579133] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1689620074.287691950] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1689620074.287717982] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1689620074.289358908] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1689620074.292937806] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result


[INFO] [1689620119.950229190] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1689620119.957283958] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1689620132.416342337] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1689620132.416578705] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1689620132.419772296] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1689620132.420638612] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1689620132.420823349] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1689620132.420875893] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1689620132.430172569] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
terminate called after throwing an instance of 'std::future_error'
  what():  std::future_error: No associated state
( | )fxm@alpamayo:~$ 
( | )fxm@alpamayo:~$ 
( | )fxm@alpamayo:~$ source_amr_ros_bridge && ros2 run ros1_bridge action_bridge ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob --ros-args --remap __name:=action_bridge_execute_transferjob
ROS_DISTRO was set to 'foxy' before. Please make sure that the environment does not mix paths from different distributions.
ROS_DISTRO was set to 'noetic' before. Please make sure that the environment does not mix paths from different distributions.
ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob
created action factory
[INFO] [1689620183.713589640] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1689620183.713839222] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1689620183.729346627] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1689620183.729728018] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1689620183.730827437] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1689620183.730877262] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1689620183.731656075] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1689620183.732905783] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1689620229.961474958] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1689620229.962202873] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1689620239.598471487] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1689620239.598579691] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1689620239.602885522] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1689620239.603728071] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1689620239.603888110] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1689620239.603936083] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1689620239.604408865] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1689620239.613769884] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result

fmessmer · 2023-07-17T19:10:18Z

these cancel calls are being triggered by the SM ❗

fxm@alpamayo:~$ rostopic echo /execute_transferjob/cancel 
stamp: 
  secs: 0
  nsecs:         0
id: "/flexbe_onboard_behavior-13-1689620728.715"
---

maybe some timeout or something...

fmessmer · 2023-08-01T20:35:11Z

I still fail to actually catch the exception (future_error) 😭

here is a log of the latest commit:

( | )fxm@alpamayo:~$ source_amr_ros_bridge && ros2 run ros1_bridge action_bridge ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob --ros-args --remap __name:=action_bridge_execute_transferjob
ROS_DISTRO was set to 'foxy' before. Please make sure that the environment does not mix paths from different distributions.
ROS_DISTRO was set to 'noetic' before. Please make sure that the environment does not mix paths from different distributions.
ros2 amr_road_network_msgs action/ExecuteTransferJob /execute_transferjob
created action factory
[INFO] [1690921098.745033399] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921098.745357690] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921098.762788567] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921098.763095804] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921098.763344391] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921098.763393399] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921098.769953709] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921098.950469720] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921164.377641231] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921164.379769396] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921164.615783571] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921164.615862839] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921164.620249217] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921164.621089974] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921164.621804397] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921164.623428007] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921164.624092955] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921164.650446532] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921205.419725306] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921205.432965535] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921208.937768269] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921208.937906760] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921208.945565122] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921208.953620808] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921208.953800788] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921208.953825791] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921208.956785612] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921208.972809309] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921253.875175318] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921253.884940108] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921253.979123869] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921253.979203724] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921253.980239478] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921253.980355909] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921253.981452638] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921253.983156636] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921253.983387405] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921253.986503560] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921315.639865807] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921315.640082045] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921324.687517780] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921324.687624370] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921324.688055131] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921324.688127922] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921324.688282063] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921324.688304606] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921324.688360949] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921324.688921224] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921393.441622515] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921393.456107763] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921393.581502326] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921393.581599390] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921393.586517409] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921393.586877621] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921393.587127083] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921393.587253952] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921393.587482180] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921393.588832948] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921435.190356141] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921435.202893248] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921438.168728784] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921438.168806093] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921438.169961851] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921438.170075251] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921438.170203199] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921438.170234456] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921438.170302388] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921438.182407211] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921486.888129788] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921486.888634282] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921487.015423432] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921487.015537838] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921487.035590227] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921487.037413469] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921487.038181320] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921487.044469377] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921487.058249009] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921487.058429144] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921528.827939253] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921528.832666883] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921530.204509449] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921530.204652143] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921530.208559940] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921530.208662500] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921530.208770693] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921530.208794890] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921530.208873426] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921530.209570745] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921574.786345516] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921574.791487898] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921574.904783561] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921574.904873506] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921574.911626316] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921574.911736627] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921574.911851841] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921574.912608272] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921574.912700672] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921574.915106020] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
[INFO] [1690921637.105268861] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel_cb
[INFO] [1690921637.107091453] [action_bridge_execute_transferjob]: ActionFactory_1_2::cancel
[INFO] [1690921639.004424597] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb
[INFO] [1690921639.004524771] [action_bridge_execute_transferjob]: ActionFactory_1_2::goal_cb Sending goal
[INFO] [1690921639.011611030] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle
[INFO] [1690921639.011765520] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle translate_goal_1_to_2
[INFO] [1690921639.011960328] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle action_server available
[INFO] [1690921639.012006568] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle send_goal_ops configured
[INFO] [1690921639.014251349] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_send_goal
[INFO] [1690921639.015348087] [action_bridge_execute_transferjob]: ActionFactory_1_2::handle async_get_result
terminate called after throwing an instance of 'std::future_error'
  what():  std::future_error: No associated state

but here are my insights and thoughts:

only the ActionFactory_1_2 is affected, i.e. the /execute_transferjob ActionServer implemented in ROS2 triggered by the SM from ROS1
if it happens, then it happens during the cancel of the previous action and the upcoming new goal
we might also need to verify the implementation of the ActionServer itself, i.e. (cancellation behavior, preemption by new goal, etc.)
I'm pretty sure the detached threads in the handle and cancel function are not correctly protected

@benmaidel maybe we can have a look at this together tomorrow as you know more about the actual ActionServer part

benmaidel · 2023-08-02T12:31:13Z

For debugging I would suggest to enable core dumps for this node. Core dumps can then be used to debug the problem in gdb. For this to work properly, the debug symbols needs to be attached during compilation.

How to enable compiling with debug in ros2 with colon

cd git/amr_ros2_ws
source_amr_ros2_build
colcon build --cmake-args -DCMAKE_EXPORT_COMPILE_COMMANDS=ON -DCMAKE_BUILD_TYPE=RelWithDebInfo --event-handlers console_direct+
source install/setup.bash

How to enable core dumps

enable apport

sudo systemctl enable apport
sudo systemctl start apport
echo 1 | sudo tee /proc/sys/kernel/core_uses_pid

start the process with the prefix

ulimit -c unlimited && ros2 run ...

core dumps should then be in the folder /var/lib/apport/coredump the log can be viewed in /var/log/apport.log

fmessmer · 2023-08-04T09:39:06Z

colcon build --cmake-args -DCMAKE_EXPORT_COMPILE_COMMANDS=ON -DCMAKE_BUILD_TYPE=RelWithDebInfo --event-handlers console_direct+

failed with a linker error somehow, thus I used

colcon build --cmake-args -DCMAKE_EXPORT_COMPILE_COMMANDS=ON -DCMAKE_BUILD_TYPE=Debug --event-handlers console_direct+

the coredump can directly be investigated in gdb like so

cd /var/lib/apport/coredump
gdb ~/git/amr_ros2_interfaces_ws/install/ros1_bridge/lib/ros1_bridge/action_bridge core._home_fxm_git_amr_ros2_interfaces_ws_install_ros1_bridge_lib_ros1_bridge_action_bridge.1000.6dea713d-29aa-4fab-b7ae-8bef148783e3.681138.35823180

then use bt to inspect the backtrace

fmessmer · 2023-08-07T11:12:49Z

showing the backtrace actually takes quite some time to load!

here is the output:

( | )fxm@alpamayo:/var/lib/apport/coredump$ gdb ~/git/amr_ros2_interfaces_ws/install/ros1_bridge/lib/ros1_bridge/action_bridge core._home_fxm_git_amr_ros2_interfaces_ws_install_ros1_bridge_lib_ros1_bridge_action_bridge.1000.008e1edd-e7b7-4a77-a067-3f9a89daf8dd.27569.532900 
GNU gdb (Ubuntu 9.2-0ubuntu1~20.04.1) 9.2
Copyright (C) 2020 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /home/fxm/git/amr_ros2_interfaces_ws/install/ros1_bridge/lib/ros1_bridge/action_bridge...
[New LWP 27569]
[New LWP 27602]
[New LWP 27595]
[New LWP 27597]
[New LWP 27668]
[New LWP 27599]
[New LWP 27601]
[New LWP 27603]
[New LWP 27606]
[New LWP 27607]
[New LWP 27688]
[New LWP 27694]
[New LWP 27701]
[New LWP 27705]
[New LWP 48773]
[New LWP 61635]
[New LWP 27598]
[New LWP 27689]
[New LWP 27690]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
bt
Core was generated by `/home/fxm/git/amr_ros2_interfaces_ws/install/ros1_bridge/lib/ros1_bridge/action'.
Program terminated with signal SIGABRT, Aborted.
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50	../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
[Current thread is 1 (Thread 0x7f43a16684c0 (LWP 27569))]
(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x00007f43a3fd9859 in __GI_abort () at abort.c:79
#2  0x00007f43a42648d1 in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#3  0x00007f43a427037c in ?? () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#4  0x00007f43a42703e7 in std::terminate() () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#5  0x00007f43a4270699 in __cxa_throw () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#6  0x00007f43a4267563 in std::__throw_future_error(int) () from /usr/lib/x86_64-linux-gnu/libstdc++.so.6
#7  0x00007f43b2e63208 in std::__future_base::_State_baseV2::_S_check<std::__future_base::_State_baseV2> (
    __p=std::shared_ptr<class std::__future_base::_State_baseV2> (use count 4, weak count 0) = {...}) at /usr/include/c++/9/future:553
#8  0x00007f43b33f4538 in std::__basic_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >::_M_get_result (
    this=0x7f437acd92d0) at /usr/include/c++/9/future:716
#9  0x00007f43b33e9052 in std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >::get (this=0x7f437acd92d0)
    at /usr/include/c++/9/future:925
#10 0x00007f43b33e1d10 in ros1_bridge::ActionFactory_1_2<amr_road_network_msgs::ExecuteTransferJobAction_<std::allocator<void> >, amr_road_network_msgs::action::ExecuteTransferJob>::GoalHandler::handle()::{lambda(std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >)#1}::operator()(std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >) (this=0x7f4380005d30, gh2=...)
    at /home/fxm/git/amr_ros2_interfaces_ws/src/ros1_bridge/include/ros1_bridge/action_factory.hpp:181
#11 0x00007f43b33fa623 in std::_Function_handler<void (std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >), ros1_bridge::ActionFactory_1_2<amr_road_network_msgs::ExecuteTransferJobAction_<std::allocator<void> >, amr_road_network_msgs::action::ExecuteTransferJob>::GoalHandler::handle()::{lambda(std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >)#1}>::_M_invoke(std::_Any_data const&, std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >&&) (__functor=..., __args#0=...) at /usr/include/c++/9/bits/std_function.h:300
#12 0x00007f43b33f56a3 in std::function<void (std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >)>::operator()(std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<amr_road_network_msgs::action::ExecuteTransferJob> > >) const (this=0x7f43580016e8, __args#0=...)
    at /usr/include/c++/9/bits/std_function.h:688
#13 0x00007f43b33eacaa in rclcpp_action::Client<amr_road_network_msgs::action::ExecuteTransferJob>::async_send_goal(amr_road_network_msgs::action::ExecuteTransferJob_Goal_<std::allocator<void> > const&, rclcpp_action::Client<amr_road_network_msgs::action::ExecuteTransferJob>::SendGoalOptions const&)::{lambda(std::shared_ptr<void>)#1}::operator()(std::shared_ptr<void>) (this=0x55ed0dcfb7c0, response=std::shared_ptr<void> (use count 4, weak count 0) = {...}) at /opt/ros/foxy/include/rclcpp_action/client.hpp:379
#14 0x00007f43b33fc29f in std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<amr_road_network_msgs::action::ExecuteTransferJob>::async_send_goal(amr_road_network_msgs::action::ExecuteTransferJob_Goal_<std::allocator<void> > const&, rclcpp_action::Client<amr_road_network_msgs::action::ExecuteTransferJob>::SendGoalOptions const&)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&) (__functor=..., __args#0=...) at /usr/include/c++/9/bits/std_function.h:300
#15 0x00007f43a3c5c967 in rclcpp_action::ClientBase::handle_goal_response(rmw_request_id_t const&, std::shared_ptr<void>) () from /opt/ros/foxy/lib/librclcpp_action.so
#16 0x00007f43a3c5b2a7 in rclcpp_action::ClientBase::execute() () from /opt/ros/foxy/lib/librclcpp_action.so
#17 0x00007f43a449885f in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&) () from /opt/ros/foxy/lib/librclcpp.so
#18 0x00007f43a449a4bb in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) () from /opt/ros/foxy/lib/librclcpp.so
#19 0x00007f43a449a54e in rclcpp::Executor::spin_once(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) () from /opt/ros/foxy/lib/librclcpp.so
#20 0x00007f43a44963ed in rclcpp::Executor::spin_node_once_nanoseconds(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>, std::chrono::duration<long, std::ratio<1l, 1000000000l> >) () from /opt/ros/foxy/lib/librclcpp.so
#21 0x000055ed0d435d1f in rclcpp::Executor::spin_node_once<rclcpp::Node, long, std::ratio<1l, 1000l> > (this=0x7fff455e18a0, 
    node=std::shared_ptr<class rclcpp::Node> (use count 3, weak count 1) = {...}, timeout=...) at /opt/ros/foxy/include/rclcpp/executor.hpp:147
#22 0x000055ed0d432fc0 in main (argc=7, argv=0x7fff455e1ab8) at /home/fxm/git/amr_ros2_interfaces_ws/src/ros1_bridge/src/action_bridge.cpp:68

~~so it seems we are running into this timeout:~~
~~https://github.com/fmessmer/ros1_bridge/blob/action_bridge_rebased_mojin/src/action_bridge.cpp#L68~~

also changing the spin_ node_once to use spin does not help:

  rclcpp::executors::SingleThreadedExecutor executor;
  executor.add_node(ros2_node);
  executor.spin();

OR

  rclcpp::executors::MultiThreadedExecutor executor;
  executor.add_node(ros2_node);
  executor.spin();

fmessmer · 2023-08-07T12:05:14Z

This also sounds relevant:
https://docs.ros2.org/foxy/api/rclcpp_action/structrclcpp__action_1_1Client_1_1SendGoalOptions.html#a19ce1413b932e5864699a5d43c142f6f

I also see that in the SendGoalOptions, only a goal_response_callback is registered - but no result_callback?

fmessmer · 2023-09-21T09:31:08Z

@benmaidel
does it make sense to combine #13 and #15?

benmaidel · 2023-09-21T12:59:15Z

closing in favor of #15

fmessmer · 2023-09-22T07:24:17Z

the commits were not completely obsolete as they e.g. fix format warnings in the CI and also allow proper logging for both ros2 run and ros2 launch.....I'll compose a set with minimal logging, passing CI including your bugfix

fmessmer force-pushed the action_bridge_rebased_mojin branch 3 times, most recently from 3388321 to ffef386 Compare July 11, 2023 13:23

hsd-dev and others added 15 commits July 11, 2023 16:53

Update CMakeLists.txt

099e7e1

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Update README.md

553db79

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Update include/ros1_bridge/action_factory.hpp

9048f32

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Update resource/get_factory.cpp.em

ab8e4d2

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Update ros1_bridge/__init__.py

03e9a13

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Update src/action_bridge.cpp

a988cce

Co-authored-by: Geoffrey Biggs <gbiggs@killbots.net> Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

risk leaking if the reset call crashes somehow

ef4c49e

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

Change cout to use RCLCPP logging macros.

0bcdfd5

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

remove commented out code

71cea80

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

fix parenthesis

2a4e7b5

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

remove unused params

2916013

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

fix nullptr keyword

bf61c29

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

remove outdated comments

9d58aac

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

pass logger to GoalHandler

e855ecb

Signed-off-by: Harsh Deshpande <harshavardhan.deshpande@ipa.fraunhofer.de>

fix code style divergence

1b40977

fmessmer force-pushed the action_bridge_rebased_mojin branch 3 times, most recently from 4cf0f70 to 3deb773 Compare July 12, 2023 15:57

fmessmer force-pushed the action_bridge_rebased_mojin branch 2 times, most recently from 33a3fcb to f68235f Compare July 18, 2023 04:49

fmessmer mentioned this pull request Sep 21, 2023

handle invalid std::shared_future reference #15

Closed

benmaidel closed this Sep 21, 2023

fmessmer reopened this Sep 22, 2023

fmessmer and others added 3 commits September 22, 2023 10:03

more logging via RCLCPP_INFO

d915538

handle invalid std::shared_future reference

08fc3bc

Use rclcpp logger

f64801a

fmessmer force-pushed the action_bridge_rebased_mojin branch 5 times, most recently from 567dae9 to f4572b2 Compare September 22, 2023 15:06

fix format

8ddb3c2

fmessmer force-pushed the action_bridge_rebased_mojin branch from f4572b2 to 8ddb3c2 Compare September 25, 2023 09:09

fmessmer merged commit 76a8f9b into mojin-robotics:mojin-devel Sep 25, 2023
1 check failed

fmessmer deleted the action_bridge_rebased_mojin branch September 25, 2023 09:11

fmessmer mentioned this pull request Sep 29, 2023

[WIP] Debugging action_client #11

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

action bridge rebased mojin #13

action bridge rebased mojin #13

fmessmer commented Jul 10, 2023

fmessmer commented Jul 11, 2023

fmessmer commented Jul 11, 2023

fmessmer commented Jul 17, 2023

fmessmer commented Jul 17, 2023

fmessmer commented Aug 1, 2023

benmaidel commented Aug 2, 2023 •

edited

Loading

fmessmer commented Aug 4, 2023

fmessmer commented Aug 7, 2023 •

edited

Loading

fmessmer commented Aug 7, 2023

fmessmer commented Sep 21, 2023

benmaidel commented Sep 21, 2023

fmessmer commented Sep 22, 2023

action bridge rebased mojin #13

action bridge rebased mojin #13

Conversation

fmessmer commented Jul 10, 2023

fmessmer commented Jul 11, 2023

fmessmer commented Jul 11, 2023

fmessmer commented Jul 17, 2023

fmessmer commented Jul 17, 2023

fmessmer commented Aug 1, 2023

benmaidel commented Aug 2, 2023 • edited Loading

How to enable compiling with debug in ros2 with colon

How to enable core dumps

fmessmer commented Aug 4, 2023

fmessmer commented Aug 7, 2023 • edited Loading

fmessmer commented Aug 7, 2023

fmessmer commented Sep 21, 2023

benmaidel commented Sep 21, 2023

fmessmer commented Sep 22, 2023

benmaidel commented Aug 2, 2023 •

edited

Loading

fmessmer commented Aug 7, 2023 •

edited

Loading