From 2c863e745bb8e8e22a889758c2b16db95bf29ed2 Mon Sep 17 00:00:00 2001 From: Dustin Wilson Date: Wed, 5 Apr 2023 23:59:51 -0500 Subject: [PATCH] Added handler manipulation methods to Logger, warnings on errant throwables --- README.md | 6 +- lib/Logger.php | 79 ++++++++++++-- ...IOException.php => ArgumentCountError.php} | 2 +- lib/Logger/StreamHandler.php | 45 ++++---- lib/Logger/UnderflowException.php | 11 ++ tests/cases/TestLogger.php | 103 +++++++++++++++++- 6 files changed, 213 insertions(+), 33 deletions(-) rename lib/Logger/{IOException.php => ArgumentCountError.php} (75%) create mode 100644 lib/Logger/UnderflowException.php diff --git a/README.md b/README.md index f0516a8..18f383a 100644 --- a/README.md +++ b/README.md @@ -19,4 +19,8 @@ This library attempts what we're calling an "opinionated" implementation of PSR- 3. The specification in [section 1.3][d] also specifies that if an `Exception` object is passed in the `$context` parameter it must be within an `exception` key. This makes sense, but curiously there's nary a mention of what to do with an `Error` object. They've existed since PHP 7 and can be thrown just like exceptions. _Logger_ will accept any `Throwable` in the `exception` key, but at present does nothing with it. Theoretically future handlers could be written to take advantage of it for structured data. -PSR-3 is a deeply flawed specification that is vague in many aspects it shouldn't be and is badly designed in others; sometimes it's both. Section 1.3 in the first paragraph states categorically that implementors must not trigger a warning when errant data is in the `$context` array and treat it with _as much lenience as possible_. It then states in the following paragraph that if an exception is present in the context data it *must* be in the `exception` key and that implementors *must* verify the `exception` key. This appears to be contradictory. You can't verify the `exception` key without triggering an error or exception when it's wrong. The user should be notified that they made a mistake; it's bad design otherwise. We at present do nothing. Since the `exception` key isn't currently utilized within _Logger_ we've left the issue open. \ No newline at end of file +4. Also in the first item of [section 1.3][d] it states categorically that implementors must not trigger a warning when errant data is in the `$context` array and treat it with _"as much lenience as possible"_. It then states in the following ittem that if an exception is present in the context data it *must* be in the `exception` key and that implementors *must* verify the `exception` key. This is contradictory. You can't verify the `exception` key without triggering an error or exception when it's wrong. The user should be notified they've made a mistake; it's bad design otherwise. Our solution to this problem is to remove errant throwables from `$context` and also trigger warnings when they're encountered. However, `Logger->$warnOnInvalidContextThrowables` is provided to make it easy to suppress the warnings if necessary. + +## Usage ## + +To be continued... \ No newline at end of file diff --git a/lib/Logger.php b/lib/Logger.php index 7d38032..819349e 100644 --- a/lib/Logger.php +++ b/lib/Logger.php @@ -8,10 +8,12 @@ declare(strict_types=1); namespace MensBeam; use MensBeam\Logger\{ + ArgumentCountError, Handler, InvalidArgumentException, Level, - StreamHandler + StreamHandler, + UnderflowException }; use Psr\Log\LoggerInterface; @@ -26,6 +28,12 @@ class Logger implements LoggerInterface { public const INFO = 6; public const DEBUG = 7; + /** + * Flag that causes warnings to be triggered when invalid throwables are in the + * context array + */ + public bool $warnOnInvalidContextThrowables = true; + /** The channel name identifier used for this instance of Logger */ protected ?string $channel; @@ -34,7 +42,7 @@ class Logger implements LoggerInterface { * * @var Handler[] */ - protected array $handlers; + protected array $handlers = []; public function __construct(?string $channel = null, Handler ...$handlers) { @@ -49,7 +57,7 @@ class Logger implements LoggerInterface { ]; } - $this->handlers = $handlers; + $this->pushHandler(...$handlers); } @@ -58,12 +66,49 @@ class Logger implements LoggerInterface { return $this->channel; } + public function getHandlers(): array { + return $this->handlers; + } + + public function popHandler(): Handler { + if (count($this->handlers) === 1) { + throw new UnderflowException('Popping the last handler will cause the Logger to have zero handlers; there must be at least one'); + } + + return array_pop($this->handlers); + } + + public function pushHandler(Handler ...$handlers): void { + if (count($handlers) === 0) { + throw new ArgumentCountError(__METHOD__ . ' expects at least 1 argument, 0 given'); + } + + $this->handlers = [ ...$this->handlers, ...$handlers ]; + } + + public function setHandlers(Handler ...$handlers): void { + $this->handlers = []; + $this->pushHandler(...$handlers); + } + public function setChannel(?string $value): void { $this->channel = ($value !== null) ? substr($value, 0, 29) : null; } - public function getHandlers(): array { - return $this->handlers; + public function shiftHandler(): Handler { + if (count($this->handlers) === 1) { + throw new UnderflowException('Shifting the last handler will cause the Logger to have zero handlers; there must be at least one'); + } + + return array_shift($this->handlers); + } + + public function unshiftHandler(Handler ...$handlers): void { + if (count($handlers) === 0) { + throw new ArgumentCountError(__METHOD__ . 'expects at least 1 argument, 0 given'); + } + + $this->handlers = [ ...$handlers, ...$this->handlers ]; } @@ -156,10 +201,28 @@ class Logger implements LoggerInterface { # is actually an Exception before using it as such, as it MAY contain # anything. - // Really shitty user experience to not trigger a warning when someone does - // something incorrectly, but okay... + // The first paragraph states that we must be lenient with objects in the + // context array, but the second paragraph says that exceptions MUST be in the + // exception key and that we MUST verify it. They're contradictory. We + // can't verify the exception while at the same time be lenient. + + // Our solution is to essentially violate the specification; we will remove + // errant throwables and trigger warnings when encountered. Not issuing warnings + // here provides a bad user experience. The user can be left in a situation + // where it becomes difficult to ascertain why something isn't working. We do, + // however, provide an easy way to suppress these warnings when necessary. foreach ($context as $k => $v) { - if (($v instanceof \Throwable && $k !== 'exception') || (!$v instanceof \Throwable && $k === 'exception')) { + if ($k === 'exception' && !$v instanceof \Throwable) { + if ($this->warnOnInvalidContextThrowables) { + $type = gettype($v); + $type = ($type === 'object') ? $v::class : $type; + trigger_error(sprintf('The \'exception\' key in argument #3 ($context) can only contain values of type \Throwable, %s given', $type), \E_USER_WARNING); + } + unset($context[$k]); + } elseif ($k !== 'exception' && $v instanceof \Throwable) { + if ($this->warnOnInvalidContextThrowables) { + trigger_error(sprintf('Values of type %s can only be contained in the \'exception\' key in argument #3 ($context)', $v::class), \E_USER_WARNING); + } unset($context[$k]); } } diff --git a/lib/Logger/IOException.php b/lib/Logger/ArgumentCountError.php similarity index 75% rename from lib/Logger/IOException.php rename to lib/Logger/ArgumentCountError.php index 528a1a1..6c06d97 100644 --- a/lib/Logger/IOException.php +++ b/lib/Logger/ArgumentCountError.php @@ -8,4 +8,4 @@ declare(strict_types=1); namespace MensBeam\Logger; -class IOException extends \RuntimeException {} \ No newline at end of file +class ArgumentCountError extends \ArgumentCountError {} \ No newline at end of file diff --git a/lib/Logger/StreamHandler.php b/lib/Logger/StreamHandler.php index 5dabf6c..3ad3581 100644 --- a/lib/Logger/StreamHandler.php +++ b/lib/Logger/StreamHandler.php @@ -40,27 +40,7 @@ class StreamHandler extends Handler { $this->chunkSize = min($this->chunkSize, max((int)($num / 10), 100 * 1024)); } - if (is_resource($stream)) { - $this->resource = $stream; - stream_set_chunk_size($this->resource, $this->chunkSize); - } elseif(is_string($stream)) { - $stream = Path::canonicalize($stream); - // This wouldn't be useful for validating a URI schema, but it's fine for what this needs - preg_match('/^(?:(?[^:\s\/]+):)?(?\/*)/i', $stream, $matches); - if (in_array($matches['scheme'], [ 'file', '' ])) { - $slashCount = strlen($matches['slashes'] ?? ''); - $relative = ($matches['scheme'] === 'file') ? ($slashCount === 0 || $slashCount === 2) : ($slashCount === 0); - $stream = (($relative) ? getcwd() : '') . '/' . substr($stream, strlen($matches[0])); - } - - $this->url = $stream; - $this->urlScheme = $matches['scheme'] ?: 'file'; - } else { - $type = gettype($stream); - $type = ($type === 'object') ? $stream::class : $stream; - throw new InvalidArgumentException(sprintf('Argument #1 ($stream) must be of type resource|string, %s given', $type)); - } - + $this->setStream($stream); // Bad dog, no biscuit! if (($options['entryFormat'] ?? null) === '') { @@ -77,6 +57,29 @@ class StreamHandler extends Handler { return $this->resource ?? $this->url; } + public function setStream($value): void { + if (is_resource($value)) { + $this->resource = $value; + stream_set_chunk_size($this->resource, $this->chunkSize); + } elseif(is_string($value)) { + $value = Path::canonicalize($value); + // This wouldn't be useful for validating a URI schema, but it's fine for what this needs + preg_match('/^(?:(?[^:\s\/]+):)?(?\/*)/i', $value, $matches); + if (in_array($matches['scheme'], [ 'file', '' ])) { + $slashCount = strlen($matches['slashes'] ?? ''); + $relative = ($matches['scheme'] === 'file') ? ($slashCount === 0 || $slashCount === 2) : ($slashCount === 0); + $value = (($relative) ? getcwd() : '') . '/' . substr($value, strlen($matches[0])); + } + + $this->url = $value; + $this->urlScheme = $matches['scheme'] ?: 'file'; + } else { + $type = gettype($value); + $type = ($type === 'object') ? $value::class : $value; + throw new InvalidArgumentException(sprintf('Argument #1 ($value) must be of type resource|string, %s given', $type)); + } + } + protected function invokeCallback(string $datetime, int $level, string $channel, string $message, array $context = []): void { // Do entry formatting here. diff --git a/lib/Logger/UnderflowException.php b/lib/Logger/UnderflowException.php new file mode 100644 index 0000000..24e9938 --- /dev/null +++ b/lib/Logger/UnderflowException.php @@ -0,0 +1,11 @@ +assertNull($l->getChannel()); @@ -46,6 +48,45 @@ class TestLogger extends \PHPUnit\Framework\TestCase { $this->assertSame(CWD . '/eek.log', $h[1]->getStream()); } + public function testHandlerStackManipulation(): void { + $l = new Logger(); + $l->pushHandler(new StreamHandler(stream: 'ook')); + + $h = $l->getHandlers(); + $this->assertEquals(3, count($h)); + $this->assertInstanceOf(StreamHandler::class, $h[0]); + $this->assertInstanceOf(StreamHandler::class, $h[1]); + $this->assertInstanceOf(StreamHandler::class, $h[2]); + $this->assertSame(CWD . '/ook', end($h)->getStream()); + + $l->setHandlers( + new StreamHandler(stream: 'ook'), + new StreamHandler(stream: 'eek') + ); + $h = $l->getHandlers(); + $this->assertEquals(2, count($h)); + $this->assertSame(CWD . '/ook', $h[0]->getStream()); + $this->assertSame(CWD . '/eek', $h[1]->getStream()); + + $h1 = $l->shiftHandler(); + $this->assertSame($h[0], $h1); + $h = $l->getHandlers(); + $this->assertSame(CWD . '/eek', $h[0]->getStream()); + $this->assertEquals(1, count($l->getHandlers())); + + $l->unshiftHandler($h1); + $h = $l->getHandlers(); + $this->assertSame($h[0], $h1); + $this->assertSame(CWD . '/ook', $h[0]->getStream()); + $this->assertEquals(2, count($h)); + + $h2 = $l->popHandler(); + $this->assertSame($h[1], $h2); + $h = $l->getHandlers(); + $this->assertSame(CWD . '/ook', $h[0]->getStream()); + $this->assertEquals(1, count($l->getHandlers())); + } + /** @dataProvider provideLoggingTests */ public function testLogging(string $levelName): void { $s = fopen('php://memory', 'r+'); @@ -70,6 +111,13 @@ class TestLogger extends \PHPUnit\Framework\TestCase { $closure(new Logger()); } + /** @dataProvider provideNonFatalErrorTests */ + public function testNonFatalErrors(int $code, string $message, \Closure $closure): void { + $closure(new Logger()); + $this->assertEquals($code, $this->lastError?->getCode()); + $this->assertSame($message, $this->lastError?->getMessage()); + } + public static function provideLoggingTests(): iterable { foreach ([ 'emergency', 'alert', 'critical', 'error', 'warning', 'notice', 'info', 'debug' ] as $l) { @@ -90,6 +138,57 @@ class TestLogger extends \PHPUnit\Framework\TestCase { function (Logger $l): void { $l->log(42, 'Ook!'); } + ], + [ + UnderflowException::class, + function (Logger $l): void { + $l->popHandler(); + $l->popHandler(); + } + ], + [ + ArgumentCountError::class, + function (Logger $l): void { + $l->pushHandler(); + } + ], + [ + UnderflowException::class, + function (Logger $l): void { + $l->shiftHandler(); + $l->shiftHandler(); + } + ], + [ + ArgumentCountError::class, + function (Logger $l): void { + $l->unshiftHandler(); + } + ], + ]; + + foreach ($iterable as $i) { + yield $i; + } + } + + public static function provideNonFatalErrorTests(): iterable { + $iterable = [ + [ + \E_USER_WARNING, + 'The \'exception\' key in argument #3 ($context) can only contain values of type \Throwable, string given', + function (Logger $l): void { + $l->setHandlers(new StreamHandler('php://memory')); + $l->error('ook', [ 'exception' => 'ook' ]); + } + ], + [ + \E_USER_WARNING, + 'Values of type Exception can only be contained in the \'exception\' key in argument #3 ($context)', + function (Logger $l): void { + $l->setHandlers(new StreamHandler('php://memory')); + $l->error('ook', [ 'ook' => new \Exception('ook') ]); + } ] ];