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

Added initial version of logging.md file. #315

Open
wants to merge 6 commits into
base: gh-pages
Choose a base branch
from
Open

Added initial version of logging.md file. #315

Changes from 3 commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
ac29e80
Added initial version of logging.md file.
mlanting May 6, 2021
0f68b7f
Changed header levels.
mlanting May 7, 2021
3e2df37
Added new section at beginning of document
mlanting May 7, 2021
edd871e
Changed format of ROS2 to ROS 2
mlanting May 10, 2021
1386a54
Added more detail about creating loggers and setting levels
mlanting May 19, 2021
d3853d3
Added detail to output and backend sections.
mlanting Jun 4, 2021
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
75 changes: 75 additions & 0 deletions articles/logging.md
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,75 @@
## Desired User Experience
This section describes the desired user interface of the ROS2 logging system.
Copy link
Contributor

Choose a reason for hiding this comment

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

A nitpick throughout the document: we prefer "ROS 2" over "ROS2".

To define the interface of the ROS2 logging system, it is helpful to consider all of the various tasks users will want to perform.
From this list of tasks, we can describe the steps users will have to take in order to perform each one.
Based on our experiences with ROS1, other logging systems, and community feedback, the logging system in ROS2 will support the following interactions:
- creating loggers
- setting log levels
- outputting logs
- defining output destinations
- specifying a backend
- implementing a custom backend
- tailoring performance impact
### Interaction Descriptions
This section describes what each of the interactions in the list entails, and the steps users will have to take to complete them.
#### Creating Loggers
This interaction contitutes creating the objects that users will use to output information from their code.
#### Setting Log Levels
This is how users set the severity levels for the loggers in their code.
Copy link
Contributor

Choose a reason for hiding this comment

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

This section isn't only about code, so I would reword this to something like:

Suggested change
This is how users set the severity levels for the loggers in their code.
This is how users set the severity levels for the logging messages at runtime.

There are a number of ways users might want to be able to change these levels, so this interaction is further broken down to describe each of those.
##### Programatically
##### Command Line
##### Via ROS2 Service Call
Copy link
Contributor

Choose a reason for hiding this comment

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

How about in launch files? That might be covered by the other sections, but I think it bears explicitly stating.

Copy link
Author

Choose a reason for hiding this comment

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

lol, oops. Good catch; having that capability was one of my main motivations when I started this, I can't believe I left it out.

##### Environment Variable?
Copy link
Contributor

Choose a reason for hiding this comment

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

This seems more like a solution/implementation detail, rather than a thing we want users to be able to do. As such, I'd leave it out of this section.

#### Outputting Logs
This is primary interaction where users output information from their code.
#### Defining Output Destinations (Sinks)
Users may want logged information printed to the screen, written to a file, published to a topic, or a combination of those. This is how users setup those preferences.
#### Specifying A Backend
There are a number of widely used third-party logging libraries already available which may better suit a users use-case or provide extra features they need.
ROS2 logging provides a default implementation, as well as a couple alternatives.
This defines how users choose the implementation that best suits their needs.
#### Creating A Backend
Users may have requirements that none of the included backends support, so ROS2 provides an interface for users to create custom backend implementations.
#### Tailoring Performance Impact
Adding a sophisticated logging system to a complex code base can have performance impacts and are often mostly useful during development and debugging.
ROS2 provides a few ways to configure the logging system to eliminate this performance impact when the logs are not needed.
This section describes how to make those configuration changes.



## Existing infrastructure
ROS2
### `rcutils`
Contains macros for logging at several different levels and under various constraints
### `rclcpp`
Contains similar macros to those in `rcutils`, which call down to the macros in `rcutils`
### `rcl_logging`
Contains a logging interface and several implementations including log4cxx, spdlog, and a no-op implementation
### `rcl`
Contains infrastructure to tie the logger implementations defined in `rcl_logging` to the macros in `rcutils`
Copy link
Member

Choose a reason for hiding this comment

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

I think "any rmw implementation's logging system" should be mentioned here (and included wherever else applicable). The "existing infrastructure" would be rmw's rmw_set_log_severity. See:

As mentioned in the issues above, we still have to figure out if/how we want to use an rmw implementations's logging system. If we want --log-level to be ROS 2-only, then maybe we should add a separate option, e.g. --rmw-log-level?

Copy link
Contributor

Choose a reason for hiding this comment

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

You know, thinking about it further, I'm wondering if we need configuration for that to be in ROS 2 at all. That is, if you are enabling debugging on an RMW vendor, then you are obviously trying to debug something in that particular vendor. The vendors all have vendor-specific ways to enable debugging, so wouldn't it make sense to use one of those?

(this line of reasoning also questions the rmw_set_log_severity API at all)

Copy link
Member

Choose a reason for hiding this comment

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

yeah, that's a valid question.

That is, if you are enabling debugging on an RMW vendor, then you are obviously trying to debug something in that particular vendor.

This is true, but

The vendors all have vendor-specific ways to enable debugging, so wouldn't it make sense to use one of those?

this also feels like an argument in favour of an interface like rmw_set_log_severity.

Copy link
Contributor

Choose a reason for hiding this comment

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

this also feels like an argument in favour of an interface like rmw_set_log_severity.

I think it depends on whether you consider the RMW vendors to be part of ROS 2 or not. For instance, there are probably library-specific ways to enable debugging on libyaml (one of our dependencies), but I don't think anyone is arguing we should do that. So it depends on where you want to draw the line.

Copy link
Member

Choose a reason for hiding this comment

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

good point. Some vendor-specific configuration is expected (like FastDDS's xml config files), so maybe logging can just be bundled with that?

The middleware WG is a good place to have a discussion about where the line should be drawn!

Copy link
Member

Choose a reason for hiding this comment

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

FYI @clalancette @mlanting I added this discussion/question to today's middleware WG meeting agenda. Sorry for the short notice.

Copy link
Member

Choose a reason for hiding this comment

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

We had a short discussion about this in the last middleware WG meeting (2021-05-19). I'd recommend checking out the meeting notes.

In short: rmw_set_log_severity has a purpose even if there are other ways to set an rmw/DDS implementation's logging level. We could use a "well-known"/special logger name to set the logging level through the CLI (using this syntax: https://docs.ros.org/en/rolling/Tutorials/Logging-and-logger-configuration.html#logger-level-configuration-command-line). However, we have to make sure that the rmw implementation does not produce log messages if they get filtered out at the ROS 2 level (in case it is set as a log consumer).




## User Interactions
The focus of this document is to help decide what the user experience with the ROS2 logging system should look like and to identify what changes or additions need to be made to the existing infrastructure to enable that experience.
Below are enumerated the key high-level tasks that users of ROS2 will need to perform and descriptions of the current best-practices for achieving them according to my current understanding of the system.

### Creating Loggers
Within a node, users can use the `rclcpp::Node::get_logger()` function to get a logger named after the node.
Outside of a node, users can use `rclcpp::get_logger(name)` to get a logger with the passed in name.
Loggers are created the first time these functions are called for a given name.
### Setting Log Levels
#### Programmatically
Log level can be set programmatically with the `rcutils_set_logger_level(...)` function.
#### Externally
There is not currently a way to set the log level externally, though an example of using services to set log levels is included in the ros2 logging demo.
Log level is *supposed* to be able to be set via the command line while launching nodes, but that feature seems to be broken according to a couple reports (see: https://github.com/ros2/launch/issues/383)
### Outputting Logs
Users that want to log information should use the `rclcpp` logging macros which cover a variety of use cases at 5 different severity levels.
### Specifying A Backend
`rcl_logging` contians a couple different backend implementations, as well as an interface that can be used to add additional implementations. The environment variable `RCL_LOGGING_IMPLEMENTATION` can be set at compile time to select which implementation to compile in.
### Avoiding Performance Impact
`rcutils` and `rclcpp` include a flag called `RCLCPP_LOG_MIN_SEVERITY` which can be set to compile out all macros below a certain level. Constants of the form `RCLCPP_LOG_MIN_SEVERITY_[DEBUG|INFO|WARN|ERROR|FATAL|NONE]` are provided to facilitate setting the min severity that should be compiled out. (NOTE: in `rcutils` the `RCLCPP` is replaced with `RCUTILS`).