diff --git a/CHANGELOG.md b/CHANGELOG.md index 975ef0ed..e30a904a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -41,6 +41,14 @@ New deprecations: value equal to what `Logger::WARNING` was giving you. - `Logger::getLevelName()` is now deprecated. +### 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 diff --git a/src/Monolog/ErrorHandler.php b/src/Monolog/ErrorHandler.php index 45008e4b..2ed46035 100644 --- a/src/Monolog/ErrorHandler.php +++ b/src/Monolog/ErrorHandler.php @@ -45,8 +45,8 @@ class ErrorHandler private string|null $reservedMemory = null; - /** @var mixed|null */ - private $lastFatalTrace = null; + /** @var ?array{type: int, message: string, file: string, line: int, trace: mixed} */ + private array|null $lastFatalData = null; private const FATAL_ERRORS = [E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR, E_USER_ERROR]; @@ -213,7 +213,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) { @@ -233,12 +233,17 @@ class ErrorHandler { $this->reservedMemory = ''; - $lastError = error_get_last(); + if (is_array($this->lastFatalData)) { + $lastError = $this->lastFatalData; + } else { + $lastError = error_get_last(); + } if (is_array($lastError) && in_array($lastError['type'], self::FATAL_ERRORS, 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) { diff --git a/src/Monolog/Handler/RotatingFileHandler.php b/src/Monolog/Handler/RotatingFileHandler.php index 6da211c7..12ce6923 100644 --- a/src/Monolog/Handler/RotatingFileHandler.php +++ b/src/Monolog/Handler/RotatingFileHandler.php @@ -185,7 +185,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/src/Monolog/Logger.php b/src/Monolog/Logger.php index e5a32445..39d14a1b 100644 --- a/src/Monolog/Logger.php +++ b/src/Monolog/Logger.php @@ -134,6 +134,13 @@ class Logger implements LoggerInterface, ResettableInterface */ private int $logDepth = 0; + /** + * 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 bool $detectCycles = true; + /** * @param string $name The logging channel, a simple descriptive name that is attached to all log records * @param HandlerInterface[] $handlers Optional stack of handlers, the first one in the array is called first, etc. @@ -269,19 +276,29 @@ class Logger implements LoggerInterface, ResettableInterface return $this; } + public function useLoggingLoopDetection(bool $detectCycles): self + { + $this->detectCycles = $detectCycles; + + return $this; + } + /** * 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 value-of|Level $level */ - public function addRecord(int|Level $level, string $message, array $context = []): bool + public function addRecord(int|Level $level, string $message, array $context = [], DateTimeImmutable $datetime = null): 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; @@ -297,7 +314,7 @@ class Logger implements LoggerInterface, ResettableInterface context: $context, level: self::toMonologLevel($level), channel: $this->name, - datetime: new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), + datetime: $datetime ?? new DateTimeImmutable($this->microsecondTimestamps, $this->timezone), extra: [], ); $handled = false; @@ -336,7 +353,9 @@ class Logger implements LoggerInterface, ResettableInterface return $handled; } finally { - $this->logDepth--; + if ($this->detectCycles) { + $this->logDepth--; + } } } diff --git a/src/Monolog/Test/TestCase.php b/src/Monolog/Test/TestCase.php index 473c9556..98204a95 100644 --- a/src/Monolog/Test/TestCase.php +++ b/src/Monolog/Test/TestCase.php @@ -22,6 +22,8 @@ use Psr\Log\LogLevel; * Lets you easily generate log records and a dummy formatter for testing purposes * * @author Jordi Boggiano + * + * @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 { diff --git a/tests/Monolog/Handler/RotatingFileHandlerTest.php b/tests/Monolog/Handler/RotatingFileHandlerTest.php index a5dd03aa..4294b7f3 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], ]; } diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php index 7b100e6f..41bf3b6b 100644 --- a/tests/Monolog/LoggerTest.php +++ b/tests/Monolog/LoggerTest.php @@ -740,6 +740,28 @@ class LoggerTest extends 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(Level::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