Skip to content

Remove global logging mutex#713

Closed
sloretz wants to merge 1 commit intomasterfrom
revert_pr_562_global_logging_mutex
Closed

Remove global logging mutex#713
sloretz wants to merge 1 commit intomasterfrom
revert_pr_562_global_logging_mutex

Conversation

@sloretz
Copy link
Copy Markdown
Contributor

@sloretz sloretz commented Mar 11, 2021

Reverts most of #562

ros2/rclcpp#1042 describes a crash that can occur in rclcpp when rcl
logging functions are called in different threads. This was fixed in
ros2/rclcpp#1125, and a similar fix was made for rclpy in #562.

This fix is unnecessary in rclpy because it cannot call the logging
macros from multiple threads unless the GIL is released. The only place
the GIL is released is around rcl_wait(), so the logging methods are
already protected.

Removing this code makes it a little easier to divide the remaining work
of porting _rclpy.c to pybind11 (#665). If for some reason we decide to release
the GIL around logging methods in the future, then they can be protected
in the future using pybind11::call_guard<T> with a type that locks a
global logging mutex when it is default constructed and unlocks it when
its destructed.

Signed-off-by: Shane Loretz sloretz@openrobotics.org
Signed-off-by: Shane Loretz sloretz@osrfoundation.org

Reverts most of #562

ros2/rclcpp#1042 describes a crash that can occur in rclcpp when rcl
logging functions are called in different threads. This was fixed in
ros2/rclcpp#1125, and a similar fix was made for rclpy in #562.

This fix is unnecessary in rclpy because it cannot call the logging
macros from multiple threads unless the GIL is released. The only place
the GIL is released is around rcl_wait(), so the logging methods are
already protected.

Removing this code makes it a little easier to divide the remaining work
of porting _rclpy.c to pybind11. If for some reason we decide to release
the GIL around logging methods in the future, then they can be protected
in the future using `pybind11::call_guard<T>` with a type that locks a
global logging mutex when it is default constructed and unlocks it when
its destructed.

Signed-off-by: Shane Loretz <sloretz@openrobotics.org>
Signed-off-by: Shane Loretz <sloretz@osrfoundation.org>
@sloretz sloretz requested review from ivanpauno and wjwwood March 11, 2021 20:16
@sloretz sloretz self-assigned this Mar 11, 2021
@sloretz sloretz mentioned this pull request Mar 11, 2021
34 tasks
@sloretz
Copy link
Copy Markdown
Contributor Author

sloretz commented Mar 11, 2021

CI (build: --packages-up-to rclpy test: --packages-select rclpy)

  • Linux Build Status
  • Linux-aarch64 Build Status
  • macOS Build Status
  • Windows Build Status

@ivanpauno
Copy link
Copy Markdown
Member

This fix is unnecessary in rclpy because it cannot call the logging
macros from multiple threads unless the GIL is released. The only place
the GIL is released is around rcl_wait(), so the logging methods are
already protected.

Some rmw implementations create a background thread that can call the logging macros, so IMO reverting #562 isn't safe.

@ivanpauno
Copy link
Copy Markdown
Member

ivanpauno commented Mar 11, 2021

Some rmw implementations create a background thread that can call the logging macros, so IMO reverting #562 isn't safe.

And we might even be calling logging macros from some dds listener callbacks, which are called from threads controlled by the dds library.

@sloretz
Copy link
Copy Markdown
Contributor Author

sloretz commented Mar 11, 2021

Some rmw implementations create a background thread that can call the logging macros, so IMO reverting #562 isn't safe.

I don't think #562 helps. For it to be safe, the rmw implementations would have to acquire rclpy's logging mutex.

And we might even be calling logging macros from some dds listener callbacks, which are called from threads controlled by the dds library.

Same problem - the dds listener callbacks would have to acquire rclpy's logging mutex or the rclpy logging calls could happen at the same time as the dds listener callbacks.

@ivanpauno
Copy link
Copy Markdown
Member

For it to be safe, the rmw implementations would have to acquire rclpy's logging mutex.

would they?
#562 installs an ouptut handler that will always take the mutex, you don't have to manually take it

rcl_ret_t ret = rcl_logging_configure_with_output_handler(
&context->global_arguments,
&allocator,
rclpy_detail_thread_safe_logging_output_handler);
.

@ivanpauno
Copy link
Copy Markdown
Member

We could also try to make sure that we're not calling the logging macros from any background thread (which sounds as a good idea anyway), but without that this doesn't seem to be safe.

@sloretz
Copy link
Copy Markdown
Contributor Author

sloretz commented Mar 11, 2021

#562 installs an ouptut handler that will always take the mutex, you don't have to manually take it

Ah you're right. That's how the mutex gets acquired.

@sloretz sloretz closed this Mar 11, 2021
@sloretz sloretz deleted the revert_pr_562_global_logging_mutex branch March 11, 2021 23:00
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.

2 participants