Skip to content

Always log on stderr#181

Closed
rotu wants to merge 1 commit intoros2:masterfrom
RoverRobotics-forks:debug_logging_to_stderr
Closed

Always log on stderr#181
rotu wants to merge 1 commit intoros2:masterfrom
RoverRobotics-forks:debug_logging_to_stderr

Conversation

@rotu
Copy link
Copy Markdown
Contributor

@rotu rotu commented Sep 13, 2019

This follows the convention for human-readable diagnostic output on Linux systems.

fix #168

This follows the convention for human-readable diagnostic output on Linux systems.

fix ros2#168

Signed-off-by: Dan Rose <dan@digilabs.io>
@rotu rotu force-pushed the debug_logging_to_stderr branch from 19b6869 to f953981 Compare September 13, 2019 23:43
@wjwwood wjwwood added the enhancement New feature or request label Oct 24, 2019
@wjwwood wjwwood self-assigned this Oct 25, 2019
@clalancette
Copy link
Copy Markdown
Contributor

I'm going to weigh in on this, I took a look around at some popular logging utilities in different languages to see what they did. This is obviously non-exhaustive, but hopefully somewhat representative.

Python logging module - Prints all output, at all levels, to stderr by default
C++ log4cxx - Using the "BasicConfigurator", all output, at all levels, goes to stdout by default
C++ spdlog - Using whatever defaults it uses, all output, at all levels, goes to stdout by default
Ruby logger module - Needs to be told whether to use stdout or stderr, but all levels go to that stream by default
Rust log crate - All output at all levels goes to stderr by default
Perl log4Perl - All output at all levels goes to stdout by default
Java log4j - All output at all levels goes to stdout by default

Given that survey, it seems to me that ROS 2 should definitely choose a single stream for all logging output by default. Given the results above, it actually doesn't seem that clear to me which stream the default should be. I don't care hugely one way or the other, but I'd lean towards making the default stderr (as in this PR), as in the case of a real error, you want to make sure the message gets flushed out immediately. But we should also have a way to switch to the stdout stream, as nearly all loggers surveyed above have a way to do that.

So with all of that said, I'm going to do a review of this PR.

# define IS_STREAM_A_TTY(stream) (isatty(fileno(stream)) != 0)
#endif

#define IS_OUTPUT_COLORIZED(is_colorized, stream) \
Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

Here and elsewhere, instead of removing the stream, let's leave it configurable and add a new environment variable to let users choose between stderr and stdout. I don't care hugely what its called, but something descriptive would be nice. In my opinion, if the environment variable is not specified, the default should be stderr.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

@clalancette Why should it be reconfigurable here?

  • If the user wants all program output in a single stream, that's just 2>&1.
  • If it's about performance, then we should instead change the stderr buffering with setvbuf.
  • If we don't expect stream redirection to be available (or we want to make sure the user can differentiate from other types of program output), we should additionally allow the user to specify an arbitrary file, not just a stream.

Copy link
Copy Markdown
Contributor

@clalancette clalancette Oct 30, 2019

Choose a reason for hiding this comment

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

@clalancette Why should it be reconfigurable here?

So the 2>&1 isn't that straightforward to achieve when you are launching through a launch file. While it would be kind of weird to use stdout instead of stderr in one process of a launch file and not in another, it isn't invalid.

The other reason to have it is that all of the log libraries I surveyed have the ability to choose which stream to use. Given that they all have it, presumably it is functionality that is useful in a logging library, so I think we should probably follow suit here.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

(also, because there is a small performance impact from using stderr, we should give users the ability to opt out of it and get buffered performance if they want)

@clalancette
Copy link
Copy Markdown
Contributor

I did some additional work on this (including a rebase), but I'm not allowed to push to the branch here. I'm going to close out this PR, and open a new one with my new changes and replicating the discussion here.

@rotu
Copy link
Copy Markdown
Contributor Author

rotu commented Dec 13, 2019

Thank you for taking this over, @clalancette!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

enhancement New feature or request

Projects

None yet

Development

Successfully merging this pull request may close these issues.

INFO and ERROR logging should come out in order by default

3 participants