0
$\begingroup$

Rosanswers logo

Hi all,

I am unable to see any logging output from stdout when using ros2 launch, and I need some help figuring out what's going on / if this is expected. For example this cpp file:

int main(int argc, char** argv)
{
  rclcpp::init(argc, argv);
  auto node = std::make_shared<rclcpp::Node>("a_test_node");

  RCLCPP_DEBUG(node->get_logger(), "test log debug");
  RCLCPP_INFO(node->get_logger(), "test log info");
  RCLCPP_WARN(node->get_logger(), "test log warn");
  RCLCPP_ERROR(node->get_logger(), "test log error");

  rclcpp::spin(node);

  return 0;
}

and this launch file:

import launch
import launch_ros.actions

def generate_launch_description():
    return launch.LaunchDescription([
        launch_ros.actions.Node(
            package='test_pkg',
            node_executable='test_node',
            node_name='test_node',
            output={
                'stdout': 'screen',
                'stderr': 'screen',
            }
        ),
    ])

only outputs:

jlangsfeld@swri-jlangsfeld-thinkpad-T560:~/Workspaces/ros2$ ros2 launch test_pkg log_test.launch.py
[INFO] [launch]: All log files can be found below /home/jlangsfeld/.ros/log/2019-09-11-13-45-19-657412-swri-jlangsfeld-thinkpad-T560-18153
[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [test_node-1]: process started with pid [18163]
[test_node-1] [WARN] [test_node]: test log warn
[test_node-1] [ERROR] [test_node]: test log error

I've tried other output options too with no luck. For example, using own_log for both stdout and stderr means separate log files are created but the stdout one always is completely empty. Any thoughts / suggestions?

Thanks, Josh


Originally posted by jdlangs on ROS Answers with karma: 971 on 2019-09-11

Post score: 10


Original comments

Comment by stevemacenski on 2019-09-11:
can you try output="screen" without the json? That's what I usually do

ex. https://github.com/ros-planning/navigation2/blob/master/nav2_bringup/launch/nav2_navigation_launch.py#L81

I see the warn and error, but not info, perhaps because you didnt set to screen in general

Comment by jdlangs on 2019-09-11:
Yes, I've tried the single string, which should just be a shortcut for setting both stdout and stderr directly. Are you saying you don't see info outputs either when you run launch files?

Comment by stevemacenski on 2019-09-11:
No, I do see them with just the simple string

Comment by [email protected] on 2021-06-22:
in foxy, log can output to ~/.ros/log.

but i found there is a delay time to log file than screen, i found log file will increase 4096kb every time, so is it flush when buffer is fulled ?

how to set immedialy output every line ?

$\endgroup$

3 Answers 3

1
$\begingroup$

Rosanswers logo

This turned out to be connected with the known issue of subprocesses from launch having their stdout streams buffered (https://github.com/ros2/launch/issues/188). There is a emulate_tty flag that has recently been added to the ExecuteProcess action that defaults to False. Setting it to True in my launch file (through the Node action constructor) fixes the problem. Eventually it may default to True. (https://github.com/ros2/launch/pull/286)


Originally posted by jdlangs with karma: 971 on 2019-09-16

This answer was ACCEPTED on the original site

Post score: 12


Original comments

Comment by khassanov on 2019-10-10:
Could you share your snippet reaches emulate_tty, please?

Comment by mvoellmy on 2019-12-13:
I added the emulate_tty=True flag here and the outputs worked for me again.

Node(
    package='package_name',
    node_executable='package_exec',
    output='screen',
    emulate_tty=True,
    arguments=[('__log_level:=debug')]
)

Comment by MrCheesecake on 2020-07-15:
Does this work with Dashing or only newer versions?
I'm getting: [ERROR] [launch]: Caught exception in launch (see debug for traceback): __init__() got an unexpected keyword argument 'emulate_tty'

Comment by jdlangs on 2020-07-16:
The keyword was added during Eloquent development. But as of Foxy, this problem should be gone because all logging now comes out on stderr which won't buffer output.

Comment by mantangL on 2020-10-21:
i have same problem in dashing version.[ERROR] [launch]: Caught exception in launch (see debug for traceback): init() got an unexpected keyword argument 'emulate_tty'. how can you solve it?

$\endgroup$
0
$\begingroup$

Rosanswers logo

With your example, I do see the INFO output, but it comes after terminating the program (e.g SIGINT):

[INFO] [launch]: Default logging verbosity is set to INFO
[INFO] [test_node-1]: process started with pid [18943]
[test_node-1] [WARN] [test_node]: test log warn
[test_node-1] [ERROR] [test_node]: test log error
^C[WARNING] [launch]: user interrupted with ctrl-c (SIGINT)
[test_node-1] [INFO] [test_node]: test log info

It's possible there's some buffer funny-business happening in launch. It might be worth opening a issue describing the problem.

I wouldn't expect you to be able to see the DEBUG log, without setting the verbosity level accordingly.


Originally posted by jacobperron with karma: 1870 on 2019-09-13

This answer was NOT ACCEPTED on the original site

Post score: 1


Original comments

Comment by jdlangs on 2019-09-13:
I never noticed but the same thing is happening for me too. I'll go ahead and open an issue then.

$\endgroup$
0
$\begingroup$

Rosanswers logo

You can use the following to set the buffering policy to line buffering:

stdbuf -o L ros2 launch pkg pkg.launch.py

I would personally prefer this over setting an option in the launch file since it gives you some flexibility without having to modify the launch file.


Originally posted by mschickler with karma: 95 on 2019-11-06

This answer was NOT ACCEPTED on the original site

Post score: 3


Original comments

Comment by Aravind on 2020-08-10:
This worked for me. I would prefer that the default is set to line buffering since I think that is what the majority of users expect when printing output to screen. If not, how can I set the default to be line buffered?

Comment by ntrlmt on 2021-02-01:
I had same problem in dashing version. I added the prefix=['stdbuf -o L'] to Node. This worked for me.

Node(
    package='package_name',
    node_executable='package_exec',
    prefix=['stdbuf -o L'],
    output='screen'
)

Comment by andrestoga on 2021-02-19:
@ntrimt it looks that it doesn't work in Dashing in Windows 10. I'm getting a traceback.

Comment by askkvn on 2021-12-12:
@ntrlmt answer worked for me ROS2 foxy, thanks

$\endgroup$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.