Fix cycle detection within fibers (#1753)

* Fix cycle detection within fibers We keep a separate depth count per fiber. Fixes #1752. * Avoid additional call to Fiber::getCurrent() Suppresses phpstan errors, as they're false positives.
Seldaek · Feb 4, 2023 · 0f01420 · 0f01420
1 parent 58f5030
commit 0f01420
Show file tree

Hide file tree

Showing 2 changed files with 106 additions and 4 deletions.
diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php
@@ -168,6 +168,11 @@ class Logger implements LoggerInterface, ResettableInterface
      */
     private $logDepth = 0;
 
+    /**
+     * @var \WeakMap<\Fiber, int>|null Keeps track of depth inside fibers to prevent infinite logging loops
+     */
+    private $fiberLogDepth;
+
     /**
      * @var bool Whether to detect infinite logging loops
      *
@@ -189,6 +194,13 @@ public function __construct(string $name, array $handlers = [], array $processor
         $this->setHandlers($handlers);
         $this->processors = $processors;
         $this->timezone = $timezone ?: new DateTimeZone(date_default_timezone_get() ?: 'UTC');
+
+        if (\PHP_VERSION_ID >= 80100) {
+            // Local variable for phpstan, see https://github.com/phpstan/phpstan/issues/6732#issuecomment-1111118412
+            /** @var \WeakMap<\Fiber, int> $fiberLogDepth */
+            $fiberLogDepth = new \WeakMap();
+            $this->fiberLogDepth = $fiberLogDepth;
+        }
     }
 
     public function getName(): string
@@ -332,12 +344,21 @@ public function addRecord(int $level, string $message, array $context = [], Date
         }
 
         if ($this->detectCycles) {
-            $this->logDepth += 1;
+            // @phpstan-ignore-next-line
+            if (\PHP_VERSION_ID >= 80100 && $fiber = \Fiber::getCurrent()) {
+                $this->fiberLogDepth[$fiber] = $this->fiberLogDepth[$fiber] ?? 0;
+                $logDepth = ++$this->fiberLogDepth[$fiber];
+            } else {
+                $logDepth = ++$this->logDepth;
+            }
+        } else {
+            $logDepth = 0;
         }
-        if ($this->logDepth === 3) {
+
+        if ($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
+        } elseif ($logDepth >= 5) { // log depth 4 is let through, so we can log the warning above
             return false;
         }
 
@@ -387,7 +408,12 @@ public function addRecord(int $level, string $message, array $context = [], Date
             }
         } finally {
             if ($this->detectCycles) {
-                $this->logDepth--;
+                if (isset($fiber)) {
+                    // @phpstan-ignore-next-line
+                    $this->fiberLogDepth[$fiber]--;
+                } else {
+                    $this->logDepth--;
+                }
             }
         }
 

diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php
@@ -792,6 +792,58 @@ public function testLogWithDateTime()
             $this->assertEquals($datetime->format('Y-m-d H:i:s'), $record['datetime']->format('Y-m-d H:i:s'));
         }
     }
+
+    /**
+     * @requires PHP 8.1
+     */
+    public function testLogCycleDetectionWithFibersWithoutCycle()
+    {
+        $logger = new Logger(__METHOD__);
+
+        $fiberSuspendHandler = new FiberSuspendHandler();
+        $testHandler = new TestHandler();
+
+        $logger->pushHandler($fiberSuspendHandler);
+        $logger->pushHandler($testHandler);
+
+        $fibers = [];
+        for ($i = 0; $i < 10; $i++) {
+            $fiber = new \Fiber(static function () use ($logger) {
+                $logger->info('test');
+            });
+
+            $fiber->start();
+
+            // We need to keep a reference here, because otherwise the fiber gets automatically cleaned up
+            $fibers[] = $fiber;
+        }
+
+        self::assertCount(10, $testHandler->getRecords());
+    }
+
+    /**
+     * @requires PHP 8.1
+     */
+    public function testLogCycleDetectionWithFibersWithCycle()
+    {
+        $logger = new Logger(__METHOD__);
+
+        $fiberSuspendHandler = new FiberSuspendHandler();
+        $loggingHandler = new LoggingHandler($logger);
+        $testHandler = new TestHandler();
+
+        $logger->pushHandler($fiberSuspendHandler);
+        $logger->pushHandler($loggingHandler);
+        $logger->pushHandler($testHandler);
+
+        $fiber = new \Fiber(static function () use ($logger) {
+            $logger->info('test');
+        });
+
+        $fiber->start();
+
+        self::assertCount(3, $testHandler->getRecords());
+    }
 }
 
 class LoggingHandler implements HandlerInterface
@@ -826,3 +878,27 @@ public function close(): void
     {
     }
 }
+
+
+class FiberSuspendHandler implements HandlerInterface
+{
+    public function isHandling(array $record): bool
+    {
+        return true;
+    }
+
+    public function handle(array $record): bool
+    {
+        \Fiber::suspend();
+
+        return true;
+    }
+
+    public function handleBatch(array $records): void
+    {
+    }
+
+    public function close(): void
+    {
+    }
+}