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.
161 lines
3.7 KiB
Markdown
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
|