From ebb043ad4b75f76b04cc8935c1058428441606cd Mon Sep 17 00:00:00 2001 From: Ivan Santiago Paunovic Date: Fri, 7 Feb 2020 13:28:27 -0300 Subject: [PATCH 1/2] Check that logging is initialized once Signed-off-by: Ivan Santiago Paunovic --- rcl/include/rcl/arguments.h | 3 ++ rcl/include/rcl/logging.h | 17 +++++++++ rcl/src/rcl/arguments.c | 3 -- rcl/src/rcl/init.c | 70 +++++++++++++++++++++++++------------ rcl/src/rcl/logging.c | 31 ++++++++++++++++ 5 files changed, 99 insertions(+), 25 deletions(-) diff --git a/rcl/include/rcl/arguments.h b/rcl/include/rcl/arguments.h index 0e301a207..0200c14dc 100644 --- a/rcl/include/rcl/arguments.h +++ b/rcl/include/rcl/arguments.h @@ -44,6 +44,9 @@ typedef struct rcl_arguments_t #define RCL_SHORT_REMAP_FLAG "-r" #define RCL_LOG_LEVEL_FLAG "--log-level" #define RCL_EXTERNAL_LOG_CONFIG_FLAG "--log-config-file" +// Prefixes used for some options +#define RCL_ENABLE_FLAG_PREFIX "--enable-" +#define RCL_DISABLE_FLAG_PREFIX "--disable-" // To be prefixed with --enable- or --disable- #define RCL_LOG_STDOUT_FLAG_SUFFIX "stdout-logs" #define RCL_LOG_ROSOUT_FLAG_SUFFIX "rosout-logs" diff --git a/rcl/include/rcl/logging.h b/rcl/include/rcl/logging.h index 9175c6f95..11ca22b5a 100644 --- a/rcl/include/rcl/logging.h +++ b/rcl/include/rcl/logging.h @@ -90,6 +90,23 @@ RCL_PUBLIC RCL_WARN_UNUSED bool rcl_logging_rosout_enabled(); +/// Return `true` if argv contains logging arguments. +/** + * Attribute | Adherence + * ------------------ | ------------- + * Allocates Memory | No + * Thread-Safe | No + * Uses Atomics | No + * Lock-Free | Yes + * + * \param argc + * \param argv can be `NULL`. In that case, the return value is `false`. + */ +RCL_PUBLIC +RCL_WARN_UNUSED +bool +rcl_contains_logging_arguments(int argc, char const * const * argv); + #ifdef __cplusplus } #endif diff --git a/rcl/src/rcl/arguments.c b/rcl/src/rcl/arguments.c index a8242f0b3..1a6d68dd0 100644 --- a/rcl/src/rcl/arguments.c +++ b/rcl/src/rcl/arguments.c @@ -245,9 +245,6 @@ _rcl_parse_param_file_rule( rcl_params_t * params, char ** param_file); -#define RCL_ENABLE_FLAG_PREFIX "--enable-" -#define RCL_DISABLE_FLAG_PREFIX "--disable-" - /// Parse a bool argument that may or may not be for the provided key rule. /** * \param[in] arg the argument to parse diff --git a/rcl/src/rcl/init.c b/rcl/src/rcl/init.c index d1dc84c80..7b9f1ff3d 100644 --- a/rcl/src/rcl/init.c +++ b/rcl/src/rcl/init.c @@ -19,19 +19,24 @@ extern "C" #include "rcl/init.h" -#include "./arguments_impl.h" -#include "./common.h" -#include "./context_impl.h" -#include "./init_options_impl.h" #include "rcl/arguments.h" #include "rcl/error_handling.h" #include "rcl/logging.h" + #include "rcutils/logging_macros.h" #include "rcutils/stdatomic_helper.h" + #include "rmw/error_handling.h" + #include "tracetools/tracetools.h" -static atomic_uint_least64_t __rcl_next_unique_id = ATOMIC_VAR_INIT(1); +#include "./arguments_impl.h" +#include "./common.h" +#include "./context_impl.h" +#include "./init_options_impl.h" + +static atomic_uint_least64_t g_rcl_next_unique_id = ATOMIC_VAR_INIT(1); +static atomic_uint_least64_t g_logging_ref_count = ATOMIC_VAR_INIT(0); rcl_ret_t rcl_init( @@ -122,23 +127,35 @@ rcl_init( goto fail; } - ret = rcl_logging_configure(&context->global_arguments, &allocator); - if (RCL_RET_OK != ret) { - fail_ret = ret; - RCUTILS_LOG_ERROR_NAMED( - ROS_PACKAGE_NAME, - "Failed to configure logging: %s", - rcutils_get_error_string().str); - goto fail; + if (0u == rcutils_atomic_fetch_add_uint64_t(&g_logging_ref_count, 1)) { + ret = rcl_logging_configure(&context->global_arguments, &allocator); + if (RCL_RET_OK != ret) { + fail_ret = ret; + RCUTILS_LOG_ERROR_NAMED( + ROS_PACKAGE_NAME, + "Failed to configure logging: %s", + rcutils_get_error_string().str); + goto fail; + } + } else { + // Check if logging configurations were specified again or not. + // It's not possible to check that in the already parsed `context->global_arguments` + // as many of the configurations have default values matching a possible argument. + if (rcl_contains_logging_arguments(argc, argv)) { + RCUTILS_LOG_WARN_NAMED( + ROS_PACKAGE_NAME, + "rcl_init was called more than once with logging arguments," + "ignoring the last logging configuration"); + } } // Set the instance id. - uint64_t next_instance_id = rcutils_atomic_fetch_add_uint64_t(&__rcl_next_unique_id, 1); + uint64_t next_instance_id = rcutils_atomic_fetch_add_uint64_t(&g_rcl_next_unique_id, 1); if (0 == next_instance_id) { // Roll over occurred, this is an extremely unlikely occurrence. RCL_SET_ERROR_MSG("unique rcl instance ids exhausted"); // Roll back to try to avoid the next call succeeding, but there's a data race here. - rcutils_atomic_store(&__rcl_next_unique_id, -1); + rcutils_atomic_store(&g_rcl_next_unique_id, -1); goto fail; } rcutils_atomic_store((atomic_uint_least64_t *)(&context->instance_id_storage), next_instance_id); @@ -184,13 +201,22 @@ rcl_shutdown(rcl_context_t * context) RCL_SET_ERROR_MSG(rmw_get_error_string().str); return rcl_convert_rmw_ret_to_rcl_ret(rmw_ret); } - - rcl_ret_t rcl_ret = rcl_logging_fini(); - RCUTILS_LOG_ERROR_EXPRESSION_NAMED( - RCL_RET_OK != rcl_ret, ROS_PACKAGE_NAME, - "Failed to fini logging, rcl_ret_t: %i, rcl_error_str: %s", rcl_ret, - rcl_get_error_string().str); - rcl_reset_error(); + size_t previous_logging_ref_count = + rcutils_atomic_fetch_add_uint64_t(&g_logging_ref_count, -1); + + if (1u == previous_logging_ref_count) { + rcl_ret_t rcl_ret = rcl_logging_fini(); + RCUTILS_LOG_ERROR_EXPRESSION_NAMED( + RCL_RET_OK != rcl_ret, ROS_PACKAGE_NAME, + "Failed to fini logging, rcl_ret_t: %i, rcl_error_str: %s", rcl_ret, + rcl_get_error_string().str); + rcl_reset_error(); + } else if (0u >= previous_logging_ref_count) { + rcutils_atomic_fetch_add_uint64_t(&g_logging_ref_count, 1); + RCUTILS_LOG_ERROR_NAMED( + ROS_PACKAGE_NAME, + "logging was already finished"); + } return RCL_RET_OK; } diff --git a/rcl/src/rcl/logging.c b/rcl/src/rcl/logging.c index 96c625dcd..a43363180 100644 --- a/rcl/src/rcl/logging.c +++ b/rcl/src/rcl/logging.c @@ -201,6 +201,37 @@ rcl_logging_ext_lib_output_handler( } } +bool +rcl_contains_logging_arguments(int argc, char const * const * argv) +{ + static const char * logging_options[] = { + RCL_LOG_LEVEL_FLAG, + RCL_EXTERNAL_LOG_CONFIG_FLAG, + RCL_ENABLE_FLAG_PREFIX RCL_LOG_STDOUT_FLAG_SUFFIX, + RCL_DISABLE_FLAG_PREFIX RCL_LOG_STDOUT_FLAG_SUFFIX, + RCL_ENABLE_FLAG_PREFIX RCL_LOG_ROSOUT_FLAG_SUFFIX, + RCL_DISABLE_FLAG_PREFIX RCL_LOG_ROSOUT_FLAG_SUFFIX, + RCL_ENABLE_FLAG_PREFIX RCL_LOG_EXT_LIB_FLAG_SUFFIX, + RCL_DISABLE_FLAG_PREFIX RCL_LOG_EXT_LIB_FLAG_SUFFIX, + RCL_LOG_LEVEL_ARG_RULE, + RCL_EXTERNAL_LOG_CONFIG_ARG_RULE, + RCL_LOG_DISABLE_STDOUT_ARG_RULE, + RCL_LOG_DISABLE_ROSOUT_ARG_RULE, + RCL_LOG_DISABLE_EXT_LIB_ARG_RULE, + }; + if (!argv) { + return false; + } + for (int i = 0; i < argc; ++i) { + for (size_t j = 0; j < sizeof(logging_options) / sizeof(const char *); j++) { + if (0u == strcmp(argv[i], logging_options[j])) { + return true; + } + } + } + return false; +} + #ifdef __cplusplus } #endif From 0f37ac5056bbf8ba5a50fe32bccf7ca5d327a302 Mon Sep 17 00:00:00 2001 From: Ivan Santiago Paunovic Date: Tue, 11 Feb 2020 17:16:55 -0300 Subject: [PATCH 2/2] Address peer review comments Signed-off-by: Ivan Santiago Paunovic --- rcl/include/rcl/arguments.h | 17 +++++++++++++++++ rcl/include/rcl/logging.h | 17 ----------------- rcl/src/rcl/init.c | 8 ++++---- rcl/src/rcl/logging.c | 31 ------------------------------- 4 files changed, 21 insertions(+), 52 deletions(-) diff --git a/rcl/include/rcl/arguments.h b/rcl/include/rcl/arguments.h index 0200c14dc..b6f60971f 100644 --- a/rcl/include/rcl/arguments.h +++ b/rcl/include/rcl/arguments.h @@ -398,6 +398,23 @@ rcl_ret_t rcl_arguments_fini( rcl_arguments_t * args); +/// Return `true` if argv contains logging arguments. +/** + * Attribute | Adherence + * ------------------ | ------------- + * Allocates Memory | No + * Thread-Safe | Yes + * Uses Atomics | No + * Lock-Free | Yes + * + * \param argc + * \param argv can be `NULL`. In that case, the return value is `false`. + */ +RCL_PUBLIC +RCL_WARN_UNUSED +bool +rcl_contains_logging_arguments(int argc, char const * const * argv); + #ifdef __cplusplus } #endif diff --git a/rcl/include/rcl/logging.h b/rcl/include/rcl/logging.h index 11ca22b5a..9175c6f95 100644 --- a/rcl/include/rcl/logging.h +++ b/rcl/include/rcl/logging.h @@ -90,23 +90,6 @@ RCL_PUBLIC RCL_WARN_UNUSED bool rcl_logging_rosout_enabled(); -/// Return `true` if argv contains logging arguments. -/** - * Attribute | Adherence - * ------------------ | ------------- - * Allocates Memory | No - * Thread-Safe | No - * Uses Atomics | No - * Lock-Free | Yes - * - * \param argc - * \param argv can be `NULL`. In that case, the return value is `false`. - */ -RCL_PUBLIC -RCL_WARN_UNUSED -bool -rcl_contains_logging_arguments(int argc, char const * const * argv); - #ifdef __cplusplus } #endif diff --git a/rcl/src/rcl/init.c b/rcl/src/rcl/init.c index 7b9f1ff3d..4e9d2b3a0 100644 --- a/rcl/src/rcl/init.c +++ b/rcl/src/rcl/init.c @@ -19,10 +19,6 @@ extern "C" #include "rcl/init.h" -#include "rcl/arguments.h" -#include "rcl/error_handling.h" -#include "rcl/logging.h" - #include "rcutils/logging_macros.h" #include "rcutils/stdatomic_helper.h" @@ -30,6 +26,10 @@ extern "C" #include "tracetools/tracetools.h" +#include "rcl/arguments.h" +#include "rcl/error_handling.h" +#include "rcl/logging.h" + #include "./arguments_impl.h" #include "./common.h" #include "./context_impl.h" diff --git a/rcl/src/rcl/logging.c b/rcl/src/rcl/logging.c index a43363180..96c625dcd 100644 --- a/rcl/src/rcl/logging.c +++ b/rcl/src/rcl/logging.c @@ -201,37 +201,6 @@ rcl_logging_ext_lib_output_handler( } } -bool -rcl_contains_logging_arguments(int argc, char const * const * argv) -{ - static const char * logging_options[] = { - RCL_LOG_LEVEL_FLAG, - RCL_EXTERNAL_LOG_CONFIG_FLAG, - RCL_ENABLE_FLAG_PREFIX RCL_LOG_STDOUT_FLAG_SUFFIX, - RCL_DISABLE_FLAG_PREFIX RCL_LOG_STDOUT_FLAG_SUFFIX, - RCL_ENABLE_FLAG_PREFIX RCL_LOG_ROSOUT_FLAG_SUFFIX, - RCL_DISABLE_FLAG_PREFIX RCL_LOG_ROSOUT_FLAG_SUFFIX, - RCL_ENABLE_FLAG_PREFIX RCL_LOG_EXT_LIB_FLAG_SUFFIX, - RCL_DISABLE_FLAG_PREFIX RCL_LOG_EXT_LIB_FLAG_SUFFIX, - RCL_LOG_LEVEL_ARG_RULE, - RCL_EXTERNAL_LOG_CONFIG_ARG_RULE, - RCL_LOG_DISABLE_STDOUT_ARG_RULE, - RCL_LOG_DISABLE_ROSOUT_ARG_RULE, - RCL_LOG_DISABLE_EXT_LIB_ARG_RULE, - }; - if (!argv) { - return false; - } - for (int i = 0; i < argc; ++i) { - for (size_t j = 0; j < sizeof(logging_options) / sizeof(const char *); j++) { - if (0u == strcmp(argv[i], logging_options[j])) { - return true; - } - } - } - return false; -} - #ifdef __cplusplus } #endif