Fix LogRecord "extra" data leaking between handlers (#1819)

Co-authored-by: Jordi Boggiano <j.boggiano@seld.be>
Seldaek · Oct 27, 2023 · b0f4bf7 · b0f4bf7
1 parent 8ff4ab5
commit b0f4bf7
Show file tree

Hide file tree

Showing 9 changed files with 128 additions and 19 deletions.
diff --git a/src/Monolog/Handler/FallbackGroupHandler.php b/src/Monolog/Handler/FallbackGroupHandler.php
@@ -33,7 +33,7 @@ public function handle(LogRecord $record): bool
         }
         foreach ($this->handlers as $handler) {
             try {
-                $handler->handle($record);
+                $handler->handle(clone $record);
                 break;
             } catch (Throwable $e) {
                 // What throwable?
@@ -58,7 +58,7 @@ public function handleBatch(array $records): void
 
         foreach ($this->handlers as $handler) {
             try {
-                $handler->handleBatch($records);
+                $handler->handleBatch(array_map(fn ($record) => clone $record, $records));
                 break;
             } catch (Throwable $e) {
                 // What throwable?

diff --git a/src/Monolog/Handler/GroupHandler.php b/src/Monolog/Handler/GroupHandler.php
@@ -70,7 +70,7 @@ public function handle(LogRecord $record): bool
         }
 
         foreach ($this->handlers as $handler) {
-            $handler->handle($record);
+            $handler->handle(clone $record);
         }
 
         return false === $this->bubble;
@@ -90,7 +90,7 @@ public function handleBatch(array $records): void
         }
 
         foreach ($this->handlers as $handler) {
-            $handler->handleBatch($records);
+            $handler->handleBatch(array_map(fn ($record) => clone $record, $records));
         }
     }
 

diff --git a/src/Monolog/Handler/WhatFailureGroupHandler.php b/src/Monolog/Handler/WhatFailureGroupHandler.php
@@ -33,7 +33,7 @@ public function handle(LogRecord $record): bool
 
         foreach ($this->handlers as $handler) {
             try {
-                $handler->handle($record);
+                $handler->handle(clone $record);
             } catch (Throwable) {
                 // What failure?
             }
@@ -57,7 +57,7 @@ public function handleBatch(array $records): void
 
         foreach ($this->handlers as $handler) {
             try {
-                $handler->handleBatch($records);
+                $handler->handleBatch(array_map(fn ($record) => clone $record, $records));
             } catch (Throwable) {
                 // What failure?
             }

diff --git a/src/Monolog/Logger.php b/src/Monolog/Logger.php
@@ -355,11 +355,11 @@ public function addRecord(int|Level $level, string $message, array $context = []
             $recordInitialized = count($this->processors) === 0;
 
             $record = new LogRecord(
+                datetime: $datetime ?? new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),
+                channel: $this->name,
+                level: self::toMonologLevel($level),
                 message: $message,
                 context: $context,
-                level: self::toMonologLevel($level),
-                channel: $this->name,
-                datetime: $datetime ?? new DateTimeImmutable($this->microsecondTimestamps, $this->timezone),
                 extra: [],
             );
             $handled = false;
@@ -386,7 +386,7 @@ public function addRecord(int|Level $level, string $message, array $context = []
                 // once the record is initialized, send it to all handlers as long as the bubbling chain is not interrupted
                 try {
                     $handled = true;
-                    if (true === $handler->handle($record)) {
+                    if (true === $handler->handle(clone $record)) {
                         break;
                     }
                 } catch (Throwable $e) {

diff --git a/tests/Monolog/Handler/ExceptionTestHandler.php b/tests/Monolog/Handler/ExceptionTestHandler.php
@@ -19,10 +19,8 @@ class ExceptionTestHandler extends TestHandler
     /**
      * @inheritDoc
      */
-    public function handle(LogRecord $record): bool
+    protected function write(LogRecord $record): void
     {
         throw new Exception("ExceptionTestHandler::handle");
-
-        parent::handle($record);
     }
 }
diff --git a/tests/Monolog/Handler/FallbackGroupHandlerTest.php b/tests/Monolog/Handler/FallbackGroupHandlerTest.php
@@ -12,6 +12,7 @@
 namespace Monolog\Handler;
 
 use Monolog\Level;
+use Monolog\LogRecord;
 use Monolog\Test\TestCase;
 
 class FallbackGroupHandlerTest extends TestCase
@@ -138,4 +139,37 @@ public function testHandleBatchUsesProcessors()
         $this->assertTrue($records[0]['extra']['foo2']);
         $this->assertTrue($records[1]['extra']['foo2']);
     }
+
+    public function testProcessorsDoNotInterfereBetweenHandlers()
+    {
+        $t1 = new ExceptionTestHandler();
+        $t2 = new TestHandler();
+        $handler = new FallbackGroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+        $handler->handle($this->getRecord());
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
+
+    public function testProcessorsDoNotInterfereBetweenHandlersWithBatch()
+    {
+        $t1 = new ExceptionTestHandler();
+        $t2 = new TestHandler();
+        $handler = new FallbackGroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+
+        $handler->handleBatch([$this->getRecord()]);
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
 }
diff --git a/tests/Monolog/Handler/GroupHandlerTest.php b/tests/Monolog/Handler/GroupHandlerTest.php
@@ -11,6 +11,7 @@
 
 namespace Monolog\Handler;
 
+use Monolog\LogRecord;
 use Monolog\Test\TestCase;
 use Monolog\Level;
 
@@ -117,4 +118,37 @@ public function testHandleBatchUsesProcessors()
             $this->assertTrue($records[1]['extra']['foo2']);
         }
     }
+
+    public function testProcessorsDoNotInterfereBetweenHandlers()
+    {
+        $t1 = new TestHandler();
+        $t2 = new TestHandler();
+        $handler = new GroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+        $handler->handle($this->getRecord());
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
+
+    public function testProcessorsDoNotInterfereBetweenHandlersWithBatch()
+    {
+        $t1 = new TestHandler();
+        $t2 = new TestHandler();
+        $handler = new GroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+
+        $handler->handleBatch([$this->getRecord()]);
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
 }
diff --git a/tests/Monolog/Handler/WhatFailureGroupHandlerTest.php b/tests/Monolog/Handler/WhatFailureGroupHandlerTest.php
@@ -11,6 +11,7 @@
 
 namespace Monolog\Handler;
 
+use Monolog\LogRecord;
 use Monolog\Test\TestCase;
 use Monolog\Level;
 
@@ -136,4 +137,37 @@ public function testHandleException()
         $records = $test->getRecords();
         $this->assertTrue($records[0]['extra']['foo']);
     }
+
+    public function testProcessorsDoNotInterfereBetweenHandlers()
+    {
+        $t1 = new TestHandler();
+        $t2 = new TestHandler();
+        $handler = new WhatFailureGroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+        $handler->handle($this->getRecord());
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
+
+    public function testProcessorsDoNotInterfereBetweenHandlersWithBatch()
+    {
+        $t1 = new TestHandler();
+        $t2 = new TestHandler();
+        $handler = new WhatFailureGroupHandler([$t1, $t2]);
+
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+
+        $handler->handleBatch([$this->getRecord()]);
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
 }
diff --git a/tests/Monolog/LoggerTest.php b/tests/Monolog/LoggerTest.php
@@ -638,6 +638,21 @@ public static function useMicrosecondTimestampsProvider()
         ];
     }
 
+    public function testProcessorsDoNotInterfereBetweenHandlers()
+    {
+        $logger = new Logger('foo');
+        $logger->pushHandler($t1 = new TestHandler());
+        $logger->pushHandler($t2 = new TestHandler());
+        $t1->pushProcessor(function (LogRecord $record) {
+            $record->extra['foo'] = 'bar';
+
+            return $record;
+        });
+        $logger->error('Foo');
+
+        self::assertSame([], $t2->getRecords()[0]->extra);
+    }
+
     /**
      * @covers Logger::setExceptionHandler
      */
@@ -804,9 +819,6 @@ public function testLogWithDateTime()
         }
     }
 
-    /**
-     * @requires PHP 8.1
-     */
     public function testLogCycleDetectionWithFibersWithoutCycle()
     {
         $logger = new Logger(__METHOD__);
@@ -832,9 +844,6 @@ public function testLogCycleDetectionWithFibersWithoutCycle()
         self::assertCount(10, $testHandler->getRecords());
     }
 
-    /**
-     * @requires PHP 8.1
-     */
     public function testLogCycleDetectionWithFibersWithCycle()
     {
         $logger = new Logger(__METHOD__);