From 64dc16e4d9378817ad210198a944d55ce1febbfc Mon Sep 17 00:00:00 2001 From: Igor Scheller Date: Sun, 19 Apr 2020 20:41:38 +0200 Subject: [PATCH] Logger: Added handling for exceptions and log exceptions if they occur --- src/Exceptions/ExceptionsServiceProvider.php | 17 ++++++++ src/Exceptions/Handlers/Legacy.php | 21 ++++++++++ src/Logger/Logger.php | 29 ++++++++++--- src/Logger/UserAwareLogger.php | 4 +- tests/Feature/Logger/LoggerTest.php | 21 ++++++++++ .../ExceptionsServiceProviderTest.php | 41 +++++++++++++++---- tests/Unit/Exceptions/Handlers/LegacyTest.php | 35 ++++++++++++---- .../Unit/Logger/LoggerServiceProviderTest.php | 2 +- .../Renderer/Twig/Extensions/DevelopTest.php | 2 +- 9 files changed, 148 insertions(+), 24 deletions(-) diff --git a/src/Exceptions/ExceptionsServiceProvider.php b/src/Exceptions/ExceptionsServiceProvider.php index a9bc2b17..4b53c726 100644 --- a/src/Exceptions/ExceptionsServiceProvider.php +++ b/src/Exceptions/ExceptionsServiceProvider.php @@ -7,6 +7,7 @@ use Engelsystem\Exceptions\Handlers\HandlerInterface; use Engelsystem\Exceptions\Handlers\Legacy; use Engelsystem\Exceptions\Handlers\LegacyDevelopment; use Engelsystem\Exceptions\Handlers\Whoops; +use Psr\Log\LoggerInterface; use Whoops\Run as WhoopsRunner; class ExceptionsServiceProvider extends ServiceProvider @@ -28,6 +29,7 @@ class ExceptionsServiceProvider extends ServiceProvider $request = $this->app->get('request'); $handler->setRequest($request); + $this->addLogger($handler); } /** @@ -55,4 +57,19 @@ class ExceptionsServiceProvider extends ServiceProvider $this->app->instance('error.handler.development', $handler); $errorHandler->setHandler(Handler::ENV_DEVELOPMENT, $handler); } + + /** + * @param Handler $handler + */ + protected function addLogger(Handler $handler) + { + foreach ($handler->getHandler() as $h) { + if (!method_exists($h, 'setLogger')) { + continue; + } + + $log = $this->app->get(LoggerInterface::class); + $h->setLogger($log); + } + } } diff --git a/src/Exceptions/Handlers/Legacy.php b/src/Exceptions/Handlers/Legacy.php index 45285a8d..f8ff8e62 100644 --- a/src/Exceptions/Handlers/Legacy.php +++ b/src/Exceptions/Handlers/Legacy.php @@ -3,10 +3,14 @@ namespace Engelsystem\Exceptions\Handlers; use Engelsystem\Http\Request; +use Psr\Log\LoggerInterface; use Throwable; class Legacy implements HandlerInterface { + /** @var LoggerInterface */ + protected $log; + /** * @param Request $request * @param Throwable $e @@ -29,6 +33,23 @@ class Legacy implements HandlerInterface $e->getLine(), json_encode($e->getTrace()) )); + + if (is_null($this->log)) { + return; + } + + try { + $this->log->critical('', ['exception' => $e]); + } catch (Throwable $e) { + } + } + + /** + * @param LoggerInterface $logger + */ + public function setLogger(LoggerInterface $logger) + { + $this->log = $logger; } /** diff --git a/src/Logger/Logger.php b/src/Logger/Logger.php index 1cbc3a88..e3d3cacd 100644 --- a/src/Logger/Logger.php +++ b/src/Logger/Logger.php @@ -6,6 +6,7 @@ use Engelsystem\Models\LogEntry; use Psr\Log\AbstractLogger; use Psr\Log\InvalidArgumentException; use Psr\Log\LogLevel; +use Throwable; class Logger extends AbstractLogger { @@ -34,15 +35,13 @@ class Logger extends AbstractLogger /** * Logs with an arbitrary level. * - * @TODO: Implement $context['exception'] - * * @param mixed $level * @param string $message * @param array $context * * @throws InvalidArgumentException */ - public function log($level, $message, array $context = []) + public function log($level, $message, array $context = []): void { if (!$this->checkLevel($level)) { throw new InvalidArgumentException('Unknown log level: ' . $level); @@ -50,6 +49,10 @@ class Logger extends AbstractLogger $message = $this->interpolate($message, $context); + if (isset($context['exception']) && $context['exception'] instanceof Throwable) { + $message .= $this->formatException($context['exception']); + } + $this->log->create(['level' => $level, 'message' => $message]); } @@ -60,7 +63,7 @@ class Logger extends AbstractLogger * @param array $context * @return string */ - protected function interpolate($message, array $context = []) + protected function interpolate($message, array $context = []): string { foreach ($context as $key => $val) { // check that the value can be casted to string @@ -75,11 +78,27 @@ class Logger extends AbstractLogger return $message; } + /** + * @param Throwable $e + * @return string + */ + protected function formatException(Throwable $e): string + { + return sprintf( + implode(PHP_EOL, ['', 'Exception: %s', 'File: %s:%u', 'Code: %s', 'Trace:', '%s']), + $e->getMessage(), + $e->getFile(), + $e->getLine(), + $e->getCode(), + $e->getTraceAsString() + ); + } + /** * @param string $level * @return bool */ - protected function checkLevel($level) + protected function checkLevel($level): bool { return in_array($level, $this->allowedLevels); } diff --git a/src/Logger/UserAwareLogger.php b/src/Logger/UserAwareLogger.php index 43975b65..0d569347 100644 --- a/src/Logger/UserAwareLogger.php +++ b/src/Logger/UserAwareLogger.php @@ -19,7 +19,7 @@ class UserAwareLogger extends Logger * * @throws InvalidArgumentException */ - public function log($level, $message, array $context = []) + public function log($level, $message, array $context = []): void { if ($this->auth && ($user = $this->auth->user())) { $message = sprintf('%s (%u): %s', $user->name, $user->id, $message); @@ -31,7 +31,7 @@ class UserAwareLogger extends Logger /** * @param Authenticator $auth */ - public function setAuth(Authenticator $auth) + public function setAuth(Authenticator $auth): void { $this->auth = $auth; } diff --git a/tests/Feature/Logger/LoggerTest.php b/tests/Feature/Logger/LoggerTest.php index aac5aee8..9edec4d3 100644 --- a/tests/Feature/Logger/LoggerTest.php +++ b/tests/Feature/Logger/LoggerTest.php @@ -5,6 +5,7 @@ namespace Engelsystem\Test\Feature\Logger; use Engelsystem\Logger\Logger; use Engelsystem\Models\LogEntry; use Engelsystem\Test\Feature\ApplicationFeatureTest; +use Exception; use Psr\Log\InvalidArgumentException; use Psr\Log\LoggerInterface; use Psr\Log\LogLevel; @@ -144,6 +145,26 @@ class LoggerTest extends ApplicationFeatureTest $logger->log('This log level should never be defined', 'Some message'); } + /** + * @covers \Engelsystem\Logger\Logger::formatException + * @covers \Engelsystem\Logger\Logger::log + */ + public function testWithException() + { + $logger = $this->getLogger(); + + $logger->log(LogLevel::CRITICAL, 'Some random message', ['exception' => new Exception('Oops', 42)]); + $line = __LINE__ - 1; + + $entry = $this->getLastEntry(); + $this->assertStringContainsString('Some random message', $entry['message']); + $this->assertStringContainsString('Oops', $entry['message']); + $this->assertStringContainsString('42', $entry['message']); + $this->assertStringContainsString(__FILE__, $entry['message']); + $this->assertStringContainsString((string)$line, $entry['message']); + $this->assertStringContainsString(__FUNCTION__, $entry['message']); + } + /** * @return array */ diff --git a/tests/Unit/Exceptions/ExceptionsServiceProviderTest.php b/tests/Unit/Exceptions/ExceptionsServiceProviderTest.php index c0569086..bd0fb811 100644 --- a/tests/Unit/Exceptions/ExceptionsServiceProviderTest.php +++ b/tests/Unit/Exceptions/ExceptionsServiceProviderTest.php @@ -11,13 +11,14 @@ use Engelsystem\Exceptions\Handlers\Whoops; use Engelsystem\Http\Request; use Engelsystem\Test\Unit\ServiceProviderTest; use PHPUnit\Framework\MockObject\MockObject; +use Psr\Log\LoggerInterface; class ExceptionsServiceProviderTest extends ServiceProviderTest { /** - * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::addDevelopmentHandler() - * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::addProductionHandler() - * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::register() + * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::addDevelopmentHandler + * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::addProductionHandler + * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::register */ public function testRegister() { @@ -77,33 +78,57 @@ class ExceptionsServiceProviderTest extends ServiceProviderTest } /** - * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::boot() + * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::boot + * @covers \Engelsystem\Exceptions\ExceptionsServiceProvider::addLogger */ public function testBoot() { + /** @var HandlerInterface|MockObject $handlerImpl */ + $handlerImpl = $this->getMockForAbstractClass(HandlerInterface::class); + + /** @var Legacy|MockObject $loggingHandler */ + $loggingHandler = $this->createMock(Legacy::class); + /** @var Handler|MockObject $handler */ $handler = $this->createMock(Handler::class); /** @var Request|MockObject $request */ $request = $this->createMock(Request::class); - $handler->expects($this->once()) + /** @var LoggerInterface|MockObject $log */ + $log = $this->getMockForAbstractClass(LoggerInterface::class); + + $handler->expects($this->exactly(2)) ->method('setRequest') ->with($request); + $handler->expects($this->exactly(2)) + ->method('getHandler') + ->willReturnOnConsecutiveCalls([$handlerImpl], [$loggingHandler]); + + $loggingHandler->expects($this->once()) + ->method('setLogger') + ->with($log); $app = $this->getApp(['get']); - $app->expects($this->exactly(2)) + $app->expects($this->exactly(5)) ->method('get') ->withConsecutive( ['error.handler'], - ['request'] + ['request'], + ['error.handler'], + ['request'], + [LoggerInterface::class] ) ->willReturnOnConsecutiveCalls( $handler, - $request + $request, + $handler, + $request, + $log ); $provider = new ExceptionsServiceProvider($app); $provider->boot(); + $provider->boot(); } } diff --git a/tests/Unit/Exceptions/Handlers/LegacyTest.php b/tests/Unit/Exceptions/Handlers/LegacyTest.php index b71152e5..7430f777 100644 --- a/tests/Unit/Exceptions/Handlers/LegacyTest.php +++ b/tests/Unit/Exceptions/Handlers/LegacyTest.php @@ -4,14 +4,16 @@ namespace Engelsystem\Test\Unit\Exceptions\Handlers; use Engelsystem\Exceptions\Handlers\Legacy; use Engelsystem\Http\Request; +use ErrorException; use Exception; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; +use Psr\Log\Test\TestLogger; class LegacyTest extends TestCase { /** - * @covers \Engelsystem\Exceptions\Handlers\Legacy::render() + * @covers \Engelsystem\Exceptions\Handlers\Legacy::render */ public function testRender() { @@ -27,22 +29,36 @@ class LegacyTest extends TestCase } /** - * @covers \Engelsystem\Exceptions\Handlers\Legacy::report() - * @covers \Engelsystem\Exceptions\Handlers\Legacy::stripBasePath() + * @covers \Engelsystem\Exceptions\Handlers\Legacy::report + * @covers \Engelsystem\Exceptions\Handlers\Legacy::setLogger + * @covers \Engelsystem\Exceptions\Handlers\Legacy::stripBasePath */ public function testReport() { $handler = new Legacy(); $exception = new Exception('Lorem Ipsum', 4242); $line = __LINE__ - 1; + $exception2 = new Exception('Test Exception'); + $exception3 = new Exception('Mor Exceptions!'); + $logger = new TestLogger(); + $logger2 = $this->createMock(TestLogger::class); + $logger2->expects($this->once()) + ->method('critical') + ->willReturnCallback(function () { + throw new ErrorException(); + }); - $log = tempnam(sys_get_temp_dir(), 'engelsystem-log'); + $logfile = tempnam(sys_get_temp_dir(), 'engelsystem-log'); $errorLog = ini_get('error_log'); - ini_set('error_log', $log); + ini_set('error_log', $logfile); $handler->report($exception); + $handler->setLogger($logger); + $handler->report($exception2); + $handler->setLogger($logger2); + $handler->report($exception3); ini_set('error_log', $errorLog); - $logContent = file_get_contents($log); - unset($log); + $logContent = file_get_contents($logfile); + unset($logfile); $this->assertStringContainsString('4242', $logContent); $this->assertStringContainsString('Lorem Ipsum', $logContent); @@ -50,5 +66,10 @@ class LegacyTest extends TestCase $this->assertStringContainsString((string)$line, $logContent); $this->assertStringContainsString(__FUNCTION__, $logContent); $this->assertStringContainsString(json_encode(__CLASS__), $logContent); + + $this->assertTrue($logger->hasRecordThatPasses(function (array $record) use ($exception2) { + $context = $record['context']; + return isset($context['exception']) && $context['exception'] === $exception2; + }, 'critical')); } } diff --git a/tests/Unit/Logger/LoggerServiceProviderTest.php b/tests/Unit/Logger/LoggerServiceProviderTest.php index 9ac7eba6..1d6e1df4 100644 --- a/tests/Unit/Logger/LoggerServiceProviderTest.php +++ b/tests/Unit/Logger/LoggerServiceProviderTest.php @@ -4,8 +4,8 @@ namespace Engelsystem\Test\Unit\Logger; use Engelsystem\Helpers\Authenticator; use Engelsystem\Logger\Logger; -use Engelsystem\Logger\UserAwareLogger; use Engelsystem\Logger\LoggerServiceProvider; +use Engelsystem\Logger\UserAwareLogger; use Engelsystem\Test\Unit\ServiceProviderTest; use PHPUnit\Framework\MockObject\MockObject; use Psr\Log\LoggerInterface; diff --git a/tests/Unit/Renderer/Twig/Extensions/DevelopTest.php b/tests/Unit/Renderer/Twig/Extensions/DevelopTest.php index 0e225a23..51c92054 100644 --- a/tests/Unit/Renderer/Twig/Extensions/DevelopTest.php +++ b/tests/Unit/Renderer/Twig/Extensions/DevelopTest.php @@ -19,7 +19,7 @@ class DevelopTest extends ExtensionTest $extension = new Develop($config); $functions = $extension->getFunctions(); - $this->assertEquals($functions, []); + $this->assertEquals([], $functions); $config->set('environment', 'development'); $functions = $extension->getFunctions();