Extend logging. Write log before event is handled

jtl-software · Feb 9, 2022 · cf2bb4d · cf2bb4d
1 parent 03ed6fa
commit cf2bb4d
Show file tree

Hide file tree

Showing 5 changed files with 32 additions and 2 deletions.
diff --git a/src/Contract/Message/AmqpTransportableMessage.php b/src/Contract/Message/AmqpTransportableMessage.php
@@ -25,4 +25,6 @@ public function getMessageId(): string;
     public function setLastError(string $errorMessage): void;
 
     public function isDeadLetter(): bool;
+
+    public function getCreatedAt(): \DateTimeImmutable;
 }
diff --git a/src/Message/AbstractAmqpTransportableMessage.php b/src/Message/AbstractAmqpTransportableMessage.php
@@ -40,9 +40,12 @@ abstract class AbstractAmqpTransportableMessage implements AmqpTransportableMess
 
     private string $__eventId;
 
-    public function __construct(string $messageId = null)
+    private \DateTimeImmutable $createdAt;
+
+    public function __construct(string $messageId = null, \DateTimeImmutable $createdAt = null)
     {
         $this->__eventId = $messageId ?? Uuid::uuid4()->toString();
+        $this->createdAt = $createdAt ?? new \DateTimeImmutable();
     }
 
     public static function getRoutingKey(): string
@@ -94,4 +97,9 @@ public function __wakeup()
     {
         ++$this->__receiveCount;
     }
+
+    public function getCreatedAt(): \DateTimeImmutable
+    {
+        return $this->createdAt;
+    }
 }
diff --git a/src/Transport/Amqp/AmqpTransport.php b/src/Transport/Amqp/AmqpTransport.php
@@ -237,9 +237,11 @@ private function createCallbackFromHandler(Closure $handler): Closure
                     ));
                     $this->handleUnprocessableMessage($message);
                 } else {
+                    $this->logger->info('Handle message of type ' . get_class($event) . " which is created at {$event->getCreatedAt()->format('c')}");
                     if ($this->listenerProvider->eventHasListeners($event)) {
                         try {
                             $handler($event);
+                            $this->logger->debug('Handled message of type ' . get_class($event) . "successful");
                         } catch (Exception|Throwable $exception) {
                             $this->logError($exception->__toString());
                             $this->handleFailedMessage($message, $event, $exception);

diff --git a/tests/Message/AbstractEventTest.php b/tests/Message/AbstractEventTest.php
@@ -91,4 +91,21 @@ public function testCanSetReceiveCount(): void
         $message->setReceiveCount($receiveCount);
         $this->assertEquals($receiveCount, $message->getReceiveCount());
     }
+
+    public function testCanBeCreatedWithCreatedAt(): void
+    {
+        $createdAt = new \DateTimeImmutable();
+        $sut = new TestAmqpMessage(uniqid(), $createdAt);
+
+        self::assertSame($createdAt, $sut->getCreatedAt());
+    }
+
+    public function testCanBeCreatedWithoutCreatedAt(): void
+    {
+        $before = new \DateTimeImmutable();
+        $sut = new TestAmqpMessage(uniqid());
+        $after = new \DateTimeImmutable();
+
+        self::assertTrue($sut->getCreatedAt() > $before && $sut->getCreatedAt() < $after);
+    }
 }
diff --git a/tests/Transport/Amqp/AmqpTransportTest.php b/tests/Transport/Amqp/AmqpTransportTest.php
@@ -163,7 +163,8 @@ public function setUp(): void
         $this->message = Mockery::mock(AmqpTransportableMessage::class, [
             'getRoutingKey' => $this->routingKey,
             'getExchange' => $this->exchange,
-            'getMaxRetryCount' => 3
+            'getMaxRetryCount' => 3,
+            'getCreatedAt' => new \DateTimeImmutable()
         ]);
 
         $this->subscriptionSettings = Mockery::mock(SubscriptionSettings::class, [