ROS2 Logging

Next Generation ROS
1

Hello all,

My team at Amazon is looking at extending the existing logging functionality in ROS2. I’ve described below what our initial plans are for logging and the justifications. I welcome any feedback on the plan.

ROS 2 Logging Current State

Currently in ROS2 most of the logging implementation exists in the rcutils library. The interface into it is a set of macros that get generated during the build and a few functions in rcutils that back them. A string representing the logger name is used as input to these functions to identify which logger is being used/modified. Each implementation of the RCL then provides its own logging interface. In the RCLCPP library, for example, it is again a set of generated macros that are backed by the rcutils macros. When a logger is created in one of the language RCL libraries, it does not call down into the rcutils library to initialize any state for that logger.

Loggers can be created in association with a node or on their own. Loggers associated with a node are identical to loggers not associated with the node except that the name of the logger is automatically set based on the associated node’s name/namespace. Logs can be created in a hierarchy based on their name. The hierarchy can be used to adjust the severity level at which a logger operates.

The logging functionality in the rcutils library currently allows for only a single output function to be set for all logs. It defines a typedef for the output function header and allows the output function to be changed by calling a setter function with a pointer to a new output function. The rcutils library also includes one output function implementation which sends logs to stdout. The output function cannot be changed for different loggers in the hierarchy. Every logger uses the same output function.

Proposed Improvements

These are the changes my team is looking to implement.

  • Increase the number of output functions that can be set in the rcutils layer. We will add new functions to add and remove functions from a list of output functions in the rcutils library, but will not add this capability to the RCL interface. For the initial implementation, we will not add the ability to change the output functions at different logger hierarchies.
  • Write a new log output function in the rcutils library that will forward all logs from a logger associated with a Node to a rosout topic on that node.
  • Define an interface for a shared library that wraps more power open source logging libraries such as log4cxx. The interface will include initialize/teardown functions, call throughs for when logging metadata changes (such as log levels and formats), and functions to output logs from the rcutils library. We will also define a way of passing through a configuration file location so that the shared library implementation can use the standard config format defined by the library that backs.
  • Write a new log output function in rcutils that will call out to a shared library that implements the above interface.
  • Write an implementation of that shared library that wraps the log4cxx library. This implementation will include a default configuration that will send all logs to a file.
  • Modify the rcutils library so that when it initializes it will hook up the three output functions that now exist in the rcutils (stdout, rosout, and shared library). These will each be able to be individually enabled/disabled via an environment variable.

FAQ

  • Why not add the new interfaces for adding log output functions to the RCL layer so that people implementing their own nodes can hook up additional loggers?
    • If someone really wants to do this it will be possible by the RCL handle for their node and directly using the rcutils library. The reason for not adding to the RCL interface to make it easy to do in every language is that we do not want to encourage node developers to add their own custom logging in this way. It is better to conform to relying on only the outputs in the rcl/rcutils libraries so that your node can be more easily integrated into other applications. If an application developer wishes to use your node in their application, but wants total control over how logging is handled, it is a better experience for them to only need to adjust the standard output mechanisms natively provided by ROS 2.
  • Why not also add the ability to set different output functions for different logger hierarchies?
    • We are not providing this as part of the native rcutils library as a simplifier for our initial work. This functionality would be available as part of the shared library output that we are proposing. So anyone who really wanted that level of control could get it for both stdout and file logging by adjusting the configuration file for the shared library logger.
  • Why not send all logs to the rosout topic instead of only those sent to loggers associated with nodes?
    • Because of the way ROS 2 associates DDS concepts with ROS Nodes, there didn’t seem to be a clean way to setup a general topic on a process that wasn’t associated with an existing Node. Since a process can also contain multiple ROS Nodes, we didn’t think it would be good design to just pick one to have everything published to.
  • Why the shared library?
    • We went with the shared library approach in order to provide a way to hook into an existing logging library without tying ROS 2 to only using that library. Wrapping an existing logging library will give us the ability to have features such as file logging, log file rotation, and a hierarchy of output sinks without the need to implement all of that in the ROS codebase.
  • Why keep the existing stdout logger implementation in rcutils instead of relying on the shared library to provide the stdout implementation, since most major logging libraries already have those created.
    • We decided to keep the existing stdout output function because it provides a standard in the cases where someone does not want to rely on the shared library logger. Since you can enable/disable any of the three natively provided log output functions it is easy for a user who wants more control to disable the ROS provided stdout and rely on the
  • Since the shared library will be used in the rcutils layer will it integrate with the custom allocators that the rcl/rcutiles use?
    • No, we are not planning to provide a hook into the custom allocator for the initial implementation. This could be added later, however, most of the open source logging implementations that are well supported and provide rich features do not provide interfaces for providing your own allocator. We did not want to pass the allocator into the shared library when the shared library wouldn’t actually be able to use it. In the case where someone needs the control over allocation they would need to recompile anyways and at that point could swap out the shared library implementation with a logger of their choosing that provides more control over memory allocation.
3 Likes
2

I would suggest to keep a single output function in the core API (simpler, less memory management required). To enable multiple handlers you could create a new function which is capable to dispatch the call to N other functions.

3

Will the approach proposed here allow for using something like fluentd as an output? For complex robots, a tool like fluentd provides useful facilities for managing, viewing and processing logged information.

4

Yes, the proposed approach should be able to support fluentd. From what I can see, the easiest way to hook fluentd into this proposal would be to use a tail input to get the log events sent to to the log files. If more advanced features are needed you could always recompile the nodes and swap out the shared logger library with something that hooks directly into fluentd.

5

Is it possible to come up with a way to swap out logging systems without needing to recompile nodes?

2 Likes
6

Yes, that should be possible. Since the shared library is linked at runtime it should be possible to just link in a different implementation. I’ll need to research a little more to see what the most convenient way to do this is. It may still require you to recompile a shared package and source it in your workspace. If other people have thoughts on an easy way to do this I’d be interested in hearing.

7

(This is Forrest from the same team in Amazon) Yes our goal is to have an interface so that different types of sinks can be implemented and hooked.

That said, I would suggest the sink should be fluentd agnostic even if you want to use fluentd to consume the data – or perhaps I misunderstood you in this case…

8

Technically this is doable, but we have to be very careful because IMHO logging mechanism should be straightforward to achieve the best robustness possible. Is there a specific use case in your mind that needs such capability?

9

I’m thinking about how nodes are typically installed from binaries. If I install nodes from binaries but want to use a different logging daemon to the original node developer, then I lose the ability to install from binaries.

1 Like
10

My understanding is that even when you install Nodes from binaries that ROS dynamically links them from your sourced workspace when they run. That should allow a developer to use some environment variables or some other mechanism to swap out the logger for any predefined ones at runtime or replace the shared library logger by providing their own with the same interface to be linked in instead. I don’t know off hand how difficult or easy that is to do, but it is all possible.

11

As noted in a console_bridge issue, ros1 logging doesn’t support unicode strings, so it would be nice to support that in ros2.

12

We’ve created the first set of pull requests for the new logging features (links below). Our next steps are to work on adding rosout topic capability. As part of that we are planning on porting the Log message from ROS 1.

For the new ROS 2 message I would like to remove the list of topics the node is publishing on that is in each log message as I don’t think it makes sense to include that with every logged line. I’ll also be adjusting the verbosity level constants to match the values defined in the rcutils package. The final change I was looking at for this message was to move it into the rcl_interfaces package instead of keeping it in a rosgraph_msgs package.

Links to pull requests below.

rclcpp: #582
rcl: ros2/rcl#327
rcutils: ros2/rcutils#127

Edit (Nov 14th, 2018 9:45am PST) - Changed the package we’re planning on moving Log message into from common_interfaces/diagnostic_msgs to rcl_interfaces to avoid adding another dependency in rcl.

1 Like
13

Another pull request for the Log message definition.

14

The initial implementation of the rosout features is code complete as well and available in the branches listed below. I’m going to wait to start the pull request for the rosout changes until the existing pull request is complete.


15

Please go ahead any missing PRs asap (and add a note in it what it is blocked on). We are very close to the API freeze and can’t consider what is not visible anywhere.

16

I’ve gone ahead and created pull requests for those features, though I could not find a way to decouple them from the earlier commits being reviewed in the existing pull requests. Once those PRs are done I can rebase these so only the new commits show in the rosout PRs.


17

There was some interesting development in rosconsole from @mgrrx to use pluginlib to support different logging sinks, particuilarly to support journald (https://github.com/ros/rosconsole/issues/16). I wonder if you could consider a similar approach for logging in ROS2, which would provide a familiar mechanism for swapping logging sinks without recompilation.

18

@Paul_Bovbel is your desire to be able to actually develop custom logging sinks (a reason for using pluginlib), or are you simply suggesting that ROS2 should be able to log to a number of backends which should be configurable at runtime (not necessarily requiring pluginlib)?

19

I have a pretty limited number of sinks in mind (stdout, /rosout, journald), but given the fluentd suggestion above (and that ROS2 is cross platform), being able to develop a sink plugin outside of the rcl source tree via pluginlib seems valuable.

Of course, you can always just write /rosout to journald via an intermediate node, but this can be expensive when intra-process transport is not available.

20

it would be very nice if we can choose the backend logging system, cz some vendors have their own specific logging system once it comes to the embedded system.