Skip to content

Conversation

@tzskp1
Copy link

@tzskp1 tzskp1 commented Apr 8, 2021


Basic Info

Info Please fill out this column
Ticket(s) this addresses #2303
Primary OS tested on Ubuntu
Robotic platform tested on gazebo simulation

Description of contribution in a few bullet points

  • I added checking snippet of goal_handle_ for avoiding race conditions.

For Maintainers:

  • Check that any new parameters added are updated in navigation.ros.org
  • Check that any significant change is added to the migration guide
  • Check that any new functions have Doxygen added
  • Check that any new features have test coverage
  • Check that any new plugins is added to the plugins page
  • If BT Node, Additionally: add to BT's XML index of nodes for groot, BT package's readme table, and BT library lists

@SteveMacenski
Copy link
Member

Does #2304 resolve your issue as well? This seems related

@tzskp1
Copy link
Author

tzskp1 commented Apr 9, 2021

I tried to reproduce SIGSEGV with this patch.

diff --git a/nav2_util/include/nav2_util/simple_action_server.hpp b/nav2_util/include/nav2_util/simple_action_server.hpp
index e4767abf..15058bd7 100644
--- a/nav2_util/include/nav2_util/simple_action_server.hpp
+++ b/nav2_util/include/nav2_util/simple_action_server.hpp
@@ -97,8 +97,29 @@ public:
   }
 
   rclcpp_action::CancelResponse handle_cancel(
-    const std::shared_ptr<rclcpp_action::ServerGoalHandle<ActionT>>/*handle*/)
+    const std::shared_ptr<rclcpp_action::ServerGoalHandle<ActionT>> handle)
   {
+    if (!handle->is_active()) {
+       debug_msg(
+          "Received request for goal cancellation,"
+          "but the handle is inactive, so reject the request");
+        return rclcpp_action::CancelResponse::REJECT;
+    }
+
+    {
+      std::lock_guard<std::recursive_mutex> lock(handle_state_mutex_);
+      // If now is publishing succeeded state, ignore the cancel request.
+      // So the current goal handle would be succeeded
+      if(is_publishing_succeeded_state_) {
+        is_handling_cancel_request_ = false;
+        debug_msg(
+          "Received request for goal cancellation,"
+          "but now is publishing succeeded state, so reject the request");
+        return rclcpp_action::CancelResponse::REJECT;
+      }
+      is_handling_cancel_request_ = true;
+    }
+
     std::lock_guard<std::recursive_mutex> lock(update_mutex_);
     debug_msg("Received request for goal cancellation");
     return rclcpp_action::CancelResponse::ACCEPT;
@@ -309,6 +330,19 @@ public:
     typename std::shared_ptr<typename ActionT::Result> result =
     std::make_shared<typename ActionT::Result>())
   {
+    {
+      std::lock_guard<std::recursive_mutex> lock(handle_state_mutex_);
+      // If now is handling cancel request, ignore the succeed operation.
+      // So the current goal handle would be cancelled
+      if(is_handling_cancel_request_) {
+        debug_msg(
+          "Trying to publish succeeded state, "
+          "but the current goal handle is handling cancel request");
+        return;
+      }
+      is_publishing_succeeded_state_ = true;
+    }
+
     std::lock_guard<std::recursive_mutex> lock(update_mutex_);
 
     if (is_active(current_handle_)) {
@@ -316,6 +350,11 @@ public:
       current_handle_->succeed(result);
       current_handle_.reset();
     }
+
+    {
+      std::lock_guard<std::recursive_mutex> lock(handle_state_mutex_);
+      is_publishing_succeeded_state_ = false;
+    }
   }
 
   void publish_feedback(typename std::shared_ptr<typename ActionT::Feedback> feedback)
@@ -348,6 +387,10 @@ protected:
   std::shared_ptr<rclcpp_action::ServerGoalHandle<ActionT>> current_handle_;
   std::shared_ptr<rclcpp_action::ServerGoalHandle<ActionT>> pending_handle_;
 
+  mutable std::recursive_mutex handle_state_mutex_;
+  bool is_publishing_succeeded_state_{false};
+  bool is_handling_cancel_request_{false};
+
   typename rclcpp_action::Server<ActionT>::SharedPtr action_server_;
 
   constexpr auto empty_result() const
@@ -372,6 +415,8 @@ protected:
       if (handle->is_canceling()) {
         warn_msg("Client requested to cancel the goal. Cancelling.");
         handle->canceled(result);
+        std::lock_guard<std::recursive_mutex> handle_state_lock(handle_state_mutex_);
+        is_handling_cancel_request_ = false;
       } else {
         warn_msg("Aborting handle.");
         handle->abort(result);

The problem was still the same.

#0  0x0000007fb6f596e4 in __GI___pthread_mutex_lock (mutex=0xa0) at pthread_mutex_lock.c:67
#1  0x0000007fb7edaa7c in __gthread_mutex_lock(pthread_mutex_t*) ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#2  0x0000007fb7ee0788 in std::mutex::lock() () from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#3  0x0000007fa304bde4 in nav2_behavior_tree::BtActionNode<nav2_msgs::action::Wait>::halt() ()
   from /talbot/ros/install/nav2_behavior_tree/lib/libnav2_wait_action_bt_node.so
#4  0x0000007fb7f394dc in BT::ControlNode::haltChild(unsigned long) ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#5  0x0000007fb7f39538 in BT::ControlNode::haltChildren() ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#6  0x0000007fb7f39450 in BT::ControlNode::halt() ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#7  0x0000007fa2d5808c in nav2_behavior_tree::RoundRobinNode::halt() [clone .localalias.115] ()
   from /talbot/ros/install/nav2_behavior_tree/lib/libnav2_round_robin_node_bt_node.so
#8  0x0000007fb7f05234 in std::function<void (BT::TreeNode*)>::operator()(BT::TreeNode*) const ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#9  0x0000007fb7f042e4 in BT::applyRecursiveVisitor(BT::TreeNode*, std::function<void (BT::TreeNode*)> const&) ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#10 0x0000007fb7f04378 in BT::applyRecursiveVisitor(BT::TreeNode*, std::function<void (BT::TreeNode*)> const&) ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#11 0x0000007fb7f04378 in BT::applyRecursiveVisitor(BT::TreeNode*, std::function<void (BT::TreeNode*)> const&) ()
   from /talbot/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#12 0x0000007fb6c11424 in nav2_behavior_tree::BehaviorTreeEngine::haltAllActions(BT::TreeNode*) ()
   from /talbot/ros/install/nav2_behavior_tree/lib/libnav2_behavior_tree.so
#13 0x0000007fb73a6534 in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateToPose>::executeCallback() ()
   from /talbot/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so
#14 0x0000007fb73b41e4 in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::work() ()
   from /talbot/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so

@KavenYau
Copy link
Contributor

KavenYau commented Apr 9, 2021

I think it might be an bt_action_node.hpp issue.
#2304 is the patch for fixing simple_action_server.hpp issue. They might not be related.

@SteveMacenski
Copy link
Member

SteveMacenski commented Apr 12, 2021

You are correct -- that was an oversight on my part. Let me give this a fresh look

Copy link
Member

@SteveMacenski SteveMacenski left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

A final question I had was in checking goal_handle_, I don't see anywhere where a reset() on the shared pointer was done in terminal cases so that the bool of the shared pointer would return false after the goal handle was no longer valid.

It seems like result_callback and halt() should be resetting the goal handle potentially in those terminal cases?

{
goal_updated_ = false;
on_new_goal_received();
if (goal_handle_) {
Copy link
Member

@SteveMacenski SteveMacenski Apr 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If this condition is not true (e.g. the goal_handle_ is not valid), then we pass over this which seems reasonable since we have no valid status. However, then we just continue the looping process. Is the idea that the result callback will be triggered sometime in the near-term future to set result_ so that this BT node would then exit? That would make sense to me, but see the comment below -- it looks like you block that from occurring as well. So how would the BT node exit RUNNING?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I did not think about this case.
Is following snippet ok?

      if (goal_handle_) {
        auto goal_status = goal_handle_->get_status();
        if (goal_updated_ && (goal_status == action_msgs::msg::GoalStatus::STATUS_EXECUTING ||
          goal_status == action_msgs::msg::GoalStatus::STATUS_ACCEPTED))
        {
          goal_updated_ = false;
          on_new_goal_received();
        }

         rclcpp::spin_some(node_);

         // check if, after invoking spin_some(), we finally received the result
         if (!goal_result_available_) {
           // Yield this Action, returning RUNNING
           return BT::NodeStatus::RUNNING;
         }
      }

this snippet is not tested yet.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think this solves the problem -- if goal_handle_ == false, then the node that's being ticked will never exit, there should be some exit criteria. This is what both of these comments are pointing to, there's an issue where if not goal_handle_, then the BT node would never exit the running state. One or the other here needs a way to handle the case (probably the other makes more sense) so that it can exit.

// if goal ids are not matched, the older goal call this callback so ignore the result
// if matched, it must be processed (including aborted)
if (this->goal_handle_->get_goal_id() == result.goal_id) {
if (this->goal_handle_ && (this->goal_handle_->get_goal_id() == result.goal_id)) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In this case, if this callback is triggered, there must be a result so the goal handle has to be valid still, right? Did you end up actually having an issue in this callback? If not, I think this one can be removed.

If this one does need to stay, then we need to have some condition to check if the goal handle is invalid and if so, think closely about the value we should be setting for goal_result_available_ and result_ in that case. This would create a problem if goal_handle_ was invalid that a result was triggered by this callback but then the BT node's tick() never has a result_ to exit https://github.com/ros-planning/navigation2/blob/e95a2299be32862cd37a25ff5571e3ceed2aaca8/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L204-L212 and move onto other nodes.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

According to experiment, this check is needed.

@tzskp1 tzskp1 marked this pull request as draft April 13, 2021 07:58
@SteveMacenski
Copy link
Member

Any thoughts?

@tzskp1
Copy link
Author

tzskp1 commented Apr 13, 2021

The code should have been better thought out.
I will find more sophisticated form.
On the other hand, it is difficult to reproduce the bug, and it may take some time to fix the code.
I just need a little time.

}

if (!goal_handle_) {
throw std::logic_error("BtActionNode::Tick: invalid goal handle");
Copy link
Member

@SteveMacenski SteveMacenski Apr 16, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure.... that would make it exit in the condition that the goal_handle_ is already complete, but lets think about this more strategically -- because otherwise your navigation system every time you run into this issue is going to be throwing this error all over the place.

What situations do you have that goal_handle_ is not valid? Answer that main question first. Is it only when canceled or aborted? Where is it happening? If so, then in the result callback, you can check if its not valid and then have an else statement to set the result type to that return code https://github.com/ros-planning/navigation2/blob/7877a1225c549aa0ced78a0f263cbff31829761c/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L276-L279. Then since result_ has a populated value, you get a clean exit on the next iteration.

Rather than masking this issue, we should work to fix it. When / why is goal_handle_ being turned into a nullptr? Answer that, and we can find a real solution -- whether that's fixing an issue in this file, or in the file that's nulling out the pointer

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok. I will start investigation.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

    send_goal_options.result_callback =
      [this](const typename rclcpp_action::ClientGoalHandle<ActionT>::WrappedResult & result) {
        // TODO(#1652): a work around until rcl_action interface is updated
        // if goal ids are not matched, the older goal call this callback so ignore the result
        // if matched, it must be processed (including aborted)
        if (!this->goal_handle_) {
          RCLCPP_ERROR(node_->get_logger(), "error id: %d", result.code);
        }
        if (this->goal_handle_ && (this->goal_handle_->get_goal_id() == result.goal_id)) {
          goal_result_available_ = true;
          result_ = result;
        }
      };
[bt_navigator-11] [ERROR] [1618637514.271798607] [bt_navigator_rclcpp_node]: error id: 4
[bt_navigator-11] [ERROR] [1618637514.272602967] [bt_navigator_rclcpp_node]: error id: 5
[bt_navigator-11] [ERROR] [1618637647.774230873] [bt_navigator_rclcpp_node]: error id: 4
[bt_navigator-11] [ERROR] [1618637647.839067741] [bt_navigator_rclcpp_node]: error id: 4
[bt_navigator-11] [ERROR] [1618637698.121035886] [bt_navigator_rclcpp_node]: error id: 5
[bt_navigator-11] [ERROR] [1618637712.920679316] [bt_navigator_rclcpp_node]: error id: 5

According to experiment, result.code is 4 or 5(namely SUCCEEDED or CANCELED).

Copy link
Author

@tzskp1 tzskp1 Apr 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What situations do you have that goal_handle_ is not valid?

It is when on_new_goal_received is not called yet.

When / why is goal_handle_ being turned into a nullptr?

As far as I can see, goal_handle_ is not turned into a nullptr.
goal_handle_ is originally a nullptr when BT node is created.
But original code made assumption that goal_handle_ is always valid.

Copy link
Member

@SteveMacenski SteveMacenski Apr 26, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tzskp1 https://github.com/ros-planning/navigation2/blob/d7beb7104b952f89399fac7b78b80074a7d55ddc/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L177 on_new_goal_received is the first function called after on_tick() which populates that goal_ on the first iteration.

It is incorrect that we always assume its valid, but we need to then reset this handle properly when its terminated and also know what a nullpointer means in the context. The goal_handle_ inside of the lambda in on_new_goal_received isn't called until the result message is received (its another function, not code called on the first call of on_new_goal_received)

Copy link
Author

@tzskp1 tzskp1 Apr 27, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

its another function, not code called on the first call of on_new_goal_received

As far as I know, this spin calls the callback.
https://github.com/ros-planning/navigation2/blob/7877a1225c549aa0ced78a0f263cbff31829761c/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L284
So the assignment statement follows the callback.

My intention is that nullptr should be one of the following.

  • BT node is created. (goal_handle_ is initialized to nullptr by constructor.)
  • BT node is halted.

@tzskp1
Copy link
Author

tzskp1 commented Apr 17, 2021

My elementary reasoning is that the point is how goal_handle_ is switched from the nullptr to a valid handle.

As far as I can see, when the BT node is firstly ticked, goal_handle_ is still nullptr.

There is only one the assignment of goal_handle_:
https://github.com/ros-planning/navigation2/blob/7877a1225c549aa0ced78a0f263cbff31829761c/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L293

So if goal_handle_ is valid, on_new_goal_received was called and when on_new_goal_received is firstly called, goal_handle_ is still nullptr.

It means that original code has potential of null pointer access.

Because result callback may be called before that the assignment statement is called.

Is my understanding correct?

// if goal ids are not matched, the older goal call this callback so ignore the result
// if matched, it must be processed (including aborted)
if (this->goal_handle_->get_goal_id() == result.goal_id) {
if (!this->goal_handle_ || (this->goal_handle_->get_goal_id() == result.goal_id)) {
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

!this->goal_handle_ is if and only if first tick.

@tzskp1 tzskp1 marked this pull request as ready for review April 21, 2021 01:30
@tzskp1 tzskp1 requested a review from SteveMacenski April 21, 2021 02:02
@SteveMacenski
Copy link
Member

I'm not sure where we're at on this PR anymore to be frank. You reset the goal_handle_ on halt, which I think is a totally valid thing to do. The check in should_cancel_goal seems good to me too. But if (!this->goal_handle_ || (this->goal_handle_->get_goal_id() == result.goal_id)) {} still leaves the same gap we've been talking about. If that result callback lambda is triggered and the IDs match, then we have a legit exit that would be missed by this check.

You mention you only see it on cancel and success, I'm not sure what the best action is here. I think the cancel could only have come from the halt function (right?), so we could look at that and know that the result should be set to cancellation in that situation. But what about success?

@tzskp1 tzskp1 marked this pull request as draft April 27, 2021 00:16
@tzskp1
Copy link
Author

tzskp1 commented Apr 27, 2021

I haven't checked, but I think success will happen on the first tick.
This situation occurs at that the assignment statement is not called yet since BT node was created.
After few step executions, the assignment statement is going to be called.
So goal_handle_ is going to recovery to a valid handle soon.

@tzskp1
Copy link
Author

tzskp1 commented Apr 27, 2021

If that result callback lambda is triggered and the IDs match, then we have a legit exit that would be missed by this check.

Could you elaborate please?
I thought that the problem occurs in null case.

@SteveMacenski
Copy link
Member

I wanted to mention as part of an unrelated PR, alot of this was done to maintain state better: #2320. Can you try this PR and see if it resolves your issues? I think maybe the if (!this->goal_handle_ || (this->goal_handle_->get_goal_id() == result.goal_id)) { can go away since that PR better handles all of the goal_handle_ reset conditions. If we can drop that line, then the rest of your changes are implicitly reflected in that PR.

If that result callback lambda is triggered and the IDs match, then we have a legit exit that would be missed by this check.

The result callback can be triggered from a number of different goal handles since we pass the same lambda to the action request. Checking if the goal IDs are equal is an important step because there is no promise that they're the same. We could cache the goal handle somewhere else so it doesn't try to access there. But either way, if the goal handle isn't valid for some reason, that result callback wasn't triggered for nothing, there's something going on there that we need to process. Just ignoring it isn't a real solution.

@tzskp1
Copy link
Author

tzskp1 commented Apr 30, 2021

I could reproduce the problem at the PR: #2320.
I think that the point is this call.
https://github.com/ros-planning/navigation2/blob/f83612d28ce0db76436cf711071129eb17099c8f/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L342

This call may be called before that the assign statement is called.
https://github.com/ros-planning/navigation2/blob/f83612d28ce0db76436cf711071129eb17099c8f/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L351
It implies that the result callback may be called before that goal_handle_ changes into a valid handle.
I guess that the problem never causes at Intel CPU because of memory fence.
Is there any guarantee that goal_handle_ is not a nullptr in the result callback?

backtrace is here:

[server-5] [bt_navigator-7] Stack trace (most recent call last) in thread 13340:
[server-5] [bt_navigator-7] #31   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c717eff, in std::__invoke_result<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>::type std::__invoke<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)
[server-5] [bt_navigator-7] #30   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71b82b, in void std::__invoke_impl<void, void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::__invoke_memfun_deref, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)
[server-5] [bt_navigator-7] #29   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71022f, in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*)
[server-5] [bt_navigator-7] #28   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71540f, in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const
[server-5] [bt_navigator-7] #27   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbe4e9f, in std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&)
[server-5] [bt_navigator-7] #26   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbe4633, in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::work()
[server-5] [bt_navigator-7] #25   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbd6923, in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::executeCallback()
[server-5] [bt_navigator-7] #24   Object "/ros/install/nav2_behavior_tree/lib/libnav2_behavior_tree.so", at 0x7f7b44185b, in nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >)
[server-5] [bt_navigator-7] #23   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #22   Object "/ros/install/nav2_behavior_tree/lib/libnav2_recovery_node_bt_node.so", at 0x7f66e51c5b, in nav2_behavior_tree::RecoveryNode::tick()
[server-5] [bt_navigator-7] #21   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #20   Object "/ros/install/nav2_behavior_tree/lib/libnav2_pipeline_sequence_bt_node.so", at 0x7f66e3606b, in nav2_behavior_tree::PipelineSequence::tick()
[server-5] [bt_navigator-7] #19   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7669fb, in BT::DecoratorNode::executeTick()
[server-5] [bt_navigator-7] #18   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #17   Object "/ros/install/nav2_behavior_tree/lib/libnav2_rate_controller_bt_node.so", at 0x7f66f65d1b, in nav2_behavior_tree::RateController::tick()
[server-5] [bt_navigator-7] #16   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #15   Object "/ros/install/nav2_behavior_tree/lib/libnav2_recovery_node_bt_node.so", at 0x7f66e51c5b, in nav2_behavior_tree::RecoveryNode::tick()
[server-5] [bt_navigator-7] #14   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #13   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c781be7, in BT::ReactiveSequence::tick()
[server-5] [bt_navigator-7] #12   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #11   Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723af37, in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::tick()
[server-5] [bt_navigator-7] #10   Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723aa1b, in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::is_future_goal_handle_complete(std::chrono::duration<long, std::ratio<1l, 1000l> >&)
[server-5] [bt_navigator-7] #9    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723a75b, in rclcpp::FutureReturnCode rclcpp::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> > >, long, std::ratio<1l, 1000l> >(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>, std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> > > const&, std::chrono::duration<long, std::ratio<1l, 1000l> >)
[server-5] [bt_navigator-7] #8    Object "/ros2_master/install/rclcpp/lib/librclcpp.so", at 0x7f7c30026f, in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >)
[server-5] [bt_navigator-7] #7    Object "/ros2_master/install/rclcpp/lib/librclcpp.so", at 0x7f7c30073f, in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&)
[server-5] [bt_navigator-7] #6    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b35502b, in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&)
[server-5] [bt_navigator-7] #5    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b3540a3, in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>)
[server-5] [bt_navigator-7] #4    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b357baf, in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const
[server-5] [bt_navigator-7] #3    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f672382ef, in std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::ComputePathThroughPoses>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> >)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&)
[server-5] [bt_navigator-7] #2    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f672380eb, in rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::set_result(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)
[server-5] [bt_navigator-7] #1    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6722bfe3, in std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)
[server-5] [bt_navigator-7] #0    Object "/lib/aarch64-linux-gnu/libc.so.6", at 0x7f7b850808, in bcmp
[server-5] [bt_navigator-7] Segmentation fault (Address not mapped to object [0x8])
[server-5] [ERROR] [bt_navigator-7]: process has died [pid 13176, exit code -11, cmd '/ros/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args -r __node:=bt_navigator --params-file /tmp/tmpb2bkk9f9 -r /tf:=tf -r /tf_static:=tf_static'].

@KavenYau
Copy link
Contributor

Have you found a way (or test case) to reproduce the problem?

@tzskp1
Copy link
Author

tzskp1 commented Apr 30, 2021

No I haven't.
The problem sometime causes at ARM CPU, randomly.

@KavenYau
Copy link
Contributor

KavenYau commented Apr 30, 2021

Oh. Did you run the navigation2 without any modifications? Such as the behavior_trees/navigate_through_poses_w_replanning_and_recovery.xml file and other files.

@tzskp1
Copy link
Author

tzskp1 commented Apr 30, 2021

The original problem is checked by pure navigation2.
But since the environment is discarded now, I tested the PR #2320 at my real robot with some modification.

@KavenYau
Copy link
Contributor

Do you have any logs?

By the way, which ARM development board are you using? Raspberry Pi 4 Model B?

@tzskp1
Copy link
Author

tzskp1 commented Apr 30, 2021

full launch log is here:

[INFO] [launch]: All log files can be found below /root/.ros/log/2021-04-30-02-41-06-728076-localhost-12852
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [realsense2_camera_node-10]: process started with pid [12905]
[INFO] [static_transform_publisher-1]: process started with pid [12868]
[INFO] [static_transform_publisher-2]: process started with pid [12870]
[INFO] [static_transform_publisher-3]: process started with pid [12872]
[INFO] [static_transform_publisher-4]: process started with pid [12874]
[INFO] [server-5]: process started with pid [12876]
[INFO] [path_recorder_node-7]: process started with pid [12880]
[INFO] [urg_node_driver-8]: process started with pid [12882]
[INFO] [flip_laser-9]: process started with pid [12884]
[INFO] [can2battery-11]: process started with pid [12922]
[INFO] [rgbd_leg_detector-12]: process started with pid [12935]
[static_transform_publisher-4] [INFO] [1619750467.473547766] [static_transform_publisher_74NPXKPEcVgwupFZ]: Spinning until killed publishing transform from 'base_link' to 'bumper_rear'
[static_transform_publisher-2] [INFO] [1619750467.502073024] [static_transform_publisher_bEtmlaDY67ZMc6CC]: Spinning until killed publishing transform from 'base_link' to 'camera_link'
[static_transform_publisher-1] [INFO] [1619750467.555949559] [static_transform_publisher_TjIOXJj9BWp17SIB]: Spinning until killed publishing transform from 'base_link' to 'laser'
[static_transform_publisher-3] [INFO] [1619750467.615791859] [static_transform_publisher_YMaA6YCpQesKZPy3]: Spinning until killed publishing transform from 'base_link' to 'bumper_front'
[urg_node_driver-8] [INFO] [1619750467.723089637] [urg_node]: Connected to network device with ID: H2039348
[urg_node_driver-8] [INFO] [1619750467.749317286] [urg_node]: Streaming data.
[realsense2_camera_node-10] �[0m[INFO] [1619750467.815373461] [RealSenseCameraNode]: RealSense ROS v3.1.4�[0m
[realsense2_camera_node-10] �[0m[INFO] [1619750467.815568129] [RealSenseCameraNode]: Built with LibRealSense v2.42.0�[0m
[realsense2_camera_node-10] �[0m[INFO] [1619750467.815610403] [RealSenseCameraNode]: Running with LibRealSense v2.42.0�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750467.840701376] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] INFO:waitress:Serving on http://0.0.0.0:5000
[realsense2_camera_node-10] �[33m[WARN] [1619750473.858138358] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750479.874914725] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [INFO] [map_server-1]: process started with pid [13164]
[server-5] [INFO] [amcl-2]: process started with pid [13166]
[server-5] [INFO] [lifecycle_manager-3]: process started with pid [13168]
[server-5] [INFO] [controller_server-4]: process started with pid [13170]
[server-5] [INFO] [planner_server-5]: process started with pid [13172]
[server-5] [INFO] [recoveries_server-6]: process started with pid [13174]
[server-5] [INFO] [bt_navigator-7]: process started with pid [13176]
[server-5] [INFO] [waypoint_follower-8]: process started with pid [13178]
[server-5] [INFO] [lifecycle_manager-9]: process started with pid [13180]
[server-5] [lifecycle_manager-3] [INFO] [1619750483.269464669] [lifecycle_manager_localization]: Creating
[server-5] [controller_server-4] [INFO] [1619750483.463051300] [controller_server]:
[server-5] [controller_server-4] 	controller_server lifecycle node launched.
[server-5] [controller_server-4] 	Waiting on external lifecycle transitions to activate
[server-5] [controller_server-4] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [controller_server-4] [INFO] [1619750483.527109087] [controller_server]: Creating controller server
[server-5] [map_server-1] [INFO] [1619750483.666194503] [map_server]:
[server-5] [map_server-1] 	map_server lifecycle node launched.
[server-5] [map_server-1] 	Waiting on external lifecycle transitions to activate
[server-5] [map_server-1] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [map_server-1] [INFO] [1619750483.666771753] [map_server]: Creating
[server-5] [controller_server-4] [INFO] [1619750483.705253225] [local_costmap.local_costmap]:
[server-5] [controller_server-4] 	local_costmap lifecycle node launched.
[server-5] [controller_server-4] 	Waiting on external lifecycle transitions to activate
[server-5] [controller_server-4] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [controller_server-4] [INFO] [1619750483.715937641] [local_costmap.local_costmap]: Creating Costmap
[server-5] [lifecycle_manager-3] [INFO] [1619750483.786917187] [lifecycle_manager_localization]: �[34m�[1mCreating and initializing lifecycle service clients�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750483.814640895] [lifecycle_manager_navigation]: Creating
[server-5] [amcl-2] [INFO] [1619750483.873855064] [amcl]:
[server-5] [amcl-2] 	amcl lifecycle node launched.
[server-5] [amcl-2] 	Waiting on external lifecycle transitions to activate
[server-5] [amcl-2] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [amcl-2] [INFO] [1619750483.874367351] [amcl]: Creating
[server-5] [recoveries_server-6] [INFO] [1619750483.921628068] [recoveries_server]:
[server-5] [recoveries_server-6] 	recoveries_server lifecycle node launched.
[server-5] [recoveries_server-6] 	Waiting on external lifecycle transitions to activate
[server-5] [recoveries_server-6] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [lifecycle_manager-3] [INFO] [1619750483.974807508] [lifecycle_manager_localization]: �[34m�[1mStarting managed nodes bringup...�[0m�[0m
[server-5] [lifecycle_manager-3] [INFO] [1619750483.974963998] [lifecycle_manager_localization]: �[34m�[1mConfiguring map_server�[0m�[0m
[server-5] [map_server-1] [INFO] [1619750483.983143400] [map_server]: Configuring
[server-5] [map_server-1] [INFO] [map_io]: Loading yaml file: /map/mk-system2.yaml
[server-5] [map_server-1] [DEBUG] [map_io]: resolution: 0.05
[server-5] [map_server-1] [DEBUG] [map_io]: origin[0]: -1.04
[server-5] [map_server-1] [DEBUG] [map_io]: origin[1]: -14.9
[server-5] [map_server-1] [DEBUG] [map_io]: origin[2]: 0
[server-5] [map_server-1] [DEBUG] [map_io]: free_thresh: 0.25
[server-5] [map_server-1] [DEBUG] [map_io]: occupied_thresh: 0.65
[server-5] [map_server-1] [DEBUG] [map_io]: mode: trinary
[server-5] [map_server-1] [DEBUG] [map_io]: negate: 0
[server-5] [map_server-1] [INFO] [map_io]: Loading image_file: /map/mk-system2.pgm
[server-5] [bt_navigator-7] [INFO] [1619750484.011769434] [bt_navigator]:
[server-5] [bt_navigator-7] 	bt_navigator lifecycle node launched.
[server-5] [bt_navigator-7] 	Waiting on external lifecycle transitions to activate
[server-5] [bt_navigator-7] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [bt_navigator-7] [INFO] [1619750484.012219829] [bt_navigator]: Creating
[server-5] [map_server-1] [DEBUG] [map_io]: Read map /map/mk-system2.pgm: 215 X 411 map @ 0.05 m/cell
[server-5] [lifecycle_manager-3] [INFO] [1619750484.135061712] [lifecycle_manager_localization]: �[34m�[1mConfiguring amcl�[0m�[0m
[server-5] [amcl-2] [INFO] [1619750484.140166530] [amcl]: Configuring
[server-5] [amcl-2] [INFO] [1619750484.142911302] [amcl]: initTransforms
[server-5] [lifecycle_manager-9] [INFO] [1619750484.179523158] [lifecycle_manager_navigation]: �[34m�[1mCreating and initializing lifecycle service clients�[0m�[0m
[server-5] [waypoint_follower-8] [INFO] [1619750484.200109415] [waypoint_follower]:
[server-5] [waypoint_follower-8] 	waypoint_follower lifecycle node launched.
[server-5] [waypoint_follower-8] 	Waiting on external lifecycle transitions to activate
[server-5] [waypoint_follower-8] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [waypoint_follower-8] [INFO] [1619750484.206856251] [waypoint_follower]: Creating
[server-5] [planner_server-5] [INFO] [1619750484.238963101] [planner_server]:
[server-5] [planner_server-5] 	planner_server lifecycle node launched.
[server-5] [planner_server-5] 	Waiting on external lifecycle transitions to activate
[server-5] [planner_server-5] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [lifecycle_manager-9] [INFO] [1619750484.277631977] [lifecycle_manager_navigation]: �[34m�[1mStarting managed nodes bringup...�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750484.277761457] [lifecycle_manager_navigation]: �[34m�[1mConfiguring controller_server�[0m�[0m
[server-5] [amcl-2] [INFO] [1619750484.280116606] [amcl]: initPubSub
[server-5] [controller_server-4] [INFO] [1619750484.282348003] [controller_server]: Configuring controller interface
[server-5] [controller_server-4] [INFO] [1619750484.283407267] [controller_server]: Controller frequency set to 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750484.283529674] [local_costmap.local_costmap]: Configuring
[server-5] [planner_server-5] [INFO] [1619750484.294816494] [planner_server]: Creating
[server-5] [amcl-2] [INFO] [1619750484.304438670] [amcl]: Subscribed to map topic.
[server-5] [controller_server-4] [INFO] [1619750484.309481628] [local_costmap.local_costmap]: Using plugin "static_layer"
[server-5] [controller_server-4] [INFO] [1619750484.323806358] [local_costmap.local_costmap]: Subscribing to the map topic (/map) with transient local durability
[server-5] [controller_server-4] [INFO] [1619750484.327109691] [local_costmap.local_costmap]: Initialized plugin "static_layer"
[server-5] [controller_server-4] [INFO] [1619750484.327223106] [local_costmap.local_costmap]: Using plugin "obstacle_layer"
[server-5] [controller_server-4] [INFO] [1619750484.328965963] [local_costmap.local_costmap]: Subscribed to Topics: bumper_front bumper_rear scan
[server-5] [controller_server-4] [INFO] [1619750484.358557590] [local_costmap.local_costmap]: Initialized plugin "obstacle_layer"
[server-5] [controller_server-4] [INFO] [1619750484.358678910] [local_costmap.local_costmap]: Using plugin "inflation_layer"
[server-5] [controller_server-4] [INFO] [1619750484.361289146] [local_costmap.local_costmap]: Initialized plugin "inflation_layer"
[server-5] [controller_server-4] [INFO] [1619750484.391071921] [controller_server]: Created progress_checker : progress_checker of type nav2_controller::SimpleProgressChecker
[server-5] [controller_server-4] [INFO] [1619750484.422372067] [controller_server]: Created goal_checker : goal_checker of type nav2_controller::SimpleGoalChecker
[server-5] [controller_server-4] [INFO] [1619750484.473921842] [controller_server]: Created controller : FollowPath of type dwb_core::DWBLocalPlanner
[server-5] [controller_server-4] [INFO] [1619750484.478443137] [controller_server]: Setting transform_tolerance to 0.050000
[server-5] [controller_server-4] [INFO] [1619750484.488220778] [local_costmap.local_costmap]: StaticLayer: Resizing static layer to 215 X 411 at 0.050000 m/pix
[server-5] [lifecycle_manager-3] [INFO] [1619750484.474189922] [lifecycle_manager_localization]: �[34m�[1mActivating map_server�[0m�[0m
[server-5] [map_server-1] [INFO] [1619750484.475165053] [map_server]: Activating
[server-5] [map_server-1] [INFO] [1619750484.475716286] [map_server]: Creating bond (map_server) to lifecycle manager.
[server-5] [amcl-2] [INFO] [1619750484.485442084] [amcl]: Received a 215 X 411 map @ 0.050 m/pix
[server-5] [controller_server-4] [INFO] [1619750484.548514437] [controller_server]: Using critic "RotateToStart" (dwb_critics::RotateToStartCritic)
[server-5] [controller_server-4] [INFO] [1619750484.549805202] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.553939529] [controller_server]: Using critic "RotateToGoal" (dwb_critics::RotateToGoalCritic)
[server-5] [controller_server-4] [INFO] [1619750484.560984495] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.562418597] [controller_server]: Using critic "Oscillation" (dwb_critics::OscillationCritic)
[server-5] [controller_server-4] [INFO] [1619750484.566058783] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.567161249] [controller_server]: Using critic "BaseObstacle" (dwb_critics::BaseObstacleCritic)
[server-5] [controller_server-4] [INFO] [1619750484.568295685] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.569398119] [controller_server]: Using critic "GoalAlign" (dwb_critics::GoalAlignCritic)
[server-5] [controller_server-4] [INFO] [1619750484.572005347] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.573670759] [controller_server]: Using critic "PathAlign" (dwb_critics::PathAlignCritic)
[server-5] [controller_server-4] [INFO] [1619750484.574912145] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.575720002] [controller_server]: Using critic "PathDist" (dwb_critics::PathDistCritic)
[server-5] [controller_server-4] [INFO] [1619750484.576395498] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.577107413] [controller_server]: Using critic "GoalDist" (dwb_critics::GoalDistCritic)
[server-5] [controller_server-4] [INFO] [1619750484.577889603] [controller_server]: Critic plugin initialized
[server-5] [controller_server-4] [INFO] [1619750484.600559377] [controller_server]: Created controller : FollowPathTeb of type teb_local_planner::TebLocalPlannerROS
[server-5] [lifecycle_manager-3] [INFO] [1619750484.616144086] [lifecycle_manager_localization]: Server map_server connected with bond.
[server-5] [lifecycle_manager-3] [INFO] [1619750484.616269566] [lifecycle_manager_localization]: �[34m�[1mActivating amcl�[0m�[0m
[server-5] [amcl-2] [INFO] [1619750484.622245731] [amcl]: Activating
[server-5] [amcl-2] [INFO] [1619750484.622365579] [amcl]: Creating bond (amcl) to lifecycle manager.
[server-5] [amcl-2] [INFO] [1619750484.680454881] [amcl]: createLaserObject
[server-5] [controller_server-4] [INFO] [1619750484.703771541] [controller_server]: Footprint model 'polygon' loaded for trajectory optimization.
[server-5] [controller_server-4] [INFO] [1619750484.704014372] [controller_server]: Parallel planning in distinctive topologies enabled.
[server-5] [amcl-2] [INFO] [1619750484.725158678] [amcl]: initialPoseReceived
[server-5] [amcl-2] [INFO] [1619750484.730514006] [amcl]: Setting pose (1619750484.730507): 0.458 0.211 -0.141
[server-5] [controller_server-4] [INFO] [1619750484.756946949] [controller_server]: library path :
[server-5] [controller_server-4] [INFO] [1619750484.757933824] [controller_server]: Costmap conversion plugin costmap_converter::CostmapToPolygonsDBSMCCH loaded.
[server-5] [controller_server-4] [INFO] [1619750484.804727250] [controller_server]: Created controller : FollowPathReg of type nav2_regulated_pure_pursuit_controller::RegulatedPurePursuitController
[server-5] [controller_server-4] [INFO] [1619750484.823478229] [controller_server]: Controller Server has FollowPath FollowPathTeb FollowPathReg  controllers available.
[server-5] [lifecycle_manager-3] [INFO] [1619750484.825488877] [lifecycle_manager_localization]: Server amcl connected with bond.
[server-5] [lifecycle_manager-3] [INFO] [1619750484.825620021] [lifecycle_manager_localization]: �[34m�[1mManaged nodes are active�[0m�[0m
[server-5] [lifecycle_manager-3] [INFO] [1619750484.825666200] [lifecycle_manager_localization]: �[34m�[1mCreating bond timer...�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750484.859538468] [lifecycle_manager_navigation]: �[34m�[1mConfiguring planner_server�[0m�[0m
[server-5] [planner_server-5] [INFO] [1619750484.957088725] [global_costmap.global_costmap]:
[server-5] [planner_server-5] 	global_costmap lifecycle node launched.
[server-5] [planner_server-5] 	Waiting on external lifecycle transitions to activate
[server-5] [planner_server-5] 	See https://design.ros2.org/articles/node_lifecycle.html for more information.
[server-5] [planner_server-5] [INFO] [1619750484.970984117] [global_costmap.global_costmap]: Creating Costmap
[server-5] [planner_server-5] [INFO] [1619750485.072618043] [planner_server]: Configuring
[server-5] [planner_server-5] [INFO] [1619750485.075449956] [global_costmap.global_costmap]: Configuring
[server-5] [planner_server-5] [INFO] [1619750485.114323516] [global_costmap.global_costmap]: Using plugin "static_layer"
[server-5] [planner_server-5] [INFO] [1619750485.136205339] [global_costmap.global_costmap]: Subscribing to the map topic (/map) with transient local durability
[server-5] [planner_server-5] [INFO] [1619750485.144491243] [global_costmap.global_costmap]: Initialized plugin "static_layer"
[server-5] [planner_server-5] [INFO] [1619750485.144897731] [global_costmap.global_costmap]: Using plugin "obstacle_layer"
[server-5] [planner_server-5] [INFO] [1619750485.154687533] [global_costmap.global_costmap]: Subscribed to Topics: bumper_front bumper_rear scan
[server-5] [planner_server-5] [INFO] [1619750485.186954841] [global_costmap.global_costmap]: StaticLayer: Resizing costmap to 215 X 411 at 0.050000 m/pix
[server-5] [planner_server-5] [INFO] [1619750485.217758766] [global_costmap.global_costmap]: Initialized plugin "obstacle_layer"
[server-5] [planner_server-5] [INFO] [1619750485.217877781] [global_costmap.global_costmap]: Using plugin "inflation_layer"
[server-5] [planner_server-5] [INFO] [1619750485.230208472] [global_costmap.global_costmap]: Initialized plugin "inflation_layer"
[server-5] [planner_server-5] [INFO] [1619750485.300304445] [planner_server]: Created global planner plugin GridBased of type nav2_smac_planner/SmacPlanner2D
[server-5] [planner_server-5] [INFO] [1619750485.312027131] [planner_server]: maximum iteration selected as <= 0, disabling maximum iterations.
[server-5] [planner_server-5] [INFO] [1619750485.315504363] [planner_server]: Configured plugin GridBased of type SmacPlanner2D with tolerance 0.50, maximum iterations 2147483647, max on approach iterations 1000, and not allowing unknown traversal. Using motion model: Moore.
[server-5] [planner_server-5] [INFO] [1619750485.322246687] [planner_server]: Created global planner plugin Straight of type nav2_straightline_planner/StraightLine
[server-5] [planner_server-5] [INFO] [1619750485.331080368] [planner_server]: maximum iteration selected as <= 0, disabling maximum iterations.
[server-5] [planner_server-5] [INFO] [1619750485.334117734] [planner_server]: Configured plugin Straight of type SmacPlanner2D with tolerance 0.50, maximum iterations 2147483647, max on approach iterations 1000, and not allowing unknown traversal. Using motion model: Moore.
[server-5] [planner_server-5] [INFO] [1619750485.334250606] [planner_server]: Planner Server has GridBased Straight  planners available.
[server-5] [lifecycle_manager-9] [INFO] [1619750485.374816619] [lifecycle_manager_navigation]: �[34m�[1mConfiguring recoveries_server�[0m�[0m
[server-5] [recoveries_server-6] [INFO] [1619750485.376673594] [recoveries_server]: Configuring
[server-5] [recoveries_server-6] [INFO] [1619750485.427847730] [recoveries_server]: Creating recovery plugin spin of type nav2_recoveries/Spin
[server-5] [recoveries_server-6] [INFO] [1619750485.432443142] [recoveries_server]: Configuring spin
[server-5] [recoveries_server-6] [INFO] [1619750485.466206027] [recoveries_server]: Creating recovery plugin backup of type nav2_recoveries/BackUp
[server-5] [recoveries_server-6] [INFO] [1619750485.470557104] [recoveries_server]: Configuring backup
[server-5] [recoveries_server-6] [INFO] [1619750485.503662894] [recoveries_server]: Creating recovery plugin wait of type nav2_recoveries/Wait
[server-5] [recoveries_server-6] [INFO] [1619750485.507966384] [recoveries_server]: Configuring wait
[server-5] [lifecycle_manager-9] [INFO] [1619750485.545542010] [lifecycle_manager_navigation]: �[34m�[1mConfiguring bt_navigator�[0m�[0m
[server-5] [bt_navigator-7] [INFO] [1619750485.547620694] [bt_navigator]: Configuring
[server-5] [bt_navigator-7] [WARN] [1619750485.767566313] [rcl.logging_rosout]: Publisher already registered for provided node name. If this is due to multiple nodes with the same name then all logs for that logger name will go out over the existing publisher. As soon as any node with that name is destructed it will unregister the publisher, preventing any further logs for that name from being published on the rosout topic.
[server-5] [lifecycle_manager-9] [INFO] [1619750485.850494671] [lifecycle_manager_navigation]: �[34m�[1mConfiguring waypoint_follower�[0m�[0m
[server-5] [waypoint_follower-8] [INFO] [1619750485.852650736] [waypoint_follower]: Configuring
[realsense2_camera_node-10] �[33m[WARN] [1619750485.897637174] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750486.045116629] [lifecycle_manager_navigation]: �[34m�[1mActivating controller_server�[0m�[0m
[server-5] [controller_server-4] [INFO] [1619750486.046398722] [controller_server]: Activating
[server-5] [controller_server-4] [INFO] [1619750486.046533354] [local_costmap.local_costmap]: Activating
[server-5] [controller_server-4] [INFO] [1619750486.046576621] [local_costmap.local_costmap]: Checking transform
[server-5] [controller_server-4] [INFO] [1619750486.047023719] [local_costmap.local_costmap]: start
[server-5] [controller_server-4] [INFO] [1619750486.053969095] [controller_server]: Activating controller: FollowPathReg of type regulated_pure_pursuit_controller::RegulatedPurePursuitController
[server-5] [controller_server-4] [INFO] [1619750486.054116176] [controller_server]: Creating bond (controller_server) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.174089985] [lifecycle_manager_navigation]: Server controller_server connected with bond.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.174227401] [lifecycle_manager_navigation]: �[34m�[1mActivating planner_server�[0m�[0m
[server-5] [planner_server-5] [INFO] [1619750486.179429504] [planner_server]: Activating
[server-5] [planner_server-5] [INFO] [1619750486.179555016] [global_costmap.global_costmap]: Activating
[server-5] [planner_server-5] [INFO] [1619750486.179604235] [global_costmap.global_costmap]: Checking transform
[server-5] [planner_server-5] [INFO] [1619750486.180128682] [global_costmap.global_costmap]: start
[server-5] [planner_server-5] [INFO] [1619750486.241091853] [planner_server]: Activating plugin Straight of type NavfnPlanner
[server-5] [planner_server-5] [INFO] [1619750486.241259639] [planner_server]: Activating plugin Straight of type SmacPlanner2D
[server-5] [planner_server-5] [INFO] [1619750486.241297657] [planner_server]: Activating plugin GridBased of type SmacPlanner2D
[server-5] [planner_server-5] [INFO] [1619750486.241374046] [planner_server]: Creating bond (planner_server) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.365431171] [lifecycle_manager_navigation]: Server planner_server connected with bond.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.365783576] [lifecycle_manager_navigation]: �[34m�[1mActivating recoveries_server�[0m�[0m
[server-5] [recoveries_server-6] [INFO] [1619750486.366946366] [recoveries_server]: Activating
[server-5] [recoveries_server-6] [INFO] [1619750486.367063365] [recoveries_server]: Activating spin
[server-5] [recoveries_server-6] [INFO] [1619750486.367100903] [recoveries_server]: Activating backup
[server-5] [recoveries_server-6] [INFO] [1619750486.367132553] [recoveries_server]: Activating wait
[server-5] [recoveries_server-6] [INFO] [1619750486.367166699] [recoveries_server]: Creating bond (recoveries_server) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.504742682] [lifecycle_manager_navigation]: Server recoveries_server connected with bond.
[server-5] [lifecycle_manager-9] [INFO] [1619750486.507701611] [lifecycle_manager_navigation]: �[34m�[1mActivating bt_navigator�[0m�[0m
[server-5] [bt_navigator-7] [INFO] [1619750486.510213921] [bt_navigator]: Activating
[server-5] [bt_navigator-7] [PublisherZMQ] Publisher quitting.
[server-5] [bt_navigator-7] [PublisherZMQ] just died. Exeption Context was terminated
[server-5] [bt_navigator-7] [INFO] [1619750486.937484244] [bt_navigator]: Creating bond (bt_navigator) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750487.054826951] [lifecycle_manager_navigation]: Server bt_navigator connected with bond.
[server-5] [lifecycle_manager-9] [INFO] [1619750487.054990065] [lifecycle_manager_navigation]: �[34m�[1mActivating waypoint_follower�[0m�[0m
[server-5] [waypoint_follower-8] [INFO] [1619750487.058353818] [waypoint_follower]: Activating
[server-5] WARNING:waitress.queue:Task queue depth is 1
[server-5] [waypoint_follower-8] [INFO] [1619750487.371703144] [waypoint_follower]: Creating bond (waypoint_follower) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750487.497956689] [lifecycle_manager_navigation]: Server waypoint_follower connected with bond.
[server-5] [lifecycle_manager-9] [INFO] [1619750487.498094393] [lifecycle_manager_navigation]: �[34m�[1mManaged nodes are active�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750487.498137820] [lifecycle_manager_navigation]: �[34m�[1mCreating bond timer...�[0m�[0m
[server-5] [bt_navigator-7] [PublisherZMQ] Server quitting.
[server-5] [bt_navigator-7] [PublisherZMQ] just died. Exeption Context was terminated
[server-5] [bt_navigator-7] [PublisherZMQ] Publisher quitting.
[server-5] [bt_navigator-7] [PublisherZMQ] just died. Exeption Context was terminated
[server-5] [amcl-2] [INFO] [1619750488.222471920] [amcl_rclcpp_node]: Message Filter dropping message: frame 'laser' at time 1619750487.970 for reason 'discarding message because the queue is full'
[server-5] [amcl-2] [INFO] [1619750488.248727348] [amcl_rclcpp_node]: Message Filter dropping message: frame 'laser' at time 1619750487.995 for reason 'discarding message because the queue is full'
[server-5] [bt_navigator-7] [INFO] [1619750488.608457469] [bt_navigator]: Begin navigating from current location through 221 poses to (0.69, 0.32)
[server-5] [controller_server-4] [INFO] [1619750488.644217786] [controller_server]: Received a goal, begin computing control effort.
[server-5] [controller_server-4] [WARN] [1619750488.801317787] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750488.920997883] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750489.206290778] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750489.208461564] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750489.312703360] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750489.423708184] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750489.590565986] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750489.693150210] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750489.771109184] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] WARNING:waitress.queue:Task queue depth is 1
[server-5] [controller_server-4] [WARN] [1619750489.846468545] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750489.928720352] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750490.010284693] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750490.010427838] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750490.507162519] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750491.007139890] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750491.423825458] [controller_server]: Passing new path to controller.
[realsense2_camera_node-10] �[33m[WARN] [1619750491.924346608] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [controller_server-4] [INFO] [1619750491.923815088] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750492.340495537] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750492.840483473] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750493.257155954] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750493.757154388] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750494.173796948] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750494.673819385] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750495.090482940] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750495.590485377] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750496.007156646] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750496.507173454] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750497.090500373] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750497.590438266] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750497.767355939] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750497.862281115] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750497.946736256] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[realsense2_camera_node-10] �[33m[WARN] [1619750497.977129789] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [controller_server-4] [WARN] [1619750498.037864660] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750498.038105283] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750498.140507099] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750498.229078455] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750498.293841184] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750498.359894518] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750498.432986386] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750498.507141677] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750498.923828567] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750499.013112381] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750499.340500289] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750499.840487595] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750500.257327808] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750500.757165380] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750501.173818479] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750501.673821918] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750502.173824621] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750502.590472570] [controller_server]: Passing new path to controller.
[server-5] [bt_navigator-7] [WARN] [1619750503.022532834] [bt_navigator_rclcpp_node]: Timed out while waiting for action server to acknowledge goal request for follow_path
[server-5] [controller_server-4] [INFO] [1619750503.025949135] [local_costmap.local_costmap]: Received request to clear entirely the local_costmap
[server-5] [controller_server-4] [WARN] [1619750503.030674026] [controller_server_rclcpp_node]: [follow_path] [ActionServer] Aborting handle.
[server-5] [controller_server-4] [INFO] [1619750503.090500844] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750503.507163355] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750504.007861558] [controller_server]: Passing new path to controller.
[realsense2_camera_node-10] �[33m[WARN] [1619750504.013509961] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [controller_server-4] [INFO] [1619750504.423826301] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750504.840480012] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750505.340487041] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750505.757144914] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750506.257148456] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750506.673825628] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750507.173836180] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750507.590496744] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750508.090497984] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750508.507147157] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750509.007151759] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750509.423820742] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750509.923835234] [controller_server]: Passing new path to controller.
[realsense2_camera_node-10] �[33m[WARN] [1619750510.043182102] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [controller_server-4] [INFO] [1619750510.340494489] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750510.840490198] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750511.257168048] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750511.757146605] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750511.842315552] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750512.173817575] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750512.673837480] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750513.090489570] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [WARN] [1619750513.266401080] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [INFO] [1619750513.590480419] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750514.007147807] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750514.507150114] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750514.923813823] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750515.423827428] [controller_server]: Passing new path to controller.
[server-5] [controller_server-4] [INFO] [1619750515.840489890] [controller_server]: Passing new path to controller.
[server-5] [amcl-2] [INFO] [1619750516.020087542] [amcl_rclcpp_node]: Message Filter dropping message: frame 'laser' at time 1619750515.768 for reason 'discarding message because the queue is full'
[realsense2_camera_node-10] �[33m[WARN] [1619750516.070818745] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [bt_navigator-7] [WARN] [1619750516.241940689] [bt_navigator_rclcpp_node]: Timed out while waiting for action server to acknowledge goal request for compute_path_through_poses
[server-5] [planner_server-5] [INFO] [1619750516.244935012] [global_costmap.global_costmap]: Received request to clear entirely the global_costmap
[server-5] [bt_navigator-7] Stack trace (most recent call last) in thread 13340:
[server-5] [bt_navigator-7] #31   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c717eff, in std::__invoke_result<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>::type std::__invoke<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)
[server-5] [bt_navigator-7] #30   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71b82b, in void std::__invoke_impl<void, void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::__invoke_memfun_deref, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)
[server-5] [bt_navigator-7] #29   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71022f, in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*)
[server-5] [bt_navigator-7] #28   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c71540f, in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const
[server-5] [bt_navigator-7] #27   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbe4e9f, in std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&)
[server-5] [bt_navigator-7] #26   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbe4633, in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::work()
[server-5] [bt_navigator-7] #25   Object "/ros/install/nav2_bt_navigator/lib/libbt_navigator_core.so", at 0x7f7bbd6923, in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::executeCallback()
[server-5] [bt_navigator-7] #24   Object "/ros/install/nav2_behavior_tree/lib/libnav2_behavior_tree.so", at 0x7f7b44185b, in nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >)
[server-5] [bt_navigator-7] #23   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #22   Object "/ros/install/nav2_behavior_tree/lib/libnav2_recovery_node_bt_node.so", at 0x7f66e51c5b, in nav2_behavior_tree::RecoveryNode::tick()
[server-5] [bt_navigator-7] #21   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #20   Object "/ros/install/nav2_behavior_tree/lib/libnav2_pipeline_sequence_bt_node.so", at 0x7f66e3606b, in nav2_behavior_tree::PipelineSequence::tick()
[server-5] [bt_navigator-7] #19   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7669fb, in BT::DecoratorNode::executeTick()
[server-5] [bt_navigator-7] #18   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #17   Object "/ros/install/nav2_behavior_tree/lib/libnav2_rate_controller_bt_node.so", at 0x7f66f65d1b, in nav2_behavior_tree::RateController::tick()
[server-5] [bt_navigator-7] #16   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #15   Object "/ros/install/nav2_behavior_tree/lib/libnav2_recovery_node_bt_node.so", at 0x7f66e51c5b, in nav2_behavior_tree::RecoveryNode::tick()
[server-5] [bt_navigator-7] #14   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #13   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c781be7, in BT::ReactiveSequence::tick()
[server-5] [bt_navigator-7] #12   Object "/ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so", at 0x7f7c7687d3, in BT::TreeNode::executeTick()
[server-5] [bt_navigator-7] #11   Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723af37, in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::tick()
[server-5] [bt_navigator-7] #10   Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723aa1b, in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::is_future_goal_handle_complete(std::chrono::duration<long, std::ratio<1l, 1000l> >&)
[server-5] [bt_navigator-7] #9    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6723a75b, in rclcpp::FutureReturnCode rclcpp::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> > >, long, std::ratio<1l, 1000l> >(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>, std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> > > const&, std::chrono::duration<long, std::ratio<1l, 1000l> >)
[server-5] [bt_navigator-7] #8    Object "/ros2_master/install/rclcpp/lib/librclcpp.so", at 0x7f7c30026f, in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >)
[server-5] [bt_navigator-7] #7    Object "/ros2_master/install/rclcpp/lib/librclcpp.so", at 0x7f7c30073f, in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&)
[server-5] [bt_navigator-7] #6    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b35502b, in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&)
[server-5] [bt_navigator-7] #5    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b3540a3, in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>)
[server-5] [bt_navigator-7] #4    Object "/ros2_master/install/rclcpp_action/lib/librclcpp_action.so", at 0x7f7b357baf, in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const
[server-5] [bt_navigator-7] #3    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f672382ef, in std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::ComputePathThroughPoses>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> >)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&)
[server-5] [bt_navigator-7] #2    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f672380eb, in rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::set_result(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)
[server-5] [bt_navigator-7] #1    Object "/ros/install/nav2_behavior_tree/lib/libnav2_compute_path_through_poses_action_bt_node.so", at 0x7f6722bfe3, in std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)
[server-5] [bt_navigator-7] #0    Object "/lib/aarch64-linux-gnu/libc.so.6", at 0x7f7b850808, in bcmp
[server-5] [bt_navigator-7] Segmentation fault (Address not mapped to object [0x8])
[server-5] [ERROR] [bt_navigator-7]: process has died [pid 13176, exit code -11, cmd '/ros/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args -r __node:=bt_navigator --params-file /tmp/tmpb2bkk9f9 -r /tf:=tf -r /tf_static:=tf_static'].
[server-5] [planner_server-5] [WARN] [1619750517.207266814] [planner_server]: Planner loop missed its desired rate of 12.0000 Hz. Current loop rate is 1.0515 Hz
[server-5] WARNING:waitress.queue:Task queue depth is 1
[server-5] [lifecycle_manager-9] [INFO] [1619750520.300335109] [lifecycle_manager_navigation]: �[34m�[1mHave not received a heartbeat from bt_navigator.�[0m�[0m
[server-5] [lifecycle_manager-9] [ERROR] [1619750520.300515120] [lifecycle_manager_navigation]: CRITICAL FAILURE: SERVER bt_navigator IS DOWN after not receiving a heartbeat for 4000 ms. Shutting down related nodes.
[server-5] [lifecycle_manager-9] [INFO] [1619750520.300590900] [lifecycle_manager_navigation]: �[34m�[1mTerminating bond timer...�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750520.300651512] [lifecycle_manager_navigation]: �[34m�[1mResetting managed nodes...�[0m�[0m
[server-5] [lifecycle_manager-9] [INFO] [1619750520.300692378] [lifecycle_manager_navigation]: �[34m�[1mDeactivating waypoint_follower�[0m�[0m
[server-5] [waypoint_follower-8] [INFO] [1619750520.307229731] [waypoint_follower]: Deactivating
[server-5] [waypoint_follower-8] [INFO] [1619750520.309884034] [waypoint_follower]: Destroying bond (waypoint_follower) to lifecycle manager.
[server-5] [lifecycle_manager-9] [INFO] [1619750520.424634214] [lifecycle_manager_navigation]: �[34m�[1mDeactivating bt_navigator�[0m�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750522.094190441] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [controller_server-4] [WARN] [1619750525.261608939] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [WARN] [1619750525.345783110] [controller_server]: Control loop missed its desired rate of 12.0000Hz
[server-5] [controller_server-4] [ERROR] [1619750525.855212591] [controller_server]: Extrapolation Error: Lookup would require extrapolation into the past.  Requested time 1619750515.774943 but the earliest data is at time 1619750516.293514, when looking up transform from frame [map] to frame [odom]
[server-5] [controller_server-4]
[server-5] [controller_server-4] [ERROR] [1619750525.856845937] [controller_server]: Global Frame: odom Plan Frame size 268: map
[server-5] [controller_server-4]
[server-5] [controller_server-4] [WARN] [1619750525.857009915] [controller_server]: Could not transform the global plan to the frame of the controller
[server-5] [controller_server-4] [ERROR] [1619750525.857129762] [controller_server]: Controller patience exceeded
[server-5] [controller_server-4] [WARN] [1619750525.857239816] [controller_server_rclcpp_node]: [follow_path] [ActionServer] Aborting handle.
[realsense2_camera_node-10] �[33m[WARN] [1619750528.111598623] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750534.132563889] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750540.149488215] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750546.180697882] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750552.214696326] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750558.244915662] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750564.277580581] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750570.303324152] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750576.329598690] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750582.349343290] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[server-5] [amcl-2] [INFO] [1619750587.112012468] [amcl_rclcpp_node]: Message Filter dropping message: frame 'laser' at time 1619750582.578 for reason 'discarding message because the queue is full'
[realsense2_camera_node-10] �[33m[WARN] [1619750588.367199765] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750594.398481482] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750600.420736848] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750606.452088808] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750612.472619810] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750618.494468406] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750624.520094806] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750630.547973606] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750636.575974914] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750642.595907389] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750648.618893683] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750654.641756321] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750660.669114687] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750666.690749825] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750672.714322421] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750678.737399846] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750684.754062062] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750690.771779502] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750696.797428515] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750702.820993361] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750708.856218611] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750714.874507146] [RealSenseCameraNode]: No RealSense devices were found!�[0m
[realsense2_camera_node-10] �[33m[WARN] [1619750720.891928959] [RealSenseCameraNode]: No RealSense devices were found!�[0m

By the way, which ARM development board are you using? Raspberry Pi 4 Model B?

I am using Jetson AGX Xavier devkit.

@KavenYau
Copy link
Contributor

According to the logs, I probably have found the reason of this problem.

@tzskp1
Copy link
Author

tzskp1 commented Apr 30, 2021

Is that true?
Thank you.

@KavenYau
Copy link
Contributor

Would you mind using the pure Navigation2 to reproduce the problem again? If my analysis is correct, when you reproduce this problem you could see a "send_goal failed log print.

With the pure Navigation2, this problem occurs in this case.

To solve this problem, it's probably to set BT status to BT::NodeStatus::FAILURE before throwing "send_goal failed error, or checking if goal_handle_ is nullptr in halt. To me, I prefer the former because I think that the BT node status should not be BT::NodeStatus::RUNNING after throwing an error.

@SteveMacenski Maybe this issue is related to this PR #2320.

@SteveMacenski
Copy link
Member

I don't think these are directly related, but the implementation of #2320 has implication for this issue.

That traceback also gives us a little bit of an understanding, but without -g compiler flag to get debug symbols, its hard to know 100% for sure. I agree with @KavenYau a traceback from the current ros2 branch of Nav2 would be alot more informative as to the actual root issue you're running into.

To solve this problem, it's probably to set BT status to BT::NodeStatus::FAILURE before throwing "send_goal failed error

I don't understand how you expect to return a status code and then throw an exception.

or checking if goal_handle_ is nullptr in halt

https://github.com/ros-planning/navigation2/blob/f83612d28ce0db76436cf711071129eb17099c8f/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L291 #2320 does this

@tzskp1
Copy link
Author

tzskp1 commented May 1, 2021

I understand.
Could you give me some time?
I will prepare the environment again.

@KavenYau
Copy link
Contributor

KavenYau commented May 1, 2021

I don't understand how you expect to return a status code and then throw an exception.

I haven't thought it carefully. I was considering about how could we avoid Segmentation Fault while calling halt, and I found two solutations. Then I thought that it should be a FAILURE while sending goal timeout, so I left that comment, it might be incorrect. My intention was that how we maintain/process the status of BT nodes if it got errors.

@tzskp1
Copy link
Author

tzskp1 commented May 3, 2021

I reproduced SEGV on pure navigation2 (i.e #2320 without modification).
backtrace is here.

#0  memcmp () at ../sysdeps/aarch64/memcmp.S:50
#1  0x0000007fac389674 in std::__equal<true>::equal<unsigned char> (
    __first2=<optimized out>, __last1=<optimized out>,
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:814
#2  std::__equal_aux<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>,
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:831
#3  std::equal<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>,
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:1053
#4  std::operator==<unsigned char, 16ul> (__two=..., __one=...)
    at /usr/include/c++/7/array:253
#5  nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)#1}::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) const (result=...,
    __closure=0x7f841aee98)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:315
#6  std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) (__functor=..., __args#0=...)
    at /usr/include/c++/7/bits/std_function.h:316
#7  0x0000007fac39384c in std::function<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)>::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) const (
    __args#0=..., this=0x7f841aee98)
    at /usr/include/c++/7/bits/std_function.h:706
#8  rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::set_result
    (this=0x7f841aee20, wrapped_result=...)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client_goal_handle_impl.hpp:77
#9  0x0000007fac3939c8 in rclcpp_action::Client<nav2_msgs::action::FollowPath>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath> >)::{lambda(std::shared_ptr<void>)#1}::operator()(std::shared_ptr<void>) (response=..., __closure=<optimized out>)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client.hpp:745
#10 std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::FollowPath>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath> >)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&) (
    __functor=..., __args#0=...) at /usr/include/c++/7/bits/std_function.h:316
#11 0x0000007fb6acbbb0 in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#12 0x0000007fb6ac80a4 in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>) ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#13 0x0000007fb6ac902c in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&) () from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#14 0x0000007fb7a398a0 in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&) () from /ros2_master/install/rclcpp/lib/librclcpp.so
#15 0x0000007fb7a393d0 in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) ()
   from /ros2_master/install/rclcpp/lib/librclcpp.so
#16 0x0000007fac43270c in rclcpp::Executor::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> > >, long, std::ratio<1l, 1000l> > (timeout=..., future=...,
    this=0x7f8d3ce0c8)
    at /ros2_master/install/rclcpp/include/rclcpp/executor.hpp:359
#17 rclcpp::executors::spin_node_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> > >, long, std::ratio<1l, 1000l> > (timeout=..., future=..., node_ptr=...,
    executor=...)
    at /ros2_master/install/rclcpp/include/rclcpp/executors.hpp:80
#18 rclcpp::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> > >, long, std::ratio<1l, 1000l> > (node_ptr=warning: RTTI symbol not found for class 'std::_Sp_counted_ptr<rclcpp::node_interfaces::NodeBase*, (__gnu_cxx::_Lock_policy)2>'
warning: RTTI symbol not found for class 'std::_Sp_counted_ptr<rclcpp::node_interfaces::NodeBase*, (__gnu_cxx::_Lock_policy)2>'

std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface> (use count 7, weak count 4) = {...}, future=..., timeout=..., timeout@entry=...)
    at /ros2_master/install/rclcpp/include/rclcpp/executors.hpp:111
#19 0x0000007fac4329cc in rclcpp::spin_until_future_complete<rclcpp::Node, std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> > >, long, std::ratio<1l, 1000l> > (timeout=...,
    future=..., node_ptr=...)
    at /ros2_master/install/rclcpp/include/rclcpp/executors.hpp:122
#20 nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::is_future_goal_handle_complete (this=this@entry=0x55558490b0, elapsed=...)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:344
#21 0x0000007fac432d24 in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::tick (this=0x55558490b0)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:186
#22 0x0000007fb7e9e7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#23 0x0000007f8ffe5c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x5555848930)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#24 0x0000007fb7e9e7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#25 0x0000007fac10bd1c in nav2_behavior_tree::RateController::tick (
    this=0x5555848750)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/decorator/rate_controller.cpp:60
#26 0x0000007fb7e9e7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#27 0x0000007fb7e9c9fc in BT::DecoratorNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#28 0x0000007f8ffca06c in nav2_behavior_tree::PipelineSequence::tick (
    this=0x55558485d0)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/pipeline_sequence.cpp:39
#29 0x0000007fb7e9e7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#30 0x0000007f8ffe5c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x5555840140)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#31 0x0000007fb7e9e7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#32 0x0000007fb6bb485c in BT::Tree::tickRoot (this=0x55555dbfd0)
    at /ros/install/behaviortree_cpp_v3/include/behaviortree_cpp_v3/bt_factory.h:187
#33 nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >)
    (this=<optimized out>, tree=tree@entry=0x55555dbfd0, onLoop=...,
    cancelRequested=..., loopTimeout=...)
    at /ros/src/navigation2/nav2_behavior_tree/src/behavior_tree_engine.cpp:54
#34 0x0000007fb730fb0c in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateToPose>::executeCallback (this=0x55555dbfa0)
    at /ros/install/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_server_impl.hpp:234
#35 0x0000007fb731d854 in std::function<void ()>::operator()() const (
    this=0x555567ecf0) at /usr/include/c++/7/bits/std_function.h:706
#36 nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::work (this=0x555567ec90)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:195
#37 0x0000007fb731e0c0 in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}::operator()() const (__closure=<optimized out>)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:183
#38 std::__invoke_impl<void, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_other, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#39 std::__invoke<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_result&&, (nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#40 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=<optimized out>)
    at /usr/include/c++/7/thread:234
#41 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::operator()() (this=<optimized out>) at /usr/include/c++/7/thread:243
#42 std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::operator()() const (
    this=<optimized out>) at /usr/include/c++/7/future:1362
#43 std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&) (__functor=...)
    at /usr/include/c++/7/bits/std_function.h:302
#44 0x0000007fb7e4b410 in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const
    ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#45 0x0000007fb7e46230 in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#46 0x0000007fb7e5182c in void std::__invoke_impl<void, void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::__invoke_memfun_deref, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#47 0x0000007fb7e4df00 in std::__invoke_result<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>::type std::__invoke<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#48 0x0000007fb7e4b060 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#1}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#49 0x0000007fb7e4b0f0 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#50 0x0000007fb7e4b10c in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::_FUN() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#51 0x0000007fb6f17c00 in __pthread_once_slow (once_control=0x7f840b71a8,
    init_routine=0x7fb7181ec0 <__once_proxy>) at pthread_once.c:116
#52 0x0000007fb7306a00 in __gthread_once (__func=<optimized out>,
    __once=0x7f840b71a8)
    at /usr/include/aarch64-linux-gnu/c++/7/bits/gthr-default.h:699
#53 std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) (__f=
    @0x7f8d3d0cc8: (void (std::__future_base::_State_baseV2::*)(std::__future_base::_State_baseV2 * const, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter>()> *, bool *)) 0x7f8d3d0c98, this adjustment 273915217480, __once=...) at /usr/include/c++/7/mutex:684
#54 std::__future_base::_State_baseV2::_M_set_result(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>, bool) (__ignore_failure=false, __res=..., this=0x7f840b7190)
    at /usr/include/c++/7/future:401
#55 std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}::operator()() const (
    __closure=0x55556f7df8) at /usr/include/c++/7/future:1667
#56 std::__invoke_impl<void, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__invoke_other, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#57 std::__invoke<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&, (std::__invoke_result&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#58 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x55556f7df8)
    at /usr/include/c++/7/thread:234
#59 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::operator()() (this=0x55556f7df8) at /usr/include/c++/7/thread:243
#60 std::thread::_State_impl<std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> > >::_M_run() (this=0x55556f7df0)
    at /usr/include/c++/7/thread:186
#61 0x0000007fb7182e14 in ?? () from /usr/lib/aarch64-linux-gnu/libstdc++.so.6
#62 0x0000007fb6f10088 in start_thread (arg=0x7ffffef81f)
    at pthread_create.c:463
#63 0x0000007fb701a4ec in thread_start ()
    at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

I may have found a way to reproduce it.

  1. Set Goal via Nav2 Goal.
  2. Cancel it.
  3. Set Goal again.

@KavenYau
Copy link
Contributor

KavenYau commented May 3, 2021

I'm afraid you are still applying the patch(#2320), because there is no send_new_goal() method on branch main of Nav2.
The newest #2320 patch may fix the issue that you reproduced, you could update and have a try.

If you want to figure out the initial issue you're running into, you could checkout to branch main and try to reproduce it.
And if you just want to fix it, maybe you could follow this PR #2320. It seems that it could cover your issue.

@tzskp1
Copy link
Author

tzskp1 commented May 3, 2021

I think that the branch that was tested by me is latest #2320 (9f0e85f)

@KavenYau
Copy link
Contributor

@SteveMacenski
Hi, I reproduced this issue on the latest commit on branch main.

here is a short segment of logs:

[controller_server-4] [INFO] [1620993891.822686728] [controller_server]: Passing new path to controller.
[bt_navigator-7] [WARN] [1620993891.839904112] [bt_navigator_rclcpp_node]: follow_path previous goal received result
[bt_navigator-7] [INFO] [1620993892.569973801] [bt_navigator]: Received goal preemption request
[bt_navigator-7] [INFO] [1620993892.571881143] [bt_navigator]: Begin navigating from current location through 1 poses to (-2.00, 1.00)
[controller_server-4] [INFO] [1620993894.777394237] [controller_server]: Reached the goal!
[bt_navigator-7] [WARN] [1620993894.780799897] [bt_navigator_rclcpp_node]: follow_path this goal received result
[bt_navigator-7] [WARN] [1620993894.780902819] [bt_navigator_rclcpp_node]: BT::NodeStatus on_success follow_path
[bt_navigator-7] [WARN] [1620993894.780925363] [bt_navigator_rclcpp_node]: follow_path goal_handle_.reset() return status
[bt_navigator-7] [INFO] [1620993894.789508369] [bt_navigator]: Goal succeeded
[bt_navigator-7] [INFO] [1620993895.792508305] [bt_navigator]: Begin navigating from current location through 1 poses to (-2.00, 1.00)
[bt_navigator-7] [WARN] [1620993895.793195896] [bt_navigator_rclcpp_node]: compute_path_through_poses this goal received result
[bt_navigator-7] [WARN] [1620993895.793517591] [bt_navigator_rclcpp_node]: compute_path_through_poses goal_handle_.reset() return status
[controller_server-4] [INFO] [1620993895.795700182] [controller_server]: Received a goal, begin computing control effort.
[ERROR] [bt_navigator-7]: process has died [pid 786624, exit code -11, cmd '/home/kaven/code/ros2_master/nav2_ws/install/nav2_bt_navigator/lib/nav2_bt_navigator/bt_navigator --ros-args -r __node:=bt_navigator --params-file /tmp/tmpuwetorj2 -r /tf:=tf -r /tf_static:=tf_static'].
[controller_server-4] [WARN] [1620993896.636115590] [controller_server]: Control loop missed its desired rate of 10.0000Hz
[controller_server-4] [INFO] [1620993902.144884897] [controller_server]: Reached the goal!

here is the backtrace:

Thread 1 (Thread 0x7f5e337fe700 (LWP 807536)):
#0  __memcmp_avx2_movbe () at ../sysdeps/x86_64/multiarch/memcmp-avx2-movbe.S:268
#1  0x00007f5e70406b34 in bool std::__equal<true>::equal<unsigned char>(unsigned char const*, unsigned char const*, unsigned char const*) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#2  0x00007f5e7040685b in bool std::__equal_aux<unsigned char const*, unsigned char const*>(unsigned char const*, unsigned char const*, unsigned char const*) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#3  0x00007f5e6fa25733 in std::equal<unsigned char const*, unsigned char const*> (__first1=0x8 <error: Cannot access memory at address 0x8>, __last1=0x18 <error: Cannot access memory at address 0x18>, __first2=0x7f5e337f9a60 "}\201\033\212%B\223\204\320\314\376ᅯ\236\254\004\232\177\063^\177") at /usr/include/c++/9/bits/stl_algobase.h:1069
#4  0x00007f5e6fa25201 in std::operator==<unsigned char, 16ul> (__one=..., __two=...) at /usr/include/c++/9/array:253
#5  0x00007f5e637c22f5 in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)#1}::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&) const (this=0x55b457172f10, result=...) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:317
#6  0x00007f5e637c9574 in std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&) (__functor=..., __args#0=...) at /usr/include/c++/9/bits/std_function.h:300
#7  0x00007f5e637cc0e9 in std::function<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)>::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&) const (this=0x7f5e2417e878, __args#0=...) at /usr/include/c++/9/bits/std_function.h:688
#8  0x00007f5e637ca4e8 in rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::set_result (this=0x7f5e2417e800, wrapped_result=...) at /home/kaven/code/ros2_master/ros2_rolling/i--Type <RET> for more, q to quit, c to continue without paging--
nstall/rclcpp_action/include/rclcpp_action/client_goal_handle_impl.hpp:77
#9  0x00007f5e637c764e in rclcpp_action::Client<nav2_msgs::action::ComputePathThroughPoses>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> >)::{lambda(std::shared_ptr<void>)#1}::operator()(std::shared_ptr<void>) (this=0x55b45717faa0, response=std::shared_ptr<void> (use count 5, weak count 0) = {...}) at /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp_action/include/rclcpp_action/client.hpp:745
#10 0x00007f5e637cc1ce in std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::ComputePathThroughPoses>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses> >)::{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
#11 0x00007f5e6e8f0905 in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp_action/lib/librclcpp_action.so
#12 0x00007f5e6e8ec615 in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp_action/lib/librclcpp_action.so
#13 0x00007f5e6e8ed84b in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp_action/lib/librclcpp_action.so
#14 0x00007f5e702f21c0 in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#15 0x00007f5e702f1b5c in rclcpp::Executor::spin_some_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >, bool) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#16 0x00007f5e702f17a8 in rclcpp::Executor::spin_some(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#17 0x00007f5e702f1641 in rclcpp::Executor::spin_node_some(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#18 0x00007f5e703002a4 in rclcpp::spin_some(std::shared_ptr<rclcpp::node_interfaces::NodeBaseInterface>) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#19 0x00007f5e7030037e in rclcpp::spin_some(std::shared_ptr<rclcpp::Node>) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#20 0x00007f5e636957fa in nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::tick (this=0x55b4572c5bd0) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:227
#21 0x00007f5e7064b884 in BT::TreeNode::executeTick() () from /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#22 0x00007f5e629397bc in nav2_behavior_tree::RecoveryNode::tick (this=0x55b4572c32b0) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#23 0x00007f5e7064b884 in BT::TreeNode::executeTick() () from /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#24 0x00007f5e62902ab6 in nav2_behavior_tree::PipelineSequence::tick (this=0x55b457280b80) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/plugins/control/pipeline_sequence.cpp:39
#25 0x00007f5e7064b884 in BT::TreeNode::executeTick() () from /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#26 0x00007f5e629397bc in nav2_behavior_tree::RecoveryNode::tick (this=0x55b457253810) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#27 0x00007f5e7064b884 in BT::TreeNode::executeTick() () from /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#28 0x00007f5e6eca6710 in BT::Tree::tickRoot (this=0x55b457185d40) at /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/include/behaviortree_cpp_v3/bt_factory.h:187
--Type <RET> for more, q to quit, c to continue without paging--
#29 0x00007f5e6eca532c in nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >) (this=0x55b457252100, tree=0x55b457185d40, onLoop=..., cancelRequested=..., loopTimeout=...) at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/src/behavior_tree_engine.cpp:54
#30 0x00007f5e6f98be2d in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::executeCallback (this=0x55b457185d10) at /home/kaven/code/ros2_master/nav2_ws/install/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_server_impl.hpp:234
#31 0x00007f5e6f9cf22f in std::__invoke_impl<void, void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*&)(), nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>*&> (__f=@0x55b457291e10: (void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*)(class nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses> * const)) 0x7f5e6f98bcbc <nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::executeCallback()>, __t=@0x55b457291e20: 0x55b457185d10) at /usr/include/c++/9/bits/invoke.h:73
#32 0x00007f5e6f9c9693 in std::__invoke<void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*&)(), nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>*&> (__fn=@0x55b457291e10: (void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*)(class nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses> * const)) 0x7f5e6f98bcbc <nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::executeCallback()>) at /usr/include/c++/9/bits/invoke.h:95
#33 0x00007f5e6f9c3e93 in std::_Bind<void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*(nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>*))()>::__call<void, , 0ul>(std::tuple<>&&, std::_Index_tuple<0ul>) (this=0x55b457291e10, __args=...) at /usr/include/c++/9/functional:400
#34 0x00007f5e6f9be47d in std::_Bind<void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*(nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>*))()>::operator()<, void>() (this=0x55b457291e10) at /usr/include/c++/9/functional:484
#35 0x00007f5e6f9b7d9d in std::_Function_handler<void (), std::_Bind<void (nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>::*(nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateThroughPoses>*))()> >::_M_invoke(std::_Any_data const&) (__functor=...) at /usr/include/c++/9/bits/std_function.h:300
#36 0x00007f5e702d0a82 in std::function<void ()>::operator()() const () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#37 0x00007f5e6f9be821 in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::work (this=0x55b457290a60) at /home/kaven/code/ros2_master/nav2_ws/install/nav2_util/include/nav2_util/simple_action_server.hpp:195
#38 0x00007f5e6f9b82dd in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}::operator()() const (this=0x55b457290a60) at /home/kaven/code/ros2_master/nav2_ws/install/nav2_util/include/nav2_util/simple_action_server.hpp:183
#39 0x00007f5e6f9f88e0 in std::__invoke_impl<void, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>(std::__invoke_other, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}&&) (__f=...) at /usr/include/c++/9/bits/invoke.h:60
#40 0x00007f5e6f9f6d73 in std::__invoke<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>(std::__invoke_result&&, (nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}&&)...) (__fn=...) at /usr/include/c++/9/bits/invoke.h:95
--Type <RET> for more, q to quit, c to continue without paging--
#41 0x00007f5e6f9f509e in std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x7f5e241c25c8) at /usr/include/c++/9/thread:244
#42 0x00007f5e6f9f36ee in std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >::operator()() (this=0x7f5e241c25c8) at /usr/include/c++/9/thread:251
#43 0x00007f5e6f9f15e6 in std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::operator()() const (this=0x7f5e337fd2f0) at /usr/include/c++/9/future:1362
#44 0x00007f5e6f9ee6f9 in std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&) (__functor=...) at /usr/include/c++/9/bits/std_function.h:286
#45 0x00007f5e7061858d in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*) () from /home/kaven/code/ros2_master/nav2_depend_ws/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#46 0x00007f5e6ef3147f in __pthread_once_slow (once_control=0x7f5e241c25a8, init_routine=0x7f5e6f333b80 <__once_proxy>) at pthread_once.c:116
#47 0x00007f5e7039574e in __gthread_once(int*, void (*)()) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#48 0x00007f5e703972f9 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#49 0x00007f5e70395c5e in std::__future_base::_State_baseV2::_M_set_result(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>, bool) () from /home/kaven/code/ros2_master/ros2_rolling/install/rclcpp/lib/librclcpp.so
#50 0x00007f5e6f9e88b4 in std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}::operator()() const (this=0x7f5e241c2590) at /usr/include/c++/9/future:1662
#51 0x00007f5e6fa1d1f7 in std::__invoke_impl<void, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__invoke_other, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleA--Type <RET> for more, q to quit, c to continue without paging--
ctionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}&&) (__f=...) at /usr/include/c++/9/bits/invoke.h:60
#52 0x00007f5e6fa19bf5 in std::__invoke<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}&&, (std::__invoke_result&&)...) (__fn=...) at /usr/include/c++/9/bits/invoke.h:95
#53 0x00007f5e6fa136a4 in std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x55b4573fd038) at /usr/include/c++/9/thread:244
#54 0x00007f5e6fa0e510 in std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}> >::operator()() (this=0x55b4573fd038) at /usr/include/c++/9/thread:251
#55 0x00007f5e6fa038f2 in std::thread::_State_impl<std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateThroughPoses, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateThroughPoses> >)::{lambda()#1}>&&)::{lambda()#1}> > >::_M_run() (this=0x55b4573fd030) at /usr/include/c++/9/thread:195
#56 0x00007f5e6f334d84 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#57 0x00007f5e6ef28609 in start_thread (arg=<optimized out>) at pthread_create.c:477
#58 0x00007f5e6f171293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

goal_handle_ is null:

#5  0x00007f5e637c22f5 in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathThroughPoses>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&)#1}::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>::WrappedResult const&) const (this=0x55b457172f10, result=...)
    at /home/kaven/code/ros2_master/nav2_ws/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:317
317	        if (this->goal_handle_->get_goal_id() == result.goal_id) {
(gdb) p result.goal_id
$1 = {_M_elems = "}\201\033\212%B\223\204\320\314\376ᅯ\236\254"}
(gdb) p this->goal_handle_
$2 = std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathThroughPoses>> (empty) = {get() = 0x0}

I noticed that ComputePathThroughPoses's result_callback was called after spin_some in FollowPath's tick() called. Due to all bt nodes shared the same rclcpp node, so the result_callback would be called if spin_some called in other places.
If it sent goal timeout in this ticking time, then the goal_handle_ was still null.
https://github.com/ros-planning/navigation2/blob/8947c9fdca621624fddc49ff40af9d3f29693e81/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L342-L360

@SteveMacenski
Copy link
Member

Due to all bt nodes shared the same rclcpp node, so the result_callback would be called if spin_some called in other places.

That's not a bad point, but actually this PR: #2334 changes that so that each spin call is only spinning the individual specific BT node using individual executors and exclusive callback groups. Now that the other PR is merged, if you were to test that PR branch rebased on main, then you'd get both the reset() that Sarthak added and that exclusive spinning stuff and that could solve the issue?

Note that PR is still in review, so there are some conflicts / changes I requested, but by in large it should work (the review requested changes arent on the action nodes, but you would have to deal with the conflicts locally when you pulled in master)

@KavenYau
Copy link
Contributor

To my understanding, this PR: #2334 could guarantee that each BT node would only receive its messages, please correct me if I am wrong. If so, maybe that could solve the issue.

@tzskp1
Copy link
Author

tzskp1 commented May 19, 2021

Thank you for your support.
But I could still reproduce the problem at c88f45a.

backtrace is here:

#0  memcmp () at ../sysdeps/aarch64/memcmp.S:50
#1  0x0000007facbc67b4 in std::__equal<true>::equal<unsigned char> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:814
#2  std::__equal_aux<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:831
#3  std::equal<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:1053
#4  std::operator==<unsigned char, 16ul> (__two=..., __one=...)
    at /usr/include/c++/7/array:253
#5  nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)#1}::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) const (result=..., 
    __closure=0x7f840180a8)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:318
#6  std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) (__functor=..., __args#0=...)
    at /usr/include/c++/7/bits/std_function.h:316
#7  0x0000007facbd220c in std::function<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&)>::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::WrappedResult const&) const (
    __args#0=..., this=0x7f840180a8)
    at /usr/include/c++/7/bits/std_function.h:706
#8  rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath>::set_result
    (this=0x7f84018030, wrapped_result=...)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client_goal_handle_impl.hpp:77
#9  0x0000007facbd2388 in rclcpp_action::Client<nav2_msgs::action::FollowPath>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath> >)::{lambda(std::shared_ptr<void>)#1}::operator()(std::shared_ptr<void>) (response=..., __closure=<optimized out>)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client.hpp:745
#10 std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::FollowPath>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath> >)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&) (
    __functor=..., __args#0=...) at /usr/include/c++/7/bits/std_function.h:316
#11 0x0000007fb6b0bbb0 in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#12 0x0000007fb6b080a4 in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>) ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#13 0x0000007fb6b0902c in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&) () from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#14 0x0000007fb7a788a0 in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&) () from /ros2_master/install/rclcpp/lib/librclcpp.so
#15 0x0000007fb7a783d0 in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) ()
   from /ros2_master/install/rclcpp/lib/librclcpp.so
#16 0x0000007facbd021c in rclcpp::Executor::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::FollowPath> > >, long, std::ratio<1l, 1000l> > (timeout=..., future=..., 
    this=0x55558831c0)
    at /ros2_master/install/rclcpp/include/rclcpp/executor.hpp:359
#17 nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::is_future_goal_handle_complete (this=this@entry=0x5555882f60, elapsed=...)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:347
#18 0x0000007facbd329c in nav2_behavior_tree::BtActionNode<nav2_msgs::action::FollowPath>::tick (this=0x5555882f60)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:190
#19 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#20 0x0000007fac831c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x555587dfb0)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#21 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#22 0x0000007fac81606c in nav2_behavior_tree::PipelineSequence::tick (
    this=0x5555862e60)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/pipeline_sequence.cpp:39
#23 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#24 0x0000007fac831c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x555585aa30)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#25 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#26 0x0000007fb6bf485c in BT::Tree::tickRoot (this=0x55555db0a0)
    at /ros/install/behaviortree_cpp_v3/include/behaviortree_cpp_v3/bt_factory.h:187
#27 nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >)
    (this=<optimized out>, tree=tree@entry=0x55555db0a0, onLoop=..., 
    cancelRequested=..., loopTimeout=...)
    at /ros/src/navigation2/nav2_behavior_tree/src/behavior_tree_engine.cpp:54
#28 0x0000007fb734f86c in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateToPose>::executeCallback (this=0x55555db070)
    at /ros/install/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_server_impl.hpp:234
#29 0x0000007fb735d5b4 in std::function<void ()>::operator()() const (
    this=0x5555683a40) at /usr/include/c++/7/bits/std_function.h:706
#30 nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::work (this=0x55556839e0)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:195
#31 0x0000007fb735de20 in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}::operator()() const (__closure=<optimized out>)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:183
#32 std::__invoke_impl<void, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_other, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#33 std::__invoke<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_result&&, (nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#34 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=<optimized out>)
    at /usr/include/c++/7/thread:234
#35 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::operator()() (this=<optimized out>) at /usr/include/c++/7/thread:243
#36 std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::operator()() const (
    this=<optimized out>) at /usr/include/c++/7/future:1362
#37 std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&) (__functor=...)
    at /usr/include/c++/7/bits/std_function.h:302
#38 0x0000007fb7e8a410 in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const
    ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#39 0x0000007fb7e85230 in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#40 0x0000007fb7e9082c in void std::__invoke_impl<void, void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::__invoke_memfun_deref, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#41 0x0000007fb7e8cf00 in std::__invoke_result<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>::type std::__invoke<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#42 0x0000007fb7e8a060 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#1}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#43 0x0000007fb7e8a0f0 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#44 0x0000007fb7e8a10c in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::_FUN() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#45 0x0000007fb6f57c00 in __pthread_once_slow (once_control=0x55556744a8, 
    init_routine=0x7fb71c1ec0 <__once_proxy>) at pthread_once.c:116
#46 0x0000007fb7346730 in __gthread_once (__func=<optimized out>, 
    __once=0x55556744a8)
    at /usr/include/aarch64-linux-gnu/c++/7/bits/gthr-default.h:699
#47 std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) (__f=
    @0x7f927facc8: (void (std::__future_base::_State_baseV2::*)(std::__future_base::_State_baseV2 * const, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter>()> *, bool *)) 0x7f927fac98, this adjustment 273959343688, __once=...) at /usr/include/c++/7/mutex:684
#48 std::__future_base::_State_baseV2::_M_set_result(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>, bool) (__ignore_failure=false, __res=..., this=0x5555674490)
    at /usr/include/c++/7/future:401
#49 std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}::operator()() const (
    __closure=0x55558ff238) at /usr/include/c++/7/future:1667
#50 std::__invoke_impl<void, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__invoke_other, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#51 std::__invoke<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&, (std::__invoke_result&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#52 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x55558ff238)
    at /usr/include/c++/7/thread:234
#53 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::operator()() (this=0x55558ff238) at /usr/include/c++/7/thread:243
#54 std::thread::_State_impl<std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> > >::_M_run() (this=0x55558ff230)
    at /usr/include/c++/7/thread:186
#55 0x0000007fb71c2e14 in ?? () from /usr/lib/aarch64-linux-gnu/libstdc++.so.6
#56 0x0000007fb6f50088 in start_thread (arg=0x7ffffef81f)
    at pthread_create.c:463
#57 0x0000007fb705a4ec in thread_start ()
    at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

@SteveMacenski
Copy link
Member

SteveMacenski commented May 21, 2021

@tzskp1 Can you test with a new pull of rclcpp master? @KavenYau just merged something that was occasionally not sending result callbacks in rclcpp itself that might have caused this problem.

@KavenYau given your now deep familiarity with rclcpp_actions, do you think this is potentially another issue in there or something in nav2 itself?

@KavenYau
Copy link
Contributor

KavenYau commented May 21, 2021

@SteveMacenski According to that backtrace, I think this is a nav2 issue.

https://github.com/ros-planning/navigation2/blob/4277d00d52e391de7c0e7c52658bba7b00447563/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp#L345-L359
This shows us that goal_handle_ is still nullptr before spin_until_future_complete returns, but if a goal finished quickly, result_callback may be called before spin_until_future_complete returns.

In this case, if it sent a goal before, we could try to get goal_handle_ in result_callback.

To make it more clearly, I make a PR: #2356. @tzskp1 You may want to have a try? There might be some compiling errors on the latest commit of branch main, you can add the patch by hand since it's just a slight change.

@tzskp1
Copy link
Author

tzskp1 commented May 23, 2021

I will try to reproduce the problem.
Please wait a moment.

@KavenYau
Copy link
Contributor

No upsetting 😄 .

But It seems a little more complicated than I thought.

@tzskp1
Copy link
Author

tzskp1 commented May 23, 2021

I could reproduce the problem at rclcpp: 1c617515403db16b8cbabd834073eaca0f9a452d.

#0  memcmp () at ../sysdeps/aarch64/memcmp.S:50
#1  0x0000007fb405963c in std::__equal<true>::equal<unsigned char> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:814
#2  std::__equal_aux<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:831
#3  std::equal<unsigned char const*, unsigned char const*> (
    __first2=<optimized out>, __last1=<optimized out>, 
    __first1=<optimized out>) at /usr/include/c++/7/bits/stl_algobase.h:1053
#4  std::operator==<unsigned char, 16ul> (__two=..., __one=...)
    at /usr/include/c++/7/array:253
#5  nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&)#1}::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&) const (
    result=..., __closure=0x7f70014e18)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:318
#6  std::_Function_handler<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&), nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::send_new_goal()::{lambda(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&)#1}>::_M_invoke(std::_Any_data const&, rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&) (__functor=..., __args#0=...)
    at /usr/include/c++/7/bits/std_function.h:316
#7  0x0000007fb4064f1c in std::function<void (rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&)>::operator()(rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::WrappedResult const&) const (__args#0=..., this=0x7f70014e18)
    at /usr/include/c++/7/bits/std_function.h:706
#8  rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose>::set_result (this=0x7f70014da0, wrapped_result=...)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client_goal_handle_impl.hpp:77
#9  0x0000007fb4065120 in rclcpp_action::Client<nav2_msgs::action::ComputePathToPose>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> >)::{lambda(std::shared_ptr<void>)#1}::operator()(std::shared_ptr<void>) (response=..., __closure=<optimized out>)
    at /ros2_master/install/rclcpp_action/include/rclcpp_action/client.hpp:745
#10 std::_Function_handler<void (std::shared_ptr<void>), rclcpp_action::Client<nav2_msgs::action::ComputePathToPose>::make_result_aware(std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> >)::{lambda(std::shared_ptr<void>)#1}>::_M_invoke(std::_Any_data const&, std::shared_ptr<void>&&)
    (__functor=..., __args#0=...) at /usr/include/c++/7/bits/std_function.h:316
#11 0x0000007fb6a00368 in std::function<void (std::shared_ptr<void>)>::operator()(std::shared_ptr<void>) const ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#12 0x0000007fb69fc4d4 in rclcpp_action::ClientBase::handle_result_response(rmw_request_id_t const&, std::shared_ptr<void>) ()
   from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#13 0x0000007fb69fd45c in rclcpp_action::ClientBase::execute(std::shared_ptr<void>&) () from /ros2_master/install/rclcpp_action/lib/librclcpp_action.so
#14 0x0000007fb7a44258 in rclcpp::Executor::execute_any_executable(rclcpp::AnyExecutable&) () from /ros2_master/install/rclcpp/lib/librclcpp.so
#15 0x0000007fb7a43d78 in rclcpp::Executor::spin_once_impl(std::chrono::duration<long, std::ratio<1l, 1000000000l> >) ()
   from /ros2_master/install/rclcpp/lib/librclcpp.so
#16 0x0000007fb4066eb4 in rclcpp::Executor::spin_until_future_complete<std::shared_future<std::shared_ptr<rclcpp_action::ClientGoalHandle<nav2_msgs::action::ComputePathToPose> > >, long, std::ratio<1l, 1000l> > (timeout=..., future=..., 
    this=0x5555881bb8)
    at /ros2_master/install/rclcpp/include/rclcpp/executor.hpp:360
#17 nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::is_future_goal_handle_complete (this=this@entry=0x55558818f0, elapsed=...)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:347
#18 0x0000007fb40670ec in nav2_behavior_tree::BtActionNode<nav2_msgs::action::ComputePathToPose>::tick (this=0x55558818f0)
    at /ros/src/navigation2/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_node.hpp:190
#19 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#20 0x0000007fac400c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x5555881130)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#21 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#22 0x0000007fac51fd1c in nav2_behavior_tree::RateController::tick (
    this=0x5555880f50)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/decorator/rate_controller.cpp:60
#23 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#24 0x0000007fb7edb9fc in BT::DecoratorNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#25 0x0000007fac3e506c in nav2_behavior_tree::PipelineSequence::tick (
    this=0x5555880dd0)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/pipeline_sequence.cpp:39
#26 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#27 0x0000007fac400c5c in nav2_behavior_tree::RecoveryNode::tick (
    this=0x5555878850)
    at /ros/src/navigation2/nav2_behavior_tree/plugins/control/recovery_node.cpp:44
#28 0x0000007fb7edd7d4 in BT::TreeNode::executeTick() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#29 0x0000007fb6af685c in BT::Tree::tickRoot (this=0x55555e03a0)
    at /ros/install/behaviortree_cpp_v3/include/behaviortree_cpp_v3/bt_factory.h:187
#30 nav2_behavior_tree::BehaviorTreeEngine::run(BT::Tree*, std::function<void ()>, std::function<bool ()>, std::chrono::duration<long, std::ratio<1l, 1000l> >)
    (this=<optimized out>, tree=tree@entry=0x55555e03a0, onLoop=..., 
    cancelRequested=..., loopTimeout=...)
    at /ros/src/navigation2/nav2_behavior_tree/src/behavior_tree_engine.cpp:54
#31 0x0000007fb7287e7c in nav2_behavior_tree::BtActionServer<nav2_msgs::action::NavigateToPose>::executeCallback (this=0x55555e0370)
    at /ros/install/nav2_behavior_tree/include/nav2_behavior_tree/bt_action_server_impl.hpp:234
#32 0x0000007fb7295724 in std::function<void ()>::operator()() const (
    this=0x55556aac20) at /usr/include/c++/7/bits/std_function.h:706
#33 nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::work (this=0x55556aabc0)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:195
#34 0x0000007fb7295f90 in nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}::operator()() const (__closure=<optimized out>)
    at /ros/install/nav2_util/include/nav2_util/simple_action_server.hpp:183
#35 std::__invoke_impl<void, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_other, nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#36 std::__invoke<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>(std::__invoke_result&&, (nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#37 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=<optimized out>)
    at /usr/include/c++/7/thread:234
#38 std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >::operator()() (this=<optimized out>) at /usr/include/c++/7/thread:243
#39 std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::operator()() const (
    this=<optimized out>) at /usr/include/c++/7/future:1362
#40 std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> (), std::__future_base::_Task_setter<std::unique_ptr<std::__future_base::_Result<void>, std::__future_base::_Result_base::_Deleter>, std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void> >::_M_invoke(std::_Any_data const&) (__functor=...)
    at /usr/include/c++/7/bits/std_function.h:302
#41 0x0000007fb7e8a410 in std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>::operator()() const
    ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#42 0x0000007fb7e85230 in std::__future_base::_State_baseV2::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#43 0x0000007fb7e9082c in void std::__invoke_impl<void, void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::__invoke_memfun_deref, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#44 0x0000007fb7e8cf00 in std::__invoke_result<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>::type std::__invoke<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#45 0x0000007fb7e8a060 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#1}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#46 0x0000007fb7e8a0f0 in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::operator()() const ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#47 0x0000007fb7e8a10c in void std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&)::{lambda()#2}::_FUN() ()
   from /ros/install/behaviortree_cpp_v3/lib/libbehaviortree_cpp_v3.so
#48 0x0000007fb6e7ec00 in __pthread_once_slow (once_control=0x7f70022e08, 
    init_routine=0x7fb70e8ec0 <__once_proxy>) at pthread_once.c:116
#49 0x0000007fb727ecf8 in __gthread_once (__func=<optimized out>, 
    __once=0x7f70022e08)
    at /usr/include/aarch64-linux-gnu/c++/7/bits/gthr-default.h:699
#50 std::call_once<void (std::__future_base::_State_baseV2::*)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*>(std::once_flag&, void (std::__future_base::_State_baseV2::*&&)(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*, bool*), std::__future_base::_State_baseV2*&&, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>*&&, bool*&&) (__f=
    @0x7f77ffdcc8: (void (std::__future_base::_State_baseV2::*)(std::__future_base::_State_baseV2 * const, std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter>()> *, bool *)) 0x7f77ffdc98, this adjustment 273737051720, __once=...) at /usr/include/c++/7/mutex:684
#51 std::__future_base::_State_baseV2::_M_set_result(std::function<std::unique_ptr<std::__future_base::_Result_base, std::__future_base::_Result_base::_Deleter> ()>, bool) (__ignore_failure=false, __res=..., this=0x7f70022df0)
    at /usr/include/c++/7/future:401
#52 std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}::operator()() const (
    __closure=0x555592c3d8) at /usr/include/c++/7/future:1667
#53 std::__invoke_impl<void, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__invoke_other, std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&) (__f=...)
    at /usr/include/c++/7/bits/invoke.h:60
#54 std::__invoke<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}>(std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}&&, (std::__invoke_result&&)...) (__fn=...)
    at /usr/include/c++/7/bits/invoke.h:95
#55 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::_M_invoke<0ul>(std::_Index_tuple<0ul>) (this=0x555592c3d8)
    at /usr/include/c++/7/thread:234
#56 std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> >::operator()() (this=0x555592c3d8) at /usr/include/c++/7/thread:243
#57 std::thread::_State_impl<std::thread::_Invoker<std::tuple<std::__future_base::_Async_state_impl<std::thread::_Invoker<std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}> >, void>::_Async_state_impl(std::tuple<nav2_util::SimpleActionServer<nav2_msgs::action::NavigateToPose, rclcpp::Node>::handle_accepted(std::shared_ptr<rclcpp_action::ServerGoalHandle<nav2_msgs::action::NavigateToPose> >)::{lambda()#1}>&&)::{lambda()#1}> > >::_M_run() (this=0x555592c3d0)
    at /usr/include/c++/7/thread:186
#58 0x0000007fb70e9e14 in ?? () from /usr/lib/aarch64-linux-gnu/libstdc++.so.6
#59 0x0000007fb6e77088 in start_thread (arg=0x7ffffef29f)
    at pthread_create.c:463
#60 0x0000007fb6f814ec in thread_start ()
    at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

@KavenYau
Copy link
Contributor

KavenYau commented May 24, 2021

Yes, it seems that it receives/handles a result message before goal_response message.

@SteveMacenski
Copy link
Member

SteveMacenski commented May 24, 2021

Did you test @KavenYau ‘s suggestion? They kindly made a PR to support!

@SteveMacenski
Copy link
Member

Closing in favor of #2356 which I think we're all on the same page resolves this issue. If not, we can reopen this @tzskp1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants