Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ensure no redundant rcl_logging initialization and finalization. #560

Closed
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
15 changes: 10 additions & 5 deletions rcl/src/rcl/logging.c
Original file line number Diff line number Diff line change
Expand Up @@ -71,7 +71,9 @@ rcl_logging_init(const rcl_arguments_t * global_args, const rcl_allocator_t * al
{
RCL_CHECK_ARGUMENT_FOR_NULL(global_args, RCL_RET_INVALID_ARGUMENT);
RCL_CHECK_ARGUMENT_FOR_NULL(allocator, RCL_RET_INVALID_ARGUMENT);

if (rcutils_atomic_fetch_add_uint64_t(&__rcl_logging_init_count, 1)) {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why are we counting and not just using a flag? This function is marked as not thread-safe, and rcl_logging_fini as well. So we don't have to handle the case where this is called multiple times concurrently. It's up to the code above this to ensure it isn't called in a thread unsafe way.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ok, I see why a counter, but why atomic?

return RCL_RET_OK;
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I wonder if we should log something here, to not return silently.
Maybe, an user might expect to be able to configure a logging of two contexts differently.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

okay, that is one of the cases, let's add it to notify the user.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree, but instead I'd prefer for this to fail instead (return an error code). That way the caller can decide how to react to this. As-is the caller cannot tell if the function succeeded or "succeeded" but didn't use the given settings.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In fact, I think the better solution would look like this (from the caller side):

Context::Context(...)
{
  // ...
  std::lock_guard<std::mutex> lock(g_logging_mutex);  // ensures thread-safety
  if (rcl_logging_is_initialized()) {
    auto ret = rcl_logging_init(...);
    if (ret != RCL_RET_OK) {
      // error handling
    }
  } else {
    auto ret = rcl_logging_increase_ref_count();  // safe because of lock above
    if (ret != RCL_RET_OK) {
      // error handling
    }
  }
  // ...
}

Context::~Context()
{
  // ...
  std::lock_guard<std::mutex> lock(g_logging_mutex);  // ensures thread-safety
  auto ret = rcl_logging_decrease_ref_count();  // will implicitly fini() if ref_count is zero
  if (ret != RCL_RET_OK) {
    // error handling
  }
  // ...
}

So that it is more explicit what's happening.

Or in the case where something is using logging but doesn't have what is required to initialize it (requires something else initialized it first):

{
  // ...
  std::lock_guard<std::mutex> lock(g_logging_mutex);  // ensures thread-safety
  if (rcl_logging_increase_ref_count() == RCL_LOGGING_NOT_INITIALIZED) {
    // error handling because it was unexpectedly not initialized...
  }
  // ...
}

Not sure there's a use case for the second example, but either way I think having init return OK but not actually consider the input arguments is probably not good. But at the same time you need to see if it is initialized and increase the reference count some how.


Also, out of scope for this pr, but logging should probably not require the use of global... This is only a problem because we're mapping non-globals (multiple context) to the initialization of a global. If each context could create its own logging instance this would not be a problem.

}
RCUTILS_LOGGING_AUTOINIT
g_logging_allocator = *allocator;
int default_level = global_args->impl->log_level;
Expand All @@ -81,7 +83,6 @@ rcl_logging_init(const rcl_arguments_t * global_args, const rcl_allocator_t * al
g_rcl_logging_ext_lib_enabled = !global_args->impl->log_ext_lib_disabled;
rcl_ret_t status = RCL_RET_OK;
g_rcl_logging_num_out_handlers = 0;
(void) rcutils_atomic_fetch_add_uint64_t(&__rcl_logging_init_count, 1);

if (default_level >= 0) {
rcutils_logging_set_default_logger_level(default_level);
Expand Down Expand Up @@ -112,10 +113,14 @@ rcl_logging_init(const rcl_arguments_t * global_args, const rcl_allocator_t * al
rcl_ret_t rcl_logging_fini()
{
rcl_ret_t status = RCL_RET_OK;
uint64_t current_count = rcutils_atomic_fetch_add_uint64_t(&__rcl_logging_init_count, -1);

if (current_count != 1) {
return status;
if (rcutils_atomic_load_uint64_t(&__rcl_logging_init_count) > 0) {
uint64_t current_count = rcutils_atomic_fetch_add_uint64_t(&__rcl_logging_init_count, -1);
wjwwood marked this conversation as resolved.
Show resolved Hide resolved
if (current_count != 1) {
return RCL_RET_OK;
}
} else {
return RCL_RET_OK;
}

rcutils_logging_set_output_handler(rcutils_logging_console_output_handler);
Expand Down