ros2 / ros2/rclcpp

Global logger mutex acquisition should be scoped smaller than entire node initialization

Open
#2,147 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

backlog bug
Dominant language
C++
Stars
805
Forks
564
Avg merge
1d 17h
Merged PRs (30d)
27

Description

#1125 made NodeBase acquire the global logging mutex before calling rcl_node_init().

https://github.com/ros2/rclcpp/blob/a5368e6fe43112eaefdd805003ba9d2e9f45bbee/rclcpp/src/rclcpp/node_interfaces/node_base.cpp#L58-L63

The rclcpp output handler also acquires the global logging mutex.

https://github.com/ros2/rclcpp/blob/a5368e6fe43112eaefdd805003ba9d2e9f45bbee/rclcpp/src/rclcpp/context.cpp#L133

ros2/rmw_fastrtps_cpp#671 added logging in a callback in CustomParticipantInfo, meaning when that callback is called, it will try to acquire the global logging mutex.

https://github.com/ros2/rmw_fastrtps/blob/901339f274fc07fad757fb32bd16f00815217302/rmw_fastrtps_shared_cpp/include/rmw_fastrtps_shared_cpp/custom_participant_info.hpp#L214-L220

In eProsima's PDP class, there's another mutex that gets acquired. One way it's acquired is before calling the above callback in CustomParticipantInfo.

https://github.com/eProsima/Fast-DDS/blob/8a5a9160482b1543495c1ba49f3100fcceda12d9/src/cpp/rtps/builtin/discovery/participant/PDP.cpp#L773-L847

Another way it get's acquired is when creating a datawriter, as rmw_fastrtps_cpp does while creating the ros_discovery_info topic.

https://github.com/ros2/rmw_fastrtps/blob/901339f274fc07fad757fb32bd16f00815217302/rmw_fastrtps_cpp/src/init_rmw_context_impl.cpp#L91-L97

Which leads to the mutex being acquired here:

https://github.com/eProsima/Fast-DDS/blob/8a5a9160482b1543495c1ba49f3100fcceda12d9/src/cpp/rtps/builtin/discovery/participant/PDP.cpp#L858-L869

I'm seeing a case where a cyclonedds subscriber is already started, and I'm starting a FastDDS publisher. The main thread acquires the logging mutex, tries to init the node, and is blocked trying to acquire the PDP mutex while creating the ros_discovery_info topic. The reason it's blocked is there's another thread that learned of the cyclonedds subscriber, acquired the PDP mutex, notified the custom participant listener, tried to log a message about a type hash mismatch, which tries to acquire the logging mutex that's held in the main thread.

I think the acquisition of the logging mutex should be reduced in scope so that it doesn't cover the entire rcl_node_init() call, so that deadlock like this is avoided when logging happens during the initialization process.

A workaround for the deadlock is to make rmw_fastrtps not use RCUTILS logging, so that it won't try to acquire the global logging mutex.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in rclcpp/src/rclcpp/node_interfaces/node_base.cpp at the mutex acquisition around rcl_node_init(), then inspect rclcpp/src/rclcpp/context.cpp and the referenced logging paths. Trace the initialization and callback lock ordering; done means the logging mutex no longer spans the entire node initialization and the described logging-during-initialization deadlock is avoided.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp
Domain
distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.