From 35ed9dc4f7ebc39a29970caf3719827168144733 Mon Sep 17 00:00:00 2001 From: turegjorup Date: Tue, 2 Jun 2026 22:58:51 +0200 Subject: [PATCH 1/4] feat(logging): add channels, context processors and auth-logging subscriber Introduce the structured-logging foundation (ADR 011): - Declare per-domain Monolog channels (auth, screen, media, feed, interactive, cache) alongside app_http. - In prod, add one always-on stderr handler per domain channel, each thresholded by a LOG_LEVEL_ env var that falls back to a global LOG_LEVEL (app.log_level parameter); a single Monolog handler carries one level, so per-channel thresholds need per-channel handlers. - Make the output destination configurable via LOG_PATH (default php://stderr); nested and app_http honour it too. Suits container stderr capture; bare-metal nginx + php-fpm operators can point it at a file. - RequestContextProcessor enriches every record with request id, route, method and identity (user_id XOR screen_id, tenant_id). Field names are the interim PR-1 names; the OTel SemConv rename follows in a later PR. - TraceContextProcessor parses a W3C traceparent header into trace_id / span_id when present. - RequestIdSubscriber adopts the inbound X-Request-Id or mints one and echoes it on the response, with no format validation. - AuthLoggingSubscriber logs login/logout and JWT-failure outcomes on the auth channel (logging only; never token strings or credentials). Co-Authored-By: Claude Opus 4.8 (1M context) --- .env | 24 ++++ CHANGELOG.md | 8 ++ README.md | 33 +++++ config/packages/monolog.yaml | 11 +- config/packages/prod/monolog.yaml | 53 ++++++- config/services.yaml | 25 +++- docs/adr/011-structured-logging.md | 90 ++++++++++++ .../EventSubscriber/AuthLoggingSubscriber.php | 88 ++++++++++++ .../EventSubscriber/RequestIdSubscriber.php | 52 +++++++ .../Processor/RequestContextProcessor.php | 118 +++++++++++++++ .../Processor/TraceContextProcessor.php | 39 +++++ .../AuthLoggingSubscriberTest.php | 63 ++++++++ .../Processor/RequestContextProcessorTest.php | 136 ++++++++++++++++++ .../Processor/TraceContextProcessorTest.php | 54 +++++++ 14 files changed, 788 insertions(+), 6 deletions(-) create mode 100644 docs/adr/011-structured-logging.md create mode 100644 src/Logger/EventSubscriber/AuthLoggingSubscriber.php create mode 100644 src/Logger/EventSubscriber/RequestIdSubscriber.php create mode 100644 src/Logger/Processor/RequestContextProcessor.php create mode 100644 src/Logger/Processor/TraceContextProcessor.php create mode 100644 tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php create mode 100644 tests/Logger/Processor/RequestContextProcessorTest.php create mode 100644 tests/Logger/Processor/TraceContextProcessorTest.php diff --git a/.env b/.env index 16868827c..e1eb3e6dc 100644 --- a/.env +++ b/.env @@ -124,6 +124,30 @@ HTTP_CLIENT_MAX_DURATION=30 HTTP_CLIENT_LOG_LEVEL=error ###< Http Client ### +###> Logging ### +# Log output destination. php://stderr suits container deployments (Docker +# captures it). Bare-metal nginx + php-fpm checkouts may set a file path, e.g. +# LOG_PATH=%kernel.logs_dir%/prod.log (the operator owns rotation/permissions). +# Image/container deployments must keep php://stderr. +LOG_PATH=php://stderr +# Global log level for the application domain channels +# (debug, info, notice, warning, error, critical). info reproduces prior output. +LOG_LEVEL=info +# Per-channel override; empty or unset inherits LOG_LEVEL. +LOG_LEVEL_AUTH= +# Per-channel override; empty or unset inherits LOG_LEVEL. +LOG_LEVEL_SCREEN= +# Per-channel override; empty or unset inherits LOG_LEVEL. +LOG_LEVEL_MEDIA= +# Per-channel override; empty or unset inherits LOG_LEVEL. +LOG_LEVEL_FEED= +# Per-channel override; empty or unset inherits LOG_LEVEL. +LOG_LEVEL_INTERACTIVE= +# Threshold for Symfony's built-in cache channel (cache-adapter/Redis failures); +# not an application channel. Empty or unset inherits LOG_LEVEL. +LOG_LEVEL_CACHE= +###< Logging ### + ###> App ### # Default date format for API responses (ISO 8601 with milliseconds). DEFAULT_DATE_FORMAT='Y-m-d\TH:i:s.v\Z' diff --git a/CHANGELOG.md b/CHANGELOG.md index 90d4ff328..3c01b7314 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,14 @@ All notable changes to this project will be documented in this file. `http_client_options.timeout` on both providers, configurable via the new `OIDC_HTTP_TIMEOUT` env var (default 5s). Previously no timeout was set anywhere in the chain, so Guzzle waited indefinitely and a hung/slow IdP could tie up a php-fpm worker. +- Added structured, channel-split application logging (ADR 011): per-domain Monolog channels + (`auth`, `screen`, `media`, `feed`, `interactive`, `cache`) with per-channel prod handlers + thresholded by `LOG_LEVEL_` (falling back to a global `LOG_LEVEL`), a configurable + `LOG_PATH` output destination (default `php://stderr`), request/identity/trace-context + processors, request-id propagation via `X-Request-Id`, and an auth-event logging subscriber. +- Renamed the outbound-HTTP-client log channel `app_http` → `outbound_http` and silenced + Symfony's redundant native `http_client` channel logging (a `NullLogger` decorates it), so + `LoggingHttpClient` is the single source of outbound-HTTP logs (no duplicate request logging). - Removed the deprecated feed types `SparkleIOFeedType`, `EventDatabaseApiFeedType` and `KobaFeedType`. Made the unknown-feed-type handling consistent: **reads degrade, writes are rejected.** Feed sources (and feeds) that reference a removed type keep loading — item and collection reads return them with no diff --git a/README.md b/README.md index 56eb7ff9a..e808bbb92 100644 --- a/README.md +++ b/README.md @@ -562,6 +562,39 @@ MEDIA_MAX_UPLOAD_SIZE_MB=200 Changes are picked up on the next request once PHP-FPM workers see the new env value (in production, restart the php-fpm container or reload the workers). The admin UI re-fetches `/config/admin` on the next page load. +### Logging + +Structured JSON logging on per-domain channels (see [ADR 011](docs/adr/011-structured-logging.md) and +[docs/logging.md](docs/logging.md)). Each domain channel has a production stream handler whose threshold is +`LOG_LEVEL_`, falling back to the global `LOG_LEVEL` when the per-channel value is empty or unset. + +```dotenv +###> Logging ### +LOG_PATH=php://stderr +LOG_LEVEL=info +LOG_LEVEL_AUTH= +LOG_LEVEL_SCREEN= +LOG_LEVEL_MEDIA= +LOG_LEVEL_FEED= +LOG_LEVEL_INTERACTIVE= +LOG_LEVEL_CACHE= +###< Logging ### +``` + +- LOG_PATH: Destination for the production log handlers. Defaults to `php://stderr`, which suits container + deployments (the runtime captures stderr). Bare-metal nginx + php-fpm deployments may point it at a file + (e.g. `%kernel.logs_dir%/prod.log`); the operator then owns log rotation and the php-fpm user's write permission + to the directory. Image/container deployments must keep `php://stderr`. + + **Default**: `php://stderr`. +- LOG_LEVEL: Global log level for the application domain channels (`debug`, `info`, `notice`, `warning`, `error`, + `critical`). `info` reproduces the previous output. + + **Default**: `info`. +- LOG_LEVEL_AUTH, LOG_LEVEL_SCREEN, LOG_LEVEL_MEDIA, LOG_LEVEL_FEED, LOG_LEVEL_INTERACTIVE, LOG_LEVEL_CACHE: + Per-channel threshold overrides. Empty or unset inherits `LOG_LEVEL`. Set one to raise or lower a single channel + (e.g. `LOG_LEVEL_FEED=warning`) without affecting the others. An invalid level fails fast at boot. + ### Admin configuration Will be exposed through the `/config/admin` route. diff --git a/config/packages/monolog.yaml b/config/packages/monolog.yaml index d0452bbd5..25a0a3dad 100644 --- a/config/packages/monolog.yaml +++ b/config/packages/monolog.yaml @@ -1,2 +1,11 @@ monolog: - channels: ['app_http'] + channels: + [ + 'outbound_http', + 'auth', + 'screen', + 'media', + 'feed', + 'interactive', + 'cache', + ] diff --git a/config/packages/prod/monolog.yaml b/config/packages/prod/monolog.yaml index 2ba80f1ca..eec2a1b92 100644 --- a/config/packages/prod/monolog.yaml +++ b/config/packages/prod/monolog.yaml @@ -8,14 +8,59 @@ monolog: buffer_size: 50 # How many messages should be saved? Prevent memory leaks nested: type: stream - path: php://stderr + path: '%env(resolve:LOG_PATH)%' level: debug formatter: monolog.formatter.json - app_http: + outbound_http: type: stream - path: php://stderr + path: '%env(resolve:LOG_PATH)%' level: info - channels: ['app_http'] + channels: ['outbound_http'] + formatter: monolog.formatter.json + # One always-on handler per domain channel. A Monolog handler carries a + # single level, so per-channel thresholds require per-channel handlers. + # Each level falls back to the global LOG_LEVEL (app.log_level) when its + # LOG_LEVEL_ override is empty or unset. + auth: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_AUTH)%' + channels: ['auth'] + formatter: monolog.formatter.json + screen: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_SCREEN)%' + channels: ['screen'] + formatter: monolog.formatter.json + media: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_MEDIA)%' + channels: ['media'] + formatter: monolog.formatter.json + feed: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_FEED)%' + channels: ['feed'] + formatter: monolog.formatter.json + interactive: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_INTERACTIVE)%' + channels: ['interactive'] + formatter: monolog.formatter.json + # Symfony's built-in cache channel — NOT an application channel. The cache + # adapters (the Redis pools) log backend failures here (failed save/fetch, + # connection drops) at `warning`; this dedicated handler surfaces them, since + # the `fingers_crossed` gate (action_level: error) would otherwise buffer and + # drop a standalone warning. No application code writes to this channel. + cache: + type: stream + path: '%env(resolve:LOG_PATH)%' + level: '%env(default:app.log_level:LOG_LEVEL_CACHE)%' + channels: ['cache'] formatter: monolog.formatter.json console: type: console diff --git a/config/services.yaml b/config/services.yaml index 5c342f2bd..c1de58305 100644 --- a/config/services.yaml +++ b/config/services.yaml @@ -4,6 +4,9 @@ # Put parameters here that don't need to change on each machine where the app is deployed # https://symfony.com/doc/current/best_practices.html#use-parameters-for-application-configuration parameters: + # Global fallback log level for the per-domain Monolog channels. Each + # LOG_LEVEL_ override inherits this when empty/unset (ADR 011). + app.log_level: '%env(LOG_LEVEL)%' services: # default configuration for services in *this* file @@ -52,11 +55,31 @@ services: decorates: http_client arguments: $client: '@.inner' - $logger: '@monolog.logger.app_http' + $logger: '@monolog.logger.outbound_http' $logLevel: '%env(string:HTTP_CLIENT_LOG_LEVEL)%' + # Silence Symfony's native http_client logging at the source: it is + # request-only and redundant with LoggingHttpClient (outbound_http channel), + # which is the single, OTel-shaped source of outbound-HTTP logs. A NullLogger + # replaces the channel logger the framework injects into the native client. + app.null_http_client_logger: + class: Psr\Log\NullLogger + decorates: monolog.logger.http_client + #### App Scope below ### + # Structured logging: enrich every record with request/identity/trace context. + App\Logger\Processor\RequestContextProcessor: + tags: [{ name: monolog.processor }] + + App\Logger\Processor\TraceContextProcessor: + tags: [{ name: monolog.processor }] + + # Logs security outcomes on the `auth` channel (logging only). + App\Logger\EventSubscriber\AuthLoggingSubscriber: + arguments: + $logger: '@monolog.logger.auth' + Symfony\Component\Security\Http\Authentication\AuthenticationFailureHandlerInterface: '@Lexik\Bundle\JWTAuthenticationBundle\Security\Http\Authentication\AuthenticationFailureHandler' Symfony\Component\Security\Http\Authentication\AuthenticationSuccessHandlerInterface: '@Lexik\Bundle\JWTAuthenticationBundle\Security\Http\Authentication\AuthenticationSuccessHandler' diff --git a/docs/adr/011-structured-logging.md b/docs/adr/011-structured-logging.md new file mode 100644 index 000000000..34d59a6e9 --- /dev/null +++ b/docs/adr/011-structured-logging.md @@ -0,0 +1,90 @@ +# ADR 011 - Structured application logging + +Date: 02-06-2026 + +## Status + +Accepted + +## Context + +Logging in `display-api-service` was a single Monolog channel (`app_http`) used only by +`LoggingHttpClient`, with `fingers_crossed` (action level `error`) writing JSON to +`php://stderr` in production. Log records carried no request, identity, or tenant context, +and ~14 catch sites swallowed exceptions with no log and no rethrow. As a result, several +documented production failures were invisible end-to-end: kiosk black-screens, missing +thumbnails (PR #374), empty interactive booking results, and OIDC/JWT/refresh outcomes. + +Operators of single-server deployments frequently cannot run or monitor MariaDB directly +(no shell access to the database, no metrics scraper). The application log is therefore the +only place a database **connection** failure (too-many-connections, connection refused, +server gone away) can surface. + +## Decision + +1. **Channel splitting.** Declare per-domain application channels (`auth`, `screen`, `media`, + `feed`, `interactive`, and `database`) alongside the outbound-HTTP channel `outbound_http` + (`LoggingHttpClient`, renamed from `app_http`). Symfony's built-in `cache` channel is + additionally given a dedicated handler — not for application logging (no application code + writes to it), but so cache-adapter (Redis) backend failures surface instead of being + buffered and dropped by the `fingers_crossed` error gate. Symfony's native `http_client` + channel logging is silenced (see Consequences) so `outbound_http` is the single, + OTel-shaped source of outbound-HTTP logs. + +2. **Context processors.** Every log record is enriched by Monolog processors with request + context (request id, route, method), identity (user or screen id, tenant key), W3C trace + context when present, GDPR-safe client address (truncated), and structured exception + serialization under a single `exception` context key. Field names follow OpenTelemetry + semantic conventions as strictly as the framework allows: `http.route` is the matched + route's **path template** (e.g. `/v2/screens/{id}`), emitted only when a route matched + and never the concrete id-bearing URL (which is recorded separately as `url.path`); + `client.address` is truncated; identity is `enduser.id` XOR `screen.id` plus `tenant.key`. + +3. **No silent failures.** Catch blocks must log the exception, rethrow it (optionally + wrapped), or be explicitly annotated as intentionally silent. This is enforced in CI by + project-local PHPStan rules (`logging.silentCatch`, `logging.interpolatedLogMessage`, + `logging.exceptionContextKey`). + +4. **Database connection-error logging.** A DBAL driver middleware logs connection + establishment failures on the `database` channel, classified by the raw driver error + code, so the failure is visible regardless of whether application code swallows the + exception and regardless of which SAPI (web, CLI, Messenger) opened the connection. + +5. **Output destination is configurable, defaulting to `php://stderr`.** Handlers write to + a `LOG_PATH` env var (default `php://stderr`). The default suits the Docker image + deployment, where the runtime captures stderr. Operators who run the repo directly under + nginx + php-fpm (no container) can set `LOG_PATH` to a file, because php-fpm does not + capture worker stderr cleanly. Per-channel thresholds are set with `LOG_LEVEL_` + env vars that fall back to a global `LOG_LEVEL`. Shipping logs onward to an aggregator + (OTel Collector / Loki / Grafana) remains a separate concern in `os2display-docker-server` + and is not decided here. Records stay JSON regardless of destination. + +6. **OpenTelemetry-first.** All logging follows OpenTelemetry semantic conventions and + naming as closely as the framework allows — attribute names, value shapes, and severity + levels. When Symfony/Monolog cannot express a convention exactly, the closest compliant + form is chosen over a bespoke field (e.g. `http.route` carries the route path template, + not the Symfony route name; attributes that don't apply are omitted rather than set to a + placeholder). New log fields must reuse an existing OTel attribute where one fits before + inventing a name. This keeps the logs forward-compatible with an OTel collector, should + one be introduced. + +## Consequences + +- Contributors must attach context via the PSR-3 context array (not string interpolation) + and must never swallow exceptions silently; the PHPStan gate fails the build otherwise. + The conventions are documented in `docs/logging.md`. +- Operators gain a failure signal for database connection problems without database access, + at the cost of it being reactive (per-failure events, not "approaching the limit" trends). +- The connection-error middleware covers connection **establishment** only; mid-query drops + (`2006`/`2013`) are out of its current scope and would require also wrapping the + connection's execution path. +- Adopting OpenTelemetry semantic conventions for field names keeps logs forward-compatible + with an OTel collector, should one be introduced later. +- Symfony's native `http_client` logging is silenced at the source — a `NullLogger` decorates + the `monolog.logger.http_client` service the framework injects into the native client (it is + request-only and redundant). `LoggingHttpClient` (`outbound_http` channel) is therefore the + single, OTel-shaped source of outbound-HTTP logs — no duplicate request logging. +- `LOG_PATH` must stay `php://stderr` in the image deployment — pointing it at a + container-internal file breaks `task logs` and the planned filelog collector. Bare-metal + operators choosing a file own its rotation (e.g. logrotate) and the php-fpm user's write + permission to the log directory. diff --git a/src/Logger/EventSubscriber/AuthLoggingSubscriber.php b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php new file mode 100644 index 000000000..c16ed071f --- /dev/null +++ b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php @@ -0,0 +1,88 @@ + 'onLoginSuccess', + LoginFailureEvent::class => 'onLoginFailure', + LogoutEvent::class => 'onLogout', + LexikEvents::JWT_INVALID => 'onJwtFailure', + LexikEvents::JWT_EXPIRED => 'onJwtFailure', + LexikEvents::JWT_NOT_FOUND => 'onJwtFailure', + ]; + } + + public function onLoginSuccess(LoginSuccessEvent $event): void + { + $this->logger->info('Authentication succeeded', [ + 'event' => 'auth.login_success', + 'user_identifier' => $event->getUser()->getUserIdentifier(), + 'firewall' => $event->getFirewallName(), + 'authenticator' => $event->getAuthenticator()::class, + ]); + } + + public function onLoginFailure(LoginFailureEvent $event): void + { + $this->logger->warning('Authentication failed', [ + 'event' => 'auth.login_failure', + 'firewall' => $event->getFirewallName(), + 'authenticator' => $event->getAuthenticator()::class, + 'exception' => $event->getException(), + ]); + } + + public function onLogout(LogoutEvent $event): void + { + $this->logger->info('User logged out', [ + 'event' => 'auth.logout', + 'user_identifier' => $event->getToken()?->getUserIdentifier(), + ]); + } + + public function onJwtFailure(JWTFailureEventInterface $event): void + { + $this->logger->warning('JWT authentication failed', [ + 'event' => 'auth.jwt_failure', + 'reason' => match (true) { + $event instanceof JWTInvalidEvent => 'invalid', + $event instanceof JWTExpiredEvent => 'expired', + $event instanceof JWTNotFoundEvent => 'not_found', + default => 'unknown', + }, + 'exception' => $event->getException(), + ]); + } +} diff --git a/src/Logger/EventSubscriber/RequestIdSubscriber.php b/src/Logger/EventSubscriber/RequestIdSubscriber.php new file mode 100644 index 000000000..f54e9fa1e --- /dev/null +++ b/src/Logger/EventSubscriber/RequestIdSubscriber.php @@ -0,0 +1,52 @@ + ['onRequest', 4096], + KernelEvents::RESPONSE => ['onResponse', -4096], + ]; + } + + public function onRequest(RequestEvent $event): void + { + if (!$event->isMainRequest()) { + return; + } + $request = $event->getRequest(); + $id = $request->headers->get(self::HEADER) ?: (string) Uuid::v4(); + $request->attributes->set(self::ATTR, $id); + } + + public function onResponse(ResponseEvent $event): void + { + if (!$event->isMainRequest()) { + return; + } + $id = $event->getRequest()->attributes->get(self::ATTR); + if (null !== $id && !$event->getResponse()->headers->has(self::HEADER)) { + $event->getResponse()->headers->set(self::HEADER, $id); + } + } +} diff --git a/src/Logger/Processor/RequestContextProcessor.php b/src/Logger/Processor/RequestContextProcessor.php new file mode 100644 index 000000000..4efbc9fea --- /dev/null +++ b/src/Logger/Processor/RequestContextProcessor.php @@ -0,0 +1,118 @@ +requestStack->getMainRequest(); + if (null !== $request) { + // No format validation — accept whatever nginx/Traefik passed through. + $record->extra['request_id'] = $request->attributes->get('_request_id') + ?? $request->headers->get('X-Request-Id'); + // The matched route's declared path TEMPLATE, not the concrete URL: + // a request to `GET /v2/screens/01HXYZ…` is logged as + // `route = /v2/screens/{id}` — the entity id never appears in this + // field (low-cardinality, GDPR-safe; OTel `http.route` semantics). + // Only set when a route matched; the concrete id-bearing path is not + // logged here. + $routeTemplate = $this->routeTemplate($request); + if (null !== $routeTemplate) { + $record->extra['route'] = $routeTemplate; + } + $record->extra['method'] = $request->getMethod(); + } + + $user = $this->security->getUser(); + if (null !== $user) { + // Screen tokens authenticate as ScreenUser; everything else is a + // back-office User. Populate screen_id XOR user_id accordingly. + if ($user instanceof ScreenUser) { + $record->extra['screen_id'] = (string) $user->getScreen()->getId(); + } else { + $record->extra['user_id'] = $user->getUserIdentifier(); + } + + if ($user instanceof TenantScopedUserInterface) { + // getActiveTenant() can throw when no tenant is resolved yet; + // enrichment must never break the request it is annotating. + try { + $record->extra['tenant_id'] = $user->getActiveTenant()->getTenantKey(); + } catch (\Throwable) { + // No active tenant on this request — leave tenant_id unset. + } + } + } + + return $record; + } + + /** + * The matched route's path template (OTel `http.route`), e.g. + * `/v2/screens/{id}` — never the concrete path with the id. Reconstructed + * from the request path by substituting the matched route parameters back to + * their `{name}` placeholders, with the optional API Platform `.{_format}` + * suffix stripped. Returns null when no route matched, so the field is only + * present for matched requests (per OTel guidance). + * + * This deliberately avoids injecting the router: depending on it forms a + * circular service graph with the `database` channel logger used by the DBAL + * connection middleware (processor → router → EntityManager → DBAL middleware + * → database logger → processor). + */ + private function routeTemplate(Request $request): ?string + { + $routeName = $request->attributes->get('_route'); + if (!is_string($routeName)) { + return null; + } + + $params = $request->attributes->get('_route_params'); + if (!is_array($params)) { + $params = []; + } + + $path = $request->getPathInfo(); + foreach ($params as $name => $value) { + // Skip framework params (_format, _locale, …); only real placeholders. + if (!is_string($name) || str_starts_with($name, '_') || !is_scalar($value)) { + continue; + } + $value = (string) $value; + if ('' !== $value) { + $path = str_replace($value, '{'.$name.'}', $path); + } + } + + // Strip the optional API Platform format suffix (e.g. `.jsonld`). + $format = $params['_format'] ?? null; + if (is_string($format) && '' !== $format) { + $path = preg_replace('/\.'.preg_quote($format, '/').'$/', '', $path) ?? $path; + } + + return $path; + } +} diff --git a/src/Logger/Processor/TraceContextProcessor.php b/src/Logger/Processor/TraceContextProcessor.php new file mode 100644 index 000000000..663f4f4ec --- /dev/null +++ b/src/Logger/Processor/TraceContextProcessor.php @@ -0,0 +1,39 @@ +requestStack->getMainRequest(); + $traceparent = $request?->headers->get('traceparent'); + + // W3C traceparent: 00-<32 hex trace-id>-<16 hex span-id>-<2 hex flags> + if (null !== $traceparent + && 1 === preg_match('/^00-([0-9a-f]{32})-([0-9a-f]{16})-[0-9a-f]{2}$/', $traceparent, $m) + ) { + $record->extra['trace_id'] = $m[1]; + $record->extra['span_id'] = $m[2]; + } + + return $record; + } +} diff --git a/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php b/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php new file mode 100644 index 000000000..79fb041f5 --- /dev/null +++ b/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php @@ -0,0 +1,63 @@ +createMock(AuthenticatorInterface::class), + Request::create('/v2/authentication/token', Request::METHOD_POST, [], [], [], [], '{"password":"s3cr3t"}'), + null, + 'main', + ); + + $subscriber->onLoginFailure($event); + + $this->assertTrue($handler->hasWarningRecords()); + $records = $handler->getRecords(); + $this->assertCount(1, $records); + $record = $records[0]; + $this->assertSame(Level::Warning, $record->level); + $this->assertSame('auth.login_failure', $record->context['event']); + $this->assertSame('main', $record->context['firewall']); + + // No credential material anywhere in the serialised record. + $this->assertStringNotContainsStringIgnoringCase('s3cr3t', json_encode($record->toArray(), JSON_THROW_ON_ERROR)); + } + + public function testLogoutEmitsInfoWithUserIdentifier(): void + { + $handler = new TestHandler(); + $subscriber = new AuthLoggingSubscriber(new Logger('auth', [$handler])); + + $token = $this->createMock(TokenInterface::class); + $token->method('getUserIdentifier')->willReturn('editor@example.com'); + + $subscriber->onLogout(new LogoutEvent(Request::create('/'), $token)); + + $this->assertTrue($handler->hasInfoRecords()); + $record = $handler->getRecords()[0]; + $this->assertSame('auth.logout', $record->context['event']); + $this->assertSame('editor@example.com', $record->context['user_identifier']); + } +} diff --git a/tests/Logger/Processor/RequestContextProcessorTest.php b/tests/Logger/Processor/RequestContextProcessorTest.php new file mode 100644 index 000000000..c0b748f54 --- /dev/null +++ b/tests/Logger/Processor/RequestContextProcessorTest.php @@ -0,0 +1,136 @@ +security(null)); + + $record = $processor($this->record()); + + $this->assertArrayNotHasKey('request_id', $record->extra); + $this->assertArrayNotHasKey('route', $record->extra); + $this->assertArrayNotHasKey('user_id', $record->extra); + $this->assertArrayNotHasKey('screen_id', $record->extra); + } + + public function testRequestContextLogsPathTemplateNotConcreteId(): void + { + // A concrete item URL carrying a ULID, with the matched route params + // Symfony sets on the request after routing. + $request = Request::create('/v2/screens/01HXYZ1234567890ABCDEFGHJK', Request::METHOD_GET); + $request->attributes->set('_request_id', 'abc123def4567890abc123def4567890'); + $request->attributes->set('_route', 'screen_item'); + $request->attributes->set('_route_params', ['id' => '01HXYZ1234567890ABCDEFGHJK']); + $stack = new RequestStack(); + $stack->push($request); + + $processor = new RequestContextProcessor($stack, $this->security(null)); + + $record = $processor($this->record()); + + // 32-char hex request id accepted verbatim — no reformatting/rejection. + $this->assertSame('abc123def4567890abc123def4567890', $record->extra['request_id']); + // Path template, id-free — the concrete ULID is substituted back to {id}. + $this->assertSame('/v2/screens/{id}', $record->extra['route']); + $this->assertSame('GET', $record->extra['method']); + } + + public function testRouteIsUnsetWhenNoRouteMatched(): void + { + $request = Request::create('/v2/unmatched', Request::METHOD_GET); + $stack = new RequestStack(); + $stack->push($request); + + $processor = new RequestContextProcessor($stack, $this->security(null)); + + $record = $processor($this->record()); + + // No `_route` attribute => no template; the id-bearing path is not logged here. + $this->assertArrayNotHasKey('route', $record->extra); + $this->assertSame('GET', $record->extra['method']); + } + + public function testScreenUserPopulatesScreenIdAndTenantNotUserId(): void + { + $tenant = $this->createMock(Tenant::class); + $tenant->method('getTenantKey')->willReturn('Example1'); + + $screen = $this->createMock(Screen::class); + $screen->method('getId')->willReturn(new Ulid()); + + $user = $this->createMock(ScreenUser::class); + $user->method('getScreen')->willReturn($screen); + $user->method('getActiveTenant')->willReturn($tenant); + + $processor = new RequestContextProcessor(new RequestStack(), $this->security($user)); + + $record = $processor($this->record()); + + $this->assertArrayHasKey('screen_id', $record->extra); + $this->assertArrayNotHasKey('user_id', $record->extra); + $this->assertSame('Example1', $record->extra['tenant_id']); + } + + public function testBackOfficeUserPopulatesUserIdNotScreenId(): void + { + $tenant = $this->createMock(Tenant::class); + $tenant->method('getTenantKey')->willReturn('Example1'); + + $user = $this->createMock(User::class); + $user->method('getUserIdentifier')->willReturn('editor@example.com'); + $user->method('getActiveTenant')->willReturn($tenant); + + $processor = new RequestContextProcessor(new RequestStack(), $this->security($user)); + + $record = $processor($this->record()); + + $this->assertSame('editor@example.com', $record->extra['user_id']); + $this->assertArrayNotHasKey('screen_id', $record->extra); + $this->assertSame('Example1', $record->extra['tenant_id']); + } + + public function testActiveTenantResolutionFailureDoesNotThrow(): void + { + $user = $this->createMock(User::class); + $user->method('getUserIdentifier')->willReturn('editor@example.com'); + $user->method('getActiveTenant')->willThrowException(new \InvalidArgumentException('no tenant')); + + $processor = new RequestContextProcessor(new RequestStack(), $this->security($user)); + + $record = $processor($this->record()); + + $this->assertSame('editor@example.com', $record->extra['user_id']); + $this->assertArrayNotHasKey('tenant_id', $record->extra); + } + + private function record(): LogRecord + { + return new LogRecord(new \DateTimeImmutable('2026-06-02T00:00:00+00:00'), 'screen', Level::Info, 'test'); + } + + private function security(?object $user): Security + { + $security = $this->createMock(Security::class); + $security->method('getUser')->willReturn($user); + + return $security; + } +} diff --git a/tests/Logger/Processor/TraceContextProcessorTest.php b/tests/Logger/Processor/TraceContextProcessorTest.php new file mode 100644 index 000000000..a461dd71e --- /dev/null +++ b/tests/Logger/Processor/TraceContextProcessorTest.php @@ -0,0 +1,54 @@ +headers->set('traceparent', '00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01'); + $stack = new RequestStack(); + $stack->push($request); + + $record = (new TraceContextProcessor($stack))($this->record()); + + $this->assertSame('4bf92f3577b34da6a3ce929d0e0e4736', $record->extra['trace_id']); + $this->assertSame('00f067aa0ba902b7', $record->extra['span_id']); + } + + public function testInvalidTraceparentLeavesFieldsUnset(): void + { + $request = Request::create('/'); + $request->headers->set('traceparent', 'garbage'); + $stack = new RequestStack(); + $stack->push($request); + + $record = (new TraceContextProcessor($stack))($this->record()); + + $this->assertArrayNotHasKey('trace_id', $record->extra); + $this->assertArrayNotHasKey('span_id', $record->extra); + } + + public function testNoRequestLeavesFieldsUnset(): void + { + $record = (new TraceContextProcessor(new RequestStack()))($this->record()); + + $this->assertArrayNotHasKey('trace_id', $record->extra); + $this->assertArrayNotHasKey('span_id', $record->extra); + } + + private function record(): LogRecord + { + return new LogRecord(new \DateTimeImmutable('2026-06-02T00:00:00+00:00'), 'outbound_http', Level::Info, 'test'); + } +} From 1243de6c2be6e531e79341c556eca1dd36ebbabc Mon Sep 17 00:00:00 2001 From: turegjorup Date: Wed, 3 Jun 2026 22:15:07 +0200 Subject: [PATCH 2/4] test(logging): guard identity enrichment + auth logging, cover request-id subscriber Apply the "logging must never break the request it annotates" principle consistently: - RequestContextProcessor: widen the try/catch from getActiveTenant() to the whole identity block, so screen_id (getScreen()->getId() on an unhydrated ScreenUser throws an uninitialized-typed-property Error) and user_id are guarded too. Fields set before a throw are kept. - AuthLoggingSubscriber: run each handler's logging through a guard() so a failure (context building or write) drops the line instead of aborting authentication, making the class's "only logs, never alters auth" contract real. Tests: - New RequestIdSubscriberTest: adopt/mint/empty-header/no-overwrite/sub-request. - AuthLoggingSubscriberTest: add onLoginSuccess and onJwtFailure (all four match arms: invalid/expired/not_found/unknown). Co-Authored-By: Claude Opus 4.8 --- .../EventSubscriber/AuthLoggingSubscriber.php | 33 +++++-- .../Processor/RequestContextProcessor.php | 31 +++--- .../AuthLoggingSubscriberTest.php | 73 ++++++++++++++ .../RequestIdSubscriberTest.php | 97 +++++++++++++++++++ 4 files changed, 213 insertions(+), 21 deletions(-) create mode 100644 tests/Logger/EventSubscriber/RequestIdSubscriberTest.php diff --git a/src/Logger/EventSubscriber/AuthLoggingSubscriber.php b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php index c16ed071f..0365b425b 100644 --- a/src/Logger/EventSubscriber/AuthLoggingSubscriber.php +++ b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php @@ -46,35 +46,35 @@ public static function getSubscribedEvents(): array public function onLoginSuccess(LoginSuccessEvent $event): void { - $this->logger->info('Authentication succeeded', [ + $this->guard(fn () => $this->logger->info('Authentication succeeded', [ 'event' => 'auth.login_success', 'user_identifier' => $event->getUser()->getUserIdentifier(), 'firewall' => $event->getFirewallName(), 'authenticator' => $event->getAuthenticator()::class, - ]); + ])); } public function onLoginFailure(LoginFailureEvent $event): void { - $this->logger->warning('Authentication failed', [ + $this->guard(fn () => $this->logger->warning('Authentication failed', [ 'event' => 'auth.login_failure', 'firewall' => $event->getFirewallName(), 'authenticator' => $event->getAuthenticator()::class, 'exception' => $event->getException(), - ]); + ])); } public function onLogout(LogoutEvent $event): void { - $this->logger->info('User logged out', [ + $this->guard(fn () => $this->logger->info('User logged out', [ 'event' => 'auth.logout', 'user_identifier' => $event->getToken()?->getUserIdentifier(), - ]); + ])); } public function onJwtFailure(JWTFailureEventInterface $event): void { - $this->logger->warning('JWT authentication failed', [ + $this->guard(fn () => $this->logger->warning('JWT authentication failed', [ 'event' => 'auth.jwt_failure', 'reason' => match (true) { $event instanceof JWTInvalidEvent => 'invalid', @@ -83,6 +83,23 @@ public function onJwtFailure(JWTFailureEventInterface $event): void default => 'unknown', }, 'exception' => $event->getException(), - ]); + ])); + } + + /** + * Runs a logging closure, swallowing any failure. + * + * This subscriber observes authentication events; logging must never break + * them. Both the context building (identity accessors that can throw) and the + * write itself run inside the guard, so a logging failure drops the line + * rather than aborting login/logout. + */ + private function guard(callable $log): void + { + try { + $log(); + } catch (\Throwable) { + // Intentionally silent — see method doc. + } } } diff --git a/src/Logger/Processor/RequestContextProcessor.php b/src/Logger/Processor/RequestContextProcessor.php index 4efbc9fea..09f27fe2b 100644 --- a/src/Logger/Processor/RequestContextProcessor.php +++ b/src/Logger/Processor/RequestContextProcessor.php @@ -48,22 +48,27 @@ public function __invoke(LogRecord $record): LogRecord $user = $this->security->getUser(); if (null !== $user) { - // Screen tokens authenticate as ScreenUser; everything else is a - // back-office User. Populate screen_id XOR user_id accordingly. - if ($user instanceof ScreenUser) { - $record->extra['screen_id'] = (string) $user->getScreen()->getId(); - } else { - $record->extra['user_id'] = $user->getUserIdentifier(); - } + // Enrichment must never break the request it is annotating. Every + // identity accessor below can throw — getActiveTenant() when no tenant + // is resolved yet, getScreen() on a not-yet-hydrated screen token, + // getUserIdentifier() on a custom user — so the whole block is guarded. + // Fields written before a throw are kept (the record is mutated in + // place); the failing one and any after it are simply left unset. + try { + // Screen tokens authenticate as ScreenUser; everything else is a + // back-office User. Populate screen_id XOR user_id accordingly. + if ($user instanceof ScreenUser) { + $record->extra['screen_id'] = (string) $user->getScreen()->getId(); + } else { + $record->extra['user_id'] = $user->getUserIdentifier(); + } - if ($user instanceof TenantScopedUserInterface) { - // getActiveTenant() can throw when no tenant is resolved yet; - // enrichment must never break the request it is annotating. - try { + if ($user instanceof TenantScopedUserInterface) { $record->extra['tenant_id'] = $user->getActiveTenant()->getTenantKey(); - } catch (\Throwable) { - // No active tenant on this request — leave tenant_id unset. } + } catch (\Throwable) { + // An identity accessor failed (no active tenant, unhydrated screen, + // lazy-load error, …). Keep whatever was set; never break logging. } } diff --git a/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php b/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php index 79fb041f5..de01d9544 100644 --- a/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php +++ b/tests/Logger/EventSubscriber/AuthLoggingSubscriberTest.php @@ -5,19 +5,92 @@ namespace App\Tests\Logger\EventSubscriber; use App\Logger\EventSubscriber\AuthLoggingSubscriber; +use Lexik\Bundle\JWTAuthenticationBundle\Event\JWTExpiredEvent; +use Lexik\Bundle\JWTAuthenticationBundle\Event\JWTFailureEventInterface; +use Lexik\Bundle\JWTAuthenticationBundle\Event\JWTInvalidEvent; +use Lexik\Bundle\JWTAuthenticationBundle\Event\JWTNotFoundEvent; use Monolog\Handler\TestHandler; use Monolog\Level; use Monolog\Logger; use PHPUnit\Framework\TestCase; use Symfony\Component\HttpFoundation\Request; use Symfony\Component\Security\Core\Authentication\Token\TokenInterface; +use Symfony\Component\Security\Core\Exception\AuthenticationException; use Symfony\Component\Security\Core\Exception\BadCredentialsException; +use Symfony\Component\Security\Core\User\UserInterface; use Symfony\Component\Security\Http\Authenticator\AuthenticatorInterface; +use Symfony\Component\Security\Http\Authenticator\Passport\Badge\UserBadge; +use Symfony\Component\Security\Http\Authenticator\Passport\SelfValidatingPassport; use Symfony\Component\Security\Http\Event\LoginFailureEvent; +use Symfony\Component\Security\Http\Event\LoginSuccessEvent; use Symfony\Component\Security\Http\Event\LogoutEvent; class AuthLoggingSubscriberTest extends TestCase { + public function testLoginSuccessEmitsInfoWithIdentifierFirewallAndAuthenticator(): void + { + $handler = new TestHandler(); + $subscriber = new AuthLoggingSubscriber(new Logger('auth', [$handler])); + + $user = $this->createMock(UserInterface::class); + $user->method('getUserIdentifier')->willReturn('editor@example.com'); + $authenticator = $this->createMock(AuthenticatorInterface::class); + + $event = new LoginSuccessEvent( + $authenticator, + new SelfValidatingPassport(new UserBadge('editor@example.com', fn () => $user)), + $this->createMock(TokenInterface::class), + Request::create('/v2/authentication/token', Request::METHOD_POST), + null, + 'main', + ); + + $subscriber->onLoginSuccess($event); + + $this->assertTrue($handler->hasInfoRecords()); + $record = $handler->getRecords()[0]; + $this->assertSame('auth.login_success', $record->context['event']); + $this->assertSame('editor@example.com', $record->context['user_identifier']); + $this->assertSame('main', $record->context['firewall']); + $this->assertSame($authenticator::class, $record->context['authenticator']); + } + + /** + * The `reason` string is what operators key dashboards on, and the three + * concrete Lexik events all share JWTFailureEventInterface — an easy arm to + * mis-wire — so pin each mapping, including the `unknown` default. + */ + public function testJwtFailureMapsEachEventTypeToReason(): void + { + $exception = new AuthenticationException('nope'); + $cases = [ + 'invalid' => new JWTInvalidEvent($exception, null), + 'expired' => new JWTExpiredEvent($exception, null), + 'not_found' => new JWTNotFoundEvent($exception, null), + 'unknown' => $this->unknownFailureEvent($exception), + ]; + + foreach ($cases as $expectedReason => $event) { + $handler = new TestHandler(); + $subscriber = new AuthLoggingSubscriber(new Logger('auth', [$handler])); + + $subscriber->onJwtFailure($event); + + $this->assertTrue($handler->hasWarningRecords(), "reason=$expectedReason"); + $record = $handler->getRecords()[0]; + $this->assertSame('auth.jwt_failure', $record->context['event']); + $this->assertSame($expectedReason, $record->context['reason']); + } + } + + private function unknownFailureEvent(AuthenticationException $exception): JWTFailureEventInterface + { + $event = $this->createMock(JWTFailureEventInterface::class); + $event->method('getException')->willReturn($exception); + + return $event; + } + public function testLoginFailureEmitsAuthWarningWithoutCredentials(): void { $handler = new TestHandler(); diff --git a/tests/Logger/EventSubscriber/RequestIdSubscriberTest.php b/tests/Logger/EventSubscriber/RequestIdSubscriberTest.php new file mode 100644 index 000000000..83f4e6033 --- /dev/null +++ b/tests/Logger/EventSubscriber/RequestIdSubscriberTest.php @@ -0,0 +1,97 @@ +headers->set(self::HEADER, 'upstream-id-123'); + + $subscriber->onRequest($this->requestEvent($request)); + $this->assertSame('upstream-id-123', $request->attributes->get(self::ATTR)); + + $response = new Response(); + $subscriber->onResponse($this->responseEvent($request, $response)); + $this->assertSame('upstream-id-123', $response->headers->get(self::HEADER)); + } + + public function testIdIsMintedWhenNoInboundHeaderAndEchoedOnResponse(): void + { + $subscriber = new RequestIdSubscriber(); + $request = Request::create('/'); + + $subscriber->onRequest($this->requestEvent($request)); + $minted = $request->attributes->get(self::ATTR); + $this->assertIsString($minted); + $this->assertNotSame('', $minted); + + $response = new Response(); + $subscriber->onResponse($this->responseEvent($request, $response)); + $this->assertSame($minted, $response->headers->get(self::HEADER)); + } + + public function testEmptyInboundHeaderMintsAFreshId(): void + { + $subscriber = new RequestIdSubscriber(); + $request = Request::create('/'); + $request->headers->set(self::HEADER, ''); + + $subscriber->onRequest($this->requestEvent($request)); + + // `?:` treats the empty header as absent and mints a non-empty id. + $this->assertNotSame('', $request->attributes->get(self::ATTR)); + } + + public function testResponseHeaderIsNotOverwrittenWhenAlreadySet(): void + { + $subscriber = new RequestIdSubscriber(); + $request = Request::create('/'); + $request->attributes->set(self::ATTR, 'our-id'); + + $response = new Response(); + $response->headers->set(self::HEADER, 'downstream-id'); + $subscriber->onResponse($this->responseEvent($request, $response)); + + $this->assertSame('downstream-id', $response->headers->get(self::HEADER)); + } + + public function testSubRequestIsIgnored(): void + { + $subscriber = new RequestIdSubscriber(); + $request = Request::create('/'); + + $subscriber->onRequest($this->requestEvent($request, HttpKernelInterface::SUB_REQUEST)); + $this->assertNull($request->attributes->get(self::ATTR)); + + $request->attributes->set(self::ATTR, 'main-id'); + $response = new Response(); + $subscriber->onResponse($this->responseEvent($request, $response, HttpKernelInterface::SUB_REQUEST)); + $this->assertFalse($response->headers->has(self::HEADER)); + } + + private function requestEvent(Request $request, int $type = HttpKernelInterface::MAIN_REQUEST): RequestEvent + { + return new RequestEvent($this->createMock(HttpKernelInterface::class), $request, $type); + } + + private function responseEvent(Request $request, Response $response, int $type = HttpKernelInterface::MAIN_REQUEST): ResponseEvent + { + return new ResponseEvent($this->createMock(HttpKernelInterface::class), $request, $type, $response); + } +} From 538a4785b29e776887b846d2b39371388c0a2193 Mon Sep 17 00:00:00 2001 From: turegjorup Date: Mon, 8 Jun 2026 22:46:37 +0200 Subject: [PATCH 3/4] refactor(logging): name the auth channel logger parameter for its channel Rename AuthLoggingSubscriber's injected logger $logger -> $authLogger so the constructor self-documents which channel it writes to. The explicit @monolog.logger.auth binding stays (renamed to the matching key) and remains the authoritative, build-verified wiring; a services.yaml comment records why explicit binding is preferred over MonologBundle channel autowiring. Co-Authored-By: Claude Opus 4.8 --- config/services.yaml | 12 +++++++++++- src/Logger/EventSubscriber/AuthLoggingSubscriber.php | 10 +++++----- 2 files changed, 16 insertions(+), 6 deletions(-) diff --git a/config/services.yaml b/config/services.yaml index 00d56b844..ebdb6f1ec 100644 --- a/config/services.yaml +++ b/config/services.yaml @@ -81,9 +81,19 @@ services: tags: [{ name: monolog.processor }] # Logs security outcomes on the `auth` channel (logging only). + # + # Channel loggers are bound explicitly rather than via MonologBundle's channel + # autowiring. The constructor parameter is named for its channel + # (`$authLogger`, `$feedLogger`, …) so the call site reads clearly, but the + # explicit `@monolog.logger.` binding is the authoritative wiring: + # it fails loudly at container build if the channel id is wrong or the + # parameter is renamed, whereas the autowiring convention would silently fall + # back to the default `app` channel — a misroute neither container + # compilation nor PHPStan can catch. The parameter name and the binding must + # agree; the container enforces it. App\Logger\EventSubscriber\AuthLoggingSubscriber: arguments: - $logger: '@monolog.logger.auth' + $authLogger: '@monolog.logger.auth' Symfony\Component\Security\Http\Authentication\AuthenticationFailureHandlerInterface: '@Lexik\Bundle\JWTAuthenticationBundle\Security\Http\Authentication\AuthenticationFailureHandler' Symfony\Component\Security\Http\Authentication\AuthenticationSuccessHandlerInterface: '@Lexik\Bundle\JWTAuthenticationBundle\Security\Http\Authentication\AuthenticationSuccessHandler' diff --git a/src/Logger/EventSubscriber/AuthLoggingSubscriber.php b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php index 0365b425b..8ed11bf2f 100644 --- a/src/Logger/EventSubscriber/AuthLoggingSubscriber.php +++ b/src/Logger/EventSubscriber/AuthLoggingSubscriber.php @@ -29,7 +29,7 @@ final readonly class AuthLoggingSubscriber implements EventSubscriberInterface { public function __construct( - private LoggerInterface $logger, + private LoggerInterface $authLogger, ) {} public static function getSubscribedEvents(): array @@ -46,7 +46,7 @@ public static function getSubscribedEvents(): array public function onLoginSuccess(LoginSuccessEvent $event): void { - $this->guard(fn () => $this->logger->info('Authentication succeeded', [ + $this->guard(fn () => $this->authLogger->info('Authentication succeeded', [ 'event' => 'auth.login_success', 'user_identifier' => $event->getUser()->getUserIdentifier(), 'firewall' => $event->getFirewallName(), @@ -56,7 +56,7 @@ public function onLoginSuccess(LoginSuccessEvent $event): void public function onLoginFailure(LoginFailureEvent $event): void { - $this->guard(fn () => $this->logger->warning('Authentication failed', [ + $this->guard(fn () => $this->authLogger->warning('Authentication failed', [ 'event' => 'auth.login_failure', 'firewall' => $event->getFirewallName(), 'authenticator' => $event->getAuthenticator()::class, @@ -66,7 +66,7 @@ public function onLoginFailure(LoginFailureEvent $event): void public function onLogout(LogoutEvent $event): void { - $this->guard(fn () => $this->logger->info('User logged out', [ + $this->guard(fn () => $this->authLogger->info('User logged out', [ 'event' => 'auth.logout', 'user_identifier' => $event->getToken()?->getUserIdentifier(), ])); @@ -74,7 +74,7 @@ public function onLogout(LogoutEvent $event): void public function onJwtFailure(JWTFailureEventInterface $event): void { - $this->guard(fn () => $this->logger->warning('JWT authentication failed', [ + $this->guard(fn () => $this->authLogger->warning('JWT authentication failed', [ 'event' => 'auth.jwt_failure', 'reason' => match (true) { $event instanceof JWTInvalidEvent => 'invalid', From 6e5ba63462c975045aa9a2cb931877a1dc6e2bf5 Mon Sep 17 00:00:00 2001 From: turegjorup Date: Tue, 9 Jun 2026 10:28:55 +0200 Subject: [PATCH 4/4] docs(logging): use OTel user.id over deprecated enduser.id in ADR 011 OTel semconv deprecated the enduser.* attribute group in favour of user.id. Align the ADR's identity description; the field rename itself lands with the processor changes on the semconv branch. Co-Authored-By: Claude Opus 4.8 --- docs/adr/011-structured-logging.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/docs/adr/011-structured-logging.md b/docs/adr/011-structured-logging.md index 34d59a6e9..e60f0f44b 100644 --- a/docs/adr/011-structured-logging.md +++ b/docs/adr/011-structured-logging.md @@ -38,7 +38,7 @@ server gone away) can surface. semantic conventions as strictly as the framework allows: `http.route` is the matched route's **path template** (e.g. `/v2/screens/{id}`), emitted only when a route matched and never the concrete id-bearing URL (which is recorded separately as `url.path`); - `client.address` is truncated; identity is `enduser.id` XOR `screen.id` plus `tenant.key`. + `client.address` is truncated; identity is `user.id` XOR `screen.id` plus `tenant.key`. 3. **No silent failures.** Catch blocks must log the exception, rethrow it (optionally wrapped), or be explicitly annotated as intentionally silent. This is enforced in CI by