From 9c1566a971d42ff1acb4756708e8d9a5568bb194 Mon Sep 17 00:00:00 2001 From: Jordi Boggiano Date: Wed, 8 Jun 2022 21:51:47 +0200 Subject: [PATCH 1/6] Add a way to disable logging loop detection, closes #1681 --- src/Monolog/Logger.php | 22 ++++++++++++++++++++-- 1 file changed, 20 insertions(+), 2 deletions(-) diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php index 0c2240e2..04118959 100644 --- a/src/Monolog/Logger.php +++ b/src/Monolog/Logger.php @@ -152,6 +152,13 @@ class Logger implements LoggerInterface, ResettableInterface */ private $logDepth = 0; + /** + * @var bool Whether to detect infinite logging loops + * + * This can be disabled via {@see useLoggingLoopDetection} if you have async handlers that do not play well with this + */ + private $detectCycles = true; + /** * @psalm-param array $processors * @@ -284,6 +291,13 @@ class Logger implements LoggerInterface, ResettableInterface return $this; } + public function useLoggingLoopDetection(bool $detectCycles): self + { + $this->detectCycles = $detectCycles; + + return $this; + } + /** * Adds a log record. * @@ -296,7 +310,9 @@ class Logger implements LoggerInterface, ResettableInterface */ public function addRecord(int $level, string $message, array $context = []): bool { - $this->logDepth += 1; + if ($this->detectCycles) { + $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; @@ -349,7 +365,9 @@ class Logger implements LoggerInterface, ResettableInterface } } } finally { - $this->logDepth--; + if ($this->detectCycles) { + $this->logDepth--; + } } return null !== $record; From 64854f09da8b2874afa2ee4e0cf4b96b3d52cb07 Mon Sep 17 00:00:00 2001 From: Dmitry Menshikov Date: Thu, 9 Jun 2022 10:04:15 +0300 Subject: [PATCH 2/6] =?UTF-8?q?Correct=20handling=20of=20E=5FUSER=5FERROR?= =?UTF-8?q?=20as=20fatal=20error=20if=20registerErrorHandl=E2=80=A6=20(#16?= =?UTF-8?q?70)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * Correct handling of E_USER_ERROR as fatal error if registerErrorHandler is called with callPrevious, fixes #1669 --- src/Monolog/ErrorHandler.php | 16 +++++++++++----- 1 file changed, 11 insertions(+), 5 deletions(-) diff --git a/src/Monolog/ErrorHandler.php b/src/Monolog/ErrorHandler.php index 16794be6..576f1713 100644 --- a/src/Monolog/ErrorHandler.php +++ b/src/Monolog/ErrorHandler.php @@ -46,8 +46,8 @@ class ErrorHandler private $fatalLevel = LogLevel::ALERT; /** @var ?string */ private $reservedMemory = null; - /** @var ?mixed */ - private $lastFatalTrace; + /** @var ?array{type: int, message: string, file: string, line: int, trace: mixed} */ + private $lastFatalData = null; /** @var int[] */ private static $fatalErrors = [E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR, E_USER_ERROR]; @@ -223,7 +223,7 @@ class ErrorHandler } else { $trace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); array_shift($trace); // Exclude handleError from trace - $this->lastFatalTrace = $trace; + $this->lastFatalData = ['type' => $code, 'message' => $message, 'file' => $file, 'line' => $line, 'trace' => $trace]; } if ($this->previousErrorHandler === true) { @@ -242,12 +242,18 @@ class ErrorHandler { $this->reservedMemory = ''; - $lastError = error_get_last(); + if (is_array($this->lastFatalData)) { + $lastError = $this->lastFatalData; + } else { + $lastError = error_get_last(); + } + if ($lastError && in_array($lastError['type'], self::$fatalErrors, true)) { + $trace = $lastError['trace'] ?? null; $this->logger->log( $this->fatalLevel, 'Fatal Error ('.self::codeToString($lastError['type']).'): '.$lastError['message'], - ['code' => $lastError['type'], 'message' => $lastError['message'], 'file' => $lastError['file'], 'line' => $lastError['line'], 'trace' => $this->lastFatalTrace] + ['code' => $lastError['type'], 'message' => $lastError['message'], 'file' => $lastError['file'], 'line' => $lastError['line'], 'trace' => $trace] ); if ($this->logger instanceof Logger) { From eac0c22ad27910ac97a5c33eb588257a0993487f Mon Sep 17 00:00:00 2001 From: Jordi Boggiano Date: Thu, 9 Jun 2022 10:40:17 +0200 Subject: [PATCH 3/6] Mark TestCase internal until PHPStorm handles this better, fixes #1677 --- src/Monolog/Test/TestCase.php | 2 ++ 1 file changed, 2 insertions(+) diff --git a/src/Monolog/Test/TestCase.php b/src/Monolog/Test/TestCase.php index c4e42496..bc0b425e 100644 --- a/src/Monolog/Test/TestCase.php +++ b/src/Monolog/Test/TestCase.php @@ -22,6 +22,8 @@ use Monolog\Formatter\FormatterInterface; * * @phpstan-import-type Record from \Monolog\Logger * @phpstan-import-type Level from \Monolog\Logger + * + * @internal feel free to reuse this to test your own handlers, this is marked internal to avoid issues with PHPStorm https://github.com/Seldaek/monolog/issues/1677 */ class TestCase extends \PHPUnit\Framework\TestCase { From 8ac56aa42bff0f099af28ebe03c43004e9bc0c44 Mon Sep 17 00:00:00 2001 From: Gene Alyson Fortunado Torcende Date: Thu, 9 Jun 2022 16:41:11 +0800 Subject: [PATCH 4/6] RotatingFileHandler to maintain the correct maximum number files when using folder by date (#1671) --- src/Monolog/Handler/RotatingFileHandler.php | 6 +- .../Handler/RotatingFileHandlerTest.php | 98 +++++++++++++++++++ 2 files changed, 103 insertions(+), 1 deletion(-) diff --git a/src/Monolog/Handler/RotatingFileHandler.php b/src/Monolog/Handler/RotatingFileHandler.php index 2b7c4803..17745d22 100644 --- a/src/Monolog/Handler/RotatingFileHandler.php +++ b/src/Monolog/Handler/RotatingFileHandler.php @@ -191,7 +191,11 @@ class RotatingFileHandler extends StreamHandler $fileInfo = pathinfo($this->filename); $glob = str_replace( ['{filename}', '{date}'], - [$fileInfo['filename'], '[0-9][0-9][0-9][0-9]*'], + [$fileInfo['filename'], str_replace( + ['Y', 'y', 'm', 'd'], + ['[0-9][0-9][0-9][0-9]', '[0-9][0-9]', '[0-9][0-9]', '[0-9][0-9]'], + $this->dateFormat) + ], $fileInfo['dirname'] . '/' . $this->filenameFormat ); if (isset($fileInfo['extension'])) { diff --git a/tests/Monolog/Handler/RotatingFileHandlerTest.php b/tests/Monolog/Handler/RotatingFileHandlerTest.php index dd77c853..1f94adf5 100644 --- a/tests/Monolog/Handler/RotatingFileHandlerTest.php +++ b/tests/Monolog/Handler/RotatingFileHandlerTest.php @@ -46,11 +46,38 @@ class RotatingFileHandlerTest extends TestCase foreach (glob(__DIR__.'/Fixtures/*.rot') as $file) { unlink($file); } + + if ('testRotationWithFolderByDate' === $this->getName(false)) { + foreach (glob(__DIR__.'/Fixtures/[0-9]*') as $folder) { + $this->rrmdir($folder); + } + } + restore_error_handler(); unset($this->lastError); } + private function rrmdir($directory) { + if (! is_dir($directory)) { + throw new InvalidArgumentException("$directory must be a directory"); + } + + if (substr($directory, strlen($directory) - 1, 1) !== '/') { + $directory .= '/'; + } + + foreach (glob($directory . '*', GLOB_MARK) as $path) { + if (is_dir($path)) { + $this->rrmdir($path); + } else { + unlink($path); + } + } + + return rmdir($directory); + } + private function assertErrorWasTriggered($code, $message) { if (empty($this->lastError)) { @@ -141,6 +168,76 @@ class RotatingFileHandlerTest extends TestCase ]; } + private function createDeep($file) + { + mkdir(dirname($file), 0777, true); + touch($file); + + return $file; + } + + /** + * @dataProvider rotationWithFolderByDateTests + */ + public function testRotationWithFolderByDate($createFile, $dateFormat, $timeCallback) + { + $old1 = $this->createDeep(__DIR__.'/Fixtures/'.date($dateFormat, $timeCallback(-1)).'/foo.rot'); + $old2 = $this->createDeep(__DIR__.'/Fixtures/'.date($dateFormat, $timeCallback(-2)).'/foo.rot'); + $old3 = $this->createDeep(__DIR__.'/Fixtures/'.date($dateFormat, $timeCallback(-3)).'/foo.rot'); + $old4 = $this->createDeep(__DIR__.'/Fixtures/'.date($dateFormat, $timeCallback(-4)).'/foo.rot'); + + $log = __DIR__.'/Fixtures/'.date($dateFormat).'/foo.rot'; + + if ($createFile) { + $this->createDeep($log); + } + + $handler = new RotatingFileHandler(__DIR__.'/Fixtures/foo.rot', 2); + $handler->setFormatter($this->getIdentityFormatter()); + $handler->setFilenameFormat('{date}/{filename}', $dateFormat); + $handler->handle($this->getRecord()); + + $handler->close(); + + $this->assertTrue(file_exists($log)); + $this->assertTrue(file_exists($old1)); + $this->assertEquals($createFile, file_exists($old2)); + $this->assertEquals($createFile, file_exists($old3)); + $this->assertEquals($createFile, file_exists($old4)); + $this->assertEquals('test', file_get_contents($log)); + } + + public function rotationWithFolderByDateTests() + { + $now = time(); + $dayCallback = function ($ago) use ($now) { + return $now + 86400 * $ago; + }; + $monthCallback = function ($ago) { + return gmmktime(0, 0, 0, (int) (date('n') + $ago), 1, (int) date('Y')); + }; + $yearCallback = function ($ago) { + return gmmktime(0, 0, 0, 1, 1, (int) (date('Y') + $ago)); + }; + + return [ + 'Rotation is triggered when the file of the current day is not present' + => [true, 'Y/m/d', $dayCallback], + 'Rotation is not triggered when the file of the current day is already present' + => [false, 'Y/m/d', $dayCallback], + + 'Rotation is triggered when the file of the current month is not present' + => [true, 'Y/m', $monthCallback], + 'Rotation is not triggered when the file of the current month is already present' + => [false, 'Y/m', $monthCallback], + + 'Rotation is triggered when the file of the current year is not present' + => [true, 'Y', $yearCallback], + 'Rotation is not triggered when the file of the current year is already present' + => [false, 'Y', $yearCallback], + ]; + } + /** * @dataProvider dateFormatProvider */ @@ -205,6 +302,7 @@ class RotatingFileHandlerTest extends TestCase ['foobar-{date}', true], ['foo-{date}-bar', true], ['{date}-foobar', true], + ['{date}/{filename}', true], ['foobar', false], ]; } From 24e414c99378c227fff95a6483c85dfff2e79779 Mon Sep 17 00:00:00 2001 From: henning Date: Tue, 7 Jun 2022 16:13:46 +0200 Subject: [PATCH 5/6] Added $datetime parameter to addRecord method to optionally log into the past/future --- src/Monolog/Logger.php | 13 +++++++------ tests/Monolog/LoggerTest.php | 22 ++++++++++++++++++++++ 2 files changed, 29 insertions(+), 6 deletions(-) diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php index 04118959..09918520 100644 --- a/src/Monolog/Logger.php +++ b/src/Monolog/Logger.php @@ -301,14 +301,15 @@ class Logger implements LoggerInterface, ResettableInterface /** * Adds a log record. * - * @param int $level The logging level - * @param string $message The log message - * @param mixed[] $context The log context - * @return bool Whether the record has been processed + * @param int $level The logging level + * @param string $message The log message + * @param mixed[] $context The log context + * @param DateTimeImmutable $datetime Optional log date to log into the past or future + * @return bool Whether the record has been processed * * @phpstan-param Level $level */ - public function addRecord(int $level, string $message, array $context = []): bool + public function addRecord(int $level, string $message, array $context = [], DateTimeImmutable $datetime = null): bool { if ($this->detectCycles) { $this->logDepth += 1; @@ -338,7 +339,7 @@ class Logger implements LoggerInterface, ResettableInterface 'level' => $level, 'level_name' => $levelName, 'channel' => $this->name, - 'datetime' => new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), + 'datetime' => $datetime ?? new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), 'extra' => [], ]; diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php index bec548fd..0b07a7cf 100644 --- a/tests/Monolog/LoggerTest.php +++ b/tests/Monolog/LoggerTest.php @@ -739,6 +739,28 @@ class LoggerTest extends \PHPUnit\Framework\TestCase $this->assertNotSame($uid1, $processorUid1->getUid()); $this->assertNotSame($uid2, $processorUid2->getUid()); } + + /** + * @covers Logger::addRecord + */ + public function testLogWithDateTime() + { + foreach ([true, false] as $microseconds) { + $logger = new Logger(__METHOD__); + + $loggingHandler = new LoggingHandler($logger); + $testHandler = new TestHandler(); + + $logger->pushHandler($loggingHandler); + $logger->pushHandler($testHandler); + + $datetime = (new DateTimeImmutable($microseconds))->modify('2022-03-04 05:06:07'); + $logger->addRecord(Logger::DEBUG, 'test', [], $datetime); + + list($record) = $testHandler->getRecords(); + $this->assertEquals($datetime->format('Y-m-d H:i:s'), $record['datetime']->format('Y-m-d H:i:s')); + } + } } class LoggingHandler implements HandlerInterface From 5579edf28aee1190a798bfa5be8bc16c563bd524 Mon Sep 17 00:00:00 2001 From: Jordi Boggiano Date: Thu, 9 Jun 2022 10:59:12 +0200 Subject: [PATCH 6/6] Update changelog --- CHANGELOG.md | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index e374fa78..9ae89099 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,3 +1,11 @@ +### 2.7.0 (2022-06-09) + + * Added `$datetime` parameter to `Logger::addRecord` as low level API to allow logging into the past or future (#1682) + * Added `Logger::useLoggingLoopDetection` to allow disabling cyclic logging detection in concurrent frameworks (#1681) + * Fixed handling of fatal errors if callPrevious is disabled in ErrorHandler (#1670) + * Marked the reusable `Monolog\Test\TestCase` class as `@internal` to make sure PHPStorm does not show it above PHPUnit, you may still use it to test your own handlers/etc though (#1677) + * Fixed RotatingFileHandler issue when the date format contained slashes (#1671) + ### 2.6.0 (2022-05-10) * Deprecated `SwiftMailerHandler`, use `SymfonyMailerHandler` instead