Skip to content

Comments

Add {short_file_name} as log format option#541

Merged
fujitatomoya merged 3 commits intoros2:rollingfrom
botsandus:add-short-file-name
Feb 21, 2026
Merged

Add {short_file_name} as log format option#541
fujitatomoya merged 3 commits intoros2:rollingfrom
botsandus:add-short-file-name

Conversation

@tonynajjar
Copy link
Contributor

@tonynajjar tonynajjar commented Feb 11, 2026

Description

Add a new {short_file_name} format token to the rcutils logging system that outputs only the basename of the source file (e.g., my_node.cpp) instead of the full path (e.g., /opt/ros_ws/src/my_package/src/my_node.cpp).

The existing {file_name} token continues to output the full path as before. The new token uses strrchr to find the last path separator (/ on POSIX, \ on Windows) and returns everything after it.

Changed files

  • src/logging.c — Added expand_short_file_name() handler and registered the {short_file_name} token in the tokens[] array
  • include/rcutils/logging.h — Added short_file_name to the documented list of available format tokens
  • test/test_logging_console_output_handler.cpp — Added unit tests verifying basename extraction from full paths and passthrough for bare filenames
  • test/test_logging_output_format.py — Added integration test launching with {short_file_name}:{line_number} format and validating output
  • test/test_logging_output_format_short_file_name.txt — Expected output fixture for the integration test

Is this user-facing behavior change?

Yes. Users can now use {short_file_name} in the RCUTILS_CONSOLE_OUTPUT_FORMAT environment variable to display only the source file basename in log output, reducing log line length and improving readability.

Did you use Generative AI?

Yes — GitHub Copilot (Claude Opus 4.6)

Additional Information

  • The implementation handles both POSIX (/) and Windows (\) path separators via #ifdef _WIN32. Tested on Ubuntu Linux but I don't have a way to test on Windows.
  • If the file name contains no path separator, the full string is returned unchanged
  • No changes to rcutils_log_location_t struct — the basename is extracted at format-expansion time
  • Docs update PR: Add short_file_name placeholder to logging configuration options ros2_documentation#6226

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>
@tonynajjar
Copy link
Contributor Author

I'd love to have it backported to Kilted when merged, it doesn't break ABI

@tonynajjar tonynajjar changed the title Add {short_file_name} Add {short_file_name} as log format option Feb 11, 2026
@tonynajjar
Copy link
Contributor Author

@ahcorde this is of similar nature as #526 so you might want to take it. FYI @kscottz if you want to share with the community

@kscottz
Copy link

kscottz commented Feb 11, 2026

@tonynajjar this slaps, thanks so much. Let me see what I can cook up when I make the social media rounds tomorrow. We haven't had a "what's been merged recently post" perhaps we're past due.

Copy link
Collaborator

@fujitatomoya fujitatomoya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@tonynajjar thanks for the PR.

i have a question about this approach. what is the major background and requirement for this PR?

assuming that full absolute paths in log output can be noisy and hurt readability.
however, I'm concerned that showing only the basename isn't quite enough. in a typical ROS 2 workspace, many packages can have identically named files (main.cpp, node.cpp, etc.), so {short_file_name} alone would make it hard to tell where a log line is actually coming from.
would it be possible to instead show the path relative to the package root? for example, my_package/src/my_node.cpp instead of just my_node.cpp. that would cut out the workspace-specific noise while still keeping enough context to identify the package. something like {relative_file_name} or {package_file_name} might be a better middle ground.
curious to hear your thoughts — what was the use case that motivated going with just the basename?

@tonynajjar
Copy link
Contributor Author

tonynajjar commented Feb 12, 2026

@fujitatomoya you're right, the motivation is to reduce the unnecessary noise and cluttering from the full path (in our case it's quite long)

in a typical ROS 2 workspace, many packages can have identically named files (main.cpp, node.cpp, etc.), so {short_file_name} alone would make it hard to tell where a log line is actually coming from.

I looked into this and although I first though you have a very good point, it turns out that {short_file_name} as implemented will actually show the file where the RCLCPP_INFO macro is called, and not the original file where the node is created, which is actually convenient. I would say that typically the files with the actual node implementation (where most macro calls are) have distinct names.

Take this example from Nav2:

with export RCUTILS_CONSOLE_OUTPUT_FORMAT="[{severity} {time}] [{short_file_name}:{line_number}] [{name}]: {message}"

I get

ros2 run nav2_controller controller_server

[INFO 1770887000.671869363] [controller_server.cpp:45] [controller_server]: Creating controller server

although as you can see here, the controller_server node is started in main.cpp.

Additionally when I look at our full stack of 100+ nodes, I never see main.cpp or node.cpp which is extra assurance. I'm happy to get counter-examples though

@fujitatomoya
Copy link
Collaborator

thanks for the explanation! i was just curious about the background for this additional token. but i am not sure how much this is useful against full file path including performance overhead. l would like to see more feedback on this 👂

@tonynajjar
Copy link
Contributor Author

tonynajjar commented Feb 12, 2026

but i am not sure how much this is useful against full file path

For us here is a before and after:

[INFO 1770889009.971313974] [/opt/auto_ws/src/auto-sandbox/src/vendor/navigation2/nav2_controller/src/controller_server.cpp:45] [controller_server]: Creating controller server
[INFO 1770887000.671869363] [controller_server.cpp:45] [controller_server]: Creating controller server

With one line it might not seem like a big deal but with thousands it compounds pretty badly and makes the logs unreadable

@fujitatomoya
Copy link
Collaborator

that is good example 👍

Copy link
Collaborator

@fujitatomoya fujitatomoya left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

overall lgtm, i got a few comments.

@tonynajjar i can see @kscottz 's approval including doc support, so let's proceed !!! thanks for waiting 🙇

@kscottz
Copy link

kscottz commented Feb 19, 2026

@tonynajjar, looks like this is ready to go pending resolved suggestions. Can you resolve the suggestions so we can ship this to the community.

Also, thanks a bunch! This is great.

@tonynajjar
Copy link
Contributor Author

tonynajjar commented Feb 19, 2026

I somehow completely missed @fujitatomoya's review! Thanks for the ping, i'll address the review

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>
@fujitatomoya
Copy link
Collaborator

Pulls: #541
Gist: https://gist.githubusercontent.com/fujitatomoya/f8472cc6d61becdacf4f94a820ccd71f/raw/6f4ef84e9b0ba2f65db32e85b58ee38b463005d8/ros2.repos
BUILD args: --packages-above-and-dependencies rcutils
TEST args: --packages-above rcutils
ROS Distro: rolling
Job: ci_launcher
ci_launcher ran: https://ci.ros2.org/job/ci_launcher/18269

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Linux-rhel Build Status
  • Windows Build Status

@tonynajjar
Copy link
Contributor Author

@fujitatomoya is the test failing because of this PR? As far as I see it failed because of another reason, can you restart it?

rclcpp
02:17:07 Starting >>> rclcpp
02:17:07 FATAL: command execution failed
FATAL: Unable to delete script file /tmp/jenkins8445192309629836075.sh

@ahcorde
Copy link
Contributor

ahcorde commented Feb 20, 2026

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Linux-rhel Build Status
  • Windows Build Status

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>
@ahcorde
Copy link
Contributor

ahcorde commented Feb 20, 2026

  • Linux Build Status
  • Linux-aarch64 Build Status
  • Linux-rhel Build Status
  • Windows Build Status

@tonynajjar
Copy link
Contributor Author

What do we do with "unstable"?

@tonynajjar tonynajjar requested a review from ahcorde February 20, 2026 18:43
@fujitatomoya
Copy link
Collaborator

@tonynajjar https://ci.ros2.org/job/ci_windows/26760/ is totally unrelated to this PR, i will go ahead to merge this. thanks for your contribution!

@fujitatomoya fujitatomoya merged commit 0575342 into ros2:rolling Feb 21, 2026
3 checks passed
@tonynajjar
Copy link
Contributor Author

tonynajjar commented Feb 21, 2026

@fujitatomoya can you please trigger a backport to Kilted? Should be ABI/API compatible right?

@fujitatomoya
Copy link
Collaborator

@Mergifyio backport kilted

@mergify
Copy link

mergify bot commented Feb 22, 2026

backport kilted

✅ Backports have been created

Details

mergify bot pushed a commit that referenced this pull request Feb 22, 2026
* Add short_file_name

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>

* PR comments

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>

* fix windows set_env

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>

---------

Signed-off-by: Tony Najjar <tony.najjar@dexory.com>
(cherry picked from commit 0575342)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants