Logger does not respect RCUTILS_CONSOLE_OUTPUT_FORMAT

[SammyRamone]

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:

• Operating System: Ubuntu 22.04, ROS rolling
• Installation type: from source and binary (both tested)
• Version or commit hash: d116d7b7224bbba67c5a1b297bb66ce8d9687e76
• DDS implementation: default
• Client library (if applicable): not applicable

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]

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

[clalancette]

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]

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.