fix: safely interpolate logger context values

system/Log/Logger.php

@@ -13,6 +13,7 @@
 
 namespace CodeIgniter\Log;
 
+use CodeIgniter\Entity\Entity;
 use CodeIgniter\Exceptions\RuntimeException;
 use CodeIgniter\Log\Exceptions\LogException;
 use CodeIgniter\Log\Handlers\HandlerInterface;
@@ -298,14 +299,14 @@ protected function interpolate($message, array $context = [])
         $replace = [];
 
         foreach ($context as $key => $val) {
-            // Verify that the 'exception' key is actually an exception
-            // or error, both of which implement the 'Throwable' interface.
-            if ($key === 'exception' && $val instanceof Throwable) {
-                $val = $val->getMessage() . ' ' . clean_path($val->getFile()) . ':' . $val->getLine();
+            $placeholder = '{' . $key . '}';
+
+            if (! str_contains($message, $placeholder)) {
+                continue;
             }
 
             // todo - sanitize input before writing to file?
-            $replace['{' . $key . '}'] = $val;
+            $replace[$placeholder] = $this->stringifyContextValue($key, $val);
         }
 
         $replace['{post_vars}'] = '$_POST: ' . print_r(service('superglobals')->getPostArray(), true);
@@ -337,6 +338,48 @@ protected function interpolate($message, array $context = [])
         return strtr($message, $replace);
     }
 
+    /**
+     * Converts context values to strings without raising PHP errors.
+     */
+    protected function stringifyContextValue(int|string $key, mixed $value): string
+    {
+        // Verify that the 'exception' key is actually an exception
+        // or error, both of which implement the 'Throwable' interface.
+        if ($key === 'exception' && $value instanceof Throwable) {
+            return $value->getMessage() . ' ' . clean_path($value->getFile()) . ':' . $value->getLine();
+        }
+
+        if ($value === null || is_scalar($value)) {
+            return (string) $value;
+        }
+
+        if ($value instanceof Stringable) {
+            try {
+                return (string) $value;
+            } catch (Throwable) {
+                return '[object ' . $value::class . ']';
+            }
+        }
+
+        if (is_array($value)) {
+            return print_r($value, true);
+        }
+
+        if ($value instanceof Entity) {
+            try {
+                return print_r($value->toArray(), true);
+            } catch (Throwable) {
+                return '[object ' . $value::class . ']';
+            }
+        }
+
+        if (is_object($value)) {
+            return '[object ' . $value::class . ']';
+        }
+
+        return '[' . get_debug_type($value) . ']';
+    }
+
     /**
      * Determines the file and line that the logging call
      * was made from by analyzing the backtrace.

tests/system/Log/LoggerTest.php

@@ -13,6 +13,7 @@
 
 namespace CodeIgniter\Log;
 
+use CodeIgniter\Entity\Entity;
 use CodeIgniter\Exceptions\FrameworkException;
 use CodeIgniter\Exceptions\RuntimeException;
 use CodeIgniter\I18n\Time;
@@ -22,6 +23,8 @@
 use PHPUnit\Framework\Attributes\Group;
 use ReflectionMethod;
 use ReflectionNamedType;
+use stdClass;
+use Stringable;
 use Tests\Support\Log\Handlers\TestHandler;
 
 /**
@@ -123,6 +126,161 @@ public function testLogInterpolatesMessage(): void
         $this->assertSame($expected, $logs[0]);
     }
 
+    public function testLogInterpolatesArrayContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $payload  = ['id' => 123, 'status' => 'created'];
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message ' . print_r($payload, true);
+
+        $logger->log('debug', 'Test message {payload}', ['payload' => $payload]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesOnlyExactDottedContextKey(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message literal';
+
+        $logger->log('debug', 'Test message {foo.bar}', [
+            'foo.bar' => 'literal',
+            'foo'     => ['bar' => 'nested'],
+        ]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogIgnoresUnusedArrayContextValueDuringInterpolation(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message value';
+
+        $logger->log('debug', 'Test message {name}', [
+            'name'    => 'value',
+            'payload' => ['id' => 123],
+        ]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesStringableContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message stringable';
+
+        $logger->log('debug', 'Test message {value}', [
+            'value' => new class () implements Stringable {
+                public function __toString(): string
+                {
+                    return 'stringable';
+                }
+            },
+        ]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesTimeContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $time     = Time::parse('2024-01-02 03:04:05', 'UTC');
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message 2024-01-02 03:04:05';
+
+        $logger->log('debug', 'Test message {time}', ['time' => $time]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesNonStringableObjectContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message [object stdClass]';
+
+        $logger->log('debug', 'Test message {value}', ['value' => new stdClass()]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesResourceContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $resource = fopen('php://memory', 'rb');
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message [resource (stream)]';
+
+        $logger->log('debug', 'Test message {value}', ['value' => $resource]);
+
+        fclose($resource);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
+    public function testLogInterpolatesEntityContextValue(): void
+    {
+        $config = new LoggerConfig();
+        $logger = new Logger($config);
+
+        Time::setTestNow('2023-11-25 12:00:00');
+
+        $entity   = new Entity(['id' => 123, 'name' => 'Ada']);
+        $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message ' . print_r($entity->toArray(), true);
+
+        $logger->log('debug', 'Test message {entity}', ['entity' => $entity]);
+
+        $logs = TestHandler::getLogs();
+
+        $this->assertCount(1, $logs);
+        $this->assertSame($expected, $logs[0]);
+    }
+
     public function testLogInterpolatesPost(): void
     {
         $config = new LoggerConfig();

user_guide_src/source/changelogs/v4.7.5.rst

@@ -30,6 +30,8 @@ Deprecations
 Bugs Fixed
 **********
 
+- **Logger:** Fixed a bug where interpolating a log message with array or non-stringable context values could raise PHP warnings or errors.
+
 See the repo's
 `CHANGELOG.md <https://github.com/codeigniter4/CodeIgniter4/blob/develop/CHANGELOG.md>`_
 for a complete list of bugs fixed.