diff --git a/system/Log/Logger.php b/system/Log/Logger.php index 011920e15bd1..2308aece1962 100644 --- a/system/Log/Logger.php +++ b/system/Log/Logger.php @@ -291,10 +291,13 @@ public function log($level, string|Stringable $message, array $context = []): vo */ protected function interpolate($message, array $context = []) { - if (! is_string($message)) { + if (! is_string($message) && ! ($message instanceof Stringable)) { return print_r($message, true); } + // Cast to string in case $message is a Stringable object + $message = (string) $message; + $replace = []; foreach ($context as $key => $val) { @@ -304,7 +307,15 @@ protected function interpolate($message, array $context = []) $val = $val->getMessage() . ' ' . clean_path($val->getFile()) . ':' . $val->getLine(); } + if (is_bool($val)) { + $val = $val ? 'true' : 'false'; + } + // todo - sanitize input before writing to file? + if (is_array($val) || (is_object($val) && ! method_exists($val, '__toString'))) { + $val = print_r($val, true); + } + $replace['{' . $key . '}'] = $val; } @@ -322,9 +333,9 @@ protected function interpolate($message, array $context = []) // Match up environment variables in {env:foo} tags. if (str_contains($message, 'env:')) { - preg_match('/env:[^}]+/', $message, $matches); + preg_match_all('/env:[^}]+/', $message, $matches); - foreach ($matches as $str) { + foreach ($matches[0] as $str) { $key = str_replace('env:', '', $str); $replace["{{$str}}"] = $_ENV[$key] ?? 'n/a'; } diff --git a/tests/system/Log/LoggerTest.php b/tests/system/Log/LoggerTest.php index 80d42d6c83b3..0b309b9ee8c5 100644 --- a/tests/system/Log/LoggerTest.php +++ b/tests/system/Log/LoggerTest.php @@ -22,6 +22,8 @@ use PHPUnit\Framework\Attributes\Group; use ReflectionMethod; use ReflectionNamedType; +use stdClass; +use Stringable; use Tests\Support\Log\Handlers\TestHandler; /** @@ -438,4 +440,123 @@ public function testDetermineFileNoStackTrace(): void $this->assertSame($expected, $logger->determineFile()); } + + public function testLogInterpolatesArrayContext(): 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 ' . print_r(['foo' => 'bar'], true); + + $logger->log('debug', 'Test message {foo}', ['foo' => ['foo' => 'bar']]); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } + + public function testLogInterpolatesObjectContext(): void + { + $config = new LoggerConfig(); + $logger = new Logger($config); + + Time::setTestNow('2023-11-25 12:00:00'); + + $obj = new stdClass(); + $obj->foo = 'bar'; + + $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message ' . print_r($obj, true); + + $logger->log('debug', 'Test message {foo}', ['foo' => $obj]); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } + + public function testLogInterpolatesMultipleEnvironmentVars(): void + { + $config = new LoggerConfig(); + $logger = new Logger($config); + + Time::setTestNow('2023-11-25 12:00:00'); + + $_ENV['foo'] = 'bar'; + $_ENV['baz'] = 'qux'; + + $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Test message bar and qux'; + + $logger->log('debug', 'Test message {env:foo} and {env:baz}'); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } + + public function testLogAcceptsStringableMessage(): void + { + $config = new LoggerConfig(); + $logger = new Logger($config); + + Time::setTestNow('2023-11-25 12:00:00'); + + $message = new class () implements Stringable { + public function __toString(): string + { + return 'Stringable message {foo}'; + } + }; + + $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Stringable message bar'; + + $logger->log('debug', $message, ['foo' => 'bar']); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } + + public function testLogObjectContextLosesProperties(): void + { + $config = new LoggerConfig(); + $logger = new Logger($config); + + Time::setTestNow('2023-11-25 12:00:00'); + + $user = new stdClass(); + $user->name = 'John'; + $user->role = 'admin'; + + $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> User: ' . print_r($user, true); + + $logger->log('debug', 'User: {user}', ['user' => $user]); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } + + public function testLogBooleanFalseIsLoggedAsEmptyString(): void + { + $config = new LoggerConfig(); + $logger = new Logger($config); + + Time::setTestNow('2023-11-25 12:00:00'); + + $expected = 'DEBUG - ' . Time::now()->format('Y-m-d') . ' --> Active: false'; + + $logger->log('debug', 'Active: {status}', ['status' => false]); + + $logs = TestHandler::getLogs(); + + $this->assertCount(1, $logs); + $this->assertSame($expected, $logs[0]); + } }