Skip to content

Commit 32a3cf0

Browse files
turegjorupclaude
andcommitted
feat(logging): OTel semconv field names, redaction and exception processor
Build on the logging foundation (ADR 011): - Rename RequestContextProcessor fields to OpenTelemetry semantic conventions (http.request.method, http.route, url.path, client.address, enduser.id, screen.id, tenant.key); request_id/trace_id/span_id stay. - SensitiveDataProcessor (lowest priority, runs last) truncates client.address to a GDPR-safe form (IPv4 drops last octet, IPv6 keeps the /48) and redacts secret-bearing keys anywhere in context/extra. - ExceptionContextProcessor serialises a Throwable under the `exception` context key into a structured array with a depth-bounded previous chain, so no raw stack-trace string is emitted at info level. - Document the contract in docs/logging.md (channels, levels, message and context rules, field names, redaction guarantees). Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent c0182e1 commit 32a3cf0

9 files changed

Lines changed: 472 additions & 21 deletions

CHANGELOG.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,10 @@ All notable changes to this project will be documented in this file.
1818
thresholded by `LOG_LEVEL_<CHANNEL>` (falling back to a global `LOG_LEVEL`), a configurable
1919
`LOG_PATH` output destination (default `php://stderr`), request/identity/trace-context
2020
processors, request-id propagation via `X-Request-Id`, and an auth-event logging subscriber.
21+
- Adopted OpenTelemetry semantic-convention field names for log records, added GDPR-safe
22+
client-address truncation and secret-key redaction (`SensitiveDataProcessor`), and structured
23+
exception serialization under the `exception` context key (`ExceptionContextProcessor`). See
24+
`docs/logging.md`.
2125
- Removed the deprecated feed types `SparkleIOFeedType`, `EventDatabaseApiFeedType` and `KobaFeedType`.
2226
Made the unknown-feed-type handling consistent: **reads degrade, writes are rejected.** Feed sources
2327
(and feeds) that reference a removed type keep loading — item and collection reads return them with no

config/services.yaml

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,14 @@ services:
6767
App\Logger\Processor\TraceContextProcessor:
6868
tags: [{ name: monolog.processor }]
6969

70+
App\Logger\Processor\ExceptionContextProcessor:
71+
tags: [{ name: monolog.processor, priority: -90 }]
72+
73+
# Lowest priority: runs last so it scrubs everything the other processors
74+
# added (e.g. the raw client.address set by RequestContextProcessor).
75+
App\Logger\Processor\SensitiveDataProcessor:
76+
tags: [{ name: monolog.processor, priority: -100 }]
77+
7078
# Logs security outcomes on the `auth` channel (logging only).
7179
App\Logger\EventSubscriber\AuthLoggingSubscriber:
7280
arguments:

docs/logging.md

Lines changed: 115 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,115 @@
1+
# Logging
2+
3+
This service emits **structured JSON logs** to `php://stderr`. Every record is enriched
4+
with request, identity and trace context, and serialised so it can be ingested by a log
5+
aggregator later without changes here. The decisions behind this are recorded in
6+
[ADR 011](adr/011-structured-logging.md).
7+
8+
The conventions below are **enforced in CI** by project-local PHPStan rules
9+
(`logging.silentCatch`, `logging.interpolatedLogMessage`, `logging.exceptionContextKey`).
10+
A build fails if you break them.
11+
12+
## Channels
13+
14+
Inject a channel-specific logger instead of the generic one, so records can be routed and
15+
filtered per domain. Bind the channel in `config/services.yaml`:
16+
17+
```yaml
18+
App\Service\FeedService:
19+
arguments:
20+
$logger: '@monolog.logger.feed'
21+
```
22+
23+
| Channel | Use for |
24+
|---|---|
25+
| `app_http` | Outbound HTTP client calls (`LoggingHttpClient`). |
26+
| `auth` | Authentication and authorization outcomes (login, logout, JWT/OIDC). |
27+
| `screen` | Screen-client binding, screen authentication, screen status. |
28+
| `media` | Media upload, thumbnailing, storage. |
29+
| `feed` | Feed fetching/parsing (`FeedService`, feed types). |
30+
| `interactive` | Interactive slides (booking, instant book). |
31+
| `cache` | Cache/checksum recalculation and related batch work. |
32+
| `database` | Database connection failures (see below). |
33+
34+
## Level guidance
35+
36+
| Level | When |
37+
|---|---|
38+
| `debug` | Developer detail; verbose, off in production action buffering. |
39+
| `info` | Normal, noteworthy events (auth success, batch completed). |
40+
| `notice` | Normal but significant (config fallback applied). |
41+
| `warning` | Something recoverable went wrong (auth failure, flapping feed, malformed payload). |
42+
| `error` | An operation failed and a user/screen is affected. |
43+
| `critical` | A subsystem is down (database connection pressure/unreachable). |
44+
45+
## Message and context rules
46+
47+
1. **The message is a static string.** Never interpolate variables into it.
48+
49+
```php
50+
// ❌ flagged by logging.interpolatedLogMessage
51+
$logger->warning("Feed {$source->getId()} failed");
52+
53+
// ✅ static message, data in context
54+
$logger->warning('Feed fetch failed', ['feed_source_id' => (string) $source->getId()]);
55+
```
56+
57+
PSR-3 `{placeholder}` braces resolved from the context array are fine.
58+
59+
2. **Exceptions go under the `exception` context key — never any other key, never
60+
interpolated.**
61+
62+
```php
63+
// ❌ flagged by logging.exceptionContextKey
64+
$logger->error('Booking failed', ['error' => $e]);
65+
66+
// ✅
67+
$logger->error('Booking failed', ['exception' => $e]);
68+
```
69+
70+
`ExceptionContextProcessor` turns the `\Throwable` into a structured array
71+
(`class`, `message`, `code`, `file`, `line`, bounded `previous` chain). No raw
72+
multi-line stack-trace string is emitted at info level.
73+
74+
3. **Never swallow an exception silently.** A `catch` must log it (under `exception`),
75+
rethrow it (optionally wrapped), or be explicitly annotated when the silence is
76+
intentional:
77+
78+
```php
79+
try {
80+
$optional = $this->parse($payload);
81+
} catch (\JsonException $e) {
82+
// @phpstan-ignore logging.silentCatch (optional metadata; absence is expected)
83+
}
84+
```
85+
86+
This is enforced by `logging.silentCatch`.
87+
88+
## Field names (OpenTelemetry semantic conventions)
89+
90+
Context/extra fields follow OTel SemConv so logs line up with the OTLP traces the kiosk
91+
emits:
92+
93+
| Field | Meaning |
94+
|---|---|
95+
| `request_id` | Per-request id (inbound `X-Request-Id` or minted). |
96+
| `http.request.method` | HTTP method. |
97+
| `http.route` | Matched Symfony route name. |
98+
| `url.path` | Request path. |
99+
| `client.address` | **Truncated** client address (see redaction). |
100+
| `enduser.id` | Back-office user identifier. |
101+
| `screen.id` | Screen id (for screen-token requests). |
102+
| `tenant.key` | Active tenant key. |
103+
| `trace_id` / `span_id` | W3C trace context, when a `traceparent` header is present. |
104+
105+
## Redaction guarantees
106+
107+
`SensitiveDataProcessor` runs last and is a backstop, not a license to log secrets:
108+
109+
- `client.address` is **truncated** — IPv4 drops the last octet (`203.0.113.5` →
110+
`203.0.113.0`); IPv6 keeps the `/48` and zeroes the rest. No full client IP is emitted.
111+
- Any key whose name contains `password`, `passwd`, `secret`, `authorization`, `api_key`,
112+
`apikey`, `token`, `credential` or `bearer` is replaced with `[redacted]`, at any depth
113+
in `context`/`extra`.
114+
115+
Still: do not put credentials or token strings into log context in the first place.
Lines changed: 50 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,50 @@
1+
<?php
2+
3+
declare(strict_types=1);
4+
5+
namespace App\Logger\Processor;
6+
7+
use Monolog\LogRecord;
8+
use Monolog\Processor\ProcessorInterface;
9+
10+
/**
11+
* Replaces a `\Throwable` under the `exception` context key with a structured
12+
* array (class, message, code, file, line and a bounded `previous` chain) so a
13+
* raw multi-line stack-trace string is never emitted at info level in
14+
* production. Non-exception context is left untouched.
15+
*/
16+
final class ExceptionContextProcessor implements ProcessorInterface
17+
{
18+
private const MAX_DEPTH = 5;
19+
20+
public function __invoke(LogRecord $record): LogRecord
21+
{
22+
$context = $record->context;
23+
if (isset($context['exception']) && $context['exception'] instanceof \Throwable) {
24+
$context['exception'] = $this->normalize($context['exception'], self::MAX_DEPTH);
25+
26+
return $record->with(context: $context);
27+
}
28+
29+
return $record;
30+
}
31+
32+
/** @return array<string, mixed> */
33+
private function normalize(\Throwable $e, int $depth): array
34+
{
35+
$data = [
36+
'class' => $e::class,
37+
'message' => $e->getMessage(),
38+
'code' => $e->getCode(),
39+
'file' => $e->getFile(),
40+
'line' => $e->getLine(),
41+
];
42+
43+
$previous = $e->getPrevious();
44+
if (null !== $previous && $depth > 1) {
45+
$data['previous'] = $this->normalize($previous, $depth - 1);
46+
}
47+
48+
return $data;
49+
}
50+
}

src/Logger/Processor/RequestContextProcessor.php

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -14,9 +14,11 @@
1414
/**
1515
* Enriches every log record with request and identity context.
1616
*
17-
* Field names here are the interim PR 1 names (request_id, route, method,
18-
* user_id, screen_id, tenant_id); they are renamed to OpenTelemetry semantic
19-
* conventions in a later change.
17+
* Field names follow OpenTelemetry semantic conventions (http.request.method,
18+
* http.route, url.path, client.address, enduser.id, screen.id, tenant.key).
19+
* `request_id` is kept as-is. `client.address` is set to the raw client IP here
20+
* and truncated to a GDPR-safe form by {@see SensitiveDataProcessor}, which runs
21+
* after this processor.
2022
*/
2123
final readonly class RequestContextProcessor implements ProcessorInterface
2224
{
@@ -32,25 +34,28 @@ public function __invoke(LogRecord $record): LogRecord
3234
// No format validation — accept whatever nginx/Traefik passed through.
3335
$record->extra['request_id'] = $request->attributes->get('_request_id')
3436
?? $request->headers->get('X-Request-Id');
35-
$record->extra['route'] = $request->attributes->get('_route');
36-
$record->extra['method'] = $request->getMethod();
37+
$record->extra['http.route'] = $request->attributes->get('_route');
38+
$record->extra['http.request.method'] = $request->getMethod();
39+
$record->extra['url.path'] = $request->getPathInfo();
40+
// Raw IP; SensitiveDataProcessor truncates it to a GDPR-safe form.
41+
$record->extra['client.address'] = $request->getClientIp();
3742
}
3843

3944
$user = $this->security->getUser();
4045
if (null !== $user) {
4146
// Screen tokens authenticate as ScreenUser; everything else is a
4247
// back-office User. Populate screen_id XOR user_id accordingly.
4348
if ($user instanceof ScreenUser) {
44-
$record->extra['screen_id'] = (string) $user->getScreen()->getId();
49+
$record->extra['screen.id'] = (string) $user->getScreen()->getId();
4550
} else {
46-
$record->extra['user_id'] = $user->getUserIdentifier();
51+
$record->extra['enduser.id'] = $user->getUserIdentifier();
4752
}
4853

4954
if ($user instanceof TenantScopedUserInterface) {
5055
// getActiveTenant() can throw when no tenant is resolved yet;
5156
// enrichment must never break the request it is annotating.
5257
try {
53-
$record->extra['tenant_id'] = $user->getActiveTenant()->getTenantKey();
58+
$record->extra['tenant.key'] = $user->getActiveTenant()->getTenantKey();
5459
} catch (\Throwable) {
5560
// No active tenant on this request — leave tenant_id unset.
5661
}
Lines changed: 118 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,118 @@
1+
<?php
2+
3+
declare(strict_types=1);
4+
5+
namespace App\Logger\Processor;
6+
7+
use Monolog\LogRecord;
8+
use Monolog\Processor\ProcessorInterface;
9+
10+
/**
11+
* GDPR/secret backstop. Runs after the context processors (lower priority) so it
12+
* can scrub what they add:
13+
*
14+
* - `client.address` is truncated (IPv4: drop the last octet; IPv6: keep the
15+
* /48, i.e. the first three hextets) so no full client IP is ever emitted.
16+
* - Any key whose name looks secret-bearing (password, token, secret,
17+
* authorization, api_key, …) is replaced with a redaction marker, anywhere
18+
* in `context` or `extra`, at any nesting depth.
19+
*
20+
* This is a safety net, not a license: code must still avoid putting secrets in
21+
* log context in the first place.
22+
*/
23+
final class SensitiveDataProcessor implements ProcessorInterface
24+
{
25+
private const REDACTED = '[redacted]';
26+
private const ADDRESS_KEY = 'client.address';
27+
28+
/**
29+
* Case-insensitive substrings that mark a key as secret-bearing. Kept narrow
30+
* enough not to match legitimate keys such as `tenant.key`.
31+
*
32+
* @var list<string>
33+
*/
34+
private const SECRET_KEY_FRAGMENTS = [
35+
'password', 'passwd', 'secret', 'authorization',
36+
'api_key', 'apikey', 'token', 'credential', 'bearer',
37+
];
38+
39+
public function __invoke(LogRecord $record): LogRecord
40+
{
41+
$extra = $this->scrub($record->extra);
42+
$context = $this->scrub($record->context);
43+
44+
if (isset($extra[self::ADDRESS_KEY]) && is_string($extra[self::ADDRESS_KEY])) {
45+
$extra[self::ADDRESS_KEY] = $this->truncateAddress($extra[self::ADDRESS_KEY]);
46+
}
47+
48+
return $record->with(context: $context, extra: $extra);
49+
}
50+
51+
/**
52+
* @param array<array-key, mixed> $data
53+
*
54+
* @return array<array-key, mixed>
55+
*/
56+
private function scrub(array $data): array
57+
{
58+
foreach ($data as $key => $value) {
59+
if (is_string($key) && $this->isSecretKey($key)) {
60+
$data[$key] = self::REDACTED;
61+
continue;
62+
}
63+
if (is_array($value)) {
64+
$data[$key] = $this->scrub($value);
65+
}
66+
}
67+
68+
return $data;
69+
}
70+
71+
private function isSecretKey(string $key): bool
72+
{
73+
$key = strtolower($key);
74+
foreach (self::SECRET_KEY_FRAGMENTS as $fragment) {
75+
if (str_contains($key, $fragment)) {
76+
return true;
77+
}
78+
}
79+
80+
return false;
81+
}
82+
83+
private function truncateAddress(string $address): string
84+
{
85+
if (false !== filter_var($address, FILTER_VALIDATE_IP, FILTER_FLAG_IPV4)) {
86+
$octets = explode('.', $address);
87+
$octets[3] = '0';
88+
89+
return implode('.', $octets);
90+
}
91+
92+
if (false !== filter_var($address, FILTER_VALIDATE_IP, FILTER_FLAG_IPV6)) {
93+
// Keep the /48 (first three hextets), zero the rest.
94+
$expanded = $this->expandIpv6($address);
95+
$hextets = explode(':', $expanded);
96+
for ($i = 3; $i < 8; ++$i) {
97+
$hextets[$i] = '0';
98+
}
99+
100+
return implode(':', $hextets);
101+
}
102+
103+
// Not a recognised IP — drop it rather than risk leaking an identifier.
104+
return self::REDACTED;
105+
}
106+
107+
private function expandIpv6(string $address): string
108+
{
109+
$binary = inet_pton($address);
110+
if (false === $binary) {
111+
return $address;
112+
}
113+
114+
$hextets = unpack('n8', $binary);
115+
116+
return implode(':', array_map(dechex(...), $hextets ?: []));
117+
}
118+
}

0 commit comments

Comments
 (0)