Progressbar vs logger vs stdOutput

[Sweetchuck]

Steps to reproduce

<?php

declare(strict_types = 1);

use Consolidation\AnnotatedCommand\CommandResult;
use Psr\Log\LoggerAwareInterface;
use Psr\Log\LoggerAwareTrait;
use Robo\Common\ConfigAwareTrait;
use Robo\Contract\ConfigAwareInterface;
use Robo\Tasks;

class RoboFileDummy extends Tasks implements LoggerAwareInterface, ConfigAwareInterface
{
    use LoggerAwareTrait;
    use ConfigAwareTrait;

    /**
     * @command dummy:progressbar
     */
    public function cmdDummyProgressbarExecute(
        array $options = [
            'format' => 'list',
        ]
    ) {
        $result = $this
            ->collectionBuilder()
            ->addCode(function (\Robo\State\Data $state): int {
                $state['items'] = [
                    'item-01',
                    'item-02',
                    'item-03',
                ];

                $this->logger->info('a');
                sleep(2);
                $this->logger->info('b');

                return 0;
            })
            ->addCode(function (\Robo\State\Data $state): int {
                $this->logger->info('c');
                sleep(2);
                $this->logger->info('d');

                return 0;
            })
            ->addCode(function (\Robo\State\Data $state): int {
                sleep(2);
                $this->logger->info('e');
                sleep(2);
                $this->logger->info('f');

                return 0;
            })
            ->addCode(function (\Robo\State\Data $state): int {
                sleep(2);
                $this->output()->writeln('stdOutput line 1');
                sleep(2);
                $this->output()->writeln('stdOutput line 2');

                return 0;
            })
            ->run();

        $items = $result['items'];

        return CommandResult::data($items);
    }
}

---

Command:
./vendor/bin/robo --load-from='RoboFileDummy.php' -vv dummy:progressbar

Actual output:

 [info] a
 [info] b
 0/4 [>---------------------------]   0% < 1 sec/< 1 sec [info] c
 [info] d
 2/4 [==============>-------------]  50% 2 secs/4 secs [info] e
 [info] f
 3/4 [=====================>------]  75% 6 secs/8 secsstdOutput line 1
stdOutput line 2
 4/4 [============================] 100% 10 secs/10 secs
item-01
item-02
item-03

Expected:

1. The problem is that, the progressbar and a log entry are in the same line.
2. The problem is that, the progressbar and a stdOutput text are in the same line.

---

Command:
./vendor/bin/robo --load-from='RoboFileDummy.php' -vv dummy:progressbar 2>/dev/null

Actual output:

stdOutput line 1
stdOutput line 2

item-01
item-02
item-03

Expected output

stdOutput line 1
stdOutput line 2
item-01
item-02
item-03

---

Same as above but without the $this->output()->writeln('stdOutput line 1'); lines.

Command:
./vendor/bin/robo --load-from='RoboFileDummy.php' -vv dummy:progressbar 2>/dev/null

Actual output:
The output starts with an empty line.

item-01
item-02
item-03

Expected output

item-01
item-02
item-03

The leading empty line not just a blemish, because it can cause problem in certain use cases.
robo dummy:progressbar | xargs ...

---

Other progressbar related issues:

• Disable globally progress bar #674

System Configuration

consolidation/robo 3.x

[greg-1-anderson]

Robo makes an effort to hide and re-show the progress bar when it writes other output; however, there is an existing bug when exec-ing external programs.

The progress bar should auto-disable when stdout is redirected. If it does not, you can turn it off via an option, --no-progress, I presume.

[Sweetchuck]

1. In the example above there is no "exec-ing external programs"
2. I could not find the --no-progress option among the global options. (--help --quiet --version --ansi --no-interaction --simulate --progress-delay --define --verbose)

My main problem is that sometimes a log entry or an StdOutput line or an StdError line are in the same line with the progress bar.
Like this:
0/4 [>---------------------------] 0% < 1 sec/< 1 sec [info] c
or like this:
3/4 [=====================>------] 75% 6 secs/8 secsstdOutput line 1

A little bit messy and very difficult to read, and hard to follow what is going on.

[greg-1-anderson]

In the example above there is no "exec-ing external programs"

There may be other bugs in addition to the exec bug. Compare against ./robo try:progress, which works correctly. Log output works. I don't know if any other sort of output does.

I could not find the --no-progress option among the global options

Sorry, my mistake. --progress-delay=-1 will do the trick.

[greg-1-anderson]

Also, in my experience, ./robo try:progress --progress-delay=0 | cat is disabling the progress bar, as it should when stdout is redirected. I don't know why you are still getting progress output when using redirection.

[Sweetchuck]

The simplified version of my command:

public function myCmd(): CommandResult
{
    $cb = $this->collectionBuilder();
    $cb->addTask($this->taskFoo());
    $result = $cb->run();

    return CommandResult::data($result['my_list']);
}

When I do nothing extra and I run this command: robo my:cmd > output.txt
And I open the output.txt file with a hexeditor
then the first two characters are:

• 0D 0A.
• or chr(13)chr(10)
• or \r\n

The "\r" is a little bit surprising, because the running OS is openSUSE Tumbleweed (Linux). I assume it is related to the progressBar re-drawing.

The stdOutput is the same with --progress-delay=0 and 2>/dev/null

The progressBar is always there even with --progress-delay=0 or -1 or 9999

The progressBar is always there even with --progress-delay=X | cat.

---

When I initialise the collection builder like this:

$nullOutput = new NullOutput();
$nullLogger = new NullLogger();
$io = new ConsoleIO(Robo::input(), $nullOutput);
$progressBar = new ProgressBar($nullOutput, 0, 99999);
$progressIndicator = new ProgressIndicator($progressBar, $nullOutput);
$cb = $this->collectionBuilder($io);
$cb->setLogger($nullLogger);
$cb->setProgressIndicator($progressIndicator);

Then the stdOutput is the expected.

I think the progressBar manager for some operation uses the stdOutput instead of the stdError.

[Sweetchuck]

When a a symfony progressBar receives the $output it checks that if it is a ConsoleOutputInterface or not, if it is, then uses the srdError part.
https://github.com/symfony/console/blob/5.4/Helper/ProgressBar.php#L71

\Robo\Common\ProgressIndicator does not do such a checking, just uses it directly.

robo/src/Common/ProgressIndicator.php

Line 59 in 1daaeae

$this->output = $output;

robo/src/Common/ProgressIndicator.php

Line 82 in 1daaeae

$this->output->write("\x0D");