apf_portal/decisions/0012-observability-pino-opentelemetry.md

status, date, decision-makers, tags

status	date	decision-makers	tags
accepted	2026-04-29	R&D Lead	observability backend frontend

Observability — Pino structured logs + OpenTelemetry tracing, W3C Trace Context propagation, stdout + collector

Context and Problem Statement

The portal has stated security, performance, and accessibility as first-class concerns. None of the three can be operated, audited, or improved without observability built in from day one. We need a fixed answer to:

• How application events are recorded (logs, traces);
• Which identifier ties together what happens in the SPA, the BFF, the DB, the cache, and any downstream API call for a single user action;
• Where the signals are emitted, and how they reach a backend;
• What must never appear in a log line (PII, credentials, tokens);
• How the architecture stays vendor-neutral so the chosen on-prem backend (Grafana stack, ELK, or otherwise — phase 3) can be selected without rewriting the application.

Two signals are in scope here: logs and traces. Metrics are deliberately out of scope; if metrics become necessary later, they fit naturally into the same OpenTelemetry pipeline and will get their own ADR.

Decision Drivers

• A single correlation identifier across all signals — front-end click, BFF request, DB query, downstream API call, log line — debuggable in seconds, not in spelunking.
• Vendor-neutral standards (OpenTelemetry, W3C Trace Context) so the on-prem backend can be chosen later (phase 3) without coupling the application to it.
• Mature, enterprise-grade libraries — anti-bricolage applies particularly here.
• 12-factor: the application emits to stdout / OTLP; shipping is an operational concern, not an application concern.
• Privacy: PII (and credentials, tokens) must never reach a log line. Defense in depth — even if a log is exfiltrated, it must contain the minimum needed for support.
• The SPA must participate in the trace so the first segment (user click → first request) is not lost.

Considered Options

Logging library

• Pino + nestjs-pino. (Chosen.)
• Winston.
• Bunyan.
• Plain console.log / NestJS default Logger only.

Tracing instrumentation

• OpenTelemetry SDK + auto-instrumentations-node. (Chosen.)
• Vendor SDKs (Datadog, New Relic).
• OpenTracing.
• Custom hand-rolled tracer.

Trace propagation header

• W3C Trace Context (traceparent, tracestate). (Chosen.)
• Custom X-Correlation-ID.
• Vendor formats (B3, Datadog, Jaeger).

Request-scoped context (correlation propagation in code)

• nestjs-cls over Node AsyncLocalStorage. (Chosen.)
• Manual passing through every call signature.
• Direct AsyncLocalStorage without the NestJS wrapper.

Sampling

• Always-on (100 %) at the application; tail sampling deferred to the collector / phase-3 ADR. (Chosen for v1.)
• Probabilistic head sampling (e.g. 10 %).

Emission and shipping

• stdout (logs) + OTLP/HTTP (traces) → local OpenTelemetry Collector → on-prem backend (phase 3). (Chosen.)
• Direct shipping from the app to the backend.

Sensitive data handling in logs

• Pino redact with an explicit allowlist of paths to strip. (Chosen.)
• Hand-rolled scrubbing per log call.
• No redaction.

Frontend tracing

• OpenTelemetry-Web in the Angular SPA, propagating traceparent on outbound HTTP. (Chosen.)
• Front-end out of the trace.

Decision Outcome

Logging. pino is the structured logger; nestjs-pino integrates it into NestJS, replacing the framework's default Logger. Output is JSON, line-delimited, on stdout. Log lines carry a fixed envelope:

{
  "level": "info",
  "time": "2026-04-29T20:15:42.123Z",
  "service": "portal-bff",
  "version": "<git sha or semver>",
  "env": "prod",
  "trace_id": "0af7651916cd43dd8448eb211c80319c",
  "span_id": "b7ad6b7169203331",
  "session_id": "…",
  "user_id_hash": "sha256:…",
  "audience": "workforce",
  "msg": "GET /documents 200",
  "method": "GET",
  "path": "/documents",
  "status": 200,
  "duration_ms": 14
}

The contextual fields (trace_id, span_id, session_id, user_id_hash, audience) are pulled from the request-scoped CLS by a custom Pino formatter — no per-call boilerplate.

Tracing. OpenTelemetry SDK for Node (@opentelemetry/sdk-node) is started before NestJS bootstrap. @opentelemetry/auto-instrumentations-node is enabled with the modules we use: HTTP, Express, NestJS core, pg, ioredis, and Prisma (via Prisma's built-in OTel hooks). Custom spans can be created inline via @opentelemetry/api's tracer.startActiveSpan for non-trivial business flows.

Propagation. W3C Trace Context is the only propagation format. The traceparent (and optionally tracestate) header carries the trace identity end to end. The trace_id extracted from traceparent is the correlation identifier — there is no separate X-Correlation-ID. If a request arrives without a traceparent, the SDK starts a new trace and the BFF emits the resulting traceparent in the response so the SPA can pick it up. Downstream HTTP calls automatically carry traceparent thanks to the HTTP auto-instrumentation.

Request-scoped context. nestjs-cls is registered globally and exposes the per-request store. At the entry of every request, an interceptor populates:

Key	Source
trace_id	OTel current span context
span_id	OTel current span context
session_id	session lookup (ADR-0010)
user_id_hash	sha256(user_id + LOG_USER_ID_SALT) computed once per session and cached on the session payload
audience	session payload (ADR-0008)

The Pino formatter and the audit-log writer (future ADR) read from CLS — neither requires the developer to thread context through call signatures.

user_id_hash salting. A per-environment salt (LOG_USER_ID_SALT) is required and read from env. The hash is sha256(userId || ":" || salt), base64-url-encoded. The salt is rotated as part of secret-rotation procedures (future ops ADR). Without the salt, the same userId always produces the same hash, which is enumerable for known userId spaces; the salt makes per-environment hashes incomparable.

Sampling. v1 emits 100 % of traces at the application. Volumes are low and end-to-end debuggability is the priority. Tail sampling (drop the boring traces, keep the slow / failed ones) is performed at the OpenTelemetry Collector, configured as part of the phase-3 infrastructure ADR. The application does not know nor care about sampling policy — moving the policy is a collector-config change.

Emission and shipping. Logs go to stdout as line-delimited JSON. Traces are exported via OTLP/HTTP to a local OpenTelemetry Collector instance running alongside the BFF (sidecar in container orchestration, local process in dev). The collector is the single point that knows the on-prem backend's address and credentials; the application stays decoupled. Backend choice and collector deployment topology are deferred to the phase-3 infrastructure ADR.

Redaction. Pino's redact option strips a fixed list of paths from every log line before it is serialised:

redact: {
  paths: [
    'req.headers.authorization',
    'req.headers.cookie',
    'req.headers["set-cookie"]',
    'res.headers["set-cookie"]',
    '*.password',
    '*.client_secret',
    '*.access_token',
    '*.refresh_token',
    '*.id_token',
    '*.tokens',
    '*.session_secret',
  ],
  censor: '[REDACTED]',
}

The list lives in apps/portal-bff/src/observability/log.redact.ts and is reviewed in every PR that adds a new field-shape (DTO, claim, header). A unit test asserts that no path on the redact list ever appears in any logger output.

Log levels. trace, debug, info, warn, error, fatal. Default level: info in prod, debug in dev, configurable via LOG_LEVEL. trace and debug must never be enabled in prod long-term — only for short-lived investigation under a feature flag.

Frontend tracing. The Angular SPA (portal-shell) is instrumented with OpenTelemetry for browsers (@opentelemetry/sdk-trace-web). An Angular HttpInterceptor propagates the current traceparent on every outbound HTTP call (typed targets only — the BFF). The trace identifier is therefore the same one the user sees if a support ticket is opened (the trace_id is exposed in the SPA's error-display UI for support hand-off). A user click → SPA dispatch → BFF request → DB query → response is a single trace, navigable end to end.

The SPA does not ship its own logs to a backend in v1. Browser-side error reporting (uncaught exceptions, Promise rejections) is a separate concern and will get its own ADR if and when it becomes necessary; in the interim, errors are visible in the browser console for development and surface as 500-equivalents in the BFF logs once the failed request reaches the server.

Audit logs are not application logs. Anything that is a security-relevant audit event (sign-in, sign-out, MFA challenge, authorization deny, admin action — when one exists) is emitted via a separate writer and a separate sink, defined by the audit-trail ADR (next). The two streams may share the trace identifier and the CLS context, but they do not share the same retention, the same access controls, or the same volume profile.

Configuration (env-driven).

Variable	Purpose
LOG_LEVEL	trace/debug/info/warn/error/fatal; default info in prod, debug in dev
LOG_USER_ID_SALT	per-env salt for user_id_hash
OTEL_SERVICE_NAME	e.g. portal-bff, portal-shell
OTEL_SERVICE_VERSION	git sha or semver
OTEL_RESOURCE_ATTRIBUTES	additional tags (deployment.environment, etc.)
OTEL_EXPORTER_OTLP_ENDPOINT	URL of the local OTel Collector
OTEL_EXPORTER_OTLP_PROTOCOL	http/protobuf (default)
OTEL_TRACES_SAMPLER	always_on in v1; the collector applies tail sampling

The BFF refuses to start if LOG_USER_ID_SALT or OTEL_SERVICE_NAME is missing.

Consequences

• Good, because every signal carries the same trace_id, navigable across the SPA, the BFF, the DB, the cache, and downstream APIs once they exist. End-to-end debugging is one click in any conformant backend.
• Good, because OpenTelemetry + W3C are vendor-neutral; the on-prem backend (Grafana / ELK / other) is chosen later without code changes.
• Good, because Pino is the fastest established Node logger; structured JSON output is directly ingestible by every backend.
• Good, because nestjs-cls removes context-threading boilerplate — the developer writes business logic, the platform handles correlation.
• Good, because PII redaction and per-environment salting on user_id_hash minimise leakage if a log is exfiltrated; the redaction list is reviewable in PRs.
• Good, because 100 % sampling at the application keeps the architecture simple in v1; sampling policy moves to the collector when volumes justify it.
• Bad, because the OTel Node SDK has historically had churn in API surface; the decision to use auto-instrumentations rather than hand-instrument is a calculated bet on the upstream stabilisation. Mitigated by pinning OTel package versions and lifting them deliberately.
• Bad, because emitting 100 % traces in prod at scale will eventually cost storage; the deferral to collector-side tail sampling is the proper answer, not "drop everything at the source".
• Bad, because the redaction list is a per-line config — adding a new sensitive shape (e.g. a future PII field) requires a PR. There is no fully automatic "redact anything that looks PII-like". This is an accepted trade-off: explicit beats clever.
• Bad, because the SPA's OTel-Web bundle adds a small payload (~30 KB gzip). Acceptable; we already prioritise observability over aesthetic minimalism.
• Bad, because no front-end log shipping in v1 means we are blind to client-only errors that don't cause a server-side request. Acceptable for v1; revisit if support volume justifies it.
• Neutral, because audit logs being a separate stream is enforced by writer separation, not by namespacing inside the same Pino logger — this is intentional (different retention, different access).

Confirmation

• apps/portal-bff/src/observability/observability.module.ts registers nestjs-pino, nestjs-cls, the OTel SDK initialiser, and the redact-list test fixture.
• apps/portal-bff/src/main.ts calls tracingSetup() before NestFactory.create(AppModule) — OTel must be initialised before any auto-instrumented module is loaded.
• The Pino transport in dev uses pino-pretty (human-readable); prod emits raw JSON.
• apps/portal-shell/src/observability/tracing.ts initialises @opentelemetry/sdk-trace-web with the OTLP/HTTP exporter pointing to the BFF's /v1/traces ingress (or directly to the collector if exposed).
• Every controller receives req and res and the http auto-instrumentation produces a span; non-trivial service methods open custom spans via tracer.startActiveSpan('domain.<verb>', ...) and propagate the CLS context within them.
• Integration tests:
  • a single user-action request emits one trace with correct parent-child structure (SPA → BFF → DB);
  • every log line for that request carries the same trace_id;
  • the redact list strips its targets from a captured stream;
  • a missing LOG_USER_ID_SALT prevents BFF startup.
• The CLS-bound user_id_hash is identical for two consecutive requests of the same user, and different across environments (different salt).
• The OTel Collector configuration ships in the deployment manifest (covered by the future infrastructure ADR), not in source — the application remains backend-agnostic.

Pros and Cons of the Options

Logging library

Pino + nestjs-pino (chosen)

• Good, because the fastest established Node logger; JSON structured output by default; first-class integration with NestJS (HTTP request logging, async context).
• Good, because rich redact configuration with path globbing — exactly what we need for PII handling.
• Bad, because nestjs-pino is third-party (well-maintained, but not Nest-team-owned). Acceptable.

Winston

• Good, because long-standing, large user base.
• Bad, because slower than Pino in JSON mode; ergonomics around async context less polished. Less aligned with our perf and DX goals.

Bunyan

• Bad, because slowing maintenance, smaller community in 2026.

console.log / NestJS default Logger only

• Bad, because no structured output, no redaction, no async context, no levels by config. Bricolage.

Tracing instrumentation

OpenTelemetry (chosen)

• Good, because the CNCF graduated standard — supported by every observability vendor and every major language.
• Good, because auto-instrumentation removes the bulk of glue work for HTTP, DB, Redis, Prisma.
• Bad, because the Node SDK has had API churn historically — managed by version pinning.

Vendor SDK (Datadog, New Relic, etc.)

• Good, because typically richer auto-instrumentation than OTel for that vendor.
• Bad, because vendor lock-in — switching backend later means rewriting instrumentation. Rejected.

OpenTracing

• Bad, because deprecated; succeeded by OTel. Rejected.

Custom

• Bad, because bricolage on a critical surface.

Propagation header

W3C Trace Context (chosen)

• Good, because the IETF/W3C standard adopted across the industry.
• Good, because covered by every OTel SDK and by intermediate proxies (Envoy, NGINX, AWS ALB, etc.).

Custom X-Correlation-ID

• Bad, because reinvents what already exists; loses the parent-child relation that traceparent carries; doesn't cooperate with auto-instrumentation.

Vendor formats (B3, Datadog, Jaeger)

• Bad, because vendor-specific. OTel can be configured to emit them as a fallback if a specific intermediate requires them, but they are not the default.

Request-scoped context

nestjs-cls (chosen)

• Good, because purpose-built for NestJS, integrates cleanly with interceptors, guards, and the logger.
• Good, because minimal boilerplate at the call sites.

Manual passing

• Bad, because every service signature acquires a context parameter — relentless ceremony, easy to forget.

AsyncLocalStorage directly

• Good, because no extra dependency.
• Bad, because we'd reinvent the request-bind plumbing already provided by nestjs-cls.

Sampling

Always-on (chosen, v1)

• Good, because end-to-end debuggability with no surprises.
• Bad, because storage cost grows linearly with volume.

Probabilistic head sampling

• Good, because cheap.
• Bad, because we lose traces of rare events — exactly the ones we need for incident analysis. Tail sampling at the collector is strictly better.

Emission and shipping

stdout + collector (chosen)

• Good, because 12-factor; the application is decoupled from the backend; rotating backends is an ops change, not a deploy.
• Good, because the collector handles batching, retries, sampling, and protocol translation.

Direct shipping

• Bad, because backend coupled to the application; outage of the backend impacts the app's emission path; multi-tenant credentials end up in the app config.

Sensitive data handling

Pino redact allowlist (chosen)

• Good, because explicit, reviewable, testable.
• Bad, because a new sensitive shape requires a PR — accepted.

Hand-rolled scrubbing

• Bad, because per-call boilerplate; easy to forget; inconsistent.

No redaction

• Bad, because a single accidental log of an Authorization header turns into a security incident.

Frontend tracing

OTel-Web in the SPA (chosen)

• Good, because the trace starts where the user clicks — first segment of every story is captured.
• Good, because the same trace_id shown to the user is the one used by support — no translation.
• Bad, because adds a small bundle to the SPA; quantifiable, accepted.

Front out of the trace

• Bad, because every trace begins one hop too late, and "front was slow" becomes uninvestigable.

More Information

• OpenTelemetry: https://opentelemetry.io/
• OpenTelemetry for Node.js: https://opentelemetry.io/docs/languages/js/
• OpenTelemetry for Web: https://opentelemetry.io/docs/languages/js/getting-started/browser/
• W3C Trace Context: https://www.w3.org/TR/trace-context/
• Pino: https://github.com/pinojs/pino
• nestjs-pino: https://github.com/iamolegga/nestjs-pino
• nestjs-cls: https://github.com/Papooch/nestjs-cls
• OWASP Logging Cheat Sheet: https://cheatsheetseries.owasp.org/cheatsheets/Logging_Cheat_Sheet.html
• Related ADRs: ADR-0005 (NestJS), ADR-0006 (Postgres + Prisma — auto-instrumented), ADR-0010 (Redis — auto-instrumented), and the future ADRs for audit trail (separate stream, same trace_id) and on-prem infrastructure (collector deployment, backend choice, retention, tail sampling).