Skip to content

Commit a553d2c

Browse files
michalsnmichalsn
committed
feat: add per-call context logging with Throwable normalization
1 parent 570acae commit a553d2c

6 files changed

Lines changed: 307 additions & 1 deletion

File tree

‎app/Config/Logger.php‎

Lines changed: 35 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,41 @@ class Logger extends BaseConfig
6767
*/
6868
public bool $logGlobalContext = false;
6969

70+
/**
71+
* --------------------------------------------------------------------------
72+
* Whether to log per-call context data
73+
* --------------------------------------------------------------------------
74+
*
75+
* When enabled, context keys not used as placeholders in the message are
76+
* passed to handlers as structured data. Any Throwable instances found in
77+
* the context are automatically normalized to an array representation.
78+
*/
79+
public bool $logContext = false;
80+
81+
/**
82+
* --------------------------------------------------------------------------
83+
* Whether to include the stack trace for Throwables in context
84+
* --------------------------------------------------------------------------
85+
*
86+
* When enabled, the stack trace is included when a Throwable is found in
87+
* the context and normalized. Only relevant when $logContext is true.
88+
*/
89+
public bool $logContextTrace = false;
90+
91+
/**
92+
* --------------------------------------------------------------------------
93+
* Whether to keep context keys that were used as placeholders
94+
* --------------------------------------------------------------------------
95+
*
96+
* By default, context keys that were interpolated into the message as
97+
* {placeholder} are stripped before passing context to handlers, since
98+
* their values are already present in the message text. Set to true to
99+
* keep them as structured data as well.
100+
*
101+
* Only relevant when $logContext is true.
102+
*/
103+
public bool $logContextUsedKeys = false;
104+
70105
/**
71106
* --------------------------------------------------------------------------
72107
* Log Handlers

‎system/Log/Logger.php‎

Lines changed: 74 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -121,6 +121,27 @@ class Logger implements LoggerInterface
121121
*/
122122
protected bool $logGlobalContext = false;
123123

124+
/**
125+
* Whether to log per-call context data passed to log methods.
126+
*
127+
* Set in app/Config/Logger.php
128+
*/
129+
protected bool $logContext = false;
130+
131+
/**
132+
* Whether to include the stack trace when a Throwable is in the context.
133+
*
134+
* Set in app/Config/Logger.php
135+
*/
136+
protected bool $logContextTrace = false;
137+
138+
/**
139+
* Whether to keep context keys that were already used as placeholders.
140+
*
141+
* Set in app/Config/Logger.php
142+
*/
143+
protected bool $logContextUsedKeys = false;
144+
124145
/**
125146
* Constructor.
126147
*
@@ -162,7 +183,10 @@ public function __construct($config, bool $debug = CI_DEBUG)
162183
$this->logCache = [];
163184
}
164185

165-
$this->logGlobalContext = $config->logGlobalContext ?? $this->logGlobalContext;
186+
$this->logGlobalContext = $config->logGlobalContext ?? $this->logGlobalContext;
187+
$this->logContext = $config->logContext ?? $this->logContext;
188+
$this->logContextTrace = $config->logContextTrace ?? $this->logContextTrace;
189+
$this->logContextUsedKeys = $config->logContextUsedKeys ?? $this->logContextUsedKeys;
166190
}
167191

168192
/**
@@ -259,8 +283,26 @@ public function log($level, string|Stringable $message, array $context = []): vo
259283
return;
260284
}
261285

286+
$interpolatedKeys = array_keys(array_filter(
287+
$context,
288+
static fn ($key): bool => str_contains((string) $message, '{' . $key . '}'),
289+
ARRAY_FILTER_USE_KEY,
290+
));
291+
262292
$message = $this->interpolate($message, $context);
263293

294+
if ($this->logContext) {
295+
if (! $this->logContextUsedKeys) {
296+
foreach ($interpolatedKeys as $key) {
297+
unset($context[$key]);
298+
}
299+
}
300+
301+
$context = $this->normalizeContext($context);
302+
} else {
303+
$context = [];
304+
}
305+
264306
if ($this->logGlobalContext) {
265307
$globalContext = service('context')->getAll();
266308
if ($globalContext !== []) {
@@ -290,6 +332,37 @@ public function log($level, string|Stringable $message, array $context = []): vo
290332
}
291333
}
292334

335+
/**
336+
* Normalizes context values for structured logging.
337+
* Converts any Throwable instances into an array representation.
338+
*
339+
* @param array<string, mixed> $context
340+
*
341+
* @return array<string, mixed>
342+
*/
343+
protected function normalizeContext(array $context): array
344+
{
345+
foreach ($context as $key => $value) {
346+
if ($value instanceof Throwable) {
347+
$normalized = [
348+
'class' => $value::class,
349+
'message' => $value->getMessage(),
350+
'code' => $value->getCode(),
351+
'file' => clean_path($value->getFile()),
352+
'line' => $value->getLine(),
353+
];
354+
355+
if ($this->logContextTrace) {
356+
$normalized['trace'] = $value->getTraceAsString();
357+
}
358+
359+
$context[$key] = $normalized;
360+
}
361+
}
362+
363+
return $context;
364+
}
365+
293366
/**
294367
* Replaces any placeholders in the message with variables
295368
* from the context, as well as a few special items like:

‎tests/system/Log/LoggerTest.php‎

Lines changed: 151 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -505,4 +505,155 @@ public function testDoesNotLogHiddenGlobalContext(): void
505505
$this->assertCount(1, $logs);
506506
$this->assertSame($expected, $logs[0]);
507507
}
508+
509+
public function testContextNotPassedToHandlersByDefault(): void
510+
{
511+
$config = new LoggerConfig();
512+
$logger = new Logger($config);
513+
514+
$logger->log('debug', 'Test message', ['foo' => 'bar', 'baz' => 'qux']);
515+
516+
$contexts = TestHandler::getContexts();
517+
518+
$this->assertSame([[]], $contexts);
519+
}
520+
521+
public function testLogContextPassesNonInterpolatedKeysToHandlers(): void
522+
{
523+
$config = new LoggerConfig();
524+
$config->logContext = true;
525+
526+
$logger = new Logger($config);
527+
528+
$logger->log('debug', 'Hello {name}', ['name' => 'World', 'user_id' => 42]);
529+
530+
$contexts = TestHandler::getContexts();
531+
532+
$this->assertArrayNotHasKey('name', $contexts[0]);
533+
$this->assertSame(42, $contexts[0]['user_id']);
534+
}
535+
536+
public function testLogContextStripsInterpolatedKeysByDefault(): void
537+
{
538+
$config = new LoggerConfig();
539+
$config->logContext = true;
540+
541+
$logger = new Logger($config);
542+
543+
$logger->log('debug', 'Hello {name}', ['name' => 'World']);
544+
545+
$contexts = TestHandler::getContexts();
546+
547+
$this->assertSame([[]], $contexts);
548+
}
549+
550+
public function testLogContextKeepsInterpolatedKeysWhenEnabled(): void
551+
{
552+
$config = new LoggerConfig();
553+
$config->logContext = true;
554+
$config->logContextUsedKeys = true;
555+
556+
$logger = new Logger($config);
557+
558+
$logger->log('debug', 'Hello {name}', ['name' => 'World']);
559+
560+
$contexts = TestHandler::getContexts();
561+
562+
$this->assertArrayHasKey('name', $contexts[0]);
563+
$this->assertSame('World', $contexts[0]['name']);
564+
}
565+
566+
public function testLogContextNormalizesThrowable(): void
567+
{
568+
$config = new LoggerConfig();
569+
$config->logContext = true;
570+
571+
$logger = new Logger($config);
572+
573+
try {
574+
throw new RuntimeException('Something went wrong', 42);
575+
} catch (RuntimeException $e) {
576+
$logger->log('error', 'An error occurred', ['exception' => $e]);
577+
}
578+
579+
$contexts = TestHandler::getContexts();
580+
581+
$this->assertArrayHasKey('exception', $contexts[0]);
582+
583+
$normalized = $contexts[0]['exception'];
584+
585+
$this->assertSame(RuntimeException::class, $normalized['class']);
586+
$this->assertSame('Something went wrong', $normalized['message']);
587+
$this->assertSame(42, $normalized['code']);
588+
$this->assertArrayHasKey('file', $normalized);
589+
$this->assertArrayHasKey('line', $normalized);
590+
$this->assertArrayNotHasKey('trace', $normalized);
591+
}
592+
593+
public function testLogContextNormalizesThrowableWithTrace(): void
594+
{
595+
$config = new LoggerConfig();
596+
$config->logContext = true;
597+
$config->logContextTrace = true;
598+
599+
$logger = new Logger($config);
600+
601+
try {
602+
throw new RuntimeException('Something went wrong');
603+
} catch (RuntimeException $e) {
604+
$logger->log('error', 'An error occurred', ['exception' => $e]);
605+
}
606+
607+
$contexts = TestHandler::getContexts();
608+
609+
$this->assertArrayHasKey('exception', $contexts[0]);
610+
$this->assertArrayHasKey('trace', $contexts[0]['exception']);
611+
$this->assertIsString($contexts[0]['exception']['trace']);
612+
}
613+
614+
public function testLogContextNormalizesInterpolatedThrowableWhenUsedKeysEnabled(): void
615+
{
616+
$config = new LoggerConfig();
617+
$config->logContext = true;
618+
$config->logContextUsedKeys = true;
619+
620+
$logger = new Logger($config);
621+
622+
try {
623+
throw new RuntimeException('Something went wrong');
624+
} catch (RuntimeException $e) {
625+
$logger->log('error', '[ERROR] {exception}', ['exception' => $e]);
626+
}
627+
628+
$contexts = TestHandler::getContexts();
629+
630+
$this->assertArrayHasKey('exception', $contexts[0]);
631+
632+
$normalized = $contexts[0]['exception'];
633+
634+
$this->assertIsArray($normalized);
635+
$this->assertSame(RuntimeException::class, $normalized['class']);
636+
$this->assertSame('Something went wrong', $normalized['message']);
637+
}
638+
639+
public function testLogContextDisabledStillAllowsGlobalContext(): void
640+
{
641+
$config = new LoggerConfig();
642+
$config->logContext = false;
643+
$config->logGlobalContext = true;
644+
645+
$logger = new Logger($config);
646+
647+
Time::setTestNow('2026-02-18 12:00:00');
648+
649+
service('context')->set('request_id', 'abc123');
650+
651+
$logger->log('debug', 'Test message', ['extra' => 'data']);
652+
653+
$contexts = TestHandler::getContexts();
654+
655+
$this->assertArrayNotHasKey('extra', $contexts[0]);
656+
$this->assertArrayHasKey('_ci_context', $contexts[0]);
657+
$this->assertSame(['request_id' => 'abc123'], $contexts[0]['_ci_context']);
658+
}
508659
}

‎user_guide_src/source/general/logging/007.php‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,10 @@
1+
<?php
2+
3+
// With $logContext = true in Config\Logger.
4+
// 'user_id' is not used as a placeholder, so it is passed to handlers as structured data.
5+
log_message('error', 'Payment failed for order {order_id}', [
6+
'order_id' => 'ord_999', // interpolated into the message, stripped from context by default
7+
'user_id' => 42, // not in message, kept and passed to handlers
8+
]);
9+
10+
// Handlers receive context: ['user_id' => 42]

‎user_guide_src/source/general/logging/008.php‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
<?php
2+
3+
// With $logContext = true in Config\Logger.
4+
// The exception is not used as a placeholder, so it is normalized and passed to handlers.
5+
try {
6+
// Something throws an error here
7+
} catch (\Exception $e) {
8+
log_message('error', 'Payment processing failed', ['exception' => $e]);
9+
}
10+
11+
// Handlers receive context:
12+
// [
13+
// 'exception' => [
14+
// 'class' => 'RuntimeException',
15+
// 'message' => 'Something went wrong',
16+
// 'code' => 0,
17+
// 'file' => 'app/Controllers/Payment.php',
18+
// 'line' => 42,
19+
// ]
20+
// ]

‎user_guide_src/source/general/logging/009.php‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,17 @@
1+
<?php
2+
3+
namespace Config;
4+
5+
use CodeIgniter\Config\BaseConfig;
6+
7+
class Logger extends BaseConfig
8+
{
9+
// Enable passing non-interpolated context keys to handlers as structured data.
10+
public bool $logContext = true;
11+
12+
// Include the stack trace when a Throwable is found in the context.
13+
public bool $logContextTrace = true;
14+
15+
// Also pass context keys that were used as {placeholder} in the message.
16+
public bool $logContextUsedKeys = false;
17+
}

0 commit comments

Comments
 (0)