Array to string conversion in TsvFormatter.php on line 35

[MPParsley]

Describe the bug
drush locale:check gives this notice: Array to string conversion in TsvFormatter.php on line 35

To Reproduce
drush locale:check

Expected behavior
No notice should appear.

Actual behavior
A notice: Array to string conversion in TsvFormatter.php on line 35

Workaround

System Configuration

Q	A
Drush version?	9.4
Drupal version?	8.6
PHP version	7.2.10
OS?	Mac

Additional information
At the end of the script this message appears:
Array

[greg-1-anderson]

What output do you get with drush locale:check --format=yaml? Whether or not you get this warning is likely dependent on the result returned by the command, which may vary based on the state of your Drupal installation.

[MPParsley]

I get this error:
The "--format" option does not exist.

Possibly not related but note that I also encountered #3722 and https://www.drupal.org/project/drupal/issues/3005958.

[greg-1-anderson]

locale:check does not return any data, so it should not be running the format manager / tsv formatter.

When I run this command, I get no output and no warning. Could you provide steps to reproduce from a fresh install?

[MPParsley]

It might be related to the PHP version.
I'm on 7.2.10 and a colleague has the same project setup on 7.2.3 and doesn't have this issue.

The array that is sent to the format manager is a list of all modules and the manager is unsuccessfully trying to format it as a table.

I'll document the steps.

[greg-1-anderson]

You're using locale:check? I'm also using php 7.2.10. local:check does not use the formatter manager, so I'm a bit perplexed as to why this is going through the tsv formatter.

[MPParsley]

Yes, I'm using drush locale:check. See this screencast.

Here's a backtrace from the point where the array occurs in tsvEscape():

#0  Consolidation\OutputFormatters\Formatters\TsvFormatter->Consolidation\OutputFormatters\Formatters\{closure}()
#1  array_map() called at [/vendor/consolidation/output-formatters/src/Formatters/TsvFormatter.php:41]
#2  Consolidation\OutputFormatters\Formatters\TsvFormatter->tsvEscape() called at [/vendor/consolidation/output-formatters/src/Formatters/TsvFormatter.php:28]
#3  Consolidation\OutputFormatters\Formatters\TsvFormatter->writeOneLine() called at [/vendor/consolidation/output-formatters/src/Formatters/CsvFormatter.php:86]
#4  Consolidation\OutputFormatters\Formatters\CsvFormatter->write() called at [/vendor/consolidation/output-formatters/src/Formatters/StringFormatter.php:67]
#5  Consolidation\OutputFormatters\Formatters\StringFormatter->reduceToSigleFieldAndWrite() called at [/vendor/consolidation/output-formatters/src/Formatters/StringFormatter.php:37]
#6  Consolidation\OutputFormatters\Formatters\StringFormatter->write() called at [/vendor/consolidation/output-formatters/src/FormatterManager.php:220]
#7  Consolidation\OutputFormatters\FormatterManager->write() called at [/vendor/consolidation/annotated-command/src/CommandProcessor.php:299]
#8  Consolidation\AnnotatedCommand\CommandProcessor->writeUsingFormatter() called at [/vendor/consolidation/annotated-command/src/CommandProcessor.php:212]
#9  Consolidation\AnnotatedCommand\CommandProcessor->handleResults() called at [/vendor/consolidation/annotated-command/src/CommandProcessor.php:152]
#10 Consolidation\AnnotatedCommand\CommandProcessor->process() called at [/vendor/consolidation/annotated-command/src/AnnotatedCommand.php:404]
#11 Consolidation\AnnotatedCommand\AnnotatedCommand->execute() called at [/vendor/symfony/console/Command/Command.php:255]
#12 Symfony\Component\Console\Command\Command->run() called at [/vendor/symfony/console/Application.php:964]
#13 Symfony\Component\Console\Application->doRunCommand() called at [/vendor/symfony/console/Application.php:248]
#14 Symfony\Component\Console\Application->doRun() called at [/vendor/symfony/console/Application.php:148]
#15 Symfony\Component\Console\Application->run() called at [/vendor/drush/drush/src/Runtime/Runtime.php:112]
#16 Drush\Runtime\Runtime->doRun() called at [/vendor/drush/drush/src/Runtime/Runtime.php:41]
#17 Drush\Runtime\Runtime->run() called at [/vendor/drush/drush/drush.php:66]
#18 require(/vendor/drush/drush/drush.php) called at [/vendor/drush/drush/includes/preflight.inc:17]
#19 drush_main() called at [phar://usr/local/bin/drush/bin/drush.php:141]

[greg-1-anderson]

writeUsingFormatter should not be called unless this function returns true:

    protected function dataCanBeFormatted($structuredOutput)
    {
        if (!isset($this->formatterManager)) {
            return false;
        }
        return
            is_object($structuredOutput) ||
            is_array($structuredOutput);
    }

However, $structuredOutput should be null, since locale:check does not produce any output.

In theory, anyway. I'll have to reproduce this locally before I can make any progress.

[MPParsley]

Here's the output of $structuredOutput during drush locale:check:

 [ok] Checked translation for drupal.
 [notice] Translation file not found: https://ftp.drupal.org/files/translations/8.x/drupal/drupal-8.5.0.en.po.
 [ok] Checked translation for drupal.
 [ok] Checked translation for drupal.
 [ok] Checked translation for drupal.
 [notice] Message: Checked available interface translation updates for 4 projects.

array(1) {
  [0]=>
  array(1) {
    ["files"]=>
    array(4) {
      [0]=>
      string(6) "drupal"
      [1]=>
      string(6) "drupal"
      [2]=>
      string(6) "drupal"
      [3]=>
      string(6) "drupal"
    }
  }
}

I also wonder why I'm getting drupal-8.5.0.en.po instead of drupal-8.6.1.en.po?

[greg-1-anderson]

I could potentially work around the symptom by making tsv detect when it is passed data that cannot be processed as a table. However, it would be good to know where that data is being provided from, since the main command handler for locale:check certainly does not return anything. Some hook somewhere, but where and why?

[MPParsley]

The data comes from here in locale_translation_batch_status_check():

  // Provide user feedback and record success or failure for reporting at the
  // end of the batch.
  if ($options['finish_feedback'] && $checked) {
    $context['results']['files'][] = $source->name; // <= This line
  }
  if ($failure && !$checked) {
    $context['results']['failed_files'][] = $source->name;
  }
  $context['message'] = t('Checked translation for %project.', ['%project' => $source->project]);

It is set in the batch so it can be printed at the end of the batch.

It is batch API that is causing the prints (I think), not locale.

// The $context array gathers batch context information about the execution (read),
// as well as 'return values' for the current operation (write)
// The following keys are provided :
// 'results' (read / write): The array of results gathered so far by
// the batch processing, for the current operation to append its own.

Furthermore, if the batch operation returns any user input in the 'results' or 'message' keys of $context, it must also sanitize them first.

[MPParsley]

So it turns out to be a Drupal core issue. See https://www.drupal.org/project/drupal/issues/3006084

Thanks for your help @greg-1-anderson!

[greg-1-anderson]

Hm, I do wonder, though, why $context['results'] ends up getting printed by Drush. Maybe we have some hook I don't know about that's trying to be helpful by injecting the batch results into the command output?

[greg-1-anderson]

Couldn't find anything like that, although I did find MessengerCommands::log() that replicates messenger logs to the console.

[greg-1-anderson]

UpdateDBCommands.php looks at $context['results'] but that shouldn't be at work here.

[MPParsley]

Indeed, in batch.inc, the output of the finish callback bubbles all the way up to drush_batch_command which is called in BatchCommands:

class BatchCommands extends DrushCommands
{

    /**
     * Process operations in the specified batch set.
     *
     * @command batch:process
     * @aliases batch-process
     * @param $batch_id The batch id that will be processed.
     * @hidden
     */
    public function process($batch_id)
    {
        return drush_batch_command($batch_id);
    }
}

Now CommandProcessor::dataCanBeFormatted() returns true when it's an array but in the case of locale it is a nested array.

    protected function dataCanBeFormatted($structuredOutput)
    {
        if (!isset($this->formatterManager)) {
            return false;
        }
        return
            is_object($structuredOutput) ||
            is_array($structuredOutput);
    }

In locale.batch.inc results is set as a nested array:

  // Provide user feedback and record success or failure for reporting at the
  // end of the batch.
  if ($options['finish_feedback'] && $checked) {
    $context['results']['files'][] = $source->name;
  }
  if ($failure && !$checked) {
    $context['results']['failed_files'][] = $source->name;
  }

So in CommandProcessor::handleResults() the output of results['files'][] & results['failed_files'][] is written:

    public function handleResults(OutputInterface $output, $names, $result, CommandData $commandData)
    {
        $statusCodeDispatcher = new StatusDeterminerHookDispatcher($this->hookManager(), $names);
        $status = $statusCodeDispatcher->determineStatusCode($result);
        // If the result is an integer and no separate status code was provided, then use the result as the status and do no output.
        if (is_integer($result) && !isset($status)) {
            return $result;
        }
        $status = $this->interpretStatusCode($status);

        // Get the structured output, the output stream and the formatter
        $extractDispatcher = new ExtracterHookDispatcher($this->hookManager(), $names);
        $structuredOutput = $extractDispatcher->extractOutput($result);
        $output = $this->chooseOutputStream($output, $status);
        if ($status != 0) {
            return $this->writeErrorMessage($output, $status, $structuredOutput, $result);
        }
        if ($this->dataCanBeFormatted($structuredOutput) && isset($this->formatterManager)) {
            return $this->writeUsingFormatter($output, $structuredOutput, $commandData);
        }
        return $this->writeCommandOutput($output, $structuredOutput);
    }

These are the context keys in _batch_process:

      // Build the 'context' array and execute the function call.
      $batch_context = [
        'sandbox'  => &$current_set['sandbox'],
        'results'  => &$current_set['results'],
        'finished' => &$finished,
        'message'  => &$task_message,
      ];

If there is output, it can be a nested array and it should probably be handled in TsvFormatter.
See consolidation/output-formatters#70

[greg-1-anderson]

So, the real bug here is that batch:process does not declare that it returns any data, but then it goes ahead and returns something anyway. The format manager presumes this means that the command meant that it returns a STRING. If a command declares that it returns a string, but instead returns an array, then it falls back to using tsv for the output. This might sound like a really bad decision; however, tsv is actually the best answer in instances where the data type is downgraded, e.g. when the user includes the --field option.

While we could certainly improve the fallback behavior of the output-formatter library, I think that the real solution would be to have batch:process return its data wrapped in UnstructuredListData (n.b. requires consolidation/output-formatters#69, which has not been merged yet), and declare its default data type to be yaml.

[MPParsley]

@greg-1-anderson, I agree. Should we reopen this issue or how do you suggest we proceed?

[greg-1-anderson]

There is now a release of output formatters that contains the UnstructuredData and UnstructuredListData types, and it is in use on the master branch of Drush. If you want to keep working on this, I would recommend making a new PR that sets the data type and default format of batch:process.

The main question in that PR is going to be whether the resulting output is then rational. Is the information present useful and interesting to the user? If not, we might want to consider making batch process return its result to backend invoke without printing the result.

[greg-1-anderson]

I think that the best way to solve this is to have batch:process declare that it returns UnstructuredListData, and its default format is NONE. I'll make a new release of output-formatters that includes a NONE format type.

[greg-1-anderson]

I named the format 'null': consolidation/output-formatters#71

[MPParsley]

Thanks, #3750 has fixed both issues:

• Notice: Array to string conversion in TsvFormatter.php
• This output: "Array Array Array"

[MPParsley]

@greg-1-anderson seems like #3750 never got merged so this issue remains.

[greg-1-anderson]

In theory it was merged as part of #3758. Could you compare #3750 with master and make a PR to re-fix?

[MPParsley]

@greg-1-anderson seems like these are the only changes:

-    "consolidation/output-formatters": "^3.3.1",
+    "consolidation/output-formatters": "^3.4",

-    public function process($batch_id, $options = ['format' => 'json'])
+    public function process($batch_id, $options = ['format' => 'null'])

I opened a PR in #3917