From a5d65f6ec48b6ec5f4aefeea59073ac48432d753 Mon Sep 17 00:00:00 2001 From: Jordi Boggiano Date: Tue, 10 May 2022 11:10:07 +0200 Subject: [PATCH] Fix infinite loops when a log handler triggers logging itself --- src/Monolog/Logger.php | 79 ++++++++++++++++++++++-------------- tests/Monolog/LoggerTest.php | 56 +++++++++++++++++++++++++ 2 files changed, 104 insertions(+), 31 deletions(-) diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php index 1f4ef7f1..0c2240e2 100644 --- a/src/Monolog/Logger.php +++ b/src/Monolog/Logger.php @@ -147,6 +147,11 @@ class Logger implements LoggerInterface, ResettableInterface */ protected $exceptionHandler; + /** + * @var int Keeps track of depth to prevent infinite logging loops + */ + private $logDepth = 0; + /** * @psalm-param array $processors * @@ -291,30 +296,51 @@ class Logger implements LoggerInterface, ResettableInterface */ public function addRecord(int $level, string $message, array $context = []): bool { - $record = null; + $this->logDepth += 1; + if ($this->logDepth === 3) { + $this->warning('A possible infinite logging loop was detected and aborted. It appears some of your handler code is triggering logging, see the previous log record for a hint as to what may be the cause.'); + return false; + } elseif ($this->logDepth >= 5) { // log depth 4 is let through so we can log the warning above + return false; + } - foreach ($this->handlers as $handler) { - if (null === $record) { - // skip creating the record as long as no handler is going to handle it - if (!$handler->isHandling(['level' => $level])) { - continue; + try { + $record = null; + + foreach ($this->handlers as $handler) { + if (null === $record) { + // skip creating the record as long as no handler is going to handle it + if (!$handler->isHandling(['level' => $level])) { + continue; + } + + $levelName = static::getLevelName($level); + + $record = [ + 'message' => $message, + 'context' => $context, + 'level' => $level, + 'level_name' => $levelName, + 'channel' => $this->name, + 'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), + 'extra' => [], + ]; + + try { + foreach ($this->processors as $processor) { + $record = $processor($record); + } + } catch (Throwable $e) { + $this->handleException($e, $record); + + return true; + } } - $levelName = static::getLevelName($level); - - $record = [ - 'message' => $message, - 'context' => $context, - 'level' => $level, - 'level_name' => $levelName, - 'channel' => $this->name, - 'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), - 'extra' => [], - ]; - + // once the record exists, send it to all handlers as long as the bubbling chain is not interrupted try { - foreach ($this->processors as $processor) { - $record = $processor($record); + if (true === $handler->handle($record)) { + break; } } catch (Throwable $e) { $this->handleException($e, $record); @@ -322,17 +348,8 @@ class Logger implements LoggerInterface, ResettableInterface return true; } } - - // once the record exists, send it to all handlers as long as the bubbling chain is not interrupted - try { - if (true === $handler->handle($record)) { - break; - } - } catch (Throwable $e) { - $this->handleException($e, $record); - - return true; - } + } finally { + $this->logDepth--; } return null !== $record; diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php index bd5ae20d..bec548fd 100644 --- a/tests/Monolog/LoggerTest.php +++ b/tests/Monolog/LoggerTest.php @@ -11,6 +11,7 @@ namespace Monolog; +use Monolog\Handler\HandlerInterface; use Monolog\Processor\WebProcessor; use Monolog\Handler\TestHandler; @@ -84,6 +85,28 @@ class LoggerTest extends \PHPUnit\Framework\TestCase $this->assertEquals('foo', $record['channel']); } + /** + * @covers Monolog\Logger::addRecord + */ + public function testLogPreventsCircularLogging() + { + $logger = new Logger(__METHOD__); + + $loggingHandler = new LoggingHandler($logger); + $testHandler = new TestHandler(); + + $logger->pushHandler($loggingHandler); + $logger->pushHandler($testHandler); + + $logger->addRecord(Logger::ALERT, 'test'); + + $records = $testHandler->getRecords(); + $this->assertCount(3, $records); + $this->assertSame('ALERT', $records[0]['level_name']); + $this->assertSame('DEBUG', $records[1]['level_name']); + $this->assertSame('WARNING', $records[2]['level_name']); + } + /** * @covers Monolog\Logger::addRecord */ @@ -717,3 +740,36 @@ class LoggerTest extends \PHPUnit\Framework\TestCase $this->assertNotSame($uid2, $processorUid2->getUid()); } } + +class LoggingHandler implements HandlerInterface +{ + /** + * @var Logger + */ + private $logger; + + public function __construct(Logger $logger) + { + $this->logger = $logger; + } + + public function isHandling(array $record): bool + { + return true; + } + + public function handle(array $record): bool + { + $this->logger->debug('Log triggered while logging'); + + return false; + } + + public function handleBatch(array $records): void + { + } + + public function close(): void + { + } +}