Allow the logger to be overwritten (#82)

Allow the logger to be overwritten which opens the door for using a different logger for testing providing the means to finally have stable tests.

Author: theofidry

src/Logger/Logger.php

@@ -33,7 +33,7 @@ public function finish(string $itemName): void;
 
     public function logUnexpectedOutput(string $buffer): void;
 
-    public function logCommandStarted(string $string): void;
+    public function logCommandStarted(string $commandName): void;
 
-    public function logCommandFinished(string $string): void;
+    public function logCommandFinished(): void;
 }

src/Logger/StandardLogger.php

@@ -135,8 +135,8 @@ public function logCommandStarted(string $commandName): void
         $this->logger->debug('Command started: '.$commandName);
     }
 
-    public function logCommandFinished(string $commandName): void
+    public function logCommandFinished(): void
     {
-        $this->logger->debug('Command finished: '.$commandName);
+        $this->logger->debug('Command finished');
     }
 }

src/Parallelization.php

@@ -280,13 +280,7 @@ protected function executeMasterProcess(
         $numberOfBatches = $config->getNumberOfBatches();
         $itemName = $this->getItemName($numberOfItems);
 
-        $logger = new StandardLogger(
-            $output,
-            self::getProgressSymbol(),
-            (new Terminal())->getWidth(),
-            new DebugProgressBarFactory(),
-            new ConsoleLogger($output),
-        );
+        $logger = $this->createLogger($output);
 
         $logger->logConfiguration(
             $segmentSize,
@@ -410,6 +404,17 @@ protected function executeChildProcess(
         }
     }
 
+    protected function createLogger(OutputInterface $output): Logger
+    {
+        return new StandardLogger(
+            $output,
+            self::getProgressSymbol(),
+            (new Terminal())->getWidth(),
+            new DebugProgressBarFactory(),
+            new ConsoleLogger($output),
+        );
+    }
+
     /**
      * @internal
      * @return positive-int

src/ProcessLauncher.php

@@ -149,7 +149,7 @@ private function startProcess(InputStream $inputStream): void
         }
         $process->start($this->callback);
 
-        $this->logger->logCommandStarted('Command started: '.$this->command);
+        $this->logger->logCommandStarted($this->command);
 
         $this->runningProcesses[] = $process;
     }
@@ -162,7 +162,7 @@ private function freeTerminatedProcesses(): void
     {
         foreach ($this->runningProcesses as $key => $process) {
             if (!$process->isRunning()) {
-                $this->logger->logCommandFinished('Command finished');
+                $this->logger->logCommandFinished();
 
                 unset($this->runningProcesses[$key]);
             }

tests/Fixtures/Command/ImportMoviesCommand.php

@@ -17,9 +17,14 @@
 use function json_decode;
 use const JSON_THROW_ON_ERROR;
 use Symfony\Component\Console\Input\InputInterface;
+use Symfony\Component\Console\Logger\ConsoleLogger;
 use Symfony\Component\Console\Output\OutputInterface;
+use Symfony\Component\Console\Terminal;
 use Webmozarts\Console\Parallelization\ContainerAwareCommand;
+use Webmozarts\Console\Parallelization\Integration\TestDebugProgressBarFactory;
 use Webmozarts\Console\Parallelization\Integration\TestLogger;
+use Webmozarts\Console\Parallelization\Logger\Logger;
+use Webmozarts\Console\Parallelization\Logger\StandardLogger;
 use Webmozarts\Console\Parallelization\Parallelization;
 
 final class ImportMoviesCommand extends ContainerAwareCommand
@@ -106,6 +111,17 @@ protected function getItemName(int $count): string
         return 1 === $count ? 'movie' : 'movies';
     }
 
+    protected function createLogger(OutputInterface $output): Logger
+    {
+        return new StandardLogger(
+            $output,
+            self::getProgressSymbol(),
+            (new Terminal())->getWidth(),
+            new TestDebugProgressBarFactory(),
+            new ConsoleLogger($output),
+        );
+    }
+
     /**
      * @param list<string> $movieFileNames
      *

tests/Fixtures/Command/NoSubProcessCommand.php

@@ -15,8 +15,13 @@
 
 use DomainException;
 use Symfony\Component\Console\Input\InputInterface;
+use Symfony\Component\Console\Logger\ConsoleLogger;
 use Symfony\Component\Console\Output\OutputInterface;
+use Symfony\Component\Console\Terminal;
 use Webmozarts\Console\Parallelization\ContainerAwareCommand;
+use Webmozarts\Console\Parallelization\Integration\TestDebugProgressBarFactory;
+use Webmozarts\Console\Parallelization\Logger\Logger;
+use Webmozarts\Console\Parallelization\Logger\StandardLogger;
 use Webmozarts\Console\Parallelization\Parallelization;
 
 final class NoSubProcessCommand extends ContainerAwareCommand
@@ -67,4 +72,15 @@ protected function getItemName(int $count): string
     {
         return 0 === $count ? 'item' : 'items';
     }
+
+    protected function createLogger(OutputInterface $output): Logger
+    {
+        return new StandardLogger(
+            $output,
+            self::getProgressSymbol(),
+            (new Terminal())->getWidth(),
+            new TestDebugProgressBarFactory(),
+            new ConsoleLogger($output),
+        );
+    }
 }

tests/Integration/ParallelizationIntegrationTest.php

@@ -64,6 +64,10 @@ public function test_it_can_run_the_command_without_sub_processes(): void
             Processing 5 items in segments of 2, batches of 2, 1 round, 1 batch in 1 process
 
              0/5 [>---------------------------]   0% 10 secs/10 secs 10.0 MiB
+             1/5 [=====>----------------------]  20% 10 secs/10 secs 10.0 MiB
+             2/5 [===========>----------------]  40% 10 secs/10 secs 10.0 MiB
+             3/5 [================>-----------]  60% 10 secs/10 secs 10.0 MiB
+             4/5 [======================>-----]  80% 10 secs/10 secs 10.0 MiB
              5/5 [============================] 100% 10 secs/10 secs 10.0 MiB
 
             Processed 5 items.
@@ -136,6 +140,18 @@ public function test_it_can_run_the_command_with_multiple_processes_in_debug_mod
             ],
         );
 
+        $expectedWithNoDebugMode = <<<'EOF'
+            Processing 5 movies in segments of 2, batches of 2, 3 rounds, 3 batches in 2 processes
+
+             0/5 [>---------------------------]   0% 10 secs/10 secs 10.0 MiB
+             2/5 [===========>----------------]  40% 10 secs/10 secs 10.0 MiB
+             4/5 [======================>-----]  80% 10 secs/10 secs 10.0 MiB
+             5/5 [============================] 100% 10 secs/10 secs 10.0 MiB
+
+            Processed 5 movies.
+
+            EOF;
+
         $expected = <<<'EOF'
             Processing 5 movies in segments of 2, batches of 2, 3 rounds, 3 batches in 2 processes
 
@@ -156,7 +172,19 @@ public function test_it_can_run_the_command_with_multiple_processes_in_debug_mod
 
         $actual = $this->getOutput($commandTester);
 
-        self::assertSame($expected, $actual, $actual);
+        $expectedChildProcessesCount = 3;
+        $expectedCommandStartedLine = "[debug] Command started: '/path/to/php' '/path/to/work-dir/bin/console' 'import:movies' '--child'\n";
+        $expectedCommandFinishedLine = "[debug] Command finished\n";
+
+        $outputWithoutExtraDebugInfo = str_replace(
+            [$expectedCommandStartedLine, $expectedCommandFinishedLine],
+            ['', ''],
+            $actual,
+        );
+
+        self::assertSame($expectedWithNoDebugMode, $outputWithoutExtraDebugInfo, $outputWithoutExtraDebugInfo);
+        self::assertSame($expectedChildProcessesCount, mb_substr_count($actual, $expectedCommandStartedLine));
+        self::assertSame($expectedChildProcessesCount, mb_substr_count($actual, $expectedCommandFinishedLine));
     }
 
     private function getOutput(CommandTester $commandTester): string

tests/Integration/TestDebugProgressBarFactory.php

@@ -0,0 +1,35 @@
+<?php
+
+/*
+ * This file is part of the Webmozarts Console Parallelization package.
+ *
+ * (c) Webmozarts GmbH <office@webmozarts.com>
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+declare(strict_types=1);
+
+namespace Webmozarts\Console\Parallelization\Integration;
+
+use const PHP_FLOAT_MIN;
+use Symfony\Component\Console\Helper\ProgressBar;
+use Symfony\Component\Console\Output\OutputInterface;
+use Webmozarts\Console\Parallelization\Logger\ProgressBarFactory;
+
+final class TestDebugProgressBarFactory implements ProgressBarFactory
+{
+    public function create(
+        OutputInterface $output,
+        int $numberOfItems
+    ): ProgressBar {
+        // Put the lowest time between redraws to ensure they we see all elements
+        // of progress.
+        $progressBar = new ProgressBar($output, $numberOfItems, PHP_FLOAT_MIN);
+        $progressBar->setFormat(ProgressBar::FORMAT_DEBUG);
+        $progressBar->start();
+
+        return $progressBar;
+    }
+}

tests/Logger/StandardLoggerTest.php

@@ -159,10 +159,10 @@ public function test_it_can_log_the_end_of_a_command(): void
     {
         $this->output->setVerbosity(OutputInterface::VERBOSITY_DEBUG);
 
-        $this->logger->logCommandFinished('/path/to/bin/console foo:bar --child');
+        $this->logger->logCommandFinished();
 
         $expected = <<<'TXT'
-            [debug] Command finished: /path/to/bin/console foo:bar --child
+            [debug] Command finished
 
             TXT;