Ask Your Question
2

No stdout logging output in ROS2 using launch

asked 2019-09-11 13:48:53 -0500

jdlangs gravatar image

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

edit retag flag offensive close merge delete

Comments

can you try output="screen" without the json? That's what I usually do

ex. https://github.com/ros-planning/navig...

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

stevemacenski gravatar imagestevemacenski ( 2019-09-11 15:04:50 -0500 )edit

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?

jdlangs gravatar imagejdlangs ( 2019-09-11 15:20:48 -0500 )edit

No, I do see them with just the simple string

stevemacenski gravatar imagestevemacenski ( 2019-09-11 15:28:04 -0500 )edit

2 Answers

Sort by ยป oldest newest most voted
2

answered 2019-09-16 11:36:05 -0500

jdlangs gravatar image

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...). 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)

edit flag offensive delete link more

Comments

Could you share your snippet reaches emulate_tty, please?

khassanov gravatar imagekhassanov ( 2019-10-10 08:45:51 -0500 )edit
0

answered 2019-09-13 16:22:08 -0500

jacobperron gravatar image

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.

edit flag offensive delete link more

Comments

I never noticed but the same thing is happening for me too. I'll go ahead and open an issue then.

jdlangs gravatar imagejdlangs ( 2019-09-13 16:53:30 -0500 )edit

Your Answer

Please start posting anonymously - your entry will be published after you log in or create a new account.

Add Answer

Question Tools

2 followers

Stats

Asked: 2019-09-11 13:48:53 -0500

Seen: 58 times

Last updated: Sep 16