From ac29e80a227a9d39b4bee1ff2bb9f93943c4f8c9 Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Thu, 6 May 2021 14:57:56 -0400 Subject: [PATCH 1/6] Added initial version of logging.md file. Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 35 +++++++++++++++++++++++++++++++++++ 1 file changed, 35 insertions(+) create mode 100644 articles/logging.md diff --git a/articles/logging.md b/articles/logging.md new file mode 100644 index 000000000..198320db1 --- /dev/null +++ b/articles/logging.md @@ -0,0 +1,35 @@ +1. What ROS1 had(?) +2. what exists +### 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` + +### 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`). + + From 0f68b7f74cfb47e4e285628ee36ddc6738e6a6d3 Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Fri, 7 May 2021 15:49:15 -0400 Subject: [PATCH 2/6] Changed header levels. Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 26 ++++++++++++++------------ 1 file changed, 14 insertions(+), 12 deletions(-) diff --git a/articles/logging.md b/articles/logging.md index 198320db1..83da0012e 100644 --- a/articles/logging.md +++ b/articles/logging.md @@ -2,34 +2,36 @@ 2. what exists ### Existing infrastructure ROS2 -#### `rcutils` +### `rcutils` Contains macros for logging at several different levels and under various constraints -#### `rclcpp` +### `rclcpp` Contains similar macros to those in `rcutils`, which call down to the macros in `rcutils` -#### `rcl_logging` +### `rcl_logging` Contains a logging interface and several implementations including log4cxx, spdlog, and a no-op implementation -#### `rcl` +### `rcl` Contains infrastructure to tie the logger implementations defined in `rcl_logging` to the macros in `rcutils` -### User Interactions + + +## 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 +### 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 +### Setting Log Levels +#### Programmatically Log level can be set programmatically with the `rcutils_set_logger_level(...)` function. -##### Externally +#### 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 +### 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 +### 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 +### 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`). From 3e2df376549ab740a217e507a6f846ded78b2a3c Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Fri, 7 May 2021 15:50:36 -0400 Subject: [PATCH 3/6] Added new section at beginning of document The new section starts to define our goals for the user interaction with ROS2 logging. Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 44 +++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 41 insertions(+), 3 deletions(-) diff --git a/articles/logging.md b/articles/logging.md index 83da0012e..ab7dee36c 100644 --- a/articles/logging.md +++ b/articles/logging.md @@ -1,6 +1,44 @@ -1. What ROS1 had(?) -2. what exists -### Existing infrastructure +## Desired User Experience +This section describes the desired user interface of the ROS2 logging system. +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. +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 +##### Environment Variable? +#### 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 From edd871e4714006b193ef07eb4a0e6bcd87975f3f Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Mon, 10 May 2021 14:40:15 -0400 Subject: [PATCH 4/6] Changed format of ROS2 to ROS 2 Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/articles/logging.md b/articles/logging.md index ab7dee36c..f29389dba 100644 --- a/articles/logging.md +++ b/articles/logging.md @@ -1,8 +1,8 @@ ## Desired User Experience -This section describes the desired user interface of the ROS2 logging system. -To define the interface of the ROS2 logging system, it is helpful to consider all of the various tasks users will want to perform. +This section describes the desired user interface of the ROS 2 logging system. +To define the interface of the ROS 2 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: +Based on our experiences with ROS 1, other logging systems, and community feedback, the logging system in ROS 2 will support the following interactions: - creating loggers - setting log levels - outputting logs @@ -19,7 +19,7 @@ This is how users set the severity levels for the loggers in their code. 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 +##### Via ROS 2 Service Call ##### Environment Variable? #### Outputting Logs This is primary interaction where users output information from their code. @@ -27,19 +27,19 @@ This is primary interaction where users output information from their code. 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. +ROS 2 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. +Users may have requirements that none of the included backends support, so ROS 2 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. +ROS 2 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 +ROS 2 ### `rcutils` Contains macros for logging at several different levels and under various constraints ### `rclcpp` @@ -52,8 +52,8 @@ Contains infrastructure to tie the logger implementations defined in `rcl_loggin ## 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. +The focus of this document is to help decide what the user experience with the ROS 2 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 ROS 2 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. From 1386a54a8efe7c8ac0f463bb1e1cffd18ec81c23 Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Wed, 19 May 2021 15:18:46 -0400 Subject: [PATCH 5/6] Added more detail about creating loggers and setting levels Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 24 ++++++++++++++++++++---- 1 file changed, 20 insertions(+), 4 deletions(-) diff --git a/articles/logging.md b/articles/logging.md index f29389dba..e344bef0a 100644 --- a/articles/logging.md +++ b/articles/logging.md @@ -13,14 +13,28 @@ Based on our experiences with ROS 1, other logging systems, and community feedba ### 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. +This interaction constitutes creating the objects that users will use to output information from their code. +Users are able to create multiple named loggers which they can use to exercise fine-grained control over the logging output at runtime. +Loggers are namespaced and can be controlled hierarchically by having their severity levels set individually. +If a logger's level is not set explicitly, it will use the level of the nearest ancestor with an explicit severity, or the default if no ancestors have had their levels set. +All named loggers are descendants of the default/unnamed logger. #### Setting Log Levels This is how users set the severity levels for the loggers in their code. 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 +##### Programmatically +Severity levels for each logger can be set programmatically by calling a function that takes the desired severity level, and optionally a reference to or the name of a specific logger. +If no name/reference is provided, function will apply the severity level as the default level. ##### Command Line +When launching nodes from the command line, an argument can be provided setting the default log severity for that node. +Programmatic logging severity changes within the node's code will override the severity set by the command line argument. +##### Via Launch File +Severity levels can be set for loggers by name via launch files. +The severity levels will be applied to the appropriate loggers at startup, but may be overridden by programmatic changes. ##### Via ROS 2 Service Call -##### Environment Variable? +Users will be able to control severity levels of loggers during runtime via ROS 2 service calls. +This level of control if often useful when debugging complex dynamic systems with many moving parts, especially when there is a high startup/restart cost. +Severity levels set this way will override levels set at launch via command line arguments or configuration files. +Programmatic changes to the severity may still occur after a level has been changed via the service call and will override the level set by the service call. #### Outputting Logs This is primary interaction where users output information from their code. #### Defining Output Destinations (Sinks) @@ -35,6 +49,8 @@ Users may have requirements that none of the included backends support, so ROS 2 Adding a sophisticated logging system to a complex code base can have performance impacts and are often mostly useful during development and debugging. ROS 2 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. +#### Interacting with RMW Logging +RMW implementations have their own built-in logging, and a function called `rmw_set_log_severity` which may need to be handled with special considerations. @@ -68,7 +84,7 @@ Log level is *supposed* to be able to be set via the command line while launchin ### 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. +`rcl_logging` contains 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`). From d3853d3c142ccf219edf7a81ea386cd33f4e4a0c Mon Sep 17 00:00:00 2001 From: "matthew.lanting" Date: Fri, 4 Jun 2021 14:45:57 -0400 Subject: [PATCH 6/6] Added detail to output and backend sections. Expanded the sections Outputting Logs, Defining Output Destinations, Specifying a Backend, and Creating a Backend. Distro A; OPSEC #4584 Signed-off-by: matthew.lanting --- articles/logging.md | 24 +++++++++++++++++++++--- 1 file changed, 21 insertions(+), 3 deletions(-) diff --git a/articles/logging.md b/articles/logging.md index e344bef0a..1cb9f51f2 100644 --- a/articles/logging.md +++ b/articles/logging.md @@ -36,15 +36,33 @@ This level of control if often useful when debugging complex dynamic systems wit Severity levels set this way will override levels set at launch via command line arguments or configuration files. Programmatic changes to the severity may still occur after a level has been changed via the service call and will override the level set by the service call. #### Outputting Logs -This is primary interaction where users output information from their code. +This is the primary interaction where users output information from their code. +Users call macros that take loggers and message text as arguments and generate the code to produce log output when appropriate. +Logging macros exist for each of the severity levels, and the macros for each severity cover a variety of use cases such as how frequently to output or whether to output based on conditional logic. +The specific cases covered for each severity level are: +- Log once +- Log if given expression is true +- Log if given function returns true +- Ignore first call +- Throttle to a certain rate (Don't log until a given duration has passed since the previous log) +- Throttle, but ignore first call #### 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. +By default, logs are printed to the stderr and written to a log file. +The location of the log file can be specified with an environment variable (`ROS_LOG_DIR`). +If the log file location environment variable is not set, it will default to `$ROS_HOME/log`, using `~/.ros` if `$ROS_HOME` is not set. +Console output can be redirected to stdout instead of stderr using an environment variable (`RCUTILS_LOGGING_USE_STDOUT`). +Individual loggers can be configured to output to specific files or output streams in launch files. +The destinations set in launch files can also be set according to severity level for a particular logger. +For example, a logger could be configured to output all messages of severity ERROR or greater to stderr and messages below that severity to stdout. +Logger configurations in launch files will override the behavior specified by the environment variables, and the behavior specified by the env variables will define the default behavior of any loggers not configured explicitly. #### 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. -ROS 2 logging provides a default implementation, as well as a couple alternatives. This defines how users choose the implementation that best suits their needs. +ROS 2 provides a default implementation, as well as alternatives based on log4cxx and spdlog, and a no-op implementation. +The implementation can be specified at compile time by setting the environment variable `RCL_LOGGING_IMPLEMENTATION` to the name of the desired implementation when building `rcl`. #### Creating A Backend -Users may have requirements that none of the included backends support, so ROS 2 provides an interface for users to create custom backend implementations. +Users may have requirements that none of the included backends support, and may create additional implementations of `rcl_logging_interface`. #### 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. ROS 2 provides a few ways to configure the logging system to eliminate this performance impact when the logs are not needed.