--- name: mvp-diagnostics-and-logging description: >- Load when you need to observe or measure MotoVaultPro instead of guessing - querying logs in Grafana/Loki, writing LogQL, tracing a request by requestId/X-Request-Id, checking /health or /api/health, cache inspection via redis-cli, PostgreSQL activity, or running the shipped diagnostic scripts (check-numeric-coercion.sh, check-route-auth.sh, local-gate.sh). This is the HOW-to-observe toolbox - load it when mvp-debugging-playbook (the symptom-triage hub) or a task needs measurements. Distinguishing triggers - "logs not appearing", Grafana unreachable, Loki curl fails, no logs from a container, alert firing, request timing, "slow requests", "5xx spike". --- # MotoVaultPro Diagnostics and Logging Measuring instead of eyeballing: where logs live, how to query them, how to check health and state, and three shipped read-only diagnostic scripts. ## When to use / When NOT to use Use this skill when you need to OBSERVE the system: query logs, trace a request, verify health, measure latency, inspect cache or database activity, or run the pre-push diagnostic scripts. Do NOT use this skill for: - Symptom-to-root-cause triage of known failure modes: `mvp-debugging-playbook` - Deploying, rolling back, blue-green mechanics, backups: `mvp-run-and-operate` - What counts as test evidence / definition of done: `mvp-validation-and-qa` - Historical incidents and settled dead ends: `mvp-failure-archaeology` - Getting a working local environment at all: `mvp-build-and-env` - Changing log config or adding config axes: `mvp-config-and-secrets` Environment reality (2026-07-07): development is done by AI sessions in this repo; end-to-end verification happens on STAGING via the PR pipeline. There is no fully working local dev loop, and CI gates nothing beyond build + boot (canonical statement: `mvp-validation-and-qa` section 1). The scripts in this skill exist because of that gap. ## 1. Logging topology One pipeline, file-provisioned end to end. Frontend is the exception: its logs go to the browser console ONLY (`frontend/src/utils/logger.ts`) and never reach Loki. ``` mvp-traefik mvp-frontend mvp-backend mvp-ocr mvp-postgres mvp-redis | | | | | | +------------+------+------+-----------+----------+------------+ | (frontend: container v stdout only; app logs Docker json-file driver (max-size 10m, stay in the browser) max-file 3 - set on every service in docker-compose.yml) | v mvp-alloy (config/alloy/config.alloy) - discovers containers via /var/run/docker.sock - labels: container = container name, service = compose service | v mvp-loki (config/loki/config.yml) - TSDB schema v13, filesystem storage - retention_period: 720h (30 days) - auth disabled; distroless image, healthcheck disabled | v mvp-grafana (Grafana 12.4.0) - https://logs.motovaultpro.com (prod) - https://logs.staging.motovaultpro.com (staging) - 4 provisioned dashboards + 5 provisioned alert rules ``` Grafana access: the Traefik router applies `grafana-ipwhitelist@file` (`config/traefik/dynamic/grafana.yml` and `dynamic-staging/grafana.yml`), which allows only RFC1918 source ranges (10/8, 172.16/12, 192.168/16). Grafana is unreachable from the public internet by design - reach it from inside the network (the servers themselves, or VPN). Admin password comes from `GRAFANA_ADMIN_PASSWORD` (default `admin`). Container name matrix (label `container` in LogQL): | Service | Dev | Staging | Production | |----------|----------------|------------------------|---------------------------------| | backend | `mvp-backend` | `mvp-backend-staging` | `mvp-backend-blue` / `-green` | | frontend | `mvp-frontend` | `mvp-frontend-staging` | `mvp-frontend-blue` / `-green` | | traefik | `mvp-traefik` | `mvp-traefik-staging` | `mvp-traefik` | | ocr | `mvp-ocr` | `mvp-ocr-staging` | `mvp-ocr` | | postgres | `mvp-postgres` | `mvp-postgres-staging` | `mvp-postgres` | | redis | `mvp-redis` | `mvp-redis-staging` | `mvp-redis` | | loki/alloy/grafana | `mvp-loki` / `mvp-alloy` / `mvp-grafana` in ALL environments (not renamed by overlays) |||| KNOWN GAP (verified 2026-07-07): the provisioned dashboards and the backend-related alert rules select `{container=~"mvp-backend(-staging)?"}`. Loki regex matchers are fully anchored, so this does NOT match the production blue-green names `mvp-backend-blue`/`-green`. On production, backend panels are blind and the "Container Silence: mvp-backend" alert (noDataState: Alerting) fires from no-data. Use `{container=~"mvp-backend-(blue|green)"}` for prod queries. ## 2. LogQL cookbook Field names below are verified against `backend/src/core/plugins/logging.plugin.ts`: every completed request logs `msg="Request processed"` with `requestId`, `method`, `path`, `status`, `duration` (ms, integer), `ip`; Pino adds `level` and `time`. Substitute the right container name from the matrix above. Request logs (the workhorse): ```logql {container="mvp-backend-staging"} | json | msg="Request processed" ``` Error sweep across all containers: ```logql {container=~"mvp-.*"} | json | level="error" ``` Errors per container over time: ```logql sum by (container) (count_over_time({container=~"mvp-.*"} | json | level="error" [5m])) ``` PostgreSQL errors (postgres logs are not JSON - use line filter): ```logql {container="mvp-postgres"} |~ "ERROR|FATAL|PANIC" ``` OCR (Python) errors: ```logql {container=~"mvp-ocr(-staging)?"} |~ "ERROR|Exception|Traceback" ``` Slow requests, p95 latency. The `| __error__=""` after `unwrap` is REQUIRED - it drops lines where `duration` failed to parse; without it the quantile returns errors or garbage: ```logql quantile_over_time(0.95, {container="mvp-backend-staging"} | json | msg="Request processed" | unwrap duration | __error__="" [5m]) ``` Individual requests slower than 500 ms: ```logql {container="mvp-backend-staging"} | json | msg="Request processed" | duration > 500 ``` All 5xx responses: ```logql {container="mvp-backend-staging"} | json | msg="Request processed" | status >= 500 ``` Correlate one request across services. The backend takes `X-Request-Id` from the incoming request or generates a UUID; Traefik access logs (JSON) keep the header. The backend does not echo it in the response, so find the ID in the request log first, then sweep: ```logql {container=~"mvp-.*"} |= "550e8400-e29b-41d4-a716-446655440000" ``` To force a known ID end-to-end, send one (CORS-allowed header): ```bash curl -H "X-Request-Id: trace-$(date +%s)" https://staging.motovaultpro.com/api/health ``` ### Provisioned alerts Defined in `config/grafana/alerting/alert-rules.yml`; evaluated every 1m, must hold for 5m. Contact point is a webhook placeholder - alerts are visible in the Grafana UI but notify nobody (2026-07-07). | Alert | Severity | Condition | |-------|----------|-----------| | Error Rate Spike | critical | error-level logs > 5% of all logs over 5m | | Container Silence: mvp-backend / mvp-postgres / mvp-redis | warning | no logs for 5m (noDataState: Alerting) | | 5xx Response Spike | critical | > 10 HTTP 5xx from backend in 5m | ### Log-level control is deploy-time One `LOG_LEVEL` fans out to all containers via `scripts/ci/generate-log-config.sh `, whose output the CI workflows append to `.env` on the server (NOT `.env.logging` - docs/LOGGING.md says `.env.logging`; the code in `.gitea/workflows/staging.yaml` appends to `.env`, and code wins). It sets `BACKEND_LOG_LEVEL`, `TRAEFIK_LOG_LEVEL`, `POSTGRES_LOG_STATEMENT`, `POSTGRES_LOG_MIN_DURATION`, `REDIS_LOGLEVEL`. Staging runs DEBUG, prod runs INFO. Caveat: the postgres leg of this fan-out is dead - the `POSTGRES_LOG_*` variables are set on the container but never applied (see the known gap under "PostgreSQL activity" in section 4); the backend, traefik, and redis legs are wired. There is no runtime toggle: changing verbosity means redeploying. Never hand-edit `.env` on a server - the next deploy's rsync/regeneration reverts it (owner non-negotiable). ## 3. Health and state checks ### /health vs /api/health Both defined in `backend/src/app.ts`, both unauthenticated, both return `status: "healthy"` plus a `features` array (currently 20 entries in code). - `GET /health` (port 3001, in-container) - used by the Docker healthcheck and CI's in-container curl. No `/api` prefix; not routed by Traefik. - `GET /api/health` - routed through Traefik; adds `scope: "api"`. This is the external verification target. The CI contract (`.gitea/workflows/staging.yaml`, REQUIRED_FEATURES) checks that 13 specific features are present in the array: admin, auth, onboarding, vehicles, documents, fuel-logs, stations, maintenance, platform, notifications, user-profile, user-preferences, user-export. The endpoint returns more than 13; the contract is a subset check. If you add a feature capsule, adding it to the app.ts arrays is cosmetic; adding it to REQUIRED_FEATURES makes it deploy-gating. ```bash curl -s https://staging.motovaultpro.com/api/health | jq '.status, (.features | length)' ``` ### Container state per environment The `-f` stack matters - a bare `docker compose ps` on staging/prod uses only the base file and shows wrong/partial state: ```bash # Dev (local machine) docker compose ps make health-check-all # ps table + Traefik service discovery counts # Staging (on mvp-staging, /opt/motovaultpro) docker compose -f docker-compose.yml -f docker-compose.staging.yml ps # Production (on prod server, /opt/motovaultpro) docker compose -f docker-compose.yml -f docker-compose.blue-green.yml -f docker-compose.prod.yml ps ``` ### config/deployment/state.json - and why it lies mid-deploy On the prod server, `config/deployment/state.json` records `active_stack` (blue/green), last deployment, and per-stack health. Read it with `cat /opt/motovaultpro/config/deployment/state.json | jq .` It lies in two windows: 1. Every deploy rsyncs `config/` with `--delete`, overwriting state.json with the repo default (`active_stack: blue`, all-null history). The workflow reads the real state BEFORE the rsync and re-stamps it at the end - but any inspection between rsync and the final stamp shows the repo default, not reality. 2. Traefik weights in `config/traefik/dynamic/blue-green.yml` are the actual routing truth; state.json is a record of intent. When in doubt, read the weights file. ### When the log pipeline itself is broken 1. `docker logs mvp-alloy` (same name in every environment) - Alloy is the collector; discovery or push errors appear here. 2. You CANNOT `curl` Loki from the host or exec into it: Loki 3.x is a distroless image (no shell, no wget/curl inside; the compose healthcheck is explicitly disabled for this reason - see the comment in docker-compose.yml). Verify Loki through Grafana: Connections > Data sources > Loki > Test, or from any container on the `backend` network, e.g. `docker exec mvp-backend-staging wget -qO- http://mvp-loki:3100/ready`. 3. `docker logs mvp-grafana` for provisioning errors (bad dashboard JSON or alert YAML shows up here at startup). 4. Docker json-file logs still exist even if the pipeline is down: `docker logs --since 10m mvp-backend-staging`. ## 4. Measuring instead of eyeballing ### Request timings Timings live in the `duration` field (ms) of `msg="Request processed"` lines - see the quantile queries above. The API Performance dashboard (p50/p95/p99, slowest endpoints by avg duration) is provisioned from `config/grafana/dashboards/api-performance.json`. For a one-off check without Grafana: ```bash docker logs --since 5m mvp-backend-staging 2>&1 | grep '"msg":"Request processed"' | awk -F'"duration":' '{split($2,a,","); gsub(/[^0-9]/,"",a[1]); print a[1]}' | sort -n | tail -5 ``` ### Cache behavior (Redis) Backend uses DB 0 with key prefix `mvp:` (`backend/src/core/config/redis.ts`; DB from `config/app/*.yml` `redis.db: 0`). The OCR service uses DB 1 (`REDIS_DB: 1` in docker-compose.yml) for job state. Locks use `mvp:lock:`. ```bash # Staging names shown; drop -staging for dev/prod docker exec mvp-redis-staging redis-cli -n 0 --scan --pattern 'mvp:*' | head -50 docker exec mvp-redis-staging redis-cli -n 0 TTL 'mvp:some-key' docker exec mvp-redis-staging redis-cli -n 1 --scan --pattern '*' | head # OCR jobs docker exec mvp-redis-staging redis-cli INFO keyspace ``` Cache reads swallow errors and return null (cache failure never breaks a request), so a dead Redis looks like a 100% miss rate, not errors. Check `docker logs mvp-redis-staging` and hit rates via `INFO stats`. ### PostgreSQL activity Dev shell: `make db-shell-app` (wraps `docker compose exec mvp-postgres psql -U postgres -d motovaultpro`). Staging/prod equivalent: ```bash docker exec -it mvp-postgres-staging psql -U postgres -d motovaultpro ``` Useful read-only checks inside psql: ```sql SELECT pid, state, now() - query_start AS age, left(query, 80) FROM pg_stat_activity WHERE state <> 'idle' ORDER BY age DESC; SELECT relname, n_live_tup FROM pg_stat_user_tables ORDER BY n_live_tup DESC LIMIT 15; ``` KNOWN GAP: the `POSTGRES_LOG_STATEMENT` / `POSTGRES_LOG_MIN_DURATION_STATEMENT` values set in compose (`docker-compose.yml:245,247`) are INERT - they are plain environment variables that the official postgres image does not read, and nothing in the repo applies them (no `command: postgres -c log_statement=...`, no custom postgresql.conf, no initdb script). Postgres runs with defaults (`log_statement=none`, `log_min_duration_statement=-1`) at every LOG_LEVEL, so per-statement and `duration:` lines never reach Loki; a `{container="mvp-postgres-staging"} |~ "duration:"` hunt finds nothing. Until compose passes the values via `command: postgres -c ...`, slow-query hunting must use `pg_stat_activity` (above) instead. ### End-to-end request trace, step by step 1. Send the request with a known `X-Request-Id` (see cookbook above). 2. Traefik: `{container="mvp-traefik-staging"} | json |= ""` - confirms arrival, router matched, status returned to client. 3. Backend: `{container="mvp-backend-staging"} |= ""` - all application log lines plus the final `Request processed` line with duration. 4. If OCR involved: `{container="mvp-ocr-staging"} |= ""`. 5. Postgres/Redis logs are not request-tagged; correlate by timestamp. ## 5. Shipped diagnostic scripts All in `.claude/skills/mvp-diagnostics-and-logging/scripts/`, all executable, all safe read-only checks (no network, no writes outside temp logs), portable bash (macOS bash 3.2). Run them from anywhere inside the repo. Each was run against the repo on 2026-07-07. ### check-numeric-coercion.sh - the #1 recurring bug class node-postgres returns NUMERIC/DECIMAL columns as STRINGS. `backend/src/core/config/database.ts` overrides only the DATE parser, so every repository mapper must coerce manually with `Number()`/`parseFloat()`. Missed coercion caused issues #239, #241, #244 (symptoms: MPG shows NaN, string concatenation instead of addition, sort by cost is alphabetical). ```bash ./.claude/skills/mvp-diagnostics-and-logging/scripts/check-numeric-coercion.sh ``` What it does: extracts every NUMERIC/DECIMAL column name from all migration SQL (column defs, ADD COLUMN, ALTER COLUMN TYPE), then (a) flags any `row.` read in a `*.repository.ts` file whose line lacks `Number(`/`parseFloat(`, and (b) flags raw-row returns (`return res.rows...`) in features whose migrations define numeric columns - the exact shape of bug #244, which bypassed the mapper entirely. Interpretation: exit 0 = clean. Exit 1 = each SUSPECT line needs coercion (`row.x != null ? parseFloat(row.x) : null` is the house pattern) - or is a false positive if coercion happens on another line or in the service layer; read before fixing. Run after ANY repository or migration change that touches numeric columns. ### check-route-auth.sh - unlisted-public routes There is no global auth hook; every route opts in via `preHandler: [fastify.authenticate]` (or `requireAdmin`/`requireTier`, or the common alias `const requireAuth = fastify.authenticate.bind(fastify)`). A forgotten preHandler ships a public endpoint silently - pre-launch, this is a RULE 0 severity gap. ```bash ./.claude/skills/mvp-diagnostics-and-logging/scripts/check-route-auth.sh ``` What it does: parses every registration block in `backend/src/features/*/api/*.routes.ts` (199 blocks as of 2026-07-07) and prints any block containing no recognized guard. Known-intentional public routes are allowlisted in the script and printed as OK: `/webhooks/stripe`, `/webhooks/resend/inbound` (provider signature auth), `/auth/signup`, `/auth/resend-verification-public` (pre-auth flows). Interpretation: exit 0 = only allowlisted routes are public AMONG the `features/*/api` route files the script scans. Routes registered in core code are OUT OF SCOPE and pass silently - including the intentionally public `GET /api/config/feature-tiers` (`backend/src/core/config/config.routes.ts`, no preHandler) and the `app.ts` registrations (`/health`, `/api/health`, `/auth/verify`); the script's header comment carries the canonical intentional-public list covering both scopes. A future unguarded route added outside `features/*/api/` would also pass silently - exit 0 is not a whole-backend guarantee. Exit 1 = an UNGUARDED route: either add a guard or, if genuinely public, add it to KNOWN_PUBLIC in the script with a justification comment. Heuristic caveats: a guard aliased under a new name reads as UNGUARDED (safe direction); a comment containing a guard word inside a block could mask a gap (verify by reading the code). Run after adding or reshaping any route file. ### local-gate.sh - the pre-push gate CI does not provide CI runs zero tests and zero lint. This script is the substitute: ```bash ./.claude/skills/mvp-diagnostics-and-logging/scripts/local-gate.sh ``` Runs, with a PASS/FAIL table and per-step logs in `$TMPDIR`: backend lint, backend type-check, backend UNIT tests (`--testPathPattern='(tests/unit|src/core)' --testPathIgnorePatterns=integration --forceExit`), frontend lint, frontend type-check. Requires `npm install` in `backend/` and `frontend/` first. Deliberate exclusions: backend integration tests need a live database and some DROP TABLE CASCADE (owner non-negotiable: no destructive DB operations without a fresh backup - never point them at a shared DB casually); the audit-log `__tests__` also require a live database and are excluded by pattern; frontend jest is broken outside the container (2026-07-07). `--forceExit` is required because open pg/redis handles otherwise hang jest. Interpretation: all PASS = safe to push (integration behavior still unverified until staging). Any FAIL = fix first; CI will not catch it. KNOWN STATE (2026-07-07): backend unit tests FAIL on main - 12 of 22 suites have pre-existing ts-jest compile errors (stale test mocks vs current types, e.g. `new AuthService(...)` missing the termsData argument) plus 2 failing assertions. This is untriaged rot from CI running nothing; treat a FAIL here as "no worse than main" only after diffing against a main-branch run, and see `mvp-validation-and-qa` for the evidence bar. ## Provenance and maintenance Authored 2026-07-07 by direct inspection of the repo (all commands, paths, field names, and line-anchored claims verified against code; where docs/LOGGING.md disagrees with code - `.env.logging` vs `.env` - code wins). Volatile facts and re-verification commands: | Fact (as of 2026-07-07) | Re-verify with | |---|---| | Request log fields (requestId/method/path/status/duration/ip) | `grep -A8 "Request processed" backend/src/core/plugins/logging.plugin.ts` | | Loki 30-day retention, TSDB v13 | `grep -E "retention_period\|schema:" config/loki/config.yml` | | Alloy labels container/service | `grep target_label config/alloy/config.alloy` | | json-file 10m x 3 on all services | `grep -c "max-size" docker-compose.yml` | | Grafana RFC1918 whitelist | `cat config/traefik/dynamic/grafana.yml config/traefik/dynamic-staging/grafana.yml` | | Alert rules (5%/5m, silence, 5xx>10) | `grep -E "title\|for:\|noDataState" config/grafana/alerting/alert-rules.yml` | | Dashboard/alert regex missing prod blue-green | `grep -c "mvp-backend(-staging)?" config/grafana/dashboards/*.json config/grafana/alerting/alert-rules.yml` vs `grep container_name docker-compose.blue-green.yml` | | 13-feature CI health contract | `grep REQUIRED_FEATURES .gitea/workflows/staging.yaml` | | /health features array (20 entries) | `grep -n "features:" backend/src/app.ts` (read the two arrays) | | Log config appended to .env | `grep -n "generate-log-config" .gitea/workflows/*.yaml` | | Redis DB 0 backend / DB 1 OCR, prefix mvp: | `grep "db:" config/app/*.yml; grep REDIS_DB docker-compose.yml; grep "prefix = " backend/src/core/config/redis.ts` | | Known-public routes allowlist | `./.claude/skills/mvp-diagnostics-and-logging/scripts/check-route-auth.sh` | | Numeric coercion clean state | `./.claude/skills/mvp-diagnostics-and-logging/scripts/check-numeric-coercion.sh` | | Backend unit tests failing on main | `cd backend && npm test -- --testPathPattern='tests/unit' --forceExit` | | Container names per env | `grep container_name docker-compose*.yml` |