Extra logs

Controller/Checkout/Redirect.php

@@ -74,7 +74,7 @@ public function execute()
                 $redirectUrl = $order->getPayment()->getAdditionalInformation(PaymentField::REDIRECT_URL_FIELD_NAME);
                 $paymentId = $order->getPayment()->getAdditionalInformation(PaymentField::PAYMENT_ID_FIELD_NAME);
                 if ($redirectUrl) {
-                    $this->logger->info(
+                    $this->logger->debug(
                         'Redirecting to payment provider page',
                         [
                             PaymentField::EXTERNAL_ID_FIELD_NAME => $order->getRealOrderId(),

Controller/Checkout/Success.php

@@ -121,15 +121,19 @@ private function retrievePaymentStatusAndUpdateOrder()
     {
         $allPayments = $this->order->getAllPayments();
         $lastPaymentId = end($allPayments)->getAdditionalInformation(PaymentField::PAYMENT_ID_FIELD_NAME);
-
         $loggerContext = [PaymentField::PAYMENT_ID_FIELD_NAME => $lastPaymentId];
+        $this->logger->info(
+            "Retrieving payment status",
+            $loggerContext
+        );
+
         try {
             $service = new Payment($this->paymentHelper->initializePaynowClient());
             $paymentStatusObject  = $service->status($lastPaymentId);
             $status = $paymentStatusObject ->getStatus();
-            $this->logger->debug(
-                "Retrieved status response",
-                array_merge($loggerContext, [$status])
+            $this->logger->info(
+                "Retrieved payment status response",
+                array_merge($loggerContext, [PaymentField::STATUS_FIELD_NAME => $status])
             );
             $this->notificationProcessor->process($lastPaymentId, $status, $this->order->getIncrementId());
 

Controller/Payment/Notifications.php

@@ -90,7 +90,7 @@ public function execute()
     {
         $payload          = $this->getRequest()->getContent();
         $notificationData = json_decode($payload, true);
-        $this->logger->debug("Received payment status notification", $notificationData);
+        $this->logger->info("Received payment status notification", $notificationData);
         $storeId      = $this->storeManager->getStore()->getId();
         $signatureKey = $this->configHelper->getSignatureKey($storeId, $this->configHelper->isTestMode($storeId));
 
@@ -118,7 +118,10 @@ public function execute()
             );
             $this->getResponse()->setHttpResponseCode(400);
         } catch (OrderHasBeenAlreadyPaidException $exception) {
-            $this->logger->info($exception->getMessage() . ' Skip processing the notification.');
+            $this->logger->info(
+                $exception->getMessage() . ' Skip processing the notification.',
+                $notificationData
+            );
             $this->getResponse()->setHttpResponseCode(200);
         }
     }

Gateway/Http/Client/PaymentAuthorization.php

@@ -54,7 +54,7 @@ public function placeRequest(TransferInterface $transferObject)
                 $transferObject->getBody(),
                 $transferObject->getHeaders()[PaymentField::IDEMPOTENCY_KEY_FIELD_NAME]
             );
-            $this->logger->debug(
+            $this->logger->info(
                 "Retrieved authorization response",
                 array_merge($loggerContext, [
                     PaymentField::STATUS_FIELD_NAME => $apiResponseObject->getStatus(),
@@ -65,13 +65,16 @@ public function placeRequest(TransferInterface $transferObject)
                 PaymentField::REDIRECT_URL_FIELD_NAME => $apiResponseObject->getRedirectUrl(),
                 PaymentField::STATUS_FIELD_NAME => $apiResponseObject->getStatus(),
                 PaymentField::PAYMENT_ID_FIELD_NAME => $apiResponseObject->getPaymentId(),
+                PaymentField::EXTERNAL_ID_FIELD_NAME => $transferObject->getBody()[PaymentField::EXTERNAL_ID_FIELD_NAME]
             ];
         } catch (PaynowException $exception) {
             $this->logger->error(
-                $exception->getMessage(),
+                'An error occurred during payment authorization',
                 array_merge($loggerContext, [
                     'service' => 'Payment',
-                    'action' => 'authorize'
+                    'action' => 'authorize',
+                    'message' => $exception->getMessage(),
+                    'errors' => $exception->getPrevious()->getErrors()
                 ])
             );
             foreach ($exception->getErrors() as $error) {

Gateway/Http/Client/PaymentCapture.php

@@ -49,19 +49,24 @@ public function placeRequest(TransferInterface $transferObject)
                 PaymentField::STATUS_FIELD_NAME => $apiResponseObject->getStatus(),
                 PaymentField::PAYMENT_ID_FIELD_NAME => $apiResponseObject->getPaymentId(),
             ];
-            $this->logger->debug(
+            $this->logger->info(
                 "Retrieved capture response",
                 array_merge($loggerContext, $response)
             );
         } catch (PaynowException $exception) {
             $response['errors'] = $exception->getMessage();
-            $this->logger->error($exception->getMessage(), array_merge(
-                $loggerContext,
-                [
-                    'service' => 'Payment',
-                    'action' => 'status'
-                ]
-            ));
+            $this->logger->error(
+                'An error occurred during payment capture',
+                array_merge(
+                    $loggerContext,
+                    [
+                        'service' => 'Payment',
+                        'action' => 'status',
+                        'message' => $exception->getMessage(),
+                        'errors' => $exception->getPrevious()->getErrors()
+                    ]
+                )
+            );
         }
 
         return $response;

Gateway/Http/Client/PaymentRefund.php

@@ -49,15 +49,21 @@ public function placeRequest(TransferInterface $transferObject)
         $loggerContext = [
             PaymentField::EXTERNAL_ID_FIELD_NAME => $transferObject->getBody()[PaymentField::EXTERNAL_ID_FIELD_NAME]
         ];
+        $data = $transferObject->getBody();
+        $this->logger->info(
+            "Processing create refund",
+            array_merge($loggerContext, [
+                PaymentField::PAYMENT_ID_FIELD_NAME => $data[PaymentField::PAYMENT_ID_FIELD_NAME],
+                RefundField::AMOUNT_FIELD_NAME => $data[RefundField::AMOUNT_FIELD_NAME]
+            ])
+        );
         try {
-            $service = new Refund($this->client);
-            $data = $transferObject->getBody();
-            $apiResponseObject = $service->create(
+            $apiResponseObject = (new Refund($this->client))->create(
                 $data[PaymentField::PAYMENT_ID_FIELD_NAME],
                 $transferObject->getHeaders()[PaymentField::IDEMPOTENCY_KEY_FIELD_NAME],
                 $data[RefundField::AMOUNT_FIELD_NAME]
             );
-            $this->logger->debug(
+            $this->logger->info(
                 "Retrieved create refund response",
                 array_merge($loggerContext, [
                     RefundField::STATUS_FIELD_NAME => $apiResponseObject->getStatus(),
@@ -71,10 +77,12 @@ public function placeRequest(TransferInterface $transferObject)
             ];
         } catch (PaynowException $exception) {
             $this->logger->error(
-                $exception->getMessage(),
+                'An error occurred during refund create',
                 array_merge($loggerContext, [
                     'service' => 'Refund',
-                    'action' => 'create'
+                    'action' => 'create',
+                    'message' => $exception->getMessage(),
+                    'errors' => $exception->getPrevious()->getErrors()
                 ])
             );
             foreach ($exception->getErrors() as $error) {

Gateway/Validator/Payment/AuthorizationValidator.php

@@ -45,7 +45,12 @@ public function validate(array $validationSubject)
             array_key_exists(PaymentField::STATUS_FIELD_NAME, $response) &&
             $response[PaymentField::STATUS_FIELD_NAME] === Status::STATUS_NEW;
 
-        $this->logger->debug("Validating authorization response", ['valid' => $isResponseValid]);
+        $this->logger->debug("Validating authorization response", [
+            PaymentField::EXTERNAL_ID_FIELD_NAME => $response[PaymentField::EXTERNAL_ID_FIELD_NAME],
+            PaymentField::PAYMENT_ID_FIELD_NAME => $response[PaymentField::PAYMENT_ID_FIELD_NAME],
+            PaymentField::STATUS_FIELD_NAME => $response[PaymentField::STATUS_FIELD_NAME],
+            'valid' => $isResponseValid
+        ]);
 
         return $this->createResult(
             $isResponseValid,

Gateway/Validator/Payment/CaptureValidator.php

@@ -40,19 +40,28 @@ public function __construct(ResultInterfaceFactory $resultFactory, Logger $logge
     public function validate(array $validationSubject)
     {
         $response = SubjectReader::readResponse($validationSubject);
-        $isResponseValid = array_key_exists(PaymentField::PAYMENT_ID_FIELD_NAME, $response) &&
-            array_key_exists(PaymentField::STATUS_FIELD_NAME, $response) &&
-            $response[PaymentField::STATUS_FIELD_NAME] === Status::STATUS_CONFIRMED;
 
-        $this->logger->debug(
+        $this->logger->info(
             "Validating capture response",
             [
-                'valid' => $isResponseValid,
                 'paymentId' => $response[PaymentField::PAYMENT_ID_FIELD_NAME],
                 'status' => $response[PaymentField::STATUS_FIELD_NAME]
             ]
         );
 
+        $isResponseValid = array_key_exists(PaymentField::PAYMENT_ID_FIELD_NAME, $response) &&
+                           array_key_exists(PaymentField::STATUS_FIELD_NAME, $response) &&
+                           $response[PaymentField::STATUS_FIELD_NAME] === Status::STATUS_CONFIRMED;
+
+        $this->logger->info(
+            "Capture response has been validated",
+            [
+                PaymentField::PAYMENT_ID_FIELD_NAME => $response[PaymentField::PAYMENT_ID_FIELD_NAME],
+                PaymentField::STATUS_FIELD_NAME => $response[PaymentField::STATUS_FIELD_NAME],
+                'valid' => $isResponseValid,
+            ]
+        );
+
         return $this->createResult(
             $isResponseValid,
             $isResponseValid ? [] : [__('Error occurred during the capture process.')]

Gateway/Validator/Refund/RefundValidator.php

@@ -40,11 +40,26 @@ public function __construct(ResultInterfaceFactory $resultFactory, Logger $logge
     public function validate(array $validationSubject)
     {
         $response = SubjectReader::readResponse($validationSubject);
+        $this->logger->info(
+            "Validating refund response",
+            [
+                RefundField::REFUND_ID_FIELD_NAME => $response[RefundField::REFUND_ID_FIELD_NAME],
+                RefundField::STATUS_FIELD_NAME => $response[RefundField::STATUS_FIELD_NAME],
+            ]
+        );
+
         $isResponseValid = array_key_exists(RefundField::REFUND_ID_FIELD_NAME, $response) &&
                            array_key_exists(RefundField::STATUS_FIELD_NAME, $response) &&
                             $response[RefundField::STATUS_FIELD_NAME] === Status::STATUS_PENDING;
 
-        $this->logger->debug("Validating refund response", ['valid' => $isResponseValid]);
+        $this->logger->info(
+            "Refund response has been validated",
+            [
+                RefundField::REFUND_ID_FIELD_NAME => $response[RefundField::REFUND_ID_FIELD_NAME],
+                RefundField::STATUS_FIELD_NAME => $response[RefundField::STATUS_FIELD_NAME],
+                'valid' => $isResponseValid
+            ]
+        );
 
         return $this->createResult(
             $isResponseValid,

Helper/NotificationProcessor.php

@@ -72,9 +72,11 @@ public function __construct(
     public function process($paymentId, $status, $externalId)
     {
         $this->loggerContext = [
+            PaymentField::EXTERNAL_ID_FIELD_NAME => $externalId,
             PaymentField::PAYMENT_ID_FIELD_NAME => $paymentId,
-            PaymentField::EXTERNAL_ID_FIELD_NAME => $externalId
+            PaymentField::STATUS_FIELD_NAME => $status
         ];
+        $this->logger->info("Processing payment status notification", $this->loggerContext);
 
         /** @var Order */
         $this->order = $this->orderFactory->create()->loadByIncrementId($externalId);
@@ -86,8 +88,17 @@ public function process($paymentId, $status, $externalId)
         $orderPaymentStatus = $paymentAdditionalInformation[PaymentField::STATUS_FIELD_NAME];
         $finalPaymentStatus = $orderPaymentStatus == Status::STATUS_CONFIRMED;
 
+        $this->logger->debug(
+            "Current order state",
+            array_merge(
+                [
+                    'currentStatus' => $orderPaymentStatus
+                ],
+                $this->loggerContext
+            )
+        );
+
         if ($finalPaymentStatus) {
-            $this->logger->info('Order has paid status. Skipped notification processing', $this->loggerContext);
             throw new OrderHasBeenAlreadyPaidException($externalId, $paymentId);
         }
 
@@ -121,6 +132,7 @@ public function process($paymentId, $status, $externalId)
                 break;
         }
         $this->orderRepository->save($this->order);
+        $this->logger->info("Finished processing payment status notification", $this->loggerContext);
     }
 
     private function paymentNew($paymentId)
@@ -203,7 +215,7 @@ private function paymentRejected()
             $this->order->addCommentToStatusHistory($message);
         }
 
-            $this->order->getPayment()->setIsClosed(true);
+        $this->order->getPayment()->setIsClosed(true);
     }
 
     /**
@@ -241,6 +253,7 @@ private function isCorrectStatus($previousStatus, $nextStatus): bool
     {
         $paymentStatusFlow = [
             Status::STATUS_NEW => [
+                Status::STATUS_NEW,
                 Status::STATUS_PENDING,
                 Status::STATUS_ERROR,
                 Status::STATUS_EXPIRED,

Model/Exception/OrderHasBeenAlreadyPaidException.php

@@ -11,7 +11,7 @@
  */
 class OrderHasBeenAlreadyPaidException extends Exception
 {
-    const EXCEPTION_MESSAGE = 'Order %s has been already paid in %s.';
+    const EXCEPTION_MESSAGE = 'An order %s has been already paid in %s.';
 
     public function __construct($orderId, $paymentId)
     {

Test/Unit/Gateway/Response/Payment/AuthorizationHandlerTest.php

@@ -34,6 +34,7 @@ public function testHandle()
             PaymentField::PAYMENT_ID_FIELD_NAME => 'testPaymentId',
             PaymentField::STATUS_FIELD_NAME => 'NEW',
             PaymentField::REDIRECT_URL_FIELD_NAME => 'testRedirectUrl',
+            PaymentField::EXTERNAL_ID_FIELD_NAME => 'testExternalId',
         ];
 
         $paymentDO->expects(static::atLeastOnce())

composer.json

@@ -2,7 +2,7 @@
   "name": "pay-now/paynow-magento2",
   "description": "Module for Paynow payments",
   "type": "magento2-module",
-  "version": "1.1.0",
+  "version": "1.1.2",
   "license": "MIT",
   "keywords": [
     "paynow",

etc/module.xml

@@ -1,7 +1,7 @@
 <?xml version="1.0"?>
 <config xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:noNamespaceSchemaLocation="urn:magento:framework:Module/etc/module.xsd">
-    <module name="Paynow_PaymentGateway" setup_version="1.1.0">
+    <module name="Paynow_PaymentGateway" setup_version="1.1.2">
         <sequence>
             <module name="Magento_Sales"/>
             <module name="Magento_Payment"/>