Merge pull request #115 from kbond/feat/microseconds

feat!: store `wait_time`/`handle_time` in milliseconds

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

config/doctrine/mapping/ProcessedMessage.orm.xml

@@ -11,8 +11,8 @@
         <field name="dispatchedAt" column="dispatched_at" type="datetime_immutable" />
         <field name="receivedAt" column="received_at" type="datetime_immutable" />
         <field name="finishedAt" column="finished_at" type="datetime_immutable" />
-        <field name="waitTime" column="wait_time" type="integer" />
-        <field name="handleTime" column="handle_time" type="integer" />
+        <field name="waitTime" column="wait_time" type="bigint" />
+        <field name="handleTime" column="handle_time" type="bigint" />
         <field name="memoryUsage" column="memory_usage" type="integer" />
         <field name="transport" column="transport" />
         <field name="tags" column="tags" nullable="true" />

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,
         ]);
     }

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,

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

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();

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;

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();

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

templates/components/messages.html.twig

@@ -47,11 +47,7 @@
                             <a href="{{ path('zenstruck_messenger_monitor_history', app.request.query.all|merge({transport: message.transport})) }}" class="badge align-text-top text-bg-secondary">{{ message.transport }}</a>
                         </td>
                         <td class="text-center">
-                            {% if helper.canFormatDuration %}
-                                <abbr title="{{ message.timeToHandle }}s">{{ helper.timeFormatter.formatDuration(message.timeToHandle) }}</abbr>
-                            {% else %}
-                                {{ message.timeToHandle }}s
-                            {% endif %}
+                            <abbr title="{{ message.timeToHandle }}s">{{ helper.formatDuration(message.timeToHandle) }}</abbr>
                         </td>
                         <td class="text-center">
                             {{ message.memoryUsage }}
@@ -64,11 +60,7 @@
                             {% endfor %}
                         </td>
                         <td>
-                            {% if helper.timeFormatter %}
-                                <abbr title="{{ message.finishedAt|date('c') }}">{{ helper.timeFormatter.formatDiff(message.finishedAt) }}</abbr>
-                            {% else %}
-                                {{ message.finishedAt|date('c') }}
-                            {% endif %}
+                            <abbr title="{{ message.finishedAt|date('c') }}">{{ helper.formatTime(message.finishedAt) }}</abbr>
                         </td>
                         <td>
                             <a href="{{ path('zenstruck_messenger_monitor_detail', {id: message.id}) }}" class="btn btn-sm btn-secondary d-inline-flex align-items-center" data-controller="message-details" data-action="message-details#click">

templates/components/snapshot.html.twig

@@ -35,21 +35,13 @@
             <tr>
                 <th class="text-end">Average Wait Time</th>
                 <td>
-                    {% if helper.canFormatDuration %}
-                        <abbr title="{{ snapshot.averageWaitTime|round }}s">{{ helper.timeFormatter.formatDuration(snapshot.averageWaitTime) }}</abbr>
-                    {% else %}
-                        {{ snapshot.averageWaitTime|round }}s
-                    {% endif %}
+                    <abbr title="{{ snapshot.averageWaitTime|round }}s">{{ helper.formatDuration(snapshot.averageWaitTime) }}</abbr>
                 </td>
             </tr>
             <tr>
                 <th class="text-end">Average Handling Time</th>
                 <td>
-                    {% if helper.canFormatDuration %}
-                        <abbr title="{{ snapshot.averageHandlingTime|round }}s">{{ helper.timeFormatter.formatDuration(snapshot.averageHandlingTime) }}</abbr>
-                    {% else %}
-                        {{ snapshot.averageHandlingTime|round }}s
-                    {% endif %}
+                    <abbr title="{{ snapshot.averageHandlingTime|round }}s">{{ helper.formatDuration(snapshot.averageHandlingTime) }}</abbr>
                 </td>
             </tr>
             <tr>