12-operations-runbookswave: W6filled40 citations

Monitoring and Observability — Health, Logging and Jobs

Audiences: developer, internal

Monitoring and Observability — Health, Logging and Jobs

Honest current-state: ddx-api ships stdout-only structured logs (no remote sink today) plus a PostgreSQL-backed access/error/audit log store (the ddx_api_log Prisma database), four @nestjs/terminus health endpoints, an hourly metrics aggregation cron that emits Grafana-ready ApiMetric rows, and a shell-level health table in ./ddx-manage.sh status. There is no Prometheus scrape endpoint, no OTLP exporter, no remote APM, and no aggregator like Loki/Datadog wired up — observability is "query the local Postgres logs + watch stdout files under ./logs/".

Business Purpose

A clinic that cannot answer "is the API up right now?" or "what was the last thing the system did before it stopped responding?" cannot meet its operational duties to patients or to its own auditors. Dudoxx HMS therefore ships three observability surfaces with different audiences: (1) a shell status table an operator runs in 1 second to see which of the managed application services (ALL_SERVICES, 11 today) and the docker infrastructure containers are healthy, (2) a set of HTTP health endpoints that Kubernetes/Docker probes (and the ddx-web BackendPool) call to make failover decisions automatically, and (3) a persistent access/error/audit log database the CLINIC_ADMIN role can query through the GET /api/v1/logging/* endpoints for incident postmortems and compliance evidence. Audit-grade event logging — who did what, when, with what outcome — is documented separately on the audit-logging page; this page covers the infrastructure observability layer underneath it.

Audiences

  • Investor: Single-clinic on-prem deployments don't pay for a Datadog seat. The product therefore ships its own observability stack — health endpoints + per-database log tables + a status CLI — that costs zero per-clinic to run. When the SaaS hosted offering arrives the same surfaces map cleanly onto external scrapers (the access-log table already aggregates response-time percentiles at the SQL layer, so a Grafana datasource is the cheapest possible integration).
  • Clinical buyer (doctor/nurse/receptionist): The platform records every HTTP call to the API (method, path, response time, status code, the user and the clinic) in a separate "logging database" that survives upgrades and is not mixed with patient data. Your clinic admin can answer questions like "who accessed Mr. Müller's record last Tuesday?" by querying the audit trail — see the audit-logging page for the privacy-preserving design.
  • Developer/partner: Use ./ddx-manage.sh status to see service health; the table prints HTTP probe results from each service's get_url() (the API's /api/v1/health/live is hit by the wider pool too — see backend-pool-ha). NestJS-side logging uses a custom QuietLogger that filters out RouterExplorer/RoutesResolver startup noise; production logs go to ./logs/{service}.log per service (the script-managed lifecycle, not pm2). There is no Prometheus /metrics endpoint today — metrics are persisted as ApiMetric rows and queried via GET /api/v1/logging/metrics.
  • Internal (ops/support): Three knobs you'll actually use. (1) LOG_TARGET=postgresql|both (default postgresql) — controls whether access logs hit Postgres only or also stdout. (2) LOG_REQUEST_BODY=false, LOG_RESPONSE_BODY=false — default off because bodies routinely contain PHI; flip ON only inside a controlled environment with consent. (3) LOG_RETENTION_DAYS=90 — drives the daily cleanup cron; AccessLog / ErrorLog / AuditTrail are pruned in one transaction at 02:00 server time.

Architecture

diagram
┌─────────────────────── stdout + file logs (per process) ────────────────┐
│ ./ddx-manage.sh start api                                                │
│   → starts NestJS with `QuietLogger` (suppresses RouterExplorer)         │
│   → output piped to ./logs/api.log (50MB rotation, 5 generations)        │
│   → ditto for the rest of ALL_SERVICES: ocr, saas, web, deepsearch,     │
│      pdf-engine, flowagent-ts, vivoxx, livekit-agents-py, stripe, fhir   │
└──────────────────────────────────────────────────────────────────────────┘

┌─────────────────────── HTTP health probes ───────────────────────────────┐
│ GET /api/v1/health         full check  (Prisma main + FHIR /metadata)    │
│ GET /api/v1/health/live    process alive    (no I/O)                     │
│ GET /api/v1/health/ready   readiness   (DB + FHIR — same as full)        │
│ GET /api/v1/health/info    masked env  (memory, uptime, node version)    │
│ GET /api/v1/health/sse     SSE bus     (publish failure rate + buffer)   │
│ GET /api/v1/health/databases  all 5 Prisma DBs pinged in parallel        │
└──────────────────────────────────────────────────────────────────────────┘

┌─────────────────────── Persistent logs (Postgres ddx_api_log) ──────────┐
│   AccessLog    — every HTTP request (method/path/status/ms + user/org)  │
│   ErrorLog     — application errors (message/stack/code)                │
│   AuditTrail   — security-sensitive actions (see audit-logging page)    │
│   ApiMetric    — hourly aggregated p50/p95/p99 per endpoint             │
│                                                                          │
│   Filled by:   AccessLogInterceptor (global)  → LoggingService.logAccess │
│   Aggregated:  LoggingCronService.aggregateMetrics  (every hour)         │
│   Retained:    90 days (LOG_RETENTION_DAYS) — cleanupOldLogs at 02:00    │
└──────────────────────────────────────────────────────────────────────────┘

┌─────────────────────── Operator surface ─────────────────────────────────┐
│   ./ddx-manage.sh status   →   table of all ALL_SERVICES (11 apps today)       │
│                                + 7 docker infra containers (postgres,    │
│                                  redis, minio, qdrant, livekit, jitsi,   │
│                                  litellm)                                │
│   Health is decided by check_health() probing each service's get_url()   │
│                                                                          │
│   Read-API for the persisted logs:                                       │
│   GET /api/v1/logging/access-logs   (CLINIC_ADMIN + above)               │
│   GET /api/v1/logging/error-logs                                         │
│   GET /api/v1/logging/audit-trail                                        │
│   GET /api/v1/logging/metrics       (hourly p50/p95/p99 — Grafana-ready) │
│   GET /api/v1/logging/stats         (last 24h / 7d summary)              │
└──────────────────────────────────────────────────────────────────────────┘

Architecture anchor: see coding_context/ddx-hms-context.md for the HMS service topology and the five-Prisma-schema layout that puts logs on ddx_api_log so a vacuum or migration on the application database doesn't compete with logging writes. The five-DB split is described in ha-strategy §Tech Stack.

Tech Stack & Choices

  • NestJS logger: Custom QuietLogger (src/platform/common/logging/quiet-logger.ts) implements LoggerService directly — not pino, not winston, not nestjs-pino. It writes timestamped lines to stdout / stderr, suppresses NestJS's RouterExplorer + RoutesResolver startup spam, collapses consecutive duplicate messages into a (repeated N more times) summary, and honours LOG_LEVEL=debug|verbose|info. Wired into the app via NestFactory.create(AppModule, { logger: quietLogger, ... }) at ddx-api/src/main.ts:57-63. Rationale: NestJS's default logger emits ~500 lines on every restart (one per route mapped); the QuietLogger trims that to ~30 actionable lines so an operator's terminal stays readable and ./logs/api.log stays small enough to grep.
  • Why not pino / winston: The ddx-web side uses a separate structured-logger.ts for its server-component logging (see ddx-web/src/lib/logging/structured-logger.ts), but ddx-api chose to stay on NestJS's LoggerService contract so every existing new Logger(ServiceName) call across 1,712 source files continues to work without a refactor. The trade-off is that there is no JSON log mode today — the logs are human-readable text, not structured records — and a Loki/Datadog ingestion would either parse the text or sit downstream of a future pino swap.
  • Health checks (@nestjs/terminus): Standard NestJS module. The controller (src/platform/health/health.controller.ts) wires PrismaHealthIndicator against the main Prisma client and HttpHealthIndicator against ${HAPI_FHIR_BASE_URL}/metadata with a 3-second timeout and an optional Authorization: Bearer {HAPI_FHIR_API_TOKEN} header. The five-DB /health/databases endpoint calls ping() on each Prisma service in parallel — a custom helper on each PrismaXxxService, not Terminus. Each indicator throws on failure; Terminus converts that to a 503 response with an error map.
  • Access logging: AccessLogInterceptor (src/platform/logging/interceptors/access-log.interceptor.ts) is registered as a global interceptor in app.module.ts (slot 5 of the 9-stage pipeline — see ddx-api/CLAUDE.md §Request Pipeline). It captures method, url, statusCode, responseTime (ms), the user context resolved from gateway headers, request IP (with X-Forwarded-For / X-Real-IP support — access-log.interceptor.ts:86-101), and fire-and-forgets the write to PostgreSQL through LoggingService.logAccess(). The write is non-blocking — the .catch() at access-log.interceptor.ts:142-145 swallows logging errors so a Postgres outage on ddx_api_log cannot take down API responses.
  • Body redaction: LoggingService.sanitizeHeaders() redacts authorization | cookie | x-api-key | x-auth-token (logging.service.ts:202-222); sanitizeBody() redacts password | token | secret | apiKey | ssn | creditCard | cvv (logging.service.ts:228-251). Bodies are logged only when LOG_REQUEST_BODY=true / LOG_RESPONSE_BODY=trueboth default to false to avoid persisting PHI by accident.
  • Metrics aggregation (LoggingCronService.aggregateMetrics): Runs every hour via @Cron(CronExpression.EVERY_HOUR). Reads the last hour of AccessLog rows, groups by method:path, computes count + success/clientErrors/serverErrors split + min/avg/max/p50/p95/p99 of responseTime, and upserts one row per (endpoint, method, periodStart, periodType='hour') into ApiMetric (logging-cron.service.ts:72-200). The composite uniqueness constraint at logging-cron.service.ts:160-167 makes the job idempotent — replays after a crash overwrite, not duplicate.
  • Retention policy: LoggingCronService.cleanupOldLogs runs at EVERY_DAY_AT_2AM (logging-cron.service.ts:30-65). Default LOG_RETENTION_DAYS=90 means three months of AccessLog + ErrorLog + AuditTrail are kept; all three tables are pruned in one Promise.all of deleteMany({ timestamp: { lt: cutoff } }). The job logs the row counts it deleted so the operator can chart logging-DB growth from the boot logs alone. ApiMetric is not pruned (hourly rollups are tiny and useful for trend analysis over years).
  • Job runner: @nestjs/schedule (no BullMQ, no Bull, no Agenda) — see ddx-api/CLAUDE.md Infrastructure row. Two cron jobs live in the logging module (LoggingCronService); a third (storage cleanup) lives in JobsModule (src/platform/jobs/jobs.module.ts:20-30) and prunes soft-deleted MinIO objects daily at 02:30. ScheduleModule.forRoot() is registered once in AppModule — sub-modules do not re-import it (logging.module.ts:3, jobs.module.ts:14).
  • Process management: ./ddx-manage.sh start api runs the NestJS process via pnpm start:dev (dev) or pnpm start:prod (prod) and pipes both stdout and stderr to ./logs/api.log — see scripts/ddx-services.sh:30-58. The script tracks PID files, can stop services by PID or by regex pattern (get_pattern api returns ddx-api/dist/main\.js | ddx-api/node_modules/.*/nest start), and supports a --watch flag on status for a 2-second refresh loop (scripts/ddx-status.sh:18-38). Log files are not centrally rotated by the script — log rotation depends on the host (logrotate at 50MB / 5 files).
  • Status-table HTTP probe: check_health() in scripts/ddx-lib.sh (referenced from scripts/ddx-status.sh:73) curls each service's get_url() and treats 200/301/302 as HEALTHY, anything else as RUNNING (port bound but not healthy) or DOWN. For voice agents (flowagent-ts, vivoxx) get_url() returns empty — the status table reports STARTED/STOPPED based on PID file alone since they bind no port (outbound LiveKit workers).
  • Forbidden patterns: never use console.log — the NestJS Logger contract is the canonical writer (see ~/.claude/rules/shared/review-checklists/nestjs.md §Warnings: console.log → use new Logger()). Logging code itself is the one exception: AccessLogInterceptor uses console.error only in its .catch branch (access-log.interceptor.ts:144) so the fallback can never call back into LoggingService.

Data Flow

Per-request observability path (the most common code path):

  1. Request enters NestJS; GatewayAuthGuard validates X-API-Key and constructs request.user from X-Gateway-* headers.
  2. AccessLogInterceptor.intercept() runs (interceptor slot 5 of 9); captures startTime = Date.now(), method, url, headers, body, IP (via extractIp()), userAgent, plus user.id|email|role|organizationId if present.
  3. Controller handler executes; service-layer work happens.
  4. Response is generated; tap({ next, error }) fires logAccess(...) with responseTime = Date.now() - startTime and either the actual response.statusCode (success) or response.statusCode || 500 (error branch).
  5. LoggingService.logAccess() parses the URL, extracts API version (v1 from /api/v1/...), classifies the endpoint group (auth | fhir | storage | mail | qdrant | ai | logging | users | organizations | roles | other), sanitizes headers + body, and writes one row to AccessLog in ddx_api_log. The write is awaited inside logAccess() but the surrounding tap does not await — so a slow logging DB never holds up the HTTP response.
  6. Once an hour, LoggingCronService.aggregateMetrics() groups the last hour's AccessLog rows by (method, path), computes percentiles, upserts a single ApiMetric row per endpoint per hour.
  7. At 02:00 daily, LoggingCronService.cleanupOldLogs() deletes rows older than LOG_RETENTION_DAYS.

Operator query path (incident response):

  1. Clinic admin calls GET /api/v1/logging/access-logs?path=/api/v1/patients&statusCode=500&startDate=... with their JWT.
  2. LoggingController (guarded by @RequireAdminRole()logging.controller.ts:28-29) builds a Prisma where filter, runs the query with take: Math.min(limit, 1000) (hard cap to prevent runaway responses), returns { data, meta: { total, limit, offset, hasMore } }.
  3. Same shape for /error-logs, /audit-trail, /metrics, /stats. The /stats endpoint runs ten parallel COUNT/aggregate queries with optional organizationId filter (logging.controller.ts:388-465) — designed to be cheap enough that a Grafana dashboard can poll it every 30 seconds.

Health-probe path (Kubernetes / ddx-web BackendPool):

  1. Probe hits GET /api/v1/health/live (cheap, no I/O — just { status, timestamp, uptime }); used as the fast health signal (every 2s) by the BackendPool — see backend-pool-ha §Data Flow.
  2. Probe hits GET /api/v1/health/ready (Prisma ping + FHIR /metadata GET with 3s timeout); used as the full health signal (every 15s by the pool, or however Kubernetes is configured). 503 if either check fails.
  3. Probe hits GET /api/v1/health/databases (Prisma ping × 5 in parallel — main, logging, ai, com, accounting); useful for "is the logging DB dead?" diagnosis, not in the BackendPool path.
  4. GET /api/v1/health/sse exposes the SSE Redis buffer state — publishFailures24h, bufferedSessions, bufferedEvents (health.controller.ts:286). Returns status: 'degraded' once publishFailures ≥ 100. This is the only health endpoint that pings Redis.

Implicated Code

≥3 file:line citations required. Count: 12 below.

  • ddx-api/src/platform/health/health.controller.ts:121check() full health endpoint; wires Terminus PrismaHealthIndicator against PrismaService and HttpHealthIndicator against ${HAPI_FHIR_BASE_URL}/metadata with the auth-token-aware getFhirPingCheckConfig().
  • ddx-api/src/platform/health/health.controller.ts:161getLiveness() zero-I/O liveness probe; the cheap fast-check target used by ddx-web's BackendPool every 2s.
  • ddx-api/src/platform/health/health.controller.ts:286 + :318getSseHealth() + getDatabaseHealth(); the SSE health endpoint pings the EventBus publish-failure counter + Redis buffer stats, and the databases endpoint runs ping() on all five Prisma clients in parallel and 503s if any is down.
  • ddx-api/src/platform/logging/logging.service.ts:120-170logAccessToDatabase() writes one AccessLog row per HTTP request; calls extractApiVersion() + classifyEndpoint() + sanitizeHeaders() + sanitizeBody() before the insert; wraps in try/catch so a logging-DB outage cannot fail the request.
  • ddx-api/src/platform/logging/logging.service.ts:202-251sanitizeHeaders() and sanitizeBody(); the PHI-protection layer that redacts authorization | cookie | x-api-key | x-auth-token from headers and password | token | secret | apiKey | ssn | creditCard | cvv from bodies before persistence.
  • ddx-api/src/platform/logging/logging-cron.service.ts:30-65cleanupOldLogs() daily 02:00 retention cleanup; deletes AccessLog / ErrorLog / AuditTrail rows older than LOG_RETENTION_DAYS (default 90) in one Promise.all and logs the deleted counts.
  • ddx-api/src/platform/logging/logging-cron.service.ts:72-214aggregateMetrics() hourly p50/p95/p99 aggregation; groups AccessLog rows by method:path and upserts one ApiMetric row per (endpoint, method, periodStart, periodType='hour') — the row shape GET /api/v1/logging/metrics returns.
  • ddx-api/src/platform/logging/interceptors/access-log.interceptor.ts:20-80 — global AccessLogInterceptor.intercept(); captures startTime, calls next.handle().pipe(tap(...)), fire-and-forgets loggingService.logAccess(...) from both the success branch and the error branch (so 5xx responses are also persisted).
  • ddx-api/src/platform/logging/logging.controller.ts:28-29@RequireAdminRole() class-level guard restricts the entire /api/v1/logging/* query surface to CLINIC_ADMIN and SUPER_ADMIN; access logs are higher-trust than feature data and should not be queryable by DOCTOR / NURSE / RECEPTIONIST.
  • ddx-api/src/platform/common/logging/quiet-logger.ts:23-138 — custom LoggerService that suppresses RouterExplorer + RoutesResolver startup noise, collapses consecutive duplicate messages, honours LOG_LEVEL=debug|verbose|info; wired via NestFactory.create(AppModule, { logger: new QuietLogger() }) at ddx-api/src/main.ts:57-63.
  • scripts/ddx-lib.sh:39 — service registry; ALL_SERVICES, get_port(), get_url(), get_name(), get_pattern(), get_type(), get_dir() — the data structures the status / logs / start / stop commands all read from. Single source of truth for what "managed services" exist.
  • scripts/ddx-status.sh:18-110cmd_status() and show_status(); the operator-facing status table that probes each service's get_url() via check_health() and renders SERVICE / PORT / STATUS / PID / MEM / UPTIME / LOG columns with a --watch 2-second-refresh mode for live monitoring.

Business → Technical match. Business outcome: a clinic admin needs to answer "what happened on the API yesterday around 14:00?" within minutes, not hours. Technical mechanism: every request is captured by AccessLogInterceptor (access-log.interceptor.ts:40-79) into AccessLog (logging.service.ts:142-162) with path, statusCode, responseTime, the user, the org, and the IP — sanitized of credentials. LoggingController.getAccessLogs() (logging.controller.ts:72-128) accepts path, statusCode, userId, organizationId, startDate, endDate filters, paginates at 1000 rows max, and returns a { data, meta } envelope; one cURL or one Grafana panel gives the admin the answer.

Operational Notes

  • ./ddx-manage.sh status is the quickest health check. Run it as the first action in any incident; it shows which application services and which Docker containers are responsive. JSON mode (--json) exists for automation.
  • ./logs/{service}.log is the second-quickest. ./ddx-manage.sh logs api --follow tails ddx-api's stdout — useful when the QuietLogger has just collapsed duplicates and you want to see which line is being repeated.
  • The logging database is the third-quickest. psql ddx_api_log -c "select method, path, status_code, response_time, timestamp from access_logs where timestamp > now() - interval '1 hour' and status_code >= 500 order by timestamp desc;" answers most "what just went wrong?" questions in one query because the table is indexed on timestamp (Prisma default @@index) and statusCode (logging.controller.ts:84-85).
  • Body logging is OFF by default for a reason. LOG_REQUEST_BODY=true will persist PHI into AccessLog.requestBody — a JSONB column — and that data is governed by the same retention as access logs (90 days) but not by the same Trusted Gateway access rules as patient resources. Flipping this on in a German clinic deployment is a notifiable processing change under GDPR Art. 30; do not enable it without a documented purpose and a DPIA update.
  • Bodies are sanitized regardless. Even with body logging ON, LoggingService.sanitizeBody() strips password | token | secret | apiKey | ssn | creditCard | cvv keys. Headers always redact authorization | cookie | x-api-key | x-auth-token. The redaction list lives at logging.service.ts:208-213 and logging.service.ts:234-242 — add to it before flipping body logging on if your DTOs carry additional sensitive keys.
  • The metrics endpoint is the closest thing to a Grafana datasource. GET /api/v1/logging/metrics?endpoint=/api/v1/patients&method=GET&periodType=hour returns one row per hour with min/avg/max/p50/p95/p99 of response time — the row shape LoggingCronService.aggregateMetrics() upserts (logging-cron.service.ts:160-200). Grafana SimpleJson + a Prisma adapter would be a half-day integration; nothing exists yet.
  • The SSE health endpoint is the only place to see Redis state. GET /api/v1/health/sse returns publishFailures24h, bufferedSessions, bufferedEvents from EventBusService.getPublishFailures() / getBufferStats() (health.controller.ts:286). If SSE-driven UI features look stuck, check this endpoint before reaching for redis-cli.
  • The five-database health endpoint can surface a single-DB outage. GET /api/v1/health/databases runs ping() on all five Prisma clients in parallel (health.controller.ts:318); if ddx_api_log is the one that's down, full /health still passes (it only pings ddx_api_main) — but per-request access logging is silently dropping rows. Add this endpoint to your external monitor if you actively rely on the logging DB.
  • The QuietLogger collapses duplicates. If you see (repeated 42 more times) in logs/api.log, that means the previous line fired 43 times in a row. Useful for noticing tight retry loops, useless for accurate timestamps on each occurrence — set LOG_LEVEL=debug if you need un-collapsed output during a debug session.
  • No remote sink today. If you want logs off the host, run tail -F logs/api.log | nc loki.internal 1514 or equivalent at the OS layer; do not ship pino-loki / pino-http until the QuietLogger is replaced with pino. The replacement is a half-day refactor (swap new QuietLogger() for a pino logger that implements LoggerService) but it would also lose the duplicate-collapsing behaviour — pino doesn't ship that out of the box.
  • Cron failures log to stdout, nowhere else. If cleanupOldLogs or aggregateMetrics throws, the error lands in logs/api.log only — there is no PagerDuty wiring. Add a downstream alert on the absence of new ApiMetric rows for >2 hours if cron health matters to you (no such alert ships today).
  • Validation commands:
    • ./ddx-manage.sh status — fastest visual check of all managed app services (ALL_SERVICES) + infra containers.
    • ./ddx-manage.sh status --json | jq — same data in machine-readable form (for automation).
    • curl -fsS http://localhost:6100/api/v1/health — full health (DB + FHIR).
    • curl -fsS http://localhost:6100/api/v1/health/databases — all five Prisma DBs.
    • curl -fsS http://localhost:6100/api/v1/health/sse — SSE publish-failure + buffer state.
    • curl -fsS -H "Authorization: Bearer $JWT" 'http://localhost:6100/api/v1/logging/stats' — last 24h / 7d totals (requires CLINIC_ADMIN+).
    • tail -F logs/api.log — live NestJS log tail (QuietLogger output).
  • Audit Logging — Request Tracing and Compliance — the AuditTrail table and the security-event side of logging; this infrastructure page describes how logs land in Postgres, the audit page describes which events and who reads them.
  • Backend Pool — High Availability and Circuit Breaker — the ddx-web client of /health/live + /health/ready; explains why fast-check is 2s and full-check is 15s and how circuit-breaker state interacts with the health signals.
  • High-Availability Strategy — Database, Vector Store, Object Storage — explains why ddx_api_log is a separate database from ddx_api_main (so logging writes never compete with clinical workload) and how the pre-migration backup script preserves the logging schema.
  • Canonical operational references (not duplicated here): ddx-api/CLAUDE.md §Request Pipeline (interceptor order) and §Module Categories (Infrastructure row); docs/claude-context/CLAUDE_SERVICES.md for the full service inventory.
    Monitoring and Observability — Health, Logging and Jobs — Dudoxx Docs | Dudoxx