Log file is exclusively named after process name in both rclpy and rclcpp

[sea-bass]

Bug report

Required Info:

• Operating System:
  • Ubuntu 22.04
• Installation type:
  • Binaries
• Version or commit hash:
  • Latest binaries on Humble
• DDS implementation:
  • Cyclone DDS
• Client library (if applicable):
  • rclpy

Steps to reproduce issue

When I run the following command:

ros2 run demo_nodes_py talker --ros-args -r __node:=my_talker

Expected behavior

I would expect looking into my ROS logs folder, e.g., ~/.ros/log and seeing a log file named after the node (my_talker).

e.g. my_talker_96363_1695751593253.log

Actual behavior

However, I am instead seeing a generic Python name: python3_96363_1695751593253.log

This makes it very inconvenient to search for logs by node name, which should be the case.

Additional information

Running ros2 node list shows this node name correctly; it's just the logger that is wrong:

$ ros2 node list
/my_talker

Additionally, this also happens with rclcpp based nodes but in a different way.

For example

ros2 run demo_nodes_cpp talker --ros-args -r __node:=my_talker

yields the following log file name:

talker_96405_1695751970731.log

... which is the default node name, but this should be as follows, right?

my_talker_96405_1695751970731.log

---

Feature request

The node name should actually be used in the log file names created from rclpy nodes, as described in the "Expected Behavior" section above.

[fujitatomoya]

ROS 2 can have multiple nodes in the same process space, so node name would not be suitable for log file name.

current implementation uses program name for the log file name,

https://github.com/ros2/rcl_logging/blob/014239dd80ab3de2a847af80f23d24da6438ecb7/rcl_logging_spdlog/src/rcl_logging_spdlog.cpp#L156

and,

https://github.com/ros2/rcutils/blob/f078c8c94885c94809d5d185822cf8ae8d4b795f/include/rcutils/process.h#L55

i think using program name is fine (rclcpp case) but once it comes to python, it returns python3.

something we can do is replace program name with argv[1]: script name? any thoughts?

[sea-bass]

I see -- thank you! So each file is specific to a process? In that case, I think using the script name could work as a first pass.

Ideally, there would also be a way to configure the logger name in ros2 run / ros2 launch as well, though?

[fujitatomoya]

allowing user application to set the log file name sounds reasonable for me. user application can set the unique identification to the log file that is easy to search the log file. (e.g environmental variable, ros2cli command line option.)

there would also be a way to configure the logger name in ros2 run / ros2 launch as well, though?

i am not sure if that option is available for launch. probably not, since underlying implementation does not seem to support that feature yet. you can open the discussion for https://github.com/ros2/launch_ros.

[MichaelOrlov]

@fujitatomoya As regards

something we can do is replace program name with argv[1]: script name? any thoughts?

Could you please clarify what you mean by that or in what place we could potentially do this?

[MichaelOrlov]

I would consider adding one extra parameter const char * program_name to the

rcl_logging_ret_t
rcl_logging_external_initialize(const char * program_name, const char * config_file, rcutils_allocator_t allocator);

and to the

rcl_ret_t
rcl_logging_configure_with_output_handler(
  const char * program_name,
  const rcl_arguments_t * global_args,
  const rcl_allocator_t * allocator,
  rcl_logging_output_handler_t output_handler)

To be able to provide program_name explicitly from the upper layer.
It could be null_ptr by default and we can fallback to the rcutils_get_executable_name(..) call if it is null_ptr as we currently do.

[fujitatomoya]

Could you please clarify what you mean by that or in what place we could potentially do this?

root         388     385  3 20:20 pts/2    00:00:01 /usr/bin/python3 /root/ros2_ws/colcon_ws/install/demo_nodes_py/lib/demo_nodes_py/talker

• before is python3_388_1698117640083.log
• after is talker_388_1698117640083.log

[MichaelOrlov]

@fujitatomoya Sorry still didn't get how you replaced the program name with argv[1] ?
How to do this with ros2cli API and extensions?

[fujitatomoya]

@MichaelOrlov oh, that is just an idea to replace python3 with python script name(argv[1]) via rcutils_get_executable_name if that is python3, so we cannot do that now. i do not think this is an good idea either, so i was thinking probably we can use global argument as well.

[fujitatomoya]

@sea-bass could you try,

• add file_name_prefix parameter to external log configuration. rcl_logging#109
• support --log-file-name to ros args. rcl#1127

it works in my local environment.

root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 run demo_nodes_py talker --ros-args --log-file-name foobar
[INFO] [1702509980.781646208] [talker]: Publishing: "Hello World: 0"
...
root@tomoyafujita:~/.ros/log# ls -lt
total 328
-rw-r--r-- 1 root root    0 Dec 13 15:26  foobar_585207_1702509979643.log

[sea-bass]

@sea-bass could you try,

• add file_name_prefix parameter to external log configuration. rcl_logging#109
• support --log-file-name to ros args. rcl#1127

it works in my local environment.

root@tomoyafujita:~/ros2_ws/colcon_ws# ros2 run demo_nodes_py talker --ros-args --log-file-name foobar
[INFO] [1702509980.781646208] [talker]: Publishing: "Hello World: 0"
...
root@tomoyafujita:~/.ros/log# ls -lt
total 328
-rw-r--r-- 1 root root    0 Dec 13 15:26  foobar_585207_1702509979643.log

This is great -- thank you for the update!

Would the path forward to specify this from launch files to similarly add to the ROS args using the existing launch APIs?

[fujitatomoya]

@sea-bass

Would the path forward to specify this from launch files to similarly add to the ROS args using the existing launch APIs?

yeah, it should be, that was the intention. along with other arguments such as --log-level.

i think we need to add those test cases for launch and ros2cli, see ros2/rcl#1127 (comment)

[fujitatomoya]

@clalancette i got a few follow-up PRs to close this issue. could you review these?

• add "--log-file-name" command line argument for test. launch_ros#387
• add unit tests for --log-file-name argument. rcl#1130
• add doc for "--log-file-name" command line argument. ros2_documentation#4087

[ros-discourse]

This issue has been mentioned on ROS Discourse. There might be relevant details there:

https://discourse.ros.org/t/ros-2-jazzy-jalisco-released/37862/1