Make rcl call rmw_set_log_severity

[christophebedard]

Feature request

Feature description

rmw_set_log_severity was added in:

• Enable setting log levels in DDS implementation rmw#124
• API to enable log severity setting.  rmw_implementation#30

It's implemented by the rmw implementations (Cyclone DDS, FastDDS, Connext), but it doesn't really seem to be used anywhere/by anything.

It would make sense to have rcl (e.g. rcl_logging_configure()?) call rmw_set_log_severity() along with its own logging level configuration. Is there any reason why these two shouldn't be connected?

Implementation considerations

TBD

[fujitatomoya]

i think it makes sense, probably setting default log level during Context::init?

[christophebedard]

assuming you mean rclcpp::Context::init, yeah it does call rcl_init and logging-related rcl_* functions.

I opened a simple draft PR just to have a concrete proposition: #918

[thomasmoore-torc]

Are there any plans to progress with resolving this issue? Getting logs out of the RMW while integrating ROS2 into target hardware has been a pain point for us. In the case of Fast DDS, getting logs currently require:

1. Building Fast DDS with LOG_NO_INFO=OFF (and FASTDDS_ENFORCE_LOG_INFO=ON if a non-debug build)
2. Add a call to rmw_set_log_severity(RMW_LOG_SEVERITY_INFO); to every process for which we want to be able to see Fast DDS info messages

The first step is not much of an issue for us as we are building Fast DDS as part of our pipeline and it's easy enough to create a build with those options set. However, the second step is the more obtrusive issue as we now have to start modifying source code, potentially in many locations.

I can see the reasoning for not necessarily wanting to couple the RCL and RMW log levels, but it would be nice to have some solution to enable RMW log messages. Here are a few options that could be considered:

1. Add a new --rmw-log-level ROS parameter
2. Add a new RMW_LOG_LEVEL environment variable

If there is a strong preference either way, then I can start working on an alternative to #918 to implement the preference.

[christophebedard]

Unfortunately, I think adding a new config option, such as a new CLI option or a new env var, may be even less well-received than the current proposal (#918).

We've been wanting to figure out logging by creating a coherent overall strategy for the past few years (see ros2/design#314), which is why some of these small/one-off changes have been put on hold, but it hasn't really happened yet (ros2/design#315). I can bring this issue up during the next ROS 2 PMC meeting, but it may get pushed back a bit.

[fujitatomoya]

@christophebedard @clalancette

• IMO default log level makes sense with --log-level arguments. but as discussed on https://github.com/ros2/rcl/pull/918/files#r625111915, default means ROS 2 core only? and for actual use case, probably user does not expect the implementation log if they set default log level.
• Logging Configuration file support (not used for now) to set implementation log level. If that is set, rcl will call the rmw_set_log_severity to set the implementation log level. related to proposal for how to unify logging and make it configurable with a file rcl_logging#92, this could be long term work for redesign and specification to add.
• How about calling rmw_set_log_severity with rcutils_logging_set_logger_level, and if the identifier matches with implementation (for example, rmw_fastrtps_cpp), it sets the implementation log level accordingly? in this way, we can enable implementation log level with --log-level rmw_fastrtps_cpp:=debug or calling logger service with name rmw_fastrtps_cpp to reset at runtime. the expectation is that if we want to change the log level rmw_fastrtps_cpp, it always affects to Fast-DDS. i am not sure if this is always useful or not...

[christophebedard]

• IMO default log level makes sense with --log-level arguments. but as discussed on https://github.com/ros2/rcl/pull/918/files#r625111915, default means ROS 2 core only? and for actual use case, probably user does not expect the implementation log if they set default log level.

Yeah, I think this makes sense.

• How about calling rmw_set_log_severity with rcutils_logging_set_logger_level, and if the identifier matches with implementation (for example, rmw_fastrtps_cpp), it sets the implementation log level accordingly? in this way, we can enable implementation log level with --log-level rmw_fastrtps_cpp:=debug or calling logger service with name rmw_fastrtps_cpp to reset at runtime. the expectation is that if we want to change the log level rmw_fastrtps_cpp, it always affects to Fast-DDS. i am not sure if this is always useful or not...

We could also make it rmw implementation-agnostic and just have --log-level rmw_implementation:=debug. It would apply to whatever rmw implementation is used.

Then this could be set through a logging configuration file (if/when we get this) using the equivalent to --log-level.