From 85142b6d8d390b6094cd9f1641bea83ed721301c Mon Sep 17 00:00:00 2001
From: avermeulen <andre.vermeulen@jtl-software.com>
Date: Tue, 8 Feb 2022 11:04:23 +0100
Subject: [PATCH] Extend logging. Write log before event is handled

---
 .../Message/AmqpTransportableMessage.php        |  2 ++
 .../AbstractAmqpTransportableMessage.php        | 10 +++++++++-
 src/Transport/Amqp/AmqpTransport.php            |  2 ++
 tests/Message/AbstractEventTest.php             | 17 +++++++++++++++++
 tests/Transport/Amqp/AmqpTransportTest.php      |  3 ++-
 5 files changed, 32 insertions(+), 2 deletions(-)

diff --git a/src/Contract/Message/AmqpTransportableMessage.php b/src/Contract/Message/AmqpTransportableMessage.php
index ff69c71..3bc94b7 100644
--- 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
index b0cda94..a350415 100644
--- 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
index 90b7ebc..8c0c73a 100644
--- 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) . " wich is createt 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
index 2a132d6..767a3c8 100644
--- 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
index 2825932..c6e4a81 100644
--- 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, [