ros2 / launch_ros

Tools for launching ROS nodes and for writing tests involving ROS nodes.
Apache License 2.0
58 stars 72 forks source link

Logger does not respect RCUTILS_CONSOLE_OUTPUT_FORMAT #368

Open SammyRamone opened 1 year ago

SammyRamone commented 1 year ago

The logger used in launch does not respect the custom formatting of logs which can be defined by the RCUTILS_CONSOLE_OUTPUT_FORMAT variable (see also here ). While this is not a critical bug, it is annoying and reduces readability of the output. I am not sure if there might be a reason for the decision to hardcode the output format, but in my oppinion it should at least follow the environment variable for the output on the console. If you agree that this is indeed not intended behavior, I would be willing to create a PR to fix it.

Bug report

Required Info:

Steps to reproduce issue

export RCUTILS_CONSOLE_OUTPUT_FORMAT='TEST {message}'
ros2 launch turtlesim multisim.launch.py

Expected behavior

➜  launch ros2 launch turtlesim multisim.launch.py
TEST All log files can be found below /home/best_mr/.ros/log/2023-06-27-16-05-37-049113-MO-310047-73934
TEST Default logging verbosity is set to INFO
TEST process started with pid [73937]
TEST process started with pid [73939]
TEST Starting turtlesim with node name /turtlesim2/turtlesim
TEST Starting turtlesim with node name /turtlesim1/turtlesim
TEST Spawning turtle [turtle1] at x=[5.544445], y=[5.544445], theta=[0.000000]
TEST Spawning turtle [turtle1] at x=[5.544445], y=[5.544445], theta=[0.000000]
^CTEST user interrupted with ctrl-c (SIGINT)
TEST signal_handler(signum=2)
TEST signal_handler(signum=2)
TEST process has finished cleanly [pid 73939]
TEST process has finished cleanly [pid 73937]

Actual behavior

➜  launch ros2 launch turtlesim multisim.launch.py
[INFO] [launch]: All log files can be found below /home/best_mr/.ros/log/2023-06-27-16-05-37-049113-MO-310047-73934
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [turtlesim_node-1]: process started with pid [73937]
[INFO] [turtlesim_node-2]: process started with pid [73939]
TEST Starting turtlesim with node name /turtlesim2/turtlesim
TEST Starting turtlesim with node name /turtlesim1/turtlesim
TEST Spawning turtle [turtle1] at x=[5.544445], y=[5.544445], theta=[0.000000]
TEST Spawning turtle [turtle1] at x=[5.544445], y=[5.544445], theta=[0.000000]
^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
TEST signal_handler(signum=2)
TEST signal_handler(signum=2)
[INFO] [turtlesim_node-2]: process has finished cleanly [pid 73939]
[INFO] [turtlesim_node-1]: process has finished cleanly [pid 73937]

Additional information

I guess the reason for this is, that the formating is hardcoded at multiple places, e.g. here https://github.com/ros2/launch/blob/8cfa72314d8a9d8e830c6818c2b39087f8fdf196/launch/launch/logging/__init__.py#L215

clalancette commented 1 year ago

We think this is probably an issue/feature request for launch_ros, so moving it over there.

clalancette commented 1 year ago

Even though RCUTILS_CONSOLE_OUTPUT_FORMAT is meant to be the format for a particular process, I think it would make sense to have launch respect it if it is set (really this should be named ROS_OUTPUT_FORMAT, but that ship may have sailed). I think a pull request to fix this would be welcome.

SammyRamone commented 1 year ago

Even though RCUTILS_CONSOLE_OUTPUT_FORMAT is meant to be the format for a particular process, I think it would make sense to have launch respect it if it is set (really this should be named ROS_OUTPUT_FORMAT, but that ship may have sailed).

Okay, then I would propose to use the RCUTILS_CONSOLE_OUTPUT_FORMAT for now. I would agree that ROS_OUTPUT_FORMAT or ROS_CONSOLE_OUTPUT_FORMAT would make more sense as a name. However, this would affect other pacakges and any name changes can also be easily done after solving this issue.

I think a pull request to fix this would be welcome.

I will create a PR. It might take some time since this is low priority for me, but it is now on my todo list.