rclcpp_action server could cause deadlock with its wrapper's mutex

[daisukes]

Bug report

Required Info:

• Operating System:
  • Ubuntu Focal
• Installation type:
  • Foxy release src build
• Version or commit hash:
  • ros2/ros2@4109e26
• DDS implementation:
  • tried with Fast-RTPS, cyclonedds
• Client library (if applicable):
  • Navigation 2

Steps to reproduce issue

The original issue is here and I think this is rclcpp issue
ros-navigation/navigation2#1961

- launch tb3 simulation and make it active
- repeat sending goal action and waiting for the result in a single loop, and wait for the deadlock 
https://gist.github.com/daisukes/46298b083a48e5db7016f3c0efba7e2d
  - I could reproduce the deadlock with this code usually in a few minutes

Expected behavior

• does not stop, keep working

Actual behavior

• the server will not accept goals when the deadlock happens

Problem

• user callbacks are called in the reentlant_mutex_ lock context

  • in the callbacks, the wrapper will lock its mutex

• in another thread, the wrapper first lock its mutex

  • then calls rclcpp_action method, which tries to lock reentlant_mutex_

This inconsistent locking order cause deadlocks.
So I think rclcpp_action needs to call user callbacks outside of reentlant_mutex_ lock context.

Additional information

Here is gdb information
Thread 9 and 14 are trying to hold two mutex in different order
https://gist.github.com/daisukes/712316a97832f5d9ab851ad47c77ad98

Thread 9: server thread
Frame# 6 nav2_util::SimpleActionServer<nav2_msgs::action::ComputePathToPose, rclcpp::Node>::handle_goal
Frame# 14 rclcpp_action::ServerBase::execute_goal_request_received()

Thread 14: working thread started here
Frame# 6 rclcpp_action::ServerBase::notify_goal_terminal_state()
Frame# 11 nav2_util::SimpleActionServer<nav2_msgs::action::ComputePathToPose, rclcpp::Node>::succeeded_current

[SteveMacenski]

And to be clear, this isn't just a specific issue with Navigation2, any users that have mutex locks on their resources will run into this problem. We typically don't run into this issue because we don't in quick succession call an action server immediately after returning a result. But clearly there are cases where that would be expected behavior.

If you were to use actions as workers though, you'd absolutely run into this issue more frequently.

[SteveMacenski]

@clalancette any thoughts? correction, I see the PR has had some motion, nothing to see here folks...

[ivanpauno]

Closing as it seems to have been fixed by #1313 (and #1518 will fix it for Foxy, where the bug was reported), feel free to reopen if that's not the case.