From cf2bca71872173bd66b7b01d0a5ca7ba59870e82 Mon Sep 17 00:00:00 2001 From: Torben Dannhauer Date: Wed, 8 Jul 2026 22:51:59 +0200 Subject: [PATCH 1/3] fix(log): avoid Array to string conversion warning in SimpleFormatter Context values that are arrays or objects (e.g. extra fields passed through Horde::log()) triggered a PHP "Array to string conversion" warning when interpolated into the format string, which could mask or corrupt the intended log entry. Encode non-scalar values as JSON before interpolation instead. --- src/Formatter/SimpleFormatter.php | 3 +++ test/Formatter/SimpleFormatterTest.php | 15 +++++++++++++++ 2 files changed, 18 insertions(+) diff --git a/src/Formatter/SimpleFormatter.php b/src/Formatter/SimpleFormatter.php index 1b50931..1fc25d0 100644 --- a/src/Formatter/SimpleFormatter.php +++ b/src/Formatter/SimpleFormatter.php @@ -82,6 +82,9 @@ public function format(LogMessage $event): string $context['levelName'] = $event->level()->name(); $context['message'] = $event->formattedMessage(); foreach ($context as $name => $value) { + if (is_array($value) || is_object($value)) { + $value = json_encode($value); + } $output = str_replace("%$name%", (string) $value, $output); } return $output; diff --git a/test/Formatter/SimpleFormatterTest.php b/test/Formatter/SimpleFormatterTest.php index 99448ab..e222fde 100644 --- a/test/Formatter/SimpleFormatterTest.php +++ b/test/Formatter/SimpleFormatterTest.php @@ -241,4 +241,19 @@ public function testFormatConvertsNonStringContextValues(): void // Should convert boolean to string $this->assertStringContainsString('Value: 1', $output); } + + public function testFormatWithArrayContextValueDoesNotWarn(): void + { + $formatter = new SimpleFormatter('Extra: %extra%'); + $message = new LogMessage( + $this->level, + 'test', + ['extra' => ['foo' => 'bar']] + ); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('Extra: {"foo":"bar"}', $output); + } } From 4950f8ef5caf9e886f445a7281a771defa1f1132 Mon Sep 17 00:00:00 2001 From: Ralf Lang Date: Sat, 11 Jul 2026 08:21:51 +0200 Subject: [PATCH 2/3] fix(log): only stringify context values that the template references --- src/Formatter/SimpleFormatter.php | 109 +++++++++++++++- test/Formatter/SimpleFormatterTest.php | 171 +++++++++++++++++++++++++ 2 files changed, 274 insertions(+), 6 deletions(-) diff --git a/src/Formatter/SimpleFormatter.php b/src/Formatter/SimpleFormatter.php index 1fc25d0..8539984 100644 --- a/src/Formatter/SimpleFormatter.php +++ b/src/Formatter/SimpleFormatter.php @@ -21,6 +21,8 @@ use Horde\Log\LogFormatter; use Horde\Log\LogMessage; use InvalidArgumentException; +use Stringable; +use Throwable; /** * @author Mike Naberezny @@ -69,24 +71,119 @@ public function __construct($options = null) /** * Formats an event to be written by the handler. * + * The template's `%name%` placeholders are looked up in the log + * event's context (with the record-level fields — `timestamp`, + * `level`, `levelName`, `message` — overlaid). Values not + * referenced by the template are ignored: PSR-3 log calls + * routinely carry structured context that a given template chooses + * not to render, and touching those values here risks emitting + * PHP warnings (Array-to-string) while the log line is being + * written, which — depending on the error handler — can suppress + * or corrupt the entry itself. Per PSR-3 "implementors MUST + * ensure they treat context data with as much lenience as + * possible." + * + * Referenced values are stringified with a light-touch strategy: + * + * - `exception` context key holding a `Throwable`: rendered as + * `Class(code): message at file:line` — PSR-3 reserves this + * key for `Throwable` instances and callers routinely reference + * `%exception%` in error templates. + * - Scalars and `Stringable` objects: cast to string. + * - Arrays: `json_encode()`; failure falls back to `[array]`. + * - Resources / non-Stringable objects: rendered as + * `[resource(type)]` / `[object ClassName]` — safe types-only + * markers, matching what Symfony's HttpKernel Logger does. + * * @param LogMessage $event Log event. * * @return string Formatted line. */ public function format(LogMessage $event): string { - $output = $this->format; $context = $event->context(); $context['timestamp'] = $event->timestamp()->format('c'); $context['level'] = $event->level()->criticality(); $context['levelName'] = $event->level()->name(); $context['message'] = $event->formattedMessage(); - foreach ($context as $name => $value) { - if (is_array($value) || is_object($value)) { - $value = json_encode($value); + + $placeholders = self::extractPlaceholders($this->format); + if ($placeholders === []) { + return $this->format; + } + + $replacements = []; + foreach ($placeholders as $name) { + if (!array_key_exists($name, $context)) { + // Leave unreferenced (or unset-in-context) placeholders + // literal in the output so a misconfigured template + // surfaces the missing key rather than producing an + // empty-looking log line. + continue; } - $output = str_replace("%$name%", (string) $value, $output); + $replacements['%' . $name . '%'] = self::stringifyContextValue($name, $context[$name]); + } + + return strtr($this->format, $replacements); + } + + /** + * Extract the set of `%name%` placeholder names from the template. + * + * @return list + */ + private static function extractPlaceholders(string $format): array + { + if (!preg_match_all('/%([A-Za-z_][A-Za-z0-9_]*)%/', $format, $matches)) { + return []; + } + // Deduplicate so we do the stringify work once per placeholder + // regardless of how many times it appears in the template. + return array_values(array_unique($matches[1])); + } + + /** + * Reduce an arbitrary context value to a string safely. + * + * PSR-3 requires that context handling never raise a PHP notice, + * warning or error. The strategy here mirrors {@see self::format()}'s + * docblock. + */ + private static function stringifyContextValue(string $name, mixed $value): string + { + // Reserved 'exception' key: PSR-3 mandates it hold a Throwable. + // Callers may still pass something else (leniency), so only + // apply the Throwable rendering when the value actually is one. + if ($name === 'exception' && $value instanceof Throwable) { + return sprintf( + '%s(%s): %s at %s:%d', + $value::class, + (string) $value->getCode(), + $value->getMessage(), + $value->getFile(), + $value->getLine(), + ); + } + + if ($value === null) { + return ''; + } + if (is_scalar($value)) { + return (string) $value; + } + if ($value instanceof Stringable) { + return (string) $value; + } + if (is_array($value)) { + $encoded = json_encode($value); + return $encoded === false ? '[array]' : $encoded; + } + if (is_object($value)) { + return '[object ' . $value::class . ']'; + } + if (is_resource($value)) { + return '[resource(' . get_resource_type($value) . ')]'; } - return $output; + return '[' . gettype($value) . ']'; } } diff --git a/test/Formatter/SimpleFormatterTest.php b/test/Formatter/SimpleFormatterTest.php index e222fde..5364a8b 100644 --- a/test/Formatter/SimpleFormatterTest.php +++ b/test/Formatter/SimpleFormatterTest.php @@ -20,6 +20,9 @@ use PHPUnit\Framework\TestCase; use PHPUnit\Framework\Attributes\CoversClass; use InvalidArgumentException; +use RuntimeException; +use Stringable; +use stdClass; #[CoversClass(SimpleFormatter::class)] class SimpleFormatterTest extends TestCase @@ -256,4 +259,172 @@ public function testFormatWithArrayContextValueDoesNotWarn(): void $this->assertStringContainsString('Extra: {"foo":"bar"}', $output); } + + public function testUnreferencedArrayContextDoesNotWarn(): void + { + // Regression for the imp#88 scenario: the *template* only + // renders %message%, but the caller carries additional array + // context (e.g. structured `exception` details). The + // unreferenced entry must not cast-to-string, or PHP emits an + // "Array to string conversion" warning while the log line is + // being written. + $formatter = new SimpleFormatter('%message%'); + $message = new LogMessage( + $this->level, + 'Login failure', + [ + // Deliberately non-scalar and not referenced by the + // template. The pre-fix code path would still cast it. + 'attempt' => ['user' => 'jan', 'ip' => '10.0.0.1'], + 'extras' => (object) ['a' => 1], + ] + ); + $message->formatMessage([]); + + // Fail if a warning is emitted while formatting. + set_error_handler(static function (int $errno, string $errstr): bool { + throw new RuntimeException( + sprintf('Unexpected PHP notice/warning during format(): [%d] %s', $errno, $errstr), + ); + }, E_WARNING | E_NOTICE); + try { + $output = $formatter->format($message); + } finally { + restore_error_handler(); + } + + $this->assertStringContainsString('Login failure', $output); + // Unreferenced placeholders were never in the template — they + // do not appear in the output. + $this->assertStringNotContainsString('attempt', $output); + $this->assertStringNotContainsString('extras', $output); + } + + public function testFormatWithReferencedExceptionRendersHumanReadable(): void + { + // The PSR-3 reserved 'exception' key is rendered via a + // dedicated Throwable-aware path, so a template referencing + // %exception% gets a readable summary rather than either a + // json_encode() of the object graph or the raw + // Throwable::__toString() (which drops the class and code). + $formatter = new SimpleFormatter('%message%: %exception%'); + $ex = new RuntimeException('boom', 42); + $message = new LogMessage( + $this->level, + 'operation failed', + ['exception' => $ex] + ); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('operation failed:', $output); + $this->assertStringContainsString('RuntimeException(42): boom at ', $output); + $this->assertStringContainsString(__FILE__, $output); + } + + public function testFormatWithReferencedExceptionKeyNotThrowableFallsBack(): void + { + // PSR-3 says the 'exception' key MAY still contain non-Throwable + // values (leniency). When it does, the formatter must fall + // through to the generic stringify path — not throw, and not + // try to call Throwable methods on the value. + $formatter = new SimpleFormatter('exc=%exception%'); + $message = new LogMessage( + $this->level, + 'test', + ['exception' => ['not' => 'a throwable']] + ); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('exc={"not":"a throwable"}', $output); + } + + public function testFormatWithStringableObjectContext(): void + { + $formatter = new SimpleFormatter('val=%val%'); + $stringable = new class implements Stringable { + public function __toString(): string + { + return 'stringable-value'; + } + }; + $message = new LogMessage($this->level, 'test', ['val' => $stringable]); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('val=stringable-value', $output); + } + + public function testFormatWithNonStringableObjectContext(): void + { + // A plain object without __toString() is not treated as an + // array (per the user's design decision: JSON only for true + // arrays; objects go through the Stringable-or-fallback path). + // The rendering is a safe type marker, matching Symfony's + // HttpKernel Logger convention. + $formatter = new SimpleFormatter('val=%val%'); + $obj = new stdClass(); + $obj->foo = 'bar'; + $message = new LogMessage($this->level, 'test', ['val' => $obj]); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('val=[object stdClass]', $output); + } + + public function testFormatWithResourceContext(): void + { + $formatter = new SimpleFormatter('val=%val%'); + $resource = fopen('php://memory', 'r'); + $this->assertIsResource($resource); + $message = new LogMessage($this->level, 'test', ['val' => $resource]); + $message->formatMessage([]); + + $output = $formatter->format($message); + fclose($resource); + + $this->assertMatchesRegularExpression('/val=\[resource\([^)]+\)\]/', $output); + } + + public function testFormatWithNullContextValue(): void + { + $formatter = new SimpleFormatter('before[%val%]after'); + $message = new LogMessage($this->level, 'test', ['val' => null]); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('before[]after', $output); + } + + public function testFormatIgnoresLiteralPercentPairsWithoutPlaceholderName(): void + { + // A `%%` pair (or any %% sequence) must be + // left alone — the regex only matches identifiers. + $formatter = new SimpleFormatter('100%% done: %message%'); + $message = new LogMessage($this->level, 'ok'); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('100%% done: ok', $output); + } + + public function testFormatWithRepeatedPlaceholder(): void + { + // The same %name% appearing twice in the template both get + // substituted with the same value. + $formatter = new SimpleFormatter('%message%/%message%'); + $message = new LogMessage($this->level, 'hi'); + $message->formatMessage([]); + + $output = $formatter->format($message); + + $this->assertStringContainsString('hi/hi', $output); + } } From 725bdc56d5cbafa49665f7a0ca5559d5e66ed2f9 Mon Sep 17 00:00:00 2001 From: Ralf Lang Date: Sat, 11 Jul 2026 09:13:24 +0200 Subject: [PATCH 3/3] fix(log): type SystemdJournalHandler::$socket as \Socket for PHP 8+ --- src/Handler/SystemdJournalHandler.php | 21 ++++++++++++--------- 1 file changed, 12 insertions(+), 9 deletions(-) diff --git a/src/Handler/SystemdJournalHandler.php b/src/Handler/SystemdJournalHandler.php index c1c69f4..d0cd41c 100644 --- a/src/Handler/SystemdJournalHandler.php +++ b/src/Handler/SystemdJournalHandler.php @@ -73,11 +73,14 @@ class SystemdJournalHandler extends BaseHandler protected SystemdJournalOptions $options; /** - * Socket resource for journal communication + * Socket for journal communication. `null` before the first + * successful `write()`; a live `\Socket` afterwards. PHP 8+ + * models the AF_UNIX/SOCK_DGRAM handle as a `\Socket` object + * rather than the pre-8.0 `resource`. * - * @var resource|null + * @var \Socket|null */ - private $socket = null; + private ?\Socket $socket = null; /** * Lazy-initialized syslog fallback handler @@ -136,17 +139,17 @@ public function write(LogMessage $event): bool // Lazy socket initialization if ($this->socket === null) { - $this->socket = socket_create(AF_UNIX, SOCK_DGRAM, 0); - if ($this->socket === false) { + $socket = socket_create(AF_UNIX, SOCK_DGRAM, 0); + if ($socket === false) { throw new LogException('Failed to create socket: ' . socket_strerror(socket_last_error())); } - if (!socket_connect($this->socket, $this->options->socketPath)) { - $error = socket_strerror(socket_last_error($this->socket)); - socket_close($this->socket); - $this->socket = null; + if (!socket_connect($socket, $this->options->socketPath)) { + $error = socket_strerror(socket_last_error($socket)); + socket_close($socket); throw new LogException('Failed to connect to journal socket: ' . $error); } + $this->socket = $socket; } // Build message payload in systemd journal format