Add performance counters to ConsoleSubsriber

src/Supportive/Console/Command/AnalyseCommand.php

@@ -12,6 +12,7 @@
 use Qossmic\Deptrac\Supportive\OutputFormatter\FormatterProvider;
 use Qossmic\Deptrac\Supportive\OutputFormatter\GithubActionsOutputFormatter;
 use Qossmic\Deptrac\Supportive\OutputFormatter\TableOutputFormatter;
+use Qossmic\Deptrac\Supportive\Time\Stopwatch;
 use Symfony\Component\Console\Command\Command;
 use Symfony\Component\Console\Input\InputInterface;
 use Symfony\Component\Console\Input\InputOption;
@@ -77,7 +78,7 @@ protected function execute(InputInterface $input, OutputInterface $output): int
  (bool) $input->getOption(self::OPTION_FAIL_ON_UNCOVERED)
  );
 
- $this->dispatcher->addSubscriber(new ConsoleSubscriber($symfonyOutput));
+ $this->dispatcher->addSubscriber(new ConsoleSubscriber($symfonyOutput, new Stopwatch()));
  if (!$options->noProgress) {
  $this->dispatcher->addSubscriber(new ProgressSubscriber($symfonyOutput));
  }

src/Supportive/Console/Subscriber/ConsoleSubscriber.php

@@ -13,12 +13,18 @@
 use Qossmic\Deptrac\Contract\Dependency\PreEmitEvent;
 use Qossmic\Deptrac\Contract\Dependency\PreFlattenEvent;
 use Qossmic\Deptrac\Contract\OutputFormatter\OutputInterface;
+use Qossmic\Deptrac\Supportive\Time\Stopwatch;
+use Qossmic\Deptrac\Supportive\Time\StopwatchException;
 use Symfony\Component\EventDispatcher\EventSubscriberInterface;
 
+use function sprintf;
+
 class ConsoleSubscriber implements EventSubscriberInterface
 {
- public function __construct(private readonly OutputInterface $output)
- {
+ public function __construct(
+ private readonly OutputInterface $output,
+ private readonly Stopwatch $stopwatch,
+ ) {
  }
 
  /**
@@ -38,9 +44,12 @@ public static function getSubscribedEvents(): array
  ];
  }
 
+ /** @throws StopwatchException */
  public function onPreCreateAstMapEvent(PreCreateAstMapEvent $preCreateAstMapEvent): void
  {
  if ($this->output->isVerbose()) {
+ $this->stopwatch->start('ast');
+
  $this->output->writeLineFormatted(
  sprintf(
  'Start to create an AstMap for <info>%u</info> Files.',
@@ -50,10 +59,18 @@ public function onPreCreateAstMapEvent(PreCreateAstMapEvent $preCreateAstMapEven
  }
  }
 
+ /** @throws StopwatchException */
  public function onPostCreateAstMapEvent(PostCreateAstMapEvent $postCreateAstMapEvent): void
  {
  if ($this->output->isVerbose()) {
- $this->output->writeLineFormatted('AstMap created.');
+ $period = $this->stopwatch->stop('ast');
+
+ $this->output->writeLineFormatted(
+ sprintf(
+ 'AstMap created in %01.2f sec.',
+ $period->toSeconds(),
+ )
+ );
  }
  }
 
@@ -73,33 +90,55 @@ public function onAstFileSyntaxErrorEvent(AstFileSyntaxErrorEvent $astFileSyntax
  ));
  }
 
+ /** @throws StopwatchException */
  public function onPreDependencyEmit(PreEmitEvent $event): void
  {
  if ($this->output->isVerbose()) {
+ $this->stopwatch->start('deps');
+
  $this->output->writeLineFormatted(
  sprintf('start emitting dependencies <info>"%s"</info>', $event->emitterName)
  );
  }
  }
 
+ /** @throws StopwatchException */
  public function onPostDependencyEmit(PostEmitEvent $event): void
  {
  if ($this->output->isVerbose()) {
- $this->output->writeLineFormatted('<info>end emitting dependencies</info>');
+ $period = $this->stopwatch->stop('deps');
+
+ $this->output->writeLineFormatted(
+ sprintf(
+ '<info>Dependencies emitted in %01.2f sec.</info>',
+ $period->toSeconds(),
+ )
+ );
  }
  }
 
+ /** @throws StopwatchException */
  public function onPreDependencyFlatten(PreFlattenEvent $event): void
  {
  if ($this->output->isVerbose()) {
+ $this->stopwatch->start('flatten');
+
  $this->output->writeLineFormatted('<info>start flatten dependencies</info>');
  }
  }
 
+ /** @throws StopwatchException */
  public function onPostDependencyFlatten(PostFlattenEvent $event): void
  {
  if ($this->output->isVerbose()) {
- $this->output->writeLineFormatted('<info>end flatten dependencies</info>');
+ $period = $this->stopwatch->stop('flatten');
+
+ $this->output->writeLineFormatted(
+ sprintf(
+ '<info>Dependencies flattened in %01.f sec.</info>',
+ $period->toSeconds(),
+ )
+ );
  }
  }
 }

src/Supportive/Time/Period.php

@@ -0,0 +1,37 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Qossmic\Deptrac\Supportive\Time;
+
+use function hrtime;
+
+/**
+ * @psalm-immutable
+ */
+final class Period
+{
+ private function __construct(
+ public readonly float|int $startedAt,
+ public readonly float|int $endedAt,
+ ) {
+ }
+
+ /**
+ * @psalm-pure
+ */
+ public static function stop(StartedPeriod $startedPeriod): self
+ {
+ return new self(
+ $startedPeriod->startedAt,
+ hrtime(true),
+ );
+ }
+
+ public function toSeconds(): float
+ {
+ $duration = $this->endedAt - $this->startedAt;
+
+ return $duration / 1e9;
+ }
+}

src/Supportive/Time/StartedPeriod.php

@@ -0,0 +1,28 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Qossmic\Deptrac\Supportive\Time;
+
+/**
+ * @psalm-immutable
+ */
+final class StartedPeriod
+{
+ private function __construct(
+ public readonly float|int $startedAt
+ ) {
+ }
+
+ public static function start(): self
+ {
+ return new self(
+ hrtime(true),
+ );
+ }
+
+ public function stop(): Period
+ {
+ return Period::stop($this);
+ }
+}

src/Supportive/Time/Stopwatch.php

@@ -0,0 +1,69 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Qossmic\Deptrac\Supportive\Time;
+
+use function array_key_exists;
+
+final class Stopwatch
+{
+ /** @var array<non-empty-string, StartedPeriod> */
+ private array $periods = [];
+
+ public function __construct()
+ {
+ }
+
+ /**
+ * @param non-empty-string $event
+ *
+ * @throws StopwatchException
+ */
+ public function start(string $event): void
+ {
+ $this->assertPeriodNotStarted($event);
+
+ $this->periods[$event] = StartedPeriod::start();
+ }
+
+ /**
+ * @param non-empty-string $event
+ *
+ * @throws StopwatchException
+ */
+ public function stop(string $event): Period
+ {
+ $this->assertPeriodStarted($event);
+
+ $period = $this->periods[$event]->stop();
+
+ unset($this->periods[$event]);
+
+ return $period;
+ }
+
+ /**
+ * @param non-empty-string $event
+ *
+ * @throws StopwatchException
+ */
+ private function assertPeriodNotStarted(string $event): void
+ {
+ if (array_key_exists($event, $this->periods)) {
+ throw StopwatchException::periodAlreadyStarted($event);
+ }
+ }
+
+ /**
+ * @param non-empty-string $event
+ *
+ * @throws StopwatchException
+ */
+ private function assertPeriodStarted(string $event): void
+ {
+ if (!array_key_exists($event, $this->periods)) {
+ throw StopwatchException::periodNotStarted($event);
+ }
+ }
+}

src/Supportive/Time/StopwatchException.php

@@ -0,0 +1,33 @@
+<?php
+
+declare(strict_types=1);
+
+namespace Qossmic\Deptrac\Supportive\Time;
+
+use Qossmic\Deptrac\Contract\ExceptionInterface;
+use RuntimeException;
+
+use function sprintf;
+
+final class StopwatchException extends RuntimeException implements ExceptionInterface
+{
+ public static function periodAlreadyStarted(string $period): self
+ {
+ return new self(
+ sprintf(
+ 'Period "%s" is already started',
+ $period,
+ )
+ );
+ }
+
+ public static function periodNotStarted(string $period): self
+ {
+ return new self(
+ sprintf(
+ 'Period "%s" is not started',
+ $period,
+ )
+ );
+ }
+}