synops/docs/infra/observerbarhet.md
vegard b31ee59868 Ytelse: profiler PG-spørringer, optimaliser node_access-oppdatering (oppgave 12.4)
Profilert alle kritiske PG-spørringer med EXPLAIN ANALYZE.
Identifiserte at recompute_access brukte single-column index
(idx_edges_type) med lav selektivitet, og RLS-policyer manglet
composite indexes for effektive oppslag.

Endringer:

Migrasjon 017_query_performance.sql:
- 6 nye composite indexes:
  - idx_edges_target_type (target_id, edge_type) — recompute_access + belongs_to
  - idx_edges_source_type (source_id, edge_type) — alias-oppslag
  - idx_edges_target_memberof (partial, member_of) — team-propagering
  - idx_nodes_created_at_desc — ORDER BY created_at DESC
  - idx_nodes_kind_created — filtrer på kind + sorter
  - idx_na_subject_covering INCLUDE (object_id) — RLS without heap lookup
- Optimalisert recompute_access(): steg 3 og 4 kjøres nå bare
  når det er relevant (EXISTS-sjekk først). For vanlige brukere
  (ikke team) unngår dette to fulle INSERT-SELECT-operasjoner.
- via_edge oppdateres nå korrekt ved access-nivå-endring.

Slow query logging (maskinrommet):
- Forespørsler >200ms logges som WARN med tag slow_request
- PG-spørringer >100ms logges som WARN med tag slow_query
- recompute_access-kall logges med varighet for overvåking
- Nytt pg_stats-felt i /metrics med tabell- og index-statistikk,
  cache hit ratio, og node_access-telling

Dokumentasjon oppdatert i docs/infra/observerbarhet.md.
2026-03-18 11:43:19 +00:00

161 lines
3.7 KiB
Markdown

# Observerbarhet
Maskinrommets observerbarhetslag: strukturert logging, request-metrikker,
jobbkø-dybde og AI-kostnadsovervåking.
## Strukturert logging
Maskinrommet bruker `tracing` med `tracing-subscriber`. Format velges via
miljøvariabel:
| `LOG_FORMAT` | Resultat |
|---|---|
| `json` | JSON-linjer (maskinlesbart, egnet for log-aggregering) |
| *(annet/utelatt)* | Human-readable (standard for utvikling) |
Loggnivå styres via `RUST_LOG` (default: `maskinrommet=info`).
### JSON-format eksempel
```json
{"timestamp":"2026-03-18T12:00:00Z","level":"INFO","fields":{"method":"GET","path":"/health","status":200,"duration_ms":1.2},"target":"maskinrommet::metrics","message":"request"}
```
## Metrikk-endepunkt
`GET /metrics` returnerer JSON med tre seksjoner:
### request_latency
In-memory per-rute statistikk (nullstilles ved restart):
```json
{
"uptime_secs": 3600,
"total_requests": 1234,
"routes": {
"/health": {
"count": 500,
"avg_ms": 1.2,
"min_ms": 0.3,
"max_ms": 15.0,
"p50_ms": 0.8,
"p95_ms": 3.5,
"p99_ms": 12.0
}
}
}
```
Percentilene beregnes fra de siste 1000 forespørslene per rute.
### queue_depth
Sanntidsstatus fra `job_queue`-tabellen:
```json
{
"pending": 3,
"running": 1,
"error": 0,
"retry": 1,
"completed_last_hour": 42
}
```
### ai_cost
Aggregerte AI-kostnader fra `ai_usage_log` for tre tidsperioder
(siste time, 24 timer, 30 dager):
```json
{
"last_hour": {
"requests": 5,
"input_tokens": 12000,
"output_tokens": 3000,
"estimated_cost_usd": 0.08
}
}
```
Kostnadsestimatet er basert på konservative gjennomsnittspriser
($3/MTok input, $15/MTok output).
### pg_stats
PG-ytelsesstatistikk for kjernetabellene (nodes, edges, node_access):
```json
{
"tables": [
{
"table_name": "nodes",
"row_count": 19,
"index_scan_count": 50,
"seq_scan_count": 10,
"index_scan_ratio": 0.83
}
],
"indexes": [
{
"index_name": "idx_edges_target_type",
"table_name": "edges",
"scan_count": 25,
"size_bytes": 16384
}
],
"node_access_count": 4,
"cache_hit_ratio": 0.9995
}
```
`index_scan_ratio` bør være >0.95 for tabeller med >1000 rader.
`cache_hit_ratio` bør være >0.99 — lavere indikerer at PG trenger mer
`shared_buffers`.
## Request-logging middleware
Alle HTTP-forespørsler logges med:
- `method` — HTTP-metode
- `path` — Forespørsels-sti
- `status` — HTTP-statuskode
- `duration_ms` — Total responstid
Forespørsler over 200ms logges med `level=WARN` og tag `slow_request`.
## Slow query logging
PG-spørringer som tar over 100ms logges med `level=WARN` og tag
`slow_query`. Terskelen er definert i `queries.rs::SLOW_QUERY_THRESHOLD_MS`.
Instrumenterte spørringer:
- `query_nodes` — søk og filtrering med RLS
- `query_graph` — rekursiv CTE graf-traversering med RLS
- `recompute_access` — node_access-oppdatering (logges i `pg_writes.rs`)
## pg_stat_statements (valgfritt)
For detaljert per-spørring statistikk, aktiver pg_stat_statements:
1. Legg til i docker-compose.yml for postgres:
`command: postgres -c shared_preload_libraries=pg_stat_statements -c pg_stat_statements.track=all`
2. Restart postgres-containeren
3. Kjør: `CREATE EXTENSION pg_stat_statements;`
4. Se topp-spørringer:
```sql
SELECT query, calls, total_exec_time, mean_exec_time
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 20;
```
## Arkitektur
Metrikker samles i minnet (ingen ekstern avhengighet som Prometheus).
Designvalg:
- **Enkel:** Ingen nye avhengigheter eller ekstern infrastruktur
- **Tilstrekkelig:** Queue depth, AI-kostnad og PG-stats fra PG, latency in-memory
- **Utvidbar:** Kan legge til Prometheus-eksport senere ved behov