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.

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

Jump to bottom

Set default logger level from command line #256

Merged
merged 18 commits into from
Jun 12, 2018
Merged

Set default logger level from command line #256

Show file tree
Hide file tree
Changes from 15 commits
Commits
Show all changes
18 commits
Select commit Hold shift + click to select a range
714751b
Set default logger level from command line
dhood Jun 6, 2018
dc35947
Return INVALID_REMAP_RULE
dhood Jun 6, 2018
08b6266
Add tests
dhood Jun 6, 2018
10b4056
Do string parsing in rcutils
dhood Jun 6, 2018
6479269
Set log level after parsing all arguments
dhood Jun 7, 2018
73b987a
Document log arg format, custom return code
dhood Jun 7, 2018
eb72a1a
Rename function
dhood Jun 7, 2018
77b1a8c
Rename argument
dhood Jun 7, 2018
7d5c90d
Refactor argument parsing after rebasing to include param files
dhood Jun 7, 2018
0cf31b5
Renaming from param files support
dhood Jun 7, 2018
9ac0f8d
Doc fixup
dhood Jun 7, 2018
3d5cba6
__log -> __log_level
dhood Jun 8, 2018
27fca18
Use RCUTILS_SAFE_FWRITE_TO_STDERR on bad alloc
dhood Jun 8, 2018
ed56679
doc fixup
dhood Jun 8, 2018
e923448
doc fixup
dhood Jun 8, 2018
0ef1505
Document behaviour if multiple __log_level rules found
dhood Jun 11, 2018
b626c0a
Update docblock formatting
dhood Jun 11, 2018
3307ff7
Label all documentation in arguments.c as internal
dhood Jun 11, 2018
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
8 changes: 8 additions & 0 deletions rcl/include/rcl/arguments.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,9 @@ typedef struct rcl_arguments_t
struct rcl_arguments_impl_t * impl;
} rcl_arguments_t;

#define RCL_LOG_LEVEL_ARG_RULE "__log_level:="
#define RCL_PARAM_FILE_ARG_RULE "__params:="

/// Return a rcl_node_t struct with members initialized to `NULL`.
RCL_PUBLIC
RCL_WARN_UNUSED
Expand All @@ -52,6 +55,11 @@ rcl_get_zero_initialized_arguments(void);
* Successfully parsed remap rules are stored in the order they were given in `argv`.
* If given arguments `{"__ns:=/foo", "__ns:=/bar"}` then the namespace used by nodes in this
* process will be `/foo` and not `/bar`.
*
* The default log level will be parsed as `__log_level:=level`, where `level` is a name representing
* one of the log levels in the `RCUTILS_LOG_SEVERITY` enum, e.g. `info`, `debug`, `warn`, not case
* sensitive.
Copy link
Member

Choose a reason for hiding this comment

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

What's the expected behavior if __log_level:= is used more than once in command line arguments? Error? Last one wins? First one wins?

Copy link
Member Author

Choose a reason for hiding this comment

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

Last one, documentation added in 0ef1505

*
* \sa rcl_remap_topic_name()
* \sa rcl_remap_service_name()
* \sa rcl_remap_node_name()
Expand Down
2 changes: 2 additions & 0 deletions rcl/include/rcl/types.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -94,5 +94,7 @@ typedef rmw_ret_t rcl_ret_t;
#define RCL_RET_WRONG_LEXEME 1002
/// Argument is not a valid parameter rule
#define RCL_RET_INVALID_PARAM_RULE 1010
/// Argument is not a valid log level rule
#define RCL_RET_INVALID_LOG_LEVEL_RULE 1020

#endif // RCL__TYPES_H_
118 changes: 96 additions & 22 deletions rcl/src/rcl/arguments.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,8 @@
#include "rcl/lexer_lookahead.h"
#include "rcl/validate_topic_name.h"
#include "rcutils/allocator.h"
#include "rcutils/error_handling.h"
#include "rcutils/logging.h"
#include "rcutils/logging_macros.h"
#include "rcutils/strdup.h"
#include "rmw/validate_namespace.h"
Expand Down Expand Up @@ -51,12 +53,22 @@ _rcl_parse_remap_rule(
rcl_allocator_t allocator,
rcl_remap_t * output_rule);

/// Parse an argument that may or may not be a parameter file rule.
/// The syntax of the file name is not validated.
/// \param[in] arg the argument to parse
/// \param[in] allocator an allocator to use
/// \param[in,out] param_file string that could be a parameter file name
/// \return RCL_RET_OK if the rule was parsed correctly, or
/// \return RCL_RET_INVALID_PARAM_RULE if the argument is not a valid rule, or
/// \return RCL_RET_BAD_ALLOC if an allocation failed, or
/// \return RLC_RET_ERROR if an unspecified error occurred.
/// \internal
Copy link
Member

Choose a reason for hiding this comment

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

nitpick: since this is not parsed by doxygen, I'd recommend using normal comments, e.g. // or /* text */.

Copy link
Member Author

Choose a reason for hiding this comment

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

while I was mostly just copying the existing formatting, I had imagined from the /internal tag that we were using doxygen formatting to optionally support building internal docs. But even without that could it still be worthwhile keeping the doxygen formatting in case one day we move them to the header? Or do you find it easier to read as a standard comment?

Copy link
Member

Choose a reason for hiding this comment

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

Well if you want to use doxygen style that’s fine, though we should turn on the internal docs feature then. But I’m sure this is something I mentioned on the other prs, but this doesn’t match the doxygen style for most of rcl. So if you’re going to touch it, I’d recommend the style described in our style guide under comments and doc comments: https://github.com/ros2/ros2/wiki/Developer-Guide#c-1

Copy link
Member Author

Choose a reason for hiding this comment

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

yep, happy to change the file to use /** style. and will look at turning on the internal docs generation

RCL_LOCAL
rcl_ret_t
_rcl_parse_param_rule(
_rcl_parse_param_file_rule(
const char * arg,
rcl_allocator_t allocator,
char ** output_rule);
char ** param_file);

rcl_ret_t
rcl_arguments_get_param_files(
Expand Down Expand Up @@ -98,6 +110,22 @@ rcl_arguments_get_param_files_count(
return args->impl->num_param_files_args;
}

/// Parse an argument that may or may not be a log level rule.
/// \param[in] arg the argument to parse
/// \param[in] allocator an allocator to use
/// \param[in,out] log_level parsed log level represented by `RCUTILS_LOG_SEVERITY` enum
/// \return RCL_RET_OK if a valid log level was parsed, or
/// \return RCL_RET_INVALID_LOG_LEVEL_RULE if the argument is not a valid rule, or
/// \return RCL_RET_BAD_ALLOC if an allocation failed, or
/// \return RLC_RET_ERROR if an unspecified error occurred.
/// \internal
RCL_LOCAL
rcl_ret_t
_rcl_parse_log_level_rule(
const char * arg,
rcl_allocator_t allocator,
int * log_level);

rcl_ret_t
rcl_parse_arguments(
int argc,
Expand Down Expand Up @@ -129,6 +157,7 @@ rcl_parse_arguments(
rcl_arguments_impl_t * args_impl = args_output->impl;
args_impl->num_remap_rules = 0;
args_impl->remap_rules = NULL;
args_impl->log_level = -1;
args_impl->unparsed_args = NULL;
args_impl->num_unparsed_args = 0;
args_impl->parameter_files = NULL;
Expand Down Expand Up @@ -157,29 +186,50 @@ rcl_parse_arguments(
goto fail;
}

// Attempt to parse arguments as remap rules
for (int i = 0; i < argc; ++i) {
rcl_remap_t * rule = &(args_impl->remap_rules[args_impl->num_remap_rules]);
*rule = rcl_remap_get_zero_initialized();
// Attempt to parse argument as parameter file rule
args_impl->parameter_files[args_impl->num_param_files_args] = NULL;
if (
RCL_RET_OK == _rcl_parse_param_rule(
RCL_RET_OK == _rcl_parse_param_file_rule(
argv[i], allocator, &(args_impl->parameter_files[args_impl->num_param_files_args])))
{
++(args_impl->num_param_files_args);
RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME,
"params rule : %s\n total num param rules %d",
args_impl->parameter_files[args_impl->num_param_files_args - 1],
args_impl->num_param_files_args)
} else if (RCL_RET_OK == _rcl_parse_remap_rule(argv[i], allocator, rule)) {
Copy link
Member Author

Choose a reason for hiding this comment

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

Note to reviewers: this block has been restructured to not have else statements. Error messages must be cleared after each attempt to avoid overwriting error messages on the next argument. This is an example output from out tests, with debug enabled:

55: [DEBUG] [rcl]: Couldn't parse arg 0 (process_name) as remap rule. Error: Expected lexeme type (19) not found, search ended at index 12, at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/lexer_lookahead.c:228
55: [DEBUG] [rcl]: Couldn't parse arg 0 (process_name) as log level rule. Error: Argument does not start with '__log_level:=', at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/arguments.c:995
55: [DEBUG] [rcl]: Couldn't parse arg 1 (/foo/bar:=) as parameter file rule. Error: Argument does not start with '__params:=', at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/arguments.c:1062
55: [DEBUG] [rcl]: Couldn't parse arg 1 (/foo/bar:=) as remap rule. Error: (null)
55: [DEBUG] [rcl]: Couldn't parse arg 1 (/foo/bar:=) as log level rule. Error: Argument does not start with '__log_level:=', at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/arguments.c:995
55: [DEBUG] [rcl]: Couldn't parse arg 2 (bar:=/fiz/buz) as parameter file rule. Error: Argument does not start with '__params:=', at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/arguments.c:1062
55: [DEBUG] [rcl]: Couldn't parse arg 3 (}bar:=fiz) as parameter file rule. Error: Argument does not start with '__params:=', at /home/dhood/ros2_ws/src/ros2/rcl/rcl/src/rcl/arguments.c:1062

args_impl->num_param_files_args);
continue;
}
RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME,
"Couldn't parse arg %d (%s) as parameter file rule. Error: %s", i, argv[i],
rcl_get_error_string());
rcl_reset_error();

// Attempt to parse argument as remap rule
rcl_remap_t * rule = &(args_impl->remap_rules[args_impl->num_remap_rules]);
*rule = rcl_remap_get_zero_initialized();
if (RCL_RET_OK == _rcl_parse_remap_rule(argv[i], allocator, rule)) {
++(args_impl->num_remap_rules);
} else {
RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME, "arg %d (%s) error '%s'", i, argv[i],
rcl_get_error_string());
rcl_reset_error();
args_impl->unparsed_args[args_impl->num_unparsed_args] = i;
++(args_impl->num_unparsed_args);
continue;
}
RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME,
"Couldn't parse arg %d (%s) as remap rule. Error: %s", i, argv[i], rcl_get_error_string());
rcl_reset_error();

// Attempt to parse argument as log level configuration
int log_level;
if (RCL_RET_OK == _rcl_parse_log_level_rule(argv[i], allocator, &log_level)) {
args_impl->log_level = log_level;
continue;
}
RCUTILS_LOG_DEBUG_NAMED(ROS_PACKAGE_NAME,
"Couldn't parse arg %d (%s) as log level rule. Error: %s", i, argv[i],
rcl_get_error_string());
rcl_reset_error();

// Argument wasn't parsed by any rule
args_impl->unparsed_args[args_impl->num_unparsed_args] = i;
++(args_impl->num_unparsed_args);
}

// Shrink remap_rules array to match number of successfully parsed rules
Expand Down Expand Up @@ -933,6 +983,29 @@ _rcl_parse_remap_begin_remap_rule(
return ret;
}

rcl_ret_t
_rcl_parse_log_level_rule(
const char * arg,
rcl_allocator_t allocator,
int * log_level)
{
RCL_CHECK_ARGUMENT_FOR_NULL(arg, RCL_RET_INVALID_ARGUMENT, allocator);
RCL_CHECK_ARGUMENT_FOR_NULL(log_level, RCL_RET_INVALID_ARGUMENT, allocator);

if (strncmp(RCL_LOG_LEVEL_ARG_RULE, arg, strlen(RCL_LOG_LEVEL_ARG_RULE)) != 0) {
RCL_SET_ERROR_MSG("Argument does not start with '" RCL_LOG_LEVEL_ARG_RULE "'", allocator);
return RCL_RET_INVALID_LOG_LEVEL_RULE;
}
rcutils_ret_t ret = rcutils_logging_severity_level_from_string(
arg + strlen(RCL_LOG_LEVEL_ARG_RULE), allocator, log_level);
if (RCUTILS_RET_OK == ret) {
return RCL_RET_OK;
}
RCL_SET_ERROR_MSG("Argument does not use a valid severity level", allocator);
return RCL_RET_INVALID_LOG_LEVEL_RULE;
}


rcl_ret_t
_rcl_parse_remap_rule(
const char * arg,
Expand Down Expand Up @@ -969,24 +1042,25 @@ _rcl_parse_remap_rule(
}

rcl_ret_t
_rcl_parse_param_rule(
_rcl_parse_param_file_rule(
const char * arg,
rcl_allocator_t allocator,
char ** output_rule)
char ** param_file)
{
RCL_CHECK_ARGUMENT_FOR_NULL(arg, RCL_RET_INVALID_ARGUMENT, allocator);

const char * param_prefix = "__params:=";
const size_t param_prefix_len = strlen(param_prefix);
if (strncmp(param_prefix, arg, param_prefix_len) == 0) {
const size_t param_prefix_len = strlen(RCL_PARAM_FILE_ARG_RULE);
if (strncmp(RCL_PARAM_FILE_ARG_RULE, arg, param_prefix_len) == 0) {
size_t outlen = strlen(arg) - param_prefix_len;
*output_rule = allocator.allocate(sizeof(char) * (outlen + 1), allocator.state);
if (NULL == output_rule) {
*param_file = allocator.allocate(sizeof(char) * (outlen + 1), allocator.state);
if (NULL == param_file) {
RCUTILS_SAFE_FWRITE_TO_STDERR("Failed to allocate memory for parameters file path\n");
return RCL_RET_BAD_ALLOC;
}
snprintf(*output_rule, outlen + 1, "%s", arg + param_prefix_len);
snprintf(*param_file, outlen + 1, "%s", arg + param_prefix_len);
return RCL_RET_OK;
}
RCL_SET_ERROR_MSG("Argument does not start with '" RCL_PARAM_FILE_ARG_RULE "'", allocator);
return RCL_RET_INVALID_PARAM_RULE;
}

Expand Down
3 changes: 3 additions & 0 deletions rcl/src/rcl/arguments_impl.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,9 @@ typedef struct rcl_arguments_impl_t
/// Length of remap_rules.
int num_remap_rules;

/// Default log level (represented by `RCUTILS_LOG_SEVERITY` enum) or -1 if not specified.
int log_level;

/// Allocator used to allocate objects in this struct
rcl_allocator_t allocator;
} rcl_arguments_impl_t;
Expand Down
6 changes: 6 additions & 0 deletions rcl/src/rcl/rcl.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -117,6 +117,12 @@ rcl_init(int argc, char const * const * argv, rcl_allocator_t allocator)
RCUTILS_LOG_ERROR_NAMED(ROS_PACKAGE_NAME, "Failed to parse global arguments");
goto fail;
}

// Update the default log level if specified in arguments.
if (global_args->impl->log_level >= 0) {
rcutils_logging_set_default_logger_level(global_args->impl->log_level);
}

rcl_atomic_store(&__rcl_instance_id, ++__rcl_next_unique_id);
if (rcl_atomic_load_uint64_t(&__rcl_instance_id) == 0) {
// Roll over occurred.
Expand Down
19 changes: 17 additions & 2 deletions rcl/test/rcl/test_arguments.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -100,7 +100,7 @@ TEST_F(CLASSNAME(TestArgumentsFixture, RMW_IMPLEMENTATION), check_valid_vs_inval
EXPECT_TRUE(is_valid_arg("rostopic://rostopic:=rosservice"));
EXPECT_TRUE(is_valid_arg("rostopic:///rosservice:=rostopic"));
EXPECT_TRUE(is_valid_arg("rostopic:///foo/bar:=baz"));
EXPECT_TRUE(is_valid_arg("__params:=node_name"));
EXPECT_TRUE(is_valid_arg("__params:=file_name.yaml"));

EXPECT_FALSE(is_valid_arg(":="));
EXPECT_FALSE(is_valid_arg("foo:="));
Expand All @@ -118,7 +118,22 @@ TEST_F(CLASSNAME(TestArgumentsFixture, RMW_IMPLEMENTATION), check_valid_vs_inval
EXPECT_FALSE(is_valid_arg("foo:=/b}ar"));
EXPECT_FALSE(is_valid_arg("rostopic://:=rosservice"));
EXPECT_FALSE(is_valid_arg("rostopic::=rosservice"));
EXPECT_FALSE(is_valid_arg("__param:=node_name"));
EXPECT_FALSE(is_valid_arg("__param:=file_name.yaml"));

// Setting logger level
EXPECT_TRUE(is_valid_arg("__log_level:=UNSET"));
EXPECT_TRUE(is_valid_arg("__log_level:=DEBUG"));
EXPECT_TRUE(is_valid_arg("__log_level:=INFO"));
EXPECT_TRUE(is_valid_arg("__log_level:=WARN"));
EXPECT_TRUE(is_valid_arg("__log_level:=ERROR"));
EXPECT_TRUE(is_valid_arg("__log_level:=FATAL"));
EXPECT_TRUE(is_valid_arg("__log_level:=debug"));
EXPECT_TRUE(is_valid_arg("__log_level:=Info"));

EXPECT_FALSE(is_valid_arg("__log:=foo"));
EXPECT_FALSE(is_valid_arg("__loglevel:=foo"));
EXPECT_FALSE(is_valid_arg("__log_level:="));
EXPECT_FALSE(is_valid_arg("__log_level:=foo"));
}

TEST_F(CLASSNAME(TestArgumentsFixture, RMW_IMPLEMENTATION), test_no_args) {
Expand Down