diff --git a/UPGRADE.md b/UPGRADE.md index cc147fd..61a78a7 100644 --- a/UPGRADE.md +++ b/UPGRADE.md @@ -2,12 +2,12 @@ ## 0.5.0 -Two new `integer` columns were added to the `processed_messages` table: -`wait_time` and `handle_time`. You will need to create a migration to -add these columns to your database. They are not nullable so your -migration will need to account for existing data. You can either -truncate (purge) the `processed_messages` table have your migration -calculate these values based on the existing data. +Two new `bigint` columns were added to the `processed_messages` table: +`wait_time` and `handle_time`. These are milliseconds. You will need to +create a migration to add these columns to your database. They are not +nullable so your migration will need to account for existing data. You +can either truncate (purge) the `processed_messages` table or have your +migration calculate these values based on the existing data. Here's a calculation example for MySQL: @@ -25,13 +25,13 @@ final class VersionXXX extends AbstractMigration public function up(Schema $schema): void { // Add the columns as nullable - $this->addSql('ALTER TABLE processed_messages ADD wait_time INT DEFAULT NULL, ADD handle_time INT DEFAULT NULL'); + $this->addSql('ALTER TABLE processed_messages ADD wait_time BIGINT DEFAULT NULL, ADD handle_time BIGINT DEFAULT NULL'); // set the times from existing data - $this->addSql('UPDATE processed_messages SET wait_time = TIMESTAMPDIFF(SECOND, dispatched_at, received_at), handle_time = TIMESTAMPDIFF(SECOND, received_at, finished_at)'); + $this->addSql('UPDATE processed_messages SET wait_time = TIMESTAMPDIFF(SECOND, dispatched_at, received_at) * 1000, handle_time = TIMESTAMPDIFF(SECOND, received_at, finished_at) * 1000'); // Make the columns not nullable - $this->addSql('ALTER TABLE processed_messages CHANGE wait_time wait_time INT NOT NULL, CHANGE handle_time handle_time INT NOT NULL'); + $this->addSql('ALTER TABLE processed_messages CHANGE wait_time wait_time BIGINT NOT NULL, CHANGE handle_time handle_time BIGINT NOT NULL'); } public function down(Schema $schema): void diff --git a/config/doctrine/mapping/ProcessedMessage.orm.xml b/config/doctrine/mapping/ProcessedMessage.orm.xml index a03e201..fac2a6f 100644 --- a/config/doctrine/mapping/ProcessedMessage.orm.xml +++ b/config/doctrine/mapping/ProcessedMessage.orm.xml @@ -11,8 +11,8 @@ - - + + diff --git a/src/Controller/MessengerMonitorController.php b/src/Controller/MessengerMonitorController.php index c53fe89..e52a447 100644 --- a/src/Controller/MessengerMonitorController.php +++ b/src/Controller/MessengerMonitorController.php @@ -37,14 +37,10 @@ abstract class MessengerMonitorController extends AbstractController #[Route(name: 'zenstruck_messenger_monitor_dashboard')] public function dashboard(ViewHelper $helper): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - return $this->render('@ZenstruckMessengerMonitor/dashboard.html.twig', [ 'helper' => $helper, - 'snapshot' => Specification::create(Period::IN_LAST_DAY)->snapshot($helper->storage), - 'messages' => Specification::new()->snapshot($helper->storage)->messages(), + 'snapshot' => Specification::create(Period::IN_LAST_DAY)->snapshot($helper->storage()), + 'messages' => Specification::new()->snapshot($helper->storage())->messages(), ]); } @@ -53,10 +49,6 @@ public function statistics( Request $request, ViewHelper $helper, ): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - $period = Period::parse($request->query->getString('period')); $specification = Specification::create([ // @phpstan-ignore-line 'period' => $period, @@ -66,7 +58,7 @@ public function statistics( 'helper' => $helper, 'periods' => [...Period::inLastCases(), ...Period::absoluteCases()], 'period' => $period, - 'metrics' => $specification->snapshot($helper->storage)->perMessageTypeMetrics(), + 'metrics' => $specification->snapshot($helper->storage())->perMessageTypeMetrics(), ]); } @@ -75,10 +67,6 @@ public function history( Request $request, ViewHelper $helper, ): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - $tags = [$request->query->get('tag')]; $notTags = []; $period = Period::parse($request->query->getString('period')); @@ -102,26 +90,22 @@ public function history( 'helper' => $helper, 'periods' => [...Period::inLastCases(), ...Period::absoluteCases()], 'period' => $period, - 'snapshot' => $specification->snapshot($helper->storage), - 'filters' => $specification->filters($helper->storage), + 'snapshot' => $specification->snapshot($helper->storage()), + 'filters' => $specification->filters($helper->storage()), ]); } #[Route('/history/{id}', name: 'zenstruck_messenger_monitor_detail')] public function detail(string $id, ViewHelper $helper): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - - if (!$message = $helper->storage->find($id)) { + if (!$message = $helper->storage()->find($id)) { throw $this->createNotFoundException('Message not found.'); } return $this->render('@ZenstruckMessengerMonitor/detail.html.twig', [ 'helper' => $helper, 'message' => $message, - 'other_attempts' => $helper->storage->filter(Specification::create(['run_id' => $message->runId()])), + 'other_attempts' => $helper->storage()->filter(Specification::create(['run_id' => $message->runId()])), ]); } @@ -289,13 +273,9 @@ public function transportsWidget( public function snapshotWidget( ViewHelper $helper, ): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - return $this->render('@ZenstruckMessengerMonitor/components/snapshot.html.twig', [ 'helper' => $helper, - 'snapshot' => Specification::create(Period::IN_LAST_DAY)->snapshot($helper->storage), + 'snapshot' => Specification::create(Period::IN_LAST_DAY)->snapshot($helper->storage()), 'subtitle' => 'Last 24 Hours', ]); } @@ -304,12 +284,8 @@ public function snapshotWidget( public function recentMessagesWidget( ViewHelper $helper, ): Response { - if (!$helper->storage) { - throw new \LogicException('Storage must be configured to use the dashboard.'); - } - return $this->render('@ZenstruckMessengerMonitor/components/recent_messages.html.twig', [ - 'messages' => Specification::new()->snapshot($helper->storage)->messages(), + 'messages' => Specification::new()->snapshot($helper->storage())->messages(), 'helper' => $helper, ]); } diff --git a/src/History/Model/MessageTypeMetric.php b/src/History/Model/MessageTypeMetric.php index b14af74..62a148e 100644 --- a/src/History/Model/MessageTypeMetric.php +++ b/src/History/Model/MessageTypeMetric.php @@ -22,6 +22,8 @@ final class MessageTypeMetric /** * @param class-string $class + * @param float $averageWaitTime In seconds + * @param float $averageHandlingTime In seconds */ public function __construct( string $class, diff --git a/src/History/Model/ProcessedMessage.php b/src/History/Model/ProcessedMessage.php index 88198ec..9612a70 100644 --- a/src/History/Model/ProcessedMessage.php +++ b/src/History/Model/ProcessedMessage.php @@ -63,8 +63,8 @@ public function __construct(Envelope $envelope, Results $results, ?\Throwable $e $this->transport = $monitorStamp->transport(); $this->tags = $tags->count() ? (string) $tags : null; $this->results = $results; - $this->waitTime = \max(0, $this->receivedAt->getTimestamp() - $this->dispatchedAt->getTimestamp()); - $this->handleTime = \max(0, $this->finishedAt->getTimestamp() - $this->receivedAt->getTimestamp()); + $this->waitTime = (int) \max(0, $this->receivedAt->format('Uv') - $this->dispatchedAt->format('Uv')); + $this->handleTime = (int) \max(0, $this->finishedAt->format('Uv') - $this->receivedAt->format('Uv')); if ($retryStamp = $envelope->last(RedeliveryStamp::class)) { $this->attempt += $retryStamp->getRetryCount(); @@ -145,19 +145,28 @@ final public function isFailure(): bool return null !== $this->failureType; } - final public function timeInQueue(): int + /** + * @return float In seconds + */ + final public function timeInQueue(): float { - return $this->waitTime; + return $this->waitTime / 1000; } - final public function timeToHandle(): int + /** + * @return float In seconds + */ + final public function timeToHandle(): float { - return $this->handleTime; + return $this->handleTime / 1000; } - final public function timeToProcess(): int + /** + * @return float In seconds + */ + final public function timeToProcess(): float { - return $this->waitTime + $this->handleTime; + return $this->timeInQueue() + $this->timeToHandle(); } final public function memoryUsage(): Bytes diff --git a/src/History/Snapshot.php b/src/History/Snapshot.php index d3567eb..6ca9835 100644 --- a/src/History/Snapshot.php +++ b/src/History/Snapshot.php @@ -77,16 +77,25 @@ public function failRate(): float } } + /** + * @return float In seconds + */ public function averageWaitTime(): float { return $this->averageWaitTime ??= $this->storage->averageWaitTime($this->specification) ?? 0.0; } + /** + * @return float In seconds + */ public function averageHandlingTime(): float { return $this->averageHandlingTime ??= $this->storage->averageHandlingTime($this->specification) ?? 0.0; } + /** + * @return float In seconds + */ public function averageProcessingTime(): float { return $this->averageWaitTime() + $this->averageHandlingTime(); diff --git a/src/History/Storage.php b/src/History/Storage.php index f2c5e77..099289b 100644 --- a/src/History/Storage.php +++ b/src/History/Storage.php @@ -35,8 +35,14 @@ public function save(Envelope $envelope, Results $results, ?\Throwable $exceptio public function delete(mixed $id): void; + /** + * @return float|null In seconds + */ public function averageWaitTime(Specification $specification): ?float; + /** + * @return float|null In seconds + */ public function averageHandlingTime(Specification $specification): ?float; public function count(Specification $specification): int; diff --git a/src/History/Storage/ORMStorage.php b/src/History/Storage/ORMStorage.php index 4dd8df2..fe7c8f8 100644 --- a/src/History/Storage/ORMStorage.php +++ b/src/History/Storage/ORMStorage.php @@ -64,8 +64,8 @@ public function perMessageTypeMetrics(Specification $specification): Collection ->select('m.type') ->addSelect('COUNT(m.type) as total_count') ->addSelect('COUNT(m.failureType) as failure_count') - ->addSelect('AVG(m.waitTime) as avg_wait_time') - ->addSelect('AVG(m.handleTime) as avg_handling_time') + ->addSelect('AVG(m.waitTime) / 1000 AS avg_wait_time') + ->addSelect('AVG(m.handleTime) / 1000 AS avg_handling_time') ->groupBy('m.type') ; @@ -121,7 +121,7 @@ public function averageWaitTime(Specification $specification): ?float { $qb = $this ->queryBuilderFor($specification, false) - ->select('AVG(m.waitTime)') + ->select('AVG(m.waitTime) / 1000') ; return (new EntityResult($qb))->asFloat()->first(); @@ -131,7 +131,7 @@ public function averageHandlingTime(Specification $specification): ?float { $qb = $this ->queryBuilderFor($specification, false) - ->select('AVG(m.handleTime)') + ->select('AVG(m.handleTime) / 1000') ; return (new EntityResult($qb))->asFloat()->first(); diff --git a/src/Twig/ViewHelper.php b/src/Twig/ViewHelper.php index 0ef1a18..40e668d 100644 --- a/src/Twig/ViewHelper.php +++ b/src/Twig/ViewHelper.php @@ -31,16 +31,34 @@ final class ViewHelper public function __construct( public readonly Transports $transports, public readonly Workers $workers, - public readonly ?Storage $storage, + private readonly ?Storage $storage, public readonly ?Schedules $schedules, - public readonly ?DateTimeFormatter $timeFormatter, - public readonly ?CsrfTokenManagerInterface $csrfTokenManager, + private readonly ?DateTimeFormatter $timeFormatter, + private readonly ?CsrfTokenManagerInterface $csrfTokenManager, ) { } - public function canFormatDuration(): bool + public function storage(): Storage { - return $this->timeFormatter && \method_exists($this->timeFormatter, 'formatDuration'); + return $this->storage ?? throw new \LogicException('Storage is not enabled.'); + } + + public function formatTime(\DateTimeInterface $from): string + { + return $this->timeFormatter?->formatDiff($from) ?? $from->format('c'); + } + + public function formatDuration(float $seconds): string + { + if ($seconds < 1) { + return \sprintf('%d ms', $seconds * 1000); + } + + if (!$this->timeFormatter || !\method_exists($this->timeFormatter, 'formatDuration')) { + return \sprintf('%.3f s', $seconds); + } + + return $this->timeFormatter->formatDuration($seconds); } public function generateCsrfToken(string ...$parts): string diff --git a/templates/components/messages.html.twig b/templates/components/messages.html.twig index fe6f465..e37f508 100644 --- a/templates/components/messages.html.twig +++ b/templates/components/messages.html.twig @@ -47,11 +47,7 @@ {{ message.transport }} - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(message.timeToHandle) }} - {% else %} - {{ message.timeToHandle }}s - {% endif %} + {{ helper.formatDuration(message.timeToHandle) }} {{ message.memoryUsage }} @@ -64,11 +60,7 @@ {% endfor %} - {% if helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(message.finishedAt) }} - {% else %} - {{ message.finishedAt|date('c') }} - {% endif %} + {{ helper.formatTime(message.finishedAt) }} diff --git a/templates/components/snapshot.html.twig b/templates/components/snapshot.html.twig index dc2009d..45cf756 100644 --- a/templates/components/snapshot.html.twig +++ b/templates/components/snapshot.html.twig @@ -35,21 +35,13 @@ Average Wait Time - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(snapshot.averageWaitTime) }} - {% else %} - {{ snapshot.averageWaitTime|round }}s - {% endif %} + {{ helper.formatDuration(snapshot.averageWaitTime) }} Average Handling Time - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(snapshot.averageHandlingTime) }} - {% else %} - {{ snapshot.averageHandlingTime|round }}s - {% endif %} + {{ helper.formatDuration(snapshot.averageHandlingTime) }} diff --git a/templates/detail.html.twig b/templates/detail.html.twig index 517343f..ce77149 100644 --- a/templates/detail.html.twig +++ b/templates/detail.html.twig @@ -66,51 +66,31 @@ Time in Queue - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(message.timeInQueue) }} - {% else %} - {{ message.timeInQueue }}s - {% endif %} + {{ helper.formatDuration(message.timeInQueue) }} Time to Handle - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(message.timeToHandle) }} - {% else %} - {{ message.timeToHandle }}s - {% endif %} + {{ helper.formatDuration(message.timeToHandle) }} Dispatched At - {% if helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(message.dispatchedAt) }} - {% else %} - {{ message.dispatchedAt|date('c') }} - {% endif %} + {{ helper.formatTime(message.dispatchedAt) }} Received At - {% if helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(message.receivedAt) }} - {% else %} - {{ message.receivedAt|date('c') }} - {% endif %} + {{ helper.formatTime(message.receivedAt) }} Finished Handling At - {% if helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(message.finishedAt) }} - {% else %} - {{ message.finishedAt|date('c') }} - {% endif %} + {{ helper.formatTime(message.finishedAt) }} diff --git a/templates/schedule.html.twig b/templates/schedule.html.twig index 272d97f..b114a29 100644 --- a/templates/schedule.html.twig +++ b/templates/schedule.html.twig @@ -123,19 +123,15 @@ {% endif %} - {% if message and helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(message.finishedAt) }} - {% elseif message %} - {{ message.finishedAt|date('c') }} + {% if message %} + {{ helper.formatTime(message.finishedAt) }} {% else %} Never {% endif %} - {% if message and helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(message.timeToHandle) }} - {% elseif message %} - {{ message.timeToHandle }}s + {% if message %} + {{ helper.formatDuration(message.timeToHandle) }} {% else %} - {% endif %} diff --git a/templates/statistics.html.twig b/templates/statistics.html.twig index d842708..d32608d 100644 --- a/templates/statistics.html.twig +++ b/templates/statistics.html.twig @@ -82,18 +82,10 @@ {% endif %} - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(metric.averageWaitTime) }} - {% else %} - {{ metric.averageWaitTime|round }}s - {% endif %} + {{ helper.formatDuration(metric.averageWaitTime) }} - {% if helper.canFormatDuration %} - {{ helper.timeFormatter.formatDuration(metric.averageHandlingTime) }} - {% else %} - {{ metric.averageHandlingTime|round }}s - {% endif %} + {{ helper.formatDuration(metric.averageHandlingTime) }} {{ metric.handledPerMinute|round(2) }} diff --git a/templates/transport.html.twig b/templates/transport.html.twig index e7209d7..e52264a 100644 --- a/templates/transport.html.twig +++ b/templates/transport.html.twig @@ -84,11 +84,7 @@ {% if queued.dispatchedAt %} - {% if helper.timeFormatter %} - {{ helper.timeFormatter.formatDiff(queued.dispatchedAt) }} - {% else %} - {{ queued.dispatchedAt|date('c') }} - {% endif %} + {{ helper.formatTime(queued.dispatchedAt) }} {% else %} n/a {% endif %} diff --git a/tests/Fixture/Factory/ProcessedMessageFactory.php b/tests/Fixture/Factory/ProcessedMessageFactory.php index 20b06b7..b55c797 100644 --- a/tests/Fixture/Factory/ProcessedMessageFactory.php +++ b/tests/Fixture/Factory/ProcessedMessageFactory.php @@ -31,11 +31,11 @@ protected function initialize(): static ->instantiateWith(Instantiator::withoutConstructor()->alwaysForce()) ->beforeInstantiate(function(array $attributes) { if (!isset($attributes['waitTime'])) { - $attributes['waitTime'] = \max(0, $attributes['receivedAt']->getTimestamp() - $attributes['dispatchedAt']->getTimestamp()); + $attributes['waitTime'] = \max(0, $attributes['receivedAt']->format('Uv') - $attributes['dispatchedAt']->format('Uv')); } if (!isset($attributes['processingTime'])) { - $attributes['handleTime'] = \max(0, $attributes['finishedAt']->getTimestamp() - $attributes['receivedAt']->getTimestamp()); + $attributes['handleTime'] = \max(0, $attributes['finishedAt']->format('Uv') - $attributes['receivedAt']->format('Uv')); } return $attributes; diff --git a/tests/Integration/History/Storage/ORMStorageTest.php b/tests/Integration/History/Storage/ORMStorageTest.php index 4b29859..ae52c48 100644 --- a/tests/Integration/History/Storage/ORMStorageTest.php +++ b/tests/Integration/History/Storage/ORMStorageTest.php @@ -46,7 +46,7 @@ public function average_wait_time(): void 'receivedAt' => $start->modify('+10 seconds'), ]); - $this->assertSame(15, (int) $this->storage()->averageWaitTime(Specification::new())); + $this->assertSame(15.0, $this->storage()->averageWaitTime(Specification::new())); } /** diff --git a/tests/Unit/History/Model/ProcessedMessageTest.php b/tests/Unit/History/Model/ProcessedMessageTest.php index 4526c02..9ef028c 100644 --- a/tests/Unit/History/Model/ProcessedMessageTest.php +++ b/tests/Unit/History/Model/ProcessedMessageTest.php @@ -36,6 +36,7 @@ final class ProcessedMessageTest extends TestCase public function minimal_constructor(): void { $start = self::mockTime()->now()->getTimestamp(); + $stamp = new MonitorStamp(); Clock::get()->sleep(1); @@ -64,9 +65,9 @@ public function id(): string|int|\Stringable|null $this->assertSame([], $message->tags()->all()); $this->assertSame([], $message->results()->all()); $this->assertSame('foo', $message->transport()); - $this->assertSame(1, $message->timeInQueue()); - $this->assertSame(2, $message->timeToHandle()); - $this->assertSame(3, $message->timeToProcess()); + $this->assertSame(1.0, $message->timeInQueue()); + $this->assertSame(2.0, $message->timeToHandle()); + $this->assertSame(3.0, $message->timeToProcess()); $this->assertFalse($message->isFailure()); $this->assertNull($message->failure()); $this->assertTrue($message->memoryUsage()->isGreaterThan(0)); @@ -101,7 +102,7 @@ public function id(): string|int|null $this->assertSame([['exception' => \RuntimeException::class, 'message' => 'failure', 'data' => []]], $message->results()->jsonSerialize()); $this->assertTrue($message->isFailure()); $this->assertSame('RuntimeException', (string) $message->failure()); - $this->assertSame('fail', $message->failure()->description()); + $this->assertSame('fail', $message->failure()?->description()); } /** @@ -139,4 +140,37 @@ public function id(): string|int|null $this->assertSame(StringableObject::class, $message->type()->class()); $this->assertSame('description value', $message->description()); } + + /** + * @test + */ + public function partial_seconds(): void + { + $start = self::mockTime('2024-10-06')->now(); + + $stamp = new MonitorStamp(); + + Clock::get()->sleep(1.1); + + $stamp = $stamp->markReceived('foo'); + + Clock::get()->sleep(2.2); + + $stamp = $stamp->markFinished(); + + $envelope = new Envelope(new \stdClass(), [$stamp]); + $message = new class($envelope, new Results([])) extends ProcessedMessage { + public function id(): string|int|\Stringable|null + { + return null; + } + }; + + $this->assertEquals($start, $message->dispatchedAt()); + $this->assertEquals($start->modify('+1100 milliseconds'), $message->receivedAt()); + $this->assertEquals($start->modify('+3300 milliseconds'), $message->finishedAt()); + $this->assertSame(1.1, $message->timeInQueue()); + $this->assertSame(2.2, $message->timeToHandle()); + $this->assertSame(3.3, \round($message->timeToProcess(), 1)); + } }