From 0a1e1d8f9ed3fdcf90f0a35575110ebbb1254381 Mon Sep 17 00:00:00 2001 From: Alan Gabriel Bem Date: Wed, 25 Dec 2019 01:05:47 +0100 Subject: [PATCH] measure time of initialization of subscription separately in "streak:subscription:run" command --- src/Command/RunSubscriptionCommand.php | 31 ++++++++++--------- src/Command/RunSubscriptionsCommand.php | 4 +-- .../Command/RunSubscriptionCommandTest.php | 12 +++---- 3 files changed, 24 insertions(+), 23 deletions(-) diff --git a/src/Command/RunSubscriptionCommand.php b/src/Command/RunSubscriptionCommand.php index bcc7eaf..b181032 100644 --- a/src/Command/RunSubscriptionCommand.php +++ b/src/Command/RunSubscriptionCommand.php @@ -17,6 +17,7 @@ use Streak\Domain\Event\Subscription\Repository; use Streak\Domain\EventStore; use Symfony\Component\Console\Command\Command; +use Symfony\Component\Console\Helper\Helper; use Symfony\Component\Console\Helper\ProgressBar; use Symfony\Component\Console\Input\InputArgument; use Symfony\Component\Console\Input\InputInterface; @@ -53,22 +54,9 @@ protected function configure() protected function execute(InputInterface $input, OutputInterface $output) { - ProgressBar::setFormatDefinition('custom', 'Subscription %subscription_type%(%subscription_id%) processed %current% events in %elapsed%.'); - - // progress bar by default is writing to stderr, lets try to mitigate that - if ($output instanceof StreamOutput) { - $output = new StreamOutput($output->getStream(), $output->getVerbosity(), null, $output->getFormatter()); // @codeCoverageIgnore - } - - // by instantiating progress bar here we start measuring time before we load subscription, - // so elapsed time will include subscription initialization period - $progress = new ProgressBar($output); - $progress->setFormat('custom'); - $progress->setOverwrite(true); - $progress->setMessage($input->getArgument('subscription-type'), 'subscription_type'); - $progress->setMessage($input->getArgument('subscription-id'), 'subscription_id'); - + $start = time(); $subscription = $this->subscriptions->find($this->id($input)); + $initializedIn = time() - $start; if (null === $subscription) { $output->write(sprintf('Subscription %s(%s) not found.', $input->getArgument('subscription-type'), $input->getArgument('subscription-id'))); @@ -82,6 +70,19 @@ protected function execute(InputInterface $input, OutputInterface $output) $limit = (int) $limit; } + ProgressBar::setFormatDefinition('custom', 'Subscription %subscription_type%(%subscription_id%) initialized in %initialized_in% and processed %current% events in %elapsed%.'); + + // progress bar by default is writing to stderr, lets try to mitigate that + if ($output instanceof StreamOutput) { + $output = new StreamOutput($output->getStream(), $output->getVerbosity(), null, $output->getFormatter()); // @codeCoverageIgnore + } + + $progress = new ProgressBar($output); + $progress->setFormat('custom'); + $progress->setOverwrite(true); + $progress->setMessage($input->getArgument('subscription-type'), 'subscription_type'); + $progress->setMessage($input->getArgument('subscription-id'), 'subscription_id'); + $progress->setMessage(Helper::formatTime($initializedIn), 'initialized_in'); $progress->display(); try { diff --git a/src/Command/RunSubscriptionsCommand.php b/src/Command/RunSubscriptionsCommand.php index 4848146..0210124 100644 --- a/src/Command/RunSubscriptionsCommand.php +++ b/src/Command/RunSubscriptionsCommand.php @@ -174,8 +174,8 @@ private function executable(array $command, InputInterface $input) : array private function decorate(string $string) : string { - $pattern = '/Subscription (.+)\((.+)\) processed (.+) events in (.+)./i'; - $replacement = 'Subscription $1($2) processed $3 events in $4.'; + $pattern = '/Subscription (.+)\((.+)\) initialized in (.+) and processed (.+) events in (.+)./i'; + $replacement = 'Subscription $1($2) initialized in $3 and processed $4 events in $5.'; $decorated = preg_replace($pattern, $replacement, $string); if (null === $decorated) { diff --git a/src/Tests/Command/RunSubscriptionCommandTest.php b/src/Tests/Command/RunSubscriptionCommandTest.php index 96b7318..a25d75e 100644 --- a/src/Tests/Command/RunSubscriptionCommandTest.php +++ b/src/Tests/Command/RunSubscriptionCommandTest.php @@ -114,9 +114,9 @@ public function testCommand() $command->run(new ArrayInput(['subscription-type' => 'Streak\\StreakBundle\\Tests\\Command\\RunSubscriptionCommandTest\\SubscriptionId1', 'subscription-id' => 'EC2BE294-C07A-4198-A159-4551686F14F9']), $this->output); $expected = - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 0 events in < 1 sec.". + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 0 events in < 1 sec.". self::TERMINAL_CLEAR_LINE. - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 2 events in < 1 sec." + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 2 events in < 1 sec." ; $this->assertEquals($expected, $this->output->output); } @@ -141,9 +141,9 @@ public function testCommandWithLimit() $command->run(new ArrayInput(['subscription-type' => 'Streak\\StreakBundle\\Tests\\Command\\RunSubscriptionCommandTest\\SubscriptionId1', 'subscription-id' => 'EC2BE294-C07A-4198-A159-4551686F14F9', '--listening-limit' => 763723]), $this->output); $expected = - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 0 events in < 1 sec.". + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 0 events in < 1 sec.". self::TERMINAL_CLEAR_LINE. - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 2 events in < 1 sec." + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 2 events in < 1 sec." ; $this->assertEquals($expected, $this->output->output); } @@ -217,9 +217,9 @@ public function testError() $command->run(new ArrayInput(['subscription-type' => 'Streak\\StreakBundle\\Tests\\Command\\RunSubscriptionCommandTest\\SubscriptionId1', 'subscription-id' => 'EC2BE294-C07A-4198-A159-4551686F14F9']), $this->output); } finally { $expected = - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 0 events in < 1 sec.". + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 0 events in < 1 sec.". self::TERMINAL_CLEAR_LINE. - "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) processed 2 events in < 1 sec." + "Subscription Streak\StreakBundle\Tests\Command\RunSubscriptionCommandTest\SubscriptionId1(EC2BE294-C07A-4198-A159-4551686F14F9) initialized in < 1 sec and processed 2 events in < 1 sec." ; $this->assertEquals($expected, $this->output->output); }