From abb1e3a546725c4860474c1b126c99491d5591d2 Mon Sep 17 00:00:00 2001 From: Patrick Johnmeyer Date: Thu, 3 Jun 2021 15:13:11 -0500 Subject: [PATCH] Log invalid log levels as errors and default to 'debug' Prior to this change, an invalid log level passed to the FilteredLogLevelDecorator constructor would result in an InvalidArgumentException. This means that a mis- configured production system could fail to boot. This patch proposes that an invalid log level should not be a hard failure. The change logs the invalid log level to the 'realLogger' as an error, then sets the default log level to 'debug'. --- src/Logger/FilteredLogLevelDecorator.php | 28 +++++++---- .../Logger/FilteredLogLevelDecoratorTest.php | 47 +++++++++++++++---- 2 files changed, 58 insertions(+), 17 deletions(-) diff --git a/src/Logger/FilteredLogLevelDecorator.php b/src/Logger/FilteredLogLevelDecorator.php index 3d653373..658279f4 100644 --- a/src/Logger/FilteredLogLevelDecorator.php +++ b/src/Logger/FilteredLogLevelDecorator.php @@ -7,6 +7,7 @@ use Psr\Log\LoggerInterface; use Psr\Log\LoggerTrait; use Psr\Log\LogLevel; +use Throwable; use Webmozart\Assert\Assert; use function array_keys; @@ -45,15 +46,24 @@ final class FilteredLogLevelDecorator implements LoggerInterface */ public function __construct(LoggerInterface $realLogger, string $minimumLogLevel) { - Assert::keyExists( - self::LOG_LEVEL_ORDER, - strtolower($minimumLogLevel), - sprintf( - 'Log level %s was not a valid PSR-3 compatible log level. Should be one of: %s', - $minimumLogLevel, - implode(', ', array_keys(self::LOG_LEVEL_ORDER)) - ) - ); + try { + Assert::keyExists( + self::LOG_LEVEL_ORDER, + strtolower($minimumLogLevel), + sprintf( + 'Log level %s was not a valid PSR-3 compatible log level. Should be one of: %s', + $minimumLogLevel, + implode(', ', array_keys(self::LOG_LEVEL_ORDER)) + ) + ); + } catch (Throwable $e) { + $minimumLogLevel = LogLevel::DEBUG; + $realLogger->log( + LogLevel::ERROR, + $e->getMessage(), + ['exception' => $e] + ); + } $this->minimumLogLevel = self::LOG_LEVEL_ORDER[strtolower($minimumLogLevel)]; $this->realLogger = $realLogger; diff --git a/tests/Unit/Logger/FilteredLogLevelDecoratorTest.php b/tests/Unit/Logger/FilteredLogLevelDecoratorTest.php index c4ac73a6..8c09d756 100644 --- a/tests/Unit/Logger/FilteredLogLevelDecoratorTest.php +++ b/tests/Unit/Logger/FilteredLogLevelDecoratorTest.php @@ -4,7 +4,6 @@ namespace Scoutapm\UnitTests\Logger; -use InvalidArgumentException; use PHPUnit\Framework\MockObject\MockObject; use PHPUnit\Framework\TestCase; use Psr\Log\LoggerInterface; @@ -31,11 +30,16 @@ public function setUp(): void public function testInvalidLogLevelStringGivesClearErrorMessage(): void { - $this->expectException(InvalidArgumentException::class); - $this->expectExceptionMessage( - 'Log level foo was not a valid PSR-3 compatible log level. ' - . 'Should be one of: debug, info, notice, warning, error, critical, alert, emergency' - ); + $this->decoratedLogger + ->expects(self::once()) + ->method('log') + ->with( + LogLevel::ERROR, + 'Log level foo was not a valid PSR-3 compatible log level. ' + . 'Should be one of: debug, info, notice, warning, error, critical, alert, emergency', + self::anything() + ); + new FilteredLogLevelDecorator($this->decoratedLogger, 'foo'); } @@ -99,9 +103,36 @@ public function invalidLogLevelProvider(): array } /** @dataProvider invalidLogLevelProvider */ - public function testInvalidLogLevelsAreRejected(string $invalidLogLevel): void + public function testInvalidLogLevelsAreLoggedAsErrors(string $invalidLogLevel): void { - $this->expectException(InvalidArgumentException::class); + $this->decoratedLogger + ->expects(self::once()) + ->method('log') + ->with( + LogLevel::ERROR, + self::stringContains($invalidLogLevel . ' was not a valid PSR-3'), + self::anything() + ); + new FilteredLogLevelDecorator($this->decoratedLogger, $invalidLogLevel); } + + /** @dataProvider invalidLogLevelProvider */ + public function testInvalidLogLevelsDefaultToDebug(string $invalidLogLevel): void + { + $decorator = new FilteredLogLevelDecorator($this->decoratedLogger, $invalidLogLevel); + + $message = 'info message'; + + $this->decoratedLogger + ->expects(self::once()) + ->method('log') + ->with( + LogLevel::DEBUG, + self::stringContains($message), + self::anything() + ); + + $decorator->debug($message); + } }