Don't assume sub-processes return valid JSON as their output

[mhavelant]

Describe the bug
When using monolog for logging errors as JSON to stderr $process->getOutputAsJson() can throw Unable to decode output into JSON: Syntax error.

To Reproduce
On a multilingual site, I have English and French set up, have the twig_tweak module enabled. I'm using the monolog module to turn log messages into JSON and print those to php://stdout and php://stderr.
Then using e.g. drush locale:check shows the error.

Expected behavior
No errors printed and the correct exit code returned.

Actual behavior
I get Unable to decode output into JSON: Syntax error and the drush command returns a non-zero exit code (even if the underlying command finished successfully). The sub-process output, due to twig_tweak not having .po files for French, show this:

{"message":"Translation file not found: https://ftp.drupal.org/files/translations/all/twig_tweak/twig_tweak-3.0.0.fr.po.","context":{},"level":250,"level_name":"NOTICE","channel":"locale","datetime":"2021-07-15T14:22:09.888357+02:00","extra":{"referer":"","ip":"127.0.0.1","request_uri":"http://mysite.docker.localhost:8000/","uid":0,"user":""},"drupal_message":"Translation file not found: @uri.","drupal_context_placeholders":{"@uri":"https://ftp.drupal.org/files/translations/all/twig_tweak/twig_tweak-3.0.0.fr.po"}}
{
    "0": {
        "files": [
            "drupal",
            .... (lots of other modules, truncated for readability)
        ],
    },
    "drush_batch_process_finished": true
}            

Workaround
I can patch monolog to detect if the current one is a batch process and unset the JSON formatter, but that's an ugly hack. Additionally, I could try to switch to some other logging method instead of stdout/err, but that's not ideal for me.

System Configuration

Q	A
Drush version?	10.5.0
Drupal version?	9.2.0
PHP version	7.4.19
OS?	Linux (Docker)

Additional information

The getOutputAsJson function is called in a few places, e.g. vendor/drush/drush/includes/batch.inc. If the sub-process prints anything that makes that function fail, this error occures, it doesn't strictly need my setup.
The code in that file is

// Suppress printing stdout since a JSON array is returned to us here.
$process->run($process->showRealtime()->hideStdout());
$result = $process->getOutputAsJson();

getOutputAsJson throws an InvalidArgumentException with such outputs, handling that would probably be a good start. It looks like the expected JSON is at the last place, trying to extract that could probably work. I'm not sure why the process returns the batch result pretty printed, turning that into a single line and taking the last line of the output and using that with json_decode would not be elegant, but would solve the issue.

[weitzman]

Dont print log messages to php://stdout. stderr is for log messages (and not just errors).