Repository: Seldaek/monolog (php)

Issue:
Cycle detection doesn't work well with fibers
[Cycle detection](https://github.com/Seldaek/monolog/blob/e68c00670e310e276da9624d75965f5d2f28aa80/src/Monolog/Logger.php#L324) is broken when using fibers, because it assumes that if the function is entered multiple times, it's a cycle. With fibers, the function might be entered multiple times in different fibers if one of them suspends somewhere within the function.

What are your thoughts to moving cycle detection to an interface? There could be a `NullCycleDetector` that doesn't detect cycles at all, a `CountingCycleDetector` and then a [`FiberLocal`](https://github.com/revoltphp/event-loop/blob/4e7455506d9ff61f3705b76a20a8f12ad4dc1552/src/EventLoop/FiberLocal.php) based implementation that keeps track of the depth for each fiber separately. I'm of course also fine with fibers being supported natively, but I don't think it's a good idea to put this logic into `Logger` itself in that case.

Pull request:
Fix cycle detection within fibers
We keep a separate depth count per fiber.

Fixes #1752.

Patch:
diff --git a/.editorconfig b/.editorconfig
new file mode 100644
index 00000000..9007f6ba
--- /dev/null
+++ b/.editorconfig
@@ -0,0 +1,12 @@
+root = true
+
+[*]
+charset = utf-8
+indent_size = 4
+indent_style = space
+end_of_line = lf
+insert_final_newline = true
+trim_trailing_whitespace = true
+
+[*.{yml,yaml}]
+indent_size = 2
diff --git a/.gitattributes b/.gitattributes
index 6da920e3..15891ca2 100644
--- a/.gitattributes
+++ b/.gitattributes
@@ -5,3 +5,4 @@
 /phpunit.xml.dist export-ignore
 /_config.yml export-ignore
 /UPGRADE.md
+/.editorconfig export-ignore
diff --git a/src/Monolog/Formatter/GoogleCloudLoggingFormatter.php b/src/Monolog/Formatter/GoogleCloudLoggingFormatter.php
index 0cd287f5..ca52ebf4 100644
--- a/src/Monolog/Formatter/GoogleCloudLoggingFormatter.php
+++ b/src/Monolog/Formatter/GoogleCloudLoggingFormatter.php
@@ -17,6 +17,7 @@ use Monolog\LogRecord;
 /**
  * Encodes message information into JSON in a format compatible with Cloud logging.
  *
+ * @see https://cloud.google.com/logging/docs/structured-logging
  * @see https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry
  *
  * @author Luís Cobucci <lcobucci@gmail.com>
@@ -28,7 +29,7 @@ final class GoogleCloudLoggingFormatter extends JsonFormatter
     {
         // Re-key level for GCP logging
         $record['severity'] = $record['level_name'];
-        $record['timestamp'] = $record['datetime']->format(DateTimeInterface::RFC3339_EXTENDED);
+        $record['time'] = $record['datetime']->format(DateTimeInterface::RFC3339_EXTENDED);
 
         // Remove keys that are not used by GCP
         unset($record['level'], $record['level_name'], $record['datetime']);
diff --git a/src/Monolog/Handler/AmqpHandler.php b/src/Monolog/Handler/AmqpHandler.php
index c4997482..994872ce 100644
--- a/src/Monolog/Handler/AmqpHandler.php
+++ b/src/Monolog/Handler/AmqpHandler.php
@@ -151,13 +151,14 @@ class AmqpHandler extends AbstractProcessingHandler
 
     private function createAmqpMessage(string $data): AMQPMessage
     {
-        return new AMQPMessage(
-            $data,
-            [
-                'delivery_mode' => 2,
-                'content_type' => 'application/json',
-            ]
-        );
+        $attributes = [
+            'delivery_mode' => 2,
+            'content_type' => 'application/json',
+        ];
+        if ($this->extraAttributes) {
+            $attributes = array_merge($attributes, $this->extraAttributes);
+        }
+        return new AMQPMessage($data, $attributes);
     }
 
     /**
diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php
index 1ab75b9e..f9ec27e8 100644
--- 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 @@ class Logger implements LoggerInterface, ResettableInterface
         $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 @@ class Logger implements LoggerInterface, ResettableInterface
         }
 
         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 @@ class Logger implements LoggerInterface, ResettableInterface
             }
         } finally {
             if ($this->detectCycles) {
-                $this->logDepth--;
+                if (isset($fiber)) {
+                    // @phpstan-ignore-next-line
+                    $this->fiberLogDepth[$fiber]--;
+                } else {
+                    $this->logDepth--;
+                }
             }
         }
 


Test patch:
diff --git a/tests/Monolog/Formatter/GoogleCloudLoggingFormatterTest.php b/tests/Monolog/Formatter/GoogleCloudLoggingFormatterTest.php
index 27aea2ca..55dfc76d 100644
--- a/tests/Monolog/Formatter/GoogleCloudLoggingFormatterTest.php
+++ b/tests/Monolog/Formatter/GoogleCloudLoggingFormatterTest.php
@@ -30,8 +30,8 @@ class GoogleCloudLoggingFormatterTest extends TestCase
 
         $formatted_decoded = json_decode($formatter->format($record), true);
         $this->assertArrayNotHasKey("datetime", $formatted_decoded);
-        $this->assertArrayHasKey("timestamp", $formatted_decoded);
-        $this->assertSame($record['datetime']->format(DateTimeInterface::RFC3339_EXTENDED), $formatted_decoded["timestamp"]);
+        $this->assertArrayHasKey("time", $formatted_decoded);
+        $this->assertSame($record['datetime']->format(DateTimeInterface::RFC3339_EXTENDED), $formatted_decoded["time"]);
     }
 
     /**
diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php
index fd99df20..a0ec7405 100644
--- a/tests/Monolog/LoggerTest.php
+++ b/tests/Monolog/LoggerTest.php
@@ -792,6 +792,58 @@ class LoggerTest extends \PHPUnit\Framework\TestCase
             $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 @@ class LoggingHandler implements HandlerInterface
     {
     }
 }
+
+
+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
+    {
+    }
+}
\ No newline at end of file