Skip to content

Conversation

@alcohol
Copy link
Member

@alcohol alcohol commented Feb 6, 2015

Since it was a low hanging fruit, voila. Some grunt work has been done.

/cc @dzuelke I was told by @Seldaek you might have some good insights into what should or should not go to stderr.

What qualifies as stderr I interpreted solely on feedback from @Seldaek and gut feeling so far. Any input is welcome.

Closes #1905
Also closes heroku/heroku-buildpack-php#100

Copy link
Member

Choose a reason for hiding this comment

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

I think it'd be better to move the write content into a private doWrite or such that is called by write/writeError instead of extending this method's signature as it's part of the public interface.

@alcohol alcohol changed the title stderr output using writeError() stderr output using writeError(), closes #1905 Feb 6, 2015
@dzuelke
Copy link
Contributor

dzuelke commented Feb 6, 2015

Will take a look ASAP; thanks!

Copy link
Contributor

Choose a reason for hiding this comment

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

This should also be writeError() I guess

Copy link
Member Author

Choose a reason for hiding this comment

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

Ah, alright. Yeah I'll give it a second go-over with the more strict guidelines you mentioned in #1905 (I admit I did not completely read all of them before).

@alcohol
Copy link
Member Author

alcohol commented Feb 6, 2015

What to do with the Commands that use the Symfony ConsoleOutput? Something like the following?

$output->writeln($messages)

becomes

$output->getErrorOutput()->writeln($messages)

@Seldaek
Copy link
Member

Seldaek commented Feb 6, 2015 via email

@alcohol
Copy link
Member Author

alcohol commented Feb 6, 2015

Should we then hint ConsoleOutputInterface? Or have a wrapper that does an instanceof check and delegates accordingly?

@Seldaek
Copy link
Member

Seldaek commented Feb 6, 2015 via email

@alcohol
Copy link
Member Author

alcohol commented Feb 6, 2015

The typehint breaks a lot of tests. Not sure if I should clean up the tests, or change the approach. Feedback?

@Seldaek
Copy link
Member

Seldaek commented Feb 6, 2015

Yeah I guess this has to be reverted.. I think it should work if you just replace $output->writeln by $this->getIO()->write[Error]

@alcohol alcohol force-pushed the write-errors-to-stderr branch from 233255d to 4c5d5b1 Compare February 6, 2015 15:45
@dzuelke
Copy link
Contributor

dzuelke commented Feb 6, 2015

I need some more time to review in detail, but here is a preliminary list that I think should output to stdout. Everything not on this list, including warnings, notices about outdated versions in the commands below etc should go to stderr:

  • composer config when getting a setting or when using --list
  • composer depends probably without the headers which should go to stderr (might need a more "condensed" more for grepping)
  • composer licenses (might need a more "condensed" more for grepping)
  • composer search
  • composer show (could maybe default to -N when stdout is not a TTY but likely shouldn't)
  • composer status

A few good rules for figuring out if something should go to stdout or stderr is:

  • if everything is fine, don't output anything to stdout unless that's the point of the command (e.g. composer show)
  • any composer command, in particular if it returns data, should be able to be in a pipeline like composer config --list | grep foo, and a sudden "this version of Composer is over 30 days old" should not break this pipeline, so it has to go to stderr.

In general, Composer will need quite a bit more Unix love. Run any command through | more and see how the color codes mess stuff up; I guess --no-color should be the default if stderr is not a TTY. Or run a script that outputs to stderr, exits with code 0, and then is treated as failed (I think) because it output to stderr, which really isn't an error condition.

@dzuelke
Copy link
Contributor

dzuelke commented Feb 6, 2015

Also, composer --version should echo the version string to stdout, but warnings to stderr. composer --help and any usage info should always go to stderr.

@alcohol alcohol force-pushed the write-errors-to-stderr branch from 67b9cdf to 36b0d6f Compare February 11, 2015 10:49
@alcohol
Copy link
Member Author

alcohol commented Feb 11, 2015

Any idea how to explain this?

$ bin/composer status
No local changes

^ the response is in green (color codes)

$ bin/composer status | more
ESC[32mNo local changesESC[39m

but...

$ bin/composer status 2>/dev/null | more
No local changes

@Seldaek
Copy link
Member

Seldaek commented Feb 11, 2015

BTW "No local changes" should be stderr as far as I understand.

As for how color usage is determined by default, AFAIK it is done here:

https://github.com/symfony/symfony/blob/2.7/src/Symfony/Component/Console/Output/StreamOutput.php#L101

It seems this is always true though here:

$ php -r 'var_dump(posix_isatty("php://stdout"));' 2>/dev/null | more
bool(true)
$ php -r 'var_dump(posix_isatty("php://stdout"));' | more
bool(true)
$ php -r 'var_dump(posix_isatty("php://stdout"));'
bool(true)

Not sure what's up on yours.

@alcohol alcohol force-pushed the write-errors-to-stderr branch from f4bfc77 to f6d775d Compare February 11, 2015 12:06
@alcohol
Copy link
Member Author

alcohol commented Feb 11, 2015

@dzuelke this should solve some color issues as well: symfony/symfony#13661

@dzuelke
Copy link
Contributor

dzuelke commented Feb 11, 2015

Correct, "no local changes" from composer status should go to stderr; if there are changes listed, then those should to to stdout I guess.

Keep up the great work on this, @alcohol!

@alcohol alcohol force-pushed the write-errors-to-stderr branch 2 times, most recently from c8c1ef8 to 7d22775 Compare February 16, 2015 08:46
@alcohol
Copy link
Member Author

alcohol commented Feb 16, 2015

@dzuelke One thing I've come across frequently while doing some reading myself is the following, "stderr is also the place where you print stuff like help docs when an invalid argument is passed to a command" with the exception being "when asking explicitly for help docs they should be printed to stdout". Personally I also feel that makes sense. Do you agree?

Edit: I specifically mean the exception here.

On a side note, do you use IRC by chance? If so, drop me a line sometime on freenode (ethanol).

@alcohol alcohol force-pushed the write-errors-to-stderr branch from 7d22775 to 5fe02d1 Compare February 16, 2015 10:41
@dzuelke
Copy link
Contributor

dzuelke commented Feb 16, 2015

Yes, I'd also print to stderr stdout if the help screen for any command was explicitly requested. Seems most Unix-y programs do that.

@alcohol
Copy link
Member Author

alcohol commented Feb 16, 2015

But then wouldn't that stop you from doing for example command --help | grep X ?

@alcohol
Copy link
Member Author

alcohol commented Feb 16, 2015

If you do a checkout and run grep -irPC 3 'io->write\(|getio\(\)->write\(' src you should get a picture of what is left going to stdout.

I'm not sure on the following cases:

  • AboutCommand - expected output, so stdout?
  • DiagnoseCommand - mostly (even warnings and errors) expected output, so stdout?
  • InitCommand - not sure about this.. lot of user interaction stuff, not likely to be used in a piped process
  • Util/[Git|Svn] - the prompt for authentication, followed by user input, should that be stderr or not?

As for help going to stderr, I'd either have to overload the default command from SF2, or submit a PR and cross fingers that they accept it (which might not be the case).

@dzuelke
Copy link
Contributor

dzuelke commented Feb 16, 2015

Sorry I meant stdout of course for explicit help!

@dzuelke
Copy link
Contributor

dzuelke commented Feb 16, 2015

  • AboutCommand - expected output, so stdout?

👍

  • DiagnoseCommand - mostly (even warnings and errors) expected output, so stdout?

Good question. I was going to say that e.g. the xdebug warning should go to stderr, but then the output of the command is mostly useless because there is no context. I guess stdout is fine.

  • InitCommand - not sure about this.. lot of user interaction stuff, not likely to be used in a piped process

Well that command is completely quiet (like it should be) when running using -n, so the prompts (and any associated status messages) should go to stderr I think.

  • Util/[Git|Svn] - the prompt for authentication, followed by user input, should that be stderr or not?

Absolutely!

@alcohol alcohol force-pushed the write-errors-to-stderr branch from 5fe02d1 to b665b26 Compare February 16, 2015 13:42
@alcohol
Copy link
Member Author

alcohol commented Feb 17, 2015

Aside from InitCommand, pretty much everything should be in order now. I'm personally conflicted about InitCommand. I feel that the interactive session with the user should mostly belong on stdout. But if you guys prefer stderr, I'll replace it. Let me know.

/cc @dzuelke @Seldaek for feedback

@stof
Copy link
Contributor

stof commented Mar 4, 2015

@josegonzalez assuming this means you are making non-standard assumption, because there is no convention about the way to use output to report failures. Detecting failures is based on the exit code only in CLI conventions (it is even something being common to both Unix and Windows systems).

stderr vs stdout is not about error report vs non error report (btw, I don't think that shell scripting calls them stdout and stderr at all). They are about message being part of the command output (i.e. something you would pipe to the next command in the chain) vs message not being part of it (informational messages for the user, and error reports are a specific kind of informational messages: they inform of an error)

@dzuelke
Copy link
Contributor

dzuelke commented Mar 4, 2015

As used here, while we should definitely check the status code, it's common to assume that any output to stderr is error output and thus users using composer in tooling may be confused as to whether their command is failing or not. I know it's a bad example because of the message itself, but would it be possible to instead move to proper log levels?

That's a wrong assumption. Try a curl https://google.com/ > google.txt. The standard error stream is not just for errors. Please use the exit code of a process to determine its success or failure. These are standard Unix conventions, and mixing diagnostics/progress/informational output with the "real" output of a program breaks the whole concept of Unix pipelines, unless you like spending your evenings messing around with awk and sed scripts to parse output from badly written applications.

@josegonzalez
Copy link
Contributor

I'm not saying that it's the right way to do this, and the example I give is a bad one. This is probably a philosophical issue, but here is a better example.

I'm the maintainer of multiple vagrant installs at my company, and we manage things through chef. I have it setup so that if chef executes a command which has error output, that is always output in red. Very useful for debugging, and you or I can easily see that the message above is not an error but status output. I would see that error and silence stderr because it's not actually an error, and is going to be confusing to users.

Now imagine I give vm access to someone else on the team, a frontend dev, who has no idea how any of the tooling below vagrant works. All they know is about npm and gulp. They bring up the vm, there is an issue with composer failing, but no error output because I silenced status output earlier. They come to me with their issue and now we have to turn on stderr, which happens to also output debug output.

What I'm asking for is a way to still have this output behind a log-level flag. You can still write it to stderr if you'd like, it's just not as useful when it's a status message.

While the above vagrant thing happens all the time, from time to time I get an email from my boss - who is by no means non-technical - as to why our deploy is erroring. Turns out npm likes to output status messages to stderr as well, resulting in hundreds of lines like this:

faux errors

It's not an error, npm is running fine, it's just letting us know that certain packages we depend on could use cleanup. And rather than place that behind a flag that I can control - we write deploy logs to files and selectively write to stdout depending upon verbosity of the deploy - it decided to just write to stderr. The deploy didn't fail - because of course i checked the exit code of the command - but it seems like there was an error to the end-user.

I guess what I'm saying is that writing these status messages to stderr by default without some notion of log-levels just isn't friendly for developers.

@dzuelke
Copy link
Contributor

dzuelke commented Mar 4, 2015

Then use the -q flag, @josegonzalez.

@josegonzalez
Copy link
Contributor

Would that silence actual error output?

@Seldaek
Copy link
Member

Seldaek commented Mar 4, 2015 via email

@josegonzalez
Copy link
Contributor

I'm not familiar with the logger you are using in composer, but if it supports the standard log-levels, would you all be opposed to me adding a --log-level argument which sorts the messages into different levels?

@stof
Copy link
Contributor

stof commented Mar 7, 2015

@josegonzalez the console output is not using a logger

@josegonzalez
Copy link
Contributor

Would you be opposed to a change that uses a logger (probably monolog)?

@alcohol
Copy link
Member Author

alcohol commented Mar 7, 2015

I don't feel a logger would be the right answer here, as tempting as it
might be. Instead, making more use of the various verbosity levels would
benefit composer more. During my scavenger hunt through the code I found
very little use of these, and more often than not it just checks for
verbose or it doesn't check anything at all, even though there are three
levels available. If anything, I would invest time in improving that. Just
my 2 cents :-)
On Mar 6, 2015 10:10 PM, "Jose Diaz-Gonzalez" notifications@github.com
wrote:

Would you be opposed to a change that uses a logger (probably monolog)?


Reply to this email directly or view it on GitHub
#3715 (comment).

@Seldaek
Copy link
Member

Seldaek commented Mar 7, 2015

Yeah I think what we need is a way to indicate the minimum verbosity level in the write/writeError call, so we can make more use of it without annoying ifs everywhere. That wouldn't solve the whole issue though, we still need a new VERBOSITY_ERROR level IMO that's used for actual error messages. It would be the same as verbosity normal (i.e. show always by default), but with this -Q flag or so we could suppress NORMAL but not ERROR, so we get quiet-except-errors or full-shut-up mode :)

@alcohol
Copy link
Member Author

alcohol commented Mar 7, 2015

Would it be an option to consider any stderr output without a verbosity
flag to always be an error as opposed to stderr output with a verbosity
flag being informational?
On Mar 7, 2015 7:50 AM, "Jordi Boggiano" notifications@github.com wrote:

Yeah I think what we need is a way to indicate the minimum verbosity level
in the write/writeError call, so we can make more use of it without
annoying ifs everywhere. That wouldn't solve the whole issue though, we
still need a new VERBOSITY_ERROR level IMO that's used for actual error
messages. It would be the same as verbosity normal (i.e. show always by
default), but with this -Q flag or so we could suppress NORMAL but not
ERROR, so we get quiet-except-errors or full-shut-up mode :)


Reply to this email directly or view it on GitHub
#3715 (comment).

Copy link
Contributor

Choose a reason for hiding this comment

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

Why are you taking this shortcut here @alcohol? It prevents self-updating progress, for instance, with composer install 2>&1 | somepipethatdecoratesoutput; you get many newlines instead (331425b and #3818 are symptoms of that).

Is there a particular reason why you don't want any overwriting behavior when piping? IMO it should still behave that way. Can/should I fix?

Copy link
Contributor

Choose a reason for hiding this comment

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

Just for the sake of testing, I removed the entire if block and it seems to all still work fine for a composer install (and now the progress works again as expected when piping), but I'm sure there's some other command where things would be broken now, or else you wouldn't have added that code? :) please advise.

Copy link
Member Author

Choose a reason for hiding this comment

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

Not sure I follow? Doesn't self updating progress use overwrite? This if block is to differentiate between stdout and stderr? I'm missing a link in the context I think... been gone for two weeks.

Copy link
Member Author

Choose a reason for hiding this comment

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

doWrite() is only used internally (private method). write() and writeError() pass the $stderr boolean. I merely added an extra check to make sure we do have an output interface that supports stderr. Not sure what you mean by shortcut here?

Copy link
Contributor

Choose a reason for hiding this comment

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

@alcohol run this to reproduce:

COMPOSER_CACHE_DIR=/dev/null composer install 2>&1 | tee /dev/null

The download progress will be written in many new lines instead of in one. The reason is this if, because it skips the entire overwriting stuff using backspaces.

Copy link
Member Author

Choose a reason for hiding this comment

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

While I am able to reproduce the new lines, I really don't see how this if statement is related. Could it be you are commenting on the wrong line?

The calls go as:
https://github.com/composer/composer/blob/master/src/Composer/Util/RemoteFilesystem.php#L161
https://github.com/composer/composer/blob/master/src/Composer/Util/RemoteFilesystem.php#L332 (repeated)
https://github.com/composer/composer/blob/master/src/Composer/Util/RemoteFilesystem.php#L231

It seems more likely to be related to this line https://github.com/composer/composer/pull/3715/files#diff-bd1b00b10d2c20047a8732546579ce78R166

Before my change, overwrite only ever checked if stdout was decorated. Now it checks if stderr is decorated instead (if trying to overwrite stderr).

Copy link
Member Author

Choose a reason for hiding this comment

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

I'm sorry, I'm going to sleep now. Have a flight of nearly 12 hours behind me and need to get back to work tomorrow morning. Will pick this up again then if not resolved/clear yet.

Copy link
Contributor

Choose a reason for hiding this comment

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

Yes, sorry, @alcohol, I mean lines 166+; picked the wrong spot in the code by accident, sorry!

mbrodala added a commit to Brainsware/puppet-composer that referenced this pull request Mar 19, 2015
Recently Composer has moved a lot of status messages from stdout
to stderr, thus we need to perform a redirect here to keep pattern
matching working.

See composer/composer#3715

Fixes #19
mbrodala added a commit to Brainsware/puppet-composer that referenced this pull request Mar 19, 2015
Recently Composer has moved a lot of status messages from stdout
to stderr, thus we need to perform a redirect here to keep pattern
matching working.

See composer/composer#3715

Fixes #19
tankist added a commit to tankist/PHPCI that referenced this pull request May 12, 2015
tankist added a commit to tankist/PHPCI that referenced this pull request May 12, 2015
tankist added a commit to tankist/PHPCI that referenced this pull request May 22, 2015
tankist added a commit to tankist/PHPCI that referenced this pull request Dec 10, 2015
@alcohol alcohol deleted the write-errors-to-stderr branch September 13, 2016 06:05
tankist added a commit to tankist/PHPCI that referenced this pull request Nov 16, 2016
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.

PHP App Crashing on Start with "Could: unbound variable" Error output printed to STDOUT instead of STDERR

5 participants