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.

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

Fix loggers to publish to /rosout #2376

Closed
henningkayser opened this issue Sep 19, 2023 · 9 comments
Closed

Fix loggers to publish to /rosout #2376

henningkayser opened this issue Sep 19, 2023 · 9 comments
Assignees
Labels
enhancement New feature or request

Comments

@henningkayser
Copy link
Member

henningkayser commented Sep 19, 2023

Is your feature request related to a problem? Please describe.
Currently, basically none of our loggers are associated with a ros node. The pattern we decided here will create detached loggers for which no rosout publishers are initiated. See ros2/rclcpp#1694 (comment)

Describe the solution you'd like
I'd like to initialize all loggers from rclcpp nodes, possibly implement child nodes wherever we have child logger namespaces.

If we do that, we'll have the issue that rclcpp::Node needs to be passed to all classes and functions that require logging, requiring many additional API changes and extensions. Question is, can we find a solution that allows us to hide this dependency (possibly like console_bridge), and even pick different logger backends?

@henningkayser henningkayser added the enhancement New feature or request label Sep 19, 2023
@henningkayser henningkayser self-assigned this Sep 19, 2023
@tylerjw
Copy link
Member

tylerjw commented Oct 10, 2023

Another thing we should consider changing is enabling the logging service to enable changing the log level via ros service.

@tylerjw
Copy link
Member

tylerjw commented Oct 10, 2023

When investigating if there is a way we can send logs to rosout that are not associated with nodes I found this quote in a Discourse thread from 2018:

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.

Source: https://discourse.ros.org/t/ros2-logging/6469?page=2

@tylerjw
Copy link
Member

tylerjw commented Oct 11, 2023

To fix the easy things first and explore the patterns we want to use, I'm starting making PRs from main functions. I'm working on the warehouse package in moveit_ros and will submit PRs. Here is the list of PRs with notes.

Only a main:

main with some free functions:

Adding a parameter to a method (do we backport changes like this?):

@tylerjw
Copy link
Member

tylerjw commented Oct 12, 2023

Here is a new approach: #2445

@tylerjw
Copy link
Member

tylerjw commented Oct 23, 2023

Here we go with more complexities.

In humble child loggers node->get_logger().get_child("child"); under a node logger are not published to /rosout. Here are references with the details:

We are left with a decision about how we should move forward and best support users on humble, rolling, and iron with moveit. We currently do not use node loggers at all so none of our logs go to /rosout.

Option 1: Save the namespaces, no /rosout on humble

Preserving the logging namespaces we currently have using child loggers will mean that on Humble converting to node loggers will largely have no useful affect (most logs will still not go out to /rosout).

Maybe this is ok because we can show that newer versions of ROS have useful features and encourage users to upgrade to Rolling (and later J-turtle) for the /rosout logging.

Option 2: Abandon namespaces for now

We could not use namespacing and just put all logs under the node, this will make logging to /rosout work in Humble but will loose us the namespaces. This means that we'll lose the ability to configure level based on namespace. We could later add back in namespaces when we drop support for Humble.

Option 3: Create nodes everywhere

As stated here a workaround for humble is to create nodes for every namespace. This is the maximum compatibility approach. I'll prototype something to do this.

@tylerjw
Copy link
Member

tylerjw commented Oct 26, 2023

The approach in #2482 for child logging has some problems.

In Humble when you call get_child on a logger it does not give you a logger that publishes to /rosout. The reason is it needs to be associated with a node with a /rosout publisher. To deal with this I had the make_child_logger function create node objects and store them in a map of names to node objects with static lifetime. Creating nodes has a couple of side-effects that are bad:

  1. Every node creates 5 services and doing this for every logging namespace in moveit is going to harm our dds discovery performance
  2. When two nodes use the same name and then one of them is destroyed the other one silently stops being able to publish. It should not be weird for multiple processes to use components of moveit that use child loggers.

So what?

Understanding this we can't go creating a bunch of node objects just to get logging working in Humble. The solution is, for humble, to just use the node logger and not make child loggers. This looses namespacing in humble.

There are two user stories for namespacing.

  1. I want to know where this log line came from so I can go read the code.
  2. I want to configure the log levels differently for this sub-module of my code.

Where did the log line come from?

To answer the first one, we can use source location information. Every log message in /rosout includes the file, function, and line number that points to where the log came from. To get at this information there are two options:

  • use a tool like rqt_console to interact with the messages on /rosout
  • Configure the environment variable RCUTILS_CONSOLE_OUTPUT_FORMAT to something like this (Documentation):
export RCUTILS_CONSOLE_OUTPUT_FORMAT="[{severity} {time}] [{name}] [{function_name}]: {message} ({file_name}:{line_number})"

Configure log levels per-component

Currently, without node logging, this is a feature we just don't have. In Rolling and Iron with the child loggers one will be able to configure each logger using the set_logger_levels service once we enable it on our nodes. Documentation for configuring log level via service

@henningkayser
Copy link
Member Author

@tylerjw thank you for investigating this so thoroughly. I think it's fine if Humble doesn't get rosout support, this really seems like a limitation that we shouldn't have to work around with running redundant nodes. From the issue linked in my original description, I've not expected that Humble would work out of the box anyway. Fixing this in MoveIt for Iron/Rolling is very much acceptable imo. As far as I can tell, the current approach doesn't come with any downsides, either. I'm for merging this approach and encourage users to switch to the latest distros. /rosout support is mostly a developer feature, anyway.

@EzraBrooks
Copy link
Member

Is this complete and should be closed?

@tylerjw
Copy link
Member

tylerjw commented Nov 20, 2023

Is this complete and should be closed?

This is not finished.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
enhancement New feature or request
Projects
None yet
Development

No branches or pull requests

4 participants