bt_navigator crashes after reaching a goal pose

[mlherd]

Terminal Logs All

[bt_navigator-11] [INFO] [bt_navigator]: Begin navigating from current location to (-0.63, 0.54)
[controller_server-8] [INFO] [controller_server]: Received a goal, begin computing control effort.
[controller_server-8] [INFO] [controller_server]: Preempting the goal. Passing the new path to the planner.
[controller_server-8] [INFO] [local_costmap.local_costmap]: Received request to clear entirely the local_costmap
[planner_server-9] [INFO] [global_costmap.global_costmap]: Received request to clear entirely the global_costmap
[planner_server-9] [INFO] [global_costmap.global_costmap]: Subscribing to the map topic (/map) with transient local durability
[recoveries_server-10] [INFO] [recoveries_server]: Attempting spin
[recoveries_server-10] [INFO] [recoveries_server]: Turning -1.57 for spin recovery.
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[recoveries_server-10] [INFO] [recoveries_server]: spin completed successfully
[recoveries_server-10] [INFO] [recoveries_server]: Attempting wait
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[controller_server-8] [WARN] [controller_server]: Control loop missed its desired rate of 20.0000Hz
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[controller_server-8] [INFO] [controller_server]: Reached the goal!
[bt_navigator-11] terminate called after throwing an instance of 'std::logic_error'
[bt_navigator-11]   what():  BtActionNode::Tick: invalid status value
[ERROR] [bt_navigator-11]: process has died [pid 21994, exit code -6, cmd '/home/melih/Desktop/ros2_eloquent/nav2_master/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args -r __node:=bt_navigator --params-file /tmp/tmplp43mjeq        '].

Terminal Log Simplified (No warning messages)

[bt_navigator-11] [INFO] [bt_navigator]: Begin navigating from current location to (-0.63, 0.54)
[controller_server-8] [INFO] [controller_server]: Received a goal, begin computing control effort.
[controller_server-8] [INFO] [controller_server]: Preempting the goal. Passing the new path to the planner.
[controller_server-8] [INFO] [local_costmap.local_costmap]: Received request to clear entirely the local_costmap
[planner_server-9] [INFO] [global_costmap.global_costmap]: Received request to clear entirely the global_costmap
[planner_server-9] [INFO] [global_costmap.global_costmap]: Subscribing to the map topic (/map) with transient local durability
[recoveries_server-10] [INFO] [recoveries_server]: Attempting spin
[recoveries_server-10] [INFO] [recoveries_server]: Turning -1.57 for spin recovery.
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[recoveries_server-10] [INFO] [recoveries_server]: spin running...
[recoveries_server-10] [INFO] [recoveries_server]: spin completed successfully
[recoveries_server-10] [INFO] [recoveries_server]: Attempting wait
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[recoveries_server-10] [INFO] [recoveries_server]: wait running...
[controller_server-8] [INFO] [controller_server]: Reached the goal!
[bt_navigator-11] terminate called after throwing an instance of 'std::logic_error'
[bt_navigator-11]   what():  BtActionNode::Tick: invalid status value
[ERROR] [bt_navigator-11]: process has died [pid 21994, exit code -6, cmd '/home/melih/Desktop/ros2_eloquent/nav2_master/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args -r __node:=bt_navigator --params-file /tmp/tmplp43mjeq        '].

Bug report

• Operating System:

  • Ubuntu 18.04

• Version or commit hash:

  • Built from source (master-branch)
  • Commit: 533044d
    • update dwb plugin pkg readme (update dwb plugin pkg readme #1380)

• DDS implementation:

  • Fast-RTPS

Steps to reproduce the issue

• Send several different goals poses in a row via RViz

Expected behavior

• Reach the goal pose and wait for the next one

Actual behavior

• the robot reaches the goal pose and then bt-navigator crashes.

Additional information

• I can't reproduce this issue consistently

[SteveMacenski]

That’s no bueno. In general can we replace all exceptions with warnings? We absolutely don’t want things crashing, log inconsistent states or we need to guarantee that all exceptions are being handled

[mlherd]

I don't have a strong opinion on this. Maybe this could be a working group discussion "replace all exceptions with warnings".

[SteveMacenski]

Well I know that’s not a popular opinion in this group- just bringing up “hey this is a case that would help”.

Trying to compile with gdb and make it happen again to get a trace...

[mlherd]

I don't see this exact problem since #1417. However, sometimes bt navigator crashes with a different error message. I haven't had a chance to fully debug this issue, but here is a screenshot of the debugger logs when bt navigator dies.

We can close this issue if it can't be reproduced anymore and I can open another issue for the other problem.

[ghost]

This new stack you've posted looks related to #1285

[maxlein]

I got this error also. Got the same debug log.
Happens to me when calling NavigateToPose in rviz while robot is already executing a goal.
But doesn't happen everytime... didn't figure out what's the cause yet.

[mkhansenbot]

Any update on this, does anyone know what's causing the exception?

[mkhansenbot]

Looks like the original issue is resolved and the new issue is a duplicate of #1285.