From f7088ef6e35dd6ec7cb93e8ac32cf53fdb1c15bd Mon Sep 17 00:00:00 2001 From: Victor Welling Date: Tue, 28 Aug 2018 17:58:13 +0200 Subject: [PATCH] Added error logging to logging middleware --- src/Middleware/LoggingMiddleware.php | 52 +++++++++++++--------- tests/Middleware/LoggingMiddlewareTest.php | 28 ++++++++++++ 2 files changed, 60 insertions(+), 20 deletions(-) diff --git a/src/Middleware/LoggingMiddleware.php b/src/Middleware/LoggingMiddleware.php index f9a03ea..0d49c82 100644 --- a/src/Middleware/LoggingMiddleware.php +++ b/src/Middleware/LoggingMiddleware.php @@ -8,6 +8,7 @@ use Shoot\Shoot\HasPresenterInterface; use Shoot\Shoot\MiddlewareInterface; use Shoot\Shoot\View; +use Throwable; /** * Logs all views being processed by Shoot. It's recommended to add this before any other middleware. @@ -36,36 +37,47 @@ public function __construct(LoggerInterface $logger) * @param callable $next * * @return View + * + * @throws Throwable */ public function process(View $view, ServerRequestInterface $request, callable $next): View { - $startTime = microtime(true); + $context = []; + $message = $view->getName(); - /** @var View $view */ - $view = $next($view); + try { + $startTime = microtime(true); - $endTime = microtime(true); + /** @var View $view */ + $view = $next($view); - $presentationModel = $view->getPresentationModel(); + $endTime = microtime(true); - $fields = [ - 'presentation_model' => $presentationModel->getName(), - 'time_taken' => sprintf("%f seconds", $endTime - $startTime), - 'variables' => $presentationModel->getVariables(), - ]; + $presentationModel = $view->getPresentationModel(); - if ($presentationModel instanceof HasPresenterInterface) { - $fields['presenter_name'] = $presentationModel->getPresenterName(); - } + $context['presentation_model'] = $presentationModel->getName(); - if ($view->hasSuppressedException()) { - $fields['exception'] = $view->getSuppressedException(); + if ($presentationModel instanceof HasPresenterInterface) { + $context['presenter_name'] = $presentationModel->getPresenterName(); + } - $this->logger->warning($view->getName(), $fields); - } else { - $this->logger->debug($view->getName(), $fields); - } + $context['time_taken'] = sprintf("%f seconds", $endTime - $startTime); + + if ($view->hasSuppressedException()) { + $context['exception'] = $view->getSuppressedException(); - return $view; + $this->logger->warning($message, $context); + } else { + $this->logger->debug($message, $context); + } + + return $view; + } catch (Throwable $exception) { + $context['exception'] = $exception; + + $this->logger->error($message, $context); + + throw $exception; + } } } diff --git a/tests/Middleware/LoggingMiddlewareTest.php b/tests/Middleware/LoggingMiddlewareTest.php index d525495..e2ecc1e 100644 --- a/tests/Middleware/LoggingMiddlewareTest.php +++ b/tests/Middleware/LoggingMiddlewareTest.php @@ -3,6 +3,7 @@ namespace Shoot\Shoot\Tests\Middleware; +use Exception; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; use Psr\Http\Message\ServerRequestInterface; @@ -79,4 +80,31 @@ public function testShouldLogSuppressedExceptions() $middleware = new LoggingMiddleware($logger); $middleware->process($view, $this->request, $this->next); } + + /** + * @return void + */ + public function testShouldLogUncaughtExceptions() + { + $view = ViewFactory::create(); + + $next = function () { + throw new Exception(); + }; + + /** @var LoggerInterface|MockObject $logger */ + $logger = $this->createMock(LoggerInterface::class); + $logger + ->expects($this->once()) + ->method('error') + ->with( + $this->equalTo('item.twig'), + $this->arrayHasKey('exception') + ); + + $this->expectException(Exception::class); + + $middleware = new LoggingMiddleware($logger); + $middleware->process($view, $this->request, $next); + } }