feat: improve logging (#310)

src/Api/Exception/ApiException.php

@@ -40,7 +40,7 @@ public function __construct(ClientResponseInterface $response, int $code = 0, Th
 
         parent::__construct(
             sprintf(
-                'Request failed. Status code: %s. Errors: %s',
+                'Request failed. Status code: %s. Message: %s',
                 $response->getStatusCode(),
                 $body['message']
             ),

src/Api/Service/AbstractApiService.php

@@ -55,43 +55,41 @@ public function doRequest(
         ];
 
         $logContext = [
-            'uri'     => $uri,
-            'method'  => $method,
-            'headers' => $options['headers'],
-            'body'    => $options['body'] ? json_decode($options['body'], true) : null,
+            'request' => [
+                'uri'     => $uri,
+                'method'  => $method,
+                'headers' => $options['headers'],
+                'body'    => $options['body'] ? json_decode($options['body'], true) : null,
+            ],
         ];
 
-        Logger::debug('Sending request to MyParcel', $logContext);
-
         try {
             $response = $this->clientAdapter->doRequest($method, $uri, $options);
         } catch (Throwable $e) {
             Logger::error(
-                'Error sending request to MyParcel',
-                ['error' => $e->getMessage()] + $logContext
+                'An exception was thrown while sending request',
+                array_replace($logContext, ['error' => $e->getMessage()])
             );
+
             throw new RuntimeException($e->getMessage(), $e->getCode(), $e);
         }
 
         /** @var \MyParcelNL\Pdk\Api\Contract\ApiResponseInterface $responseObject */
         $responseObject = new $responseClass($response);
+        $body           = $responseObject->getBody();
+
+        $logContext['response'] = [
+            'code' => $responseObject->getStatusCode(),
+            'body' => $body ? json_decode($body, true) : null,
+        ];
 
         if ($responseObject->isErrorResponse()) {
-            Logger::error(
-                'Received an error response from MyParcel',
-                [
-                    'code'   => $response->getStatusCode(),
-                    'errors' => $responseObject->getErrors(),
-                ] + $logContext
-            );
+            Logger::error('Received an error response', $logContext);
+
             throw new ApiException($response);
         }
 
-        $body = $responseObject->getBody();
-
-        Logger::debug('Received response from MyParcel', [
-            'response' => $body ? json_decode($body, true) : null,
-        ]);
+        Logger::debug('Successfully sent request', $logContext);
 
         return $responseObject;
     }

src/App/Api/PdkEndpoint.php

@@ -7,6 +7,7 @@
 use MyParcelNL\Pdk\Api\Exception\ApiException;
 use MyParcelNL\Pdk\Api\Exception\PdkEndpointException;
 use MyParcelNL\Pdk\App\Api\Contract\PdkApiInterface;
+use MyParcelNL\Pdk\Facade\Logger;
 use MyParcelNL\Pdk\Facade\Pdk;
 use Symfony\Component\HttpFoundation\JsonResponse;
 use Symfony\Component\HttpFoundation\Response;
@@ -49,11 +50,23 @@ public function call($input, string $context): Response
                 ->setContext($context)
                 ->execute($input);
         } catch (ApiException $e) {
+            // In case of an ApiException, AbstractApiService has already logged the error.
             return $this->createApiErrorResponse($e);
-        } catch (PdkEndpointException $e) {
-            return $this->createErrorResponse($e, $e->getStatusCode());
         } catch (Throwable $e) {
-            return $this->createErrorResponse($e);
+            if ($e instanceof PdkEndpointException) {
+                $response = $this->createErrorResponse($context, $e, $e->getStatusCode());
+            } else {
+                $response = $this->createErrorResponse($context, $e);
+            }
+
+            Logger::error('An exception was thrown while executing an action', [
+                'action'   => is_string($input) ? $input : $input->get('action') ?? 'unknown',
+                'context'  => $context,
+                // Pass backend context to log stack traces.
+                'response' => $this->createErrorContext(self::CONTEXT_BACKEND, $e),
+            ]);
+
+            return $response;
         }
     }
 
@@ -64,41 +77,66 @@ public function call($input, string $context): Response
      */
     public function createApiErrorResponse(ApiException $exception): JsonResponse
     {
-        return new JsonResponse(
-            [
-                'message'    => $exception->getMessage(),
-                'request_id' => $exception->getRequestId(),
-                'errors'     => $exception->getErrors(),
-            ],
-            Response::HTTP_BAD_REQUEST
-        );
+        return new JsonResponse([
+            'message'    => $exception->getMessage(),
+            'request_id' => $exception->getRequestId(),
+            'errors'     => $exception->getErrors(),
+        ], Response::HTTP_BAD_REQUEST);
     }
 
     /**
+     * @param  string     $context
      * @param  \Throwable $throwable
      * @param  int        $statusCode
      *
      * @return \Symfony\Component\HttpFoundation\JsonResponse
      */
     protected function createErrorResponse(
+        string    $context,
         Throwable $throwable,
         int       $statusCode = Response::HTTP_BAD_REQUEST
     ): JsonResponse {
-        return new JsonResponse(
-            [
-                'message' => $throwable->getMessage(),
-                'errors'  => [
-                    [
-                        'status'  => $statusCode,
-                        'code'    => $throwable->getCode(),
-                        'message' => $throwable->getMessage(),
-                        'trace'   => Pdk::isDevelopment()
-                            ? $throwable->getTrace()
-                            : 'Enable development mode to see stack trace.',
-                    ],
-                ],
-            ],
-            $statusCode
-        );
+        return new JsonResponse($this->createErrorContext($context, $throwable), $statusCode);
+    }
+
+    /**
+     * @param  string     $context
+     * @param  \Throwable $throwable
+     *
+     * @return array
+     */
+    private function createErrorContext(string $context, Throwable $throwable): array
+    {
+        $firstThrowable = $throwable;
+        $errors         = [$this->formatThrowable($firstThrowable, $context)];
+
+        while ($throwable = $throwable->getPrevious()) {
+            $errors[] = $this->formatThrowable($throwable, $context);
+        }
+
+        return [
+            'message' => $firstThrowable->getMessage(),
+            'errors'  => $errors,
+        ];
+    }
+
+    /**
+     * @param  \Throwable $throwable
+     * @param  string     $context
+     *
+     * @return array
+     */
+    private function formatThrowable(Throwable $throwable, string $context): array
+    {
+        return [
+            'code'    => $throwable->getCode(),
+            'message' => $throwable->getMessage(),
+            'file'    => $throwable->getFile(),
+            'line'    => $throwable->getLine(),
+            // Hide stack trace in frontend contexts unless in development mode
+            'trace'   => $context === self::CONTEXT_BACKEND || Pdk::isDevelopment()
+                ? $throwable->getTrace()
+                : 'Enable development mode to see stack trace.',
+        ];
     }
 }

tests/Bootstrap/MockApiExceptionAction.php

@@ -0,0 +1,42 @@
+<?php
+
+declare(strict_types=1);
+
+namespace MyParcelNL\Pdk\Tests\Bootstrap;
+
+use MyParcelNL\Pdk\Api\Exception\ApiException;
+use MyParcelNL\Pdk\Api\Response\ClientResponse;
+use MyParcelNL\Pdk\App\Action\Contract\ActionInterface;
+use Symfony\Component\HttpFoundation\Request;
+use Symfony\Component\HttpFoundation\Response;
+
+class MockApiExceptionAction implements ActionInterface
+{
+    /**
+     * @param  \Symfony\Component\HttpFoundation\Request $request
+     *
+     * @return \Symfony\Component\HttpFoundation\Response
+     * @throws \MyParcelNL\Pdk\Api\Exception\ApiException
+     */
+    public function handle(Request $request): Response
+    {
+        $body = [
+            'message'    => 'boom',
+            'errors'     => [
+                [
+                    'code'    => 24920,
+                    'message' => 'Something went wrong',
+                ],
+                [
+                    'code'    => 74892,
+                    'message' => 'Something else also went wrong',
+                ],
+            ],
+            'request_id' => '12345',
+        ];
+
+        $response = new ClientResponse(json_encode($body), Response::HTTP_BAD_REQUEST);
+
+        throw new ApiException($response);
+    }
+}

tests/Bootstrap/MockExceptionAction.php

@@ -0,0 +1,25 @@
+<?php
+
+declare(strict_types=1);
+
+namespace MyParcelNL\Pdk\Tests\Bootstrap;
+
+use MyParcelNL\Pdk\App\Action\Contract\ActionInterface;
+use RuntimeException;
+use Symfony\Component\HttpFoundation\Request;
+use Symfony\Component\HttpFoundation\Response;
+
+class MockExceptionAction implements ActionInterface
+{
+    /**
+     * @param  \Symfony\Component\HttpFoundation\Request $request
+     *
+     * @return \Symfony\Component\HttpFoundation\Response
+     */
+    public function handle(Request $request): Response
+    {
+        $previous = new RuntimeException('Previous exception', 1);
+
+        throw new RuntimeException('Something went terribly wrong', 5, $previous);
+    }
+}