From 7433795ae48755173c2e9ca90d3b753cee93ad17 Mon Sep 17 00:00:00 2001 From: Shane Loretz Date: Thu, 11 Mar 2021 12:06:00 -0800 Subject: [PATCH] Remove global logging mutex 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` 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 Signed-off-by: Shane Loretz --- rclpy/CMakeLists.txt | 3 - rclpy/src/rclpy/_rclpy.c | 44 ++---------- .../detail/execute_with_logging_mutex.cpp | 72 ------------------- .../rclpy/detail/execute_with_logging_mutex.h | 56 --------------- rclpy/src/rclpy/detail/logging_mutex.cpp | 27 ------- rclpy/src/rclpy/detail/logging_mutex.hpp | 47 ------------ .../thread_safe_logging_output_handler.cpp | 43 ----------- .../thread_safe_logging_output_handler.h | 41 ----------- 8 files changed, 6 insertions(+), 327 deletions(-) delete mode 100644 rclpy/src/rclpy/detail/execute_with_logging_mutex.cpp delete mode 100644 rclpy/src/rclpy/detail/execute_with_logging_mutex.h delete mode 100644 rclpy/src/rclpy/detail/logging_mutex.cpp delete mode 100644 rclpy/src/rclpy/detail/logging_mutex.hpp delete mode 100644 rclpy/src/rclpy/detail/thread_safe_logging_output_handler.cpp delete mode 100644 rclpy/src/rclpy/detail/thread_safe_logging_output_handler.h diff --git a/rclpy/CMakeLists.txt b/rclpy/CMakeLists.txt index 031e9ab3b..2c3723f7e 100644 --- a/rclpy/CMakeLists.txt +++ b/rclpy/CMakeLists.txt @@ -154,9 +154,6 @@ install(TARGETS rclpy_common # Main extension with bulk of the code pybind11_add_module(_rclpy SHARED src/rclpy/_rclpy.c - src/rclpy/detail/execute_with_logging_mutex.cpp - src/rclpy/detail/logging_mutex.cpp - src/rclpy/detail/thread_safe_logging_output_handler.cpp ) target_link_libraries(_rclpy PRIVATE rclpy_common diff --git a/rclpy/src/rclpy/_rclpy.c b/rclpy/src/rclpy/_rclpy.c index 21fe13f36..7eae0049f 100644 --- a/rclpy/src/rclpy/_rclpy.c +++ b/rclpy/src/rclpy/_rclpy.c @@ -45,8 +45,6 @@ #include #include -#include "./detail/thread_safe_logging_output_handler.h" -#include "./detail/execute_with_logging_mutex.h" #include "rclpy_common/common.h" #include "rclpy_common/handle.h" @@ -529,7 +527,7 @@ rclpy_init(PyObject * module, PyObject * args) * Raises RuntimeError if rcl logging could not be initialized */ static PyObject * -rclpy_logging_configure_impl(PyObject * module, PyObject * args) +rclpy_logging_configure(PyObject * module, PyObject * args) { rclpy_module_state_t * module_state = (rclpy_module_state_t *)PyModule_GetState(module); if (!module_state) { @@ -547,10 +545,8 @@ rclpy_logging_configure_impl(PyObject * module, PyObject * args) return NULL; } rcl_allocator_t allocator = rcl_get_default_allocator(); - rcl_ret_t ret = rcl_logging_configure_with_output_handler( - &context->global_arguments, - &allocator, - rclpy_detail_thread_safe_logging_output_handler); + rcl_ret_t ret = rcl_logging_configure( + &context->global_arguments, &allocator); if (RCL_RET_OK != ret) { PyErr_Format( module_state->RCLError, @@ -561,19 +557,12 @@ rclpy_logging_configure_impl(PyObject * module, PyObject * args) Py_RETURN_NONE; } -/// See rclpy_logging_configure_impl above. -static PyObject * -rclpy_logging_configure(PyObject * self, PyObject * args) -{ - return rclpy_detail_execute_with_logging_mutex(rclpy_logging_configure_impl, self, args); -} - /// Finalize rcl logging /** * Produces a RuntimeWarning if rcl logging could not be finalized */ static PyObject * -rclpy_logging_fini_impl(PyObject * Py_UNUSED(self), PyObject * Py_UNUSED(args)) +rclpy_logging_fini(PyObject * Py_UNUSED(self), PyObject * Py_UNUSED(args)) { rcl_ret_t ret = rcl_logging_fini(); if (RCL_RET_OK != ret) { @@ -589,16 +578,9 @@ rclpy_logging_fini_impl(PyObject * Py_UNUSED(self), PyObject * Py_UNUSED(args)) Py_RETURN_NONE; } -/// See rclpy_logging_fini_impl above. -static PyObject * -rclpy_logging_fini(PyObject * self, PyObject * args) -{ - return rclpy_detail_execute_with_logging_mutex(rclpy_logging_fini_impl, self, args); -} - /// Handle destructor for node static void -_rclpy_destroy_node_impl(void * p) +_rclpy_destroy_node(void * p) { rcl_node_t * node = p; if (!node) { @@ -620,13 +602,6 @@ _rclpy_destroy_node_impl(void * p) PyMem_Free(node); } -/// See _rclpy_destroy_node_impl above. -static void -_rclpy_destroy_node(void * p) -{ - rclpy_detail_execute_with_logging_mutex2(_rclpy_destroy_node_impl, p); -} - /// Create a node /** * Raises ValueError if the node name or namespace is invalid @@ -639,7 +614,7 @@ _rclpy_destroy_node(void * p) * \return NULL on failure */ static PyObject * -rclpy_create_node_impl(PyObject * module, PyObject * args) +rclpy_create_node(PyObject * module, PyObject * args) { rcl_ret_t ret; const char * node_name; @@ -752,13 +727,6 @@ rclpy_create_node_impl(PyObject * module, PyObject * args) return node_capsule; } -/// See rclpy_create_node_impl above. -static PyObject * -rclpy_create_node(PyObject * self, PyObject * args) -{ - return rclpy_detail_execute_with_logging_mutex(rclpy_create_node_impl, self, args); -} - /// Get the name of a node. /** * Raises ValueError if pynode is not a node capsule diff --git a/rclpy/src/rclpy/detail/execute_with_logging_mutex.cpp b/rclpy/src/rclpy/detail/execute_with_logging_mutex.cpp deleted file mode 100644 index 06e9ebc22..000000000 --- a/rclpy/src/rclpy/detail/execute_with_logging_mutex.cpp +++ /dev/null @@ -1,72 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#include "./execute_with_logging_mutex.h" // NOLINT(build/include) - -// Must be before Python.h; makes #-formats use ssize_t instead of int -#define PY_SSIZE_T_CLEAN -#include - -#include "rcutils/logging.h" -#include "rcutils/visibility_control_macros.h" - -#include "./logging_mutex.hpp" - -extern "C" -{ -PyObject * -rclpy_detail_execute_with_logging_mutex( - rclpy_detail_execute_with_logging_mutex_sig function, - PyObject * self, - PyObject * args) -{ - try { - std::lock_guard guard(rclpy::detail::get_global_logging_mutex()); - return function(self, args); - } catch (std::exception & ex) { - PyErr_Format( - PyExc_RuntimeError, - "Failed to acquire logging mutex: %s", ex.what()); - return NULL; - } catch (...) { - PyErr_Format( - PyExc_RuntimeError, - "Failed to acquire logging mutex"); - return NULL; - } -} - -void -rclpy_detail_execute_with_logging_mutex2( - rclpy_detail_execute_with_logging_mutex_sig2 function, - void * arg) -{ - try { - std::lock_guard guard(rclpy::detail::get_global_logging_mutex()); - function(arg); - } catch (std::exception & ex) { - // Warning should use line number of the current stack frame - int stack_level = 1; - PyErr_WarnFormat( - PyExc_RuntimeWarning, stack_level, - "Failed to acquire logging mutex: %s", ex.what()); - } catch (...) { - // Warning should use line number of the current stack frame - int stack_level = 1; - PyErr_WarnFormat( - PyExc_RuntimeWarning, stack_level, - "Failed to acquire logging mutex"); - } -} -} // extern "C" diff --git a/rclpy/src/rclpy/detail/execute_with_logging_mutex.h b/rclpy/src/rclpy/detail/execute_with_logging_mutex.h deleted file mode 100644 index eb9275e69..000000000 --- a/rclpy/src/rclpy/detail/execute_with_logging_mutex.h +++ /dev/null @@ -1,56 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#ifndef RCLPY__DETAIL__EXECUTE_WITH_LOGGING_MUTEX_H_ -#define RCLPY__DETAIL__EXECUTE_WITH_LOGGING_MUTEX_H_ - -// Must be before Python.h; makes #-formats use ssize_t instead of int -#define PY_SSIZE_T_CLEAN -#include - -#include "rcutils/logging.h" -#include "rcutils/visibility_control_macros.h" - -#ifdef __cplusplus -extern "C" -{ -#endif - -typedef PyObject * (* rclpy_detail_execute_with_logging_mutex_sig)(PyObject *, PyObject *); - -/// Execute the given function pointer after acquiring the logging mutex. -RCUTILS_LOCAL -PyObject * -rclpy_detail_execute_with_logging_mutex( - rclpy_detail_execute_with_logging_mutex_sig function, - PyObject * self, - PyObject * args); - -typedef void (* rclpy_detail_execute_with_logging_mutex_sig2)(void *); - -/// Execute the given function pointer after acquiring the logging mutex. -/** - * This version has a slightly different signature which is used when destroying a node. - */ -RCUTILS_LOCAL -void -rclpy_detail_execute_with_logging_mutex2( - rclpy_detail_execute_with_logging_mutex_sig2 function, - void * arg); - -#ifdef __cplusplus -} // extern "C" -#endif - -#endif // RCLPY__DETAIL__EXECUTE_WITH_LOGGING_MUTEX_H_ diff --git a/rclpy/src/rclpy/detail/logging_mutex.cpp b/rclpy/src/rclpy/detail/logging_mutex.cpp deleted file mode 100644 index 2508b6931..000000000 --- a/rclpy/src/rclpy/detail/logging_mutex.cpp +++ /dev/null @@ -1,27 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#include "./logging_mutex.hpp" - -#include -#include - -#include "rcutils/macros.h" - -std::recursive_mutex & -rclpy::detail::get_global_logging_mutex() -{ - static std::recursive_mutex mutex; - return mutex; -} diff --git a/rclpy/src/rclpy/detail/logging_mutex.hpp b/rclpy/src/rclpy/detail/logging_mutex.hpp deleted file mode 100644 index 051d034a0..000000000 --- a/rclpy/src/rclpy/detail/logging_mutex.hpp +++ /dev/null @@ -1,47 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#ifndef RCLPY__DETAIL__LOGGING_MUTEX_HPP_ -#define RCLPY__DETAIL__LOGGING_MUTEX_HPP_ - -#include -#include - -#include "rcutils/visibility_control_macros.h" - -namespace rclpy -{ -namespace detail -{ - -/// Global logging mutex -/** - * This mutex is locked in the following situations: - * - In initialization/destruction of contexts. - * - In initialization/destruction of nodes. - * - In the rcl logging output handler installed by rclpy, - * i.e.: in all calls to the logger macros, including RCUTILS_* ones. - */ -// Implementation detail: -// A shared pointer to the mutex is used, so that objects that need to use -// it at destruction time can keep it alive. -// In that way, a destruction ordering problem between static objects is avoided. -RCUTILS_LOCAL -std::recursive_mutex & -get_global_logging_mutex(); - -} // namespace detail -} // namespace rclpy - -#endif // RCLPY__DETAIL__LOGGING_MUTEX_HPP_ diff --git a/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.cpp b/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.cpp deleted file mode 100644 index 3d14d4f9e..000000000 --- a/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.cpp +++ /dev/null @@ -1,43 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#include "./thread_safe_logging_output_handler.h" // NOLINT(build/include) - -#include "rcl/logging.h" - -#include "./logging_mutex.hpp" - -extern "C" -{ -void -rclpy_detail_thread_safe_logging_output_handler( - const rcutils_log_location_t * location, - int severity, - const char * name, - rcutils_time_point_value_t timestamp, - const char * format, - va_list * args) -{ - try { - std::lock_guard guard(rclpy::detail::get_global_logging_mutex()); - rcl_logging_multiple_output_handler(location, severity, name, timestamp, format, args); - } catch (std::exception & ex) { - RCUTILS_SAFE_FWRITE_TO_STDERR("rclpy failed to get the global logging mutex: "); - RCUTILS_SAFE_FWRITE_TO_STDERR(ex.what()); - RCUTILS_SAFE_FWRITE_TO_STDERR("\n"); - } catch (...) { - RCUTILS_SAFE_FWRITE_TO_STDERR("rclpy failed to get the global logging mutex\n"); - } -} -} // extern "C" diff --git a/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.h b/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.h deleted file mode 100644 index e26de6740..000000000 --- a/rclpy/src/rclpy/detail/thread_safe_logging_output_handler.h +++ /dev/null @@ -1,41 +0,0 @@ -// Copyright 2020 Open Source Robotics Foundation, Inc. -// -// Licensed under the Apache License, Version 2.0 (the "License"); -// you may not use this file except in compliance with the License. -// You may obtain a copy of the License at -// -// http://www.apache.org/licenses/LICENSE-2.0 -// -// Unless required by applicable law or agreed to in writing, software -// distributed under the License is distributed on an "AS IS" BASIS, -// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -// See the License for the specific language governing permissions and -// limitations under the License. - -#ifndef RCLPY__DETAIL__THREAD_SAFE_LOGGING_OUTPUT_HANDLER_H_ -#define RCLPY__DETAIL__THREAD_SAFE_LOGGING_OUTPUT_HANDLER_H_ - -#include "rcutils/logging.h" -#include "rcutils/visibility_control_macros.h" - -#ifdef __cplusplus -extern "C" -{ -#endif - -/// A thread-safe logging output handler. -RCUTILS_LOCAL -void -rclpy_detail_thread_safe_logging_output_handler( - const rcutils_log_location_t * location, - int severity, - const char * name, - rcutils_time_point_value_t timestamp, - const char * format, - va_list * args); - -#ifdef __cplusplus -} // extern "C" -#endif - -#endif // RCLPY__DETAIL__THREAD_SAFE_LOGGING_OUTPUT_HANDLER_H_