From ace8faa8750a16e77bb616a1ca8e6f39acb60f4b Mon Sep 17 00:00:00 2001 From: Bob van de Vijver Date: Fri, 19 Jun 2020 16:30:29 +0200 Subject: [PATCH] #998: Show query and time information when using --query-time --- .../Migrations/Version/DbalExecutor.php | 21 ++++++++++++------- .../Migrations/Tests/Version/ExecutorTest.php | 8 +++---- 2 files changed, 17 insertions(+), 12 deletions(-) diff --git a/lib/Doctrine/Migrations/Version/DbalExecutor.php b/lib/Doctrine/Migrations/Version/DbalExecutor.php index c2419d4b6f..e417b3a0e2 100644 --- a/lib/Doctrine/Migrations/Version/DbalExecutor.php +++ b/lib/Doctrine/Migrations/Version/DbalExecutor.php @@ -19,6 +19,7 @@ use Doctrine\Migrations\Query\Query; use Doctrine\Migrations\Tools\BytesFormatter; use Psr\Log\LoggerInterface; +use Psr\Log\LogLevel; use Symfony\Component\Stopwatch\Stopwatch; use Throwable; use function count; @@ -176,7 +177,7 @@ private function executeMigration( $this->executeResult($configuration); } else { foreach ($this->sql as $query) { - $this->outputSqlQuery($query); + $this->outputSqlQuery($query, $configuration); } } } else { @@ -291,7 +292,7 @@ private function logResult(Throwable $e, ExecutionResult $result, MigrationPlan private function executeResult(MigratorConfiguration $configuration) : void { foreach ($this->sql as $key => $query) { - $this->outputSqlQuery($query); + $this->outputSqlQuery($query, $configuration); $stopwatchEvent = $this->stopwatch->start('query'); $this->connection->executeUpdate($query->getStatement(), $query->getParameters(), $query->getTypes()); @@ -301,23 +302,27 @@ private function executeResult(MigratorConfiguration $configuration) : void continue; } - $this->logger->debug('{duration}ms', [ + $this->logger->notice('Query took {duration}ms', [ 'duration' => $stopwatchEvent->getDuration(), ]); } } - private function outputSqlQuery(Query $query) : void + private function outputSqlQuery(Query $query, MigratorConfiguration $configuration) : void { $params = $this->parameterFormatter->formatParameters( $query->getParameters(), $query->getTypes() ); - $this->logger->debug('{query} {params}', [ - 'query' => $query->getStatement(), - 'params' => $params, - ]); + $this->logger->log( + $configuration->getTimeAllQueries() ? LogLevel::NOTICE : LogLevel::DEBUG, + '{query} {params}', + [ + 'query' => $query->getStatement(), + 'params' => $params, + ] + ); } private function getFromSchema(MigratorConfiguration $configuration) : Schema diff --git a/tests/Doctrine/Migrations/Tests/Version/ExecutorTest.php b/tests/Doctrine/Migrations/Tests/Version/ExecutorTest.php index fed73f98da..963cf041ab 100644 --- a/tests/Doctrine/Migrations/Tests/Version/ExecutorTest.php +++ b/tests/Doctrine/Migrations/Tests/Version/ExecutorTest.php @@ -140,9 +140,9 @@ public function testExecuteUp() : void self::assertSame([ 0 => '++ migrating test', 1 => 'SELECT 1 ', - 2 => '100ms', + 2 => 'Query took 100ms', 3 => 'SELECT 2 ', - 4 => '100ms', + 4 => 'Query took 100ms', 5 => 'Migration test migrated (took 100ms, used 100 memory)', ], $this->logger->logs); } @@ -223,9 +223,9 @@ public function testExecuteDown() : void self::assertSame([ 0 => '++ reverting test', 1 => 'SELECT 3 ', - 2 => '100ms', + 2 => 'Query took 100ms', 3 => 'SELECT 4 ', - 4 => '100ms', + 4 => 'Query took 100ms', 5 => 'Migration test reverted (took 100ms, used 100 memory)', ], $this->logger->logs); }