Skip to content

Ensure no redundant rcl_logging initialization and finalization. #560

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.

Sign up for GitHub

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

Closed
fujitatomoya wants to merge 5 commits into from
Closed

Ensure no redundant rcl_logging initialization and finalization. #560

Show file tree
Hide file tree
Changes from 3 commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
2a141c2
Merge remote-tracking branch 'upstream/master'
Jan 23, 2020
6602f6c
Avoid redundant rcl_logging initialization and finalization.
Jan 23, 2020
1bf89b8
use atomic counter for rcl logging init/fini.
Jan 24, 2020
894e883
reconsider atomic counter with expectation logging init/fini always s…
Jan 28, 2020
3df75c1
get rid of unnecessary difference and change name for global variable.
Feb 3, 2020
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
2 changes: 1 addition & 1 deletion rcl/include/rcl/logging.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,7 @@ extern "C"
RCL_PUBLIC
RCL_WARN_UNUSED
rcl_ret_t
rcl_logging_configure(
rcl_logging_init(
const rcl_arguments_t * global_args,
const rcl_allocator_t * allocator);

Expand Down
2 changes: 1 addition & 1 deletion rcl/src/rcl/init.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -122,7 +122,7 @@ rcl_init(
goto fail;
}

ret = rcl_logging_configure(&context->global_arguments, &allocator);
ret = rcl_logging_init(&context->global_arguments, &allocator);
if (RCL_RET_OK != ret) {
fail_ret = ret;
RCUTILS_LOG_ERROR_NAMED(
Expand Down
14 changes: 12 additions & 2 deletions rcl/src/rcl/logging.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ extern "C"
#include "rcl/macros.h"
#include "rcutils/logging.h"
#include "rcutils/time.h"
#include "rcutils/stdatomic_helper.h"

#define RCL_LOGGING_MAX_OUTPUT_FUNCS (4)

Expand All @@ -43,6 +44,8 @@ static bool g_rcl_logging_stdout_enabled = false;
static bool g_rcl_logging_rosout_enabled = false;
static bool g_rcl_logging_ext_lib_enabled = false;

static atomic_uint_least64_t __rcl_logging_init_count = ATOMIC_VAR_INIT(0);
Comment thread
fujitatomoya marked this conversation as resolved.
Outdated

/**
* An output function that sends to multiple output appenders.
*/
Expand All @@ -64,10 +67,11 @@ rcl_logging_ext_lib_output_handler(
const char * format, va_list * args);

rcl_ret_t
rcl_logging_configure(const rcl_arguments_t * global_args, const rcl_allocator_t * allocator)
rcl_logging_init(const rcl_arguments_t * global_args, const rcl_allocator_t * allocator)
{
RCL_CHECK_ARGUMENT_FOR_NULL(global_args, RCL_RET_INVALID_ARGUMENT);
RCL_CHECK_ARGUMENT_FOR_NULL(allocator, RCL_RET_INVALID_ARGUMENT);

Comment thread
fujitatomoya marked this conversation as resolved.
Outdated
RCUTILS_LOGGING_AUTOINIT
g_logging_allocator = *allocator;
int default_level = global_args->impl->log_level;
Expand All @@ -77,6 +81,7 @@ rcl_logging_configure(const rcl_arguments_t * global_args, const rcl_allocator_t
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);

@fujitatomoya fujitatomoya Jan 24, 2020

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

if multiple contexts exist, this will be called more than once. so that there should be no warning.

@ivanpauno ivanpauno Jan 24, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

I think that the return value should be used.
Like,

if(rcutils_atomic_fetch_add_uint64_t(&__rcl_logging_init_count, 1)) {
  return RMW_RET_OK;  // already inited, just return.
}

@ivanpauno ivanpauno Jan 24, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Also, I think this should be the first thing done in the function.

@fujitatomoya fujitatomoya Jan 28, 2020

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

we are not sure rcl_logging_init is actually done without any error, what if argument is missing?
counter == 1 does only mean rcl_logging_init is called, but rcl_logging_init is succeeded.


if (default_level >= 0) {
rcutils_logging_set_default_logger_level(default_level);
Expand Down Expand Up @@ -107,6 +112,12 @@ rcl_logging_configure(const rcl_arguments_t * global_args, const rcl_allocator_t
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);

@fujitatomoya fujitatomoya Jan 24, 2020

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

using atomic is not exactly thread safe, but expecting good enough for this case. besides we do not really want to introduce mutex in here.


if (current_count != 1) {

@ivanpauno ivanpauno Jan 24, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Shouldn't be != 0? The returned value by fetch add is the previous value of the atomic.

@fujitatomoya fujitatomoya Jan 28, 2020

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

No, current_count is fetched before addition(subtraction), confirmed this with simple test program.
current_count == 1 means that initialized once, so that needs to be finalized.
current_count != 1 means that initialized multiple times.

@ivanpauno ivanpauno Jan 28, 2020

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

Yes, sorry you're right. But current_count sounds confusing, maybe previous_count?

return status;
}

rcutils_logging_set_output_handler(rcutils_logging_console_output_handler);

if (g_rcl_logging_rosout_enabled) {
Expand All @@ -115,7 +126,6 @@ rcl_ret_t rcl_logging_fini()
if (RCL_RET_OK == status && g_rcl_logging_ext_lib_enabled) {
status = rcl_logging_external_shutdown();
}

Comment thread
fujitatomoya marked this conversation as resolved.
return status;
}

Expand Down