motovaultpro/.claude/skills/mvp-diagnostics-and-logging/SKILL.md

---
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 <DEBUG|INFO|WARN|ERROR>`, 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 |= "<id>"` - confirms
   arrival, router matched, status returned to client.
3. Backend: `{container="mvp-backend-staging"} |= "<id>"` - all application
   log lines plus the final `Request processed` line with duration.
4. If OCR involved: `{container="mvp-ocr-staging"} |= "<id>"`.
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.<col>` 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` |