docs(infra): shadow-run etap 2 — analiza 165 mismatchy solaria/lustro

Wszystkie mismatche = detection-lag przy planowych power-offach (prom szybszy
o ~9.5 min od TTL eventowego); zero fałszywych prom=down. vps/piha 100% zgodne.
Rekomendacja: GO dla etapu 3 per-node, mapping timestamp(up)->compute_liveness.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
oskar 2026-07-15 14:54:27 +02:00
parent 3755d7d6bb
commit 8fec62d509

View file

@ -0,0 +1,226 @@
# Prometheus cutover — Etap 2: analiza zgodności shadow-run (2026-07-15)
Analiza READ-ONLY logów `SHADOW_LIVENESS_MISMATCH` observera (parallel-run od
2026-07-09, okno wiarygodne od ~2026-07-13 po naprawach event-shippingu PIHA
i zatrutego checkpointu leksykalnego). Zero zmian w kodzie serwisów.
## TL;DR — werdykt
**Zagadka rozwikłana: żaden ze 165 mismatchy nie jest błędem Prometheusa.**
Wszystkie 165 wpisów to **dwa wyłączenia węzłów wieczorem 2026-07-14**
(lustro 21:30 UTC — planowy nocny power-off, solaria 21:34 UTC), zalogowane
w oknie, w którym tor eventowy jeszcze „dożywał" swojego TTL. Wzorzec
`event=fresh prom=down` to **nie** „żywy węzeł, którego Prometheus nie widzi" —
to **martwy węzeł, którego Prometheus wykrył w ≤45 s, a tor eventowy potrzebował
600 s**. Prometheus był w każdym przypadku *szybszy i miał rację*.
- **vps, piha**: 0 mismatchy, 0 próbek `up==0` przez całe 84 h okna
(07-12 → 07-15), 0 przejść liveness po stronie eventowej od ≥ 07-11.
→ **Prometheus w pełni wiarygodny — kandydaci do przełączenia w Etapie 3.**
- **solaria, lustro**: `prom=down` zawsze = węzeł fizycznie wyłączony.
Zero przypadków „prom=down przy realnie żywym węźle". → **NIE dyskwalifikuje
ich z cutoveru**; nocne okna off to normalny stan, który już dziś generuje
`node_offline` (alert-path bez zmian, tylko ~9,5 min wcześniej).
- Kryterium wyjścia Etapu 2 („zero **niewyjaśnionych** rozbieżności") — **spełnione**:
każda rozbieżność sklasyfikowana jako znana różnica semantyk (detection lag
TTL vs scrape), nie bug.
## Metodologia i ograniczenia danych
Źródła (surowe dane w scratchpadzie sesji, komendy odtwarzalne):
1. `docker logs control-plane-observer --since 2026-07-13` na VPS, grep
`SHADOW_LIVENESS_MISMATCH` + `query failed` + `Starting observer loop`.
2. `GET /api/v1/query_range?query=up{job="fleet-node"}&step=30` za 07-12 00:00 →
07-15 12:50 UTC (10 181 próbek na serię; Prometheus działa nieprzerwanie
od 2026-06-30 15:04, RestartCount=0).
3. Syntetyczne eventy przejść observera (`source: "observer"`) z
`/opt/homelab/events/<node>/` na VPS — trwały zapis, pokrywa okres sprzed
dostępnych logów docker.
**Ograniczenie:** kontener observera został odtworzony 2026-07-14 16:30 UTC
(StartedAt; RestartCount=0 — recreate, nie crash), więc logi docker pokrywają
tylko ~20 h (07-14 16:30 → 07-15 12:50). Mismatche z 07-13 (wyłączenia: solaria
19:22, lustro 21:30) przepadły z logami starego kontenera — ale okna te
zrekonstruowano z (2)+(3) i mają identyczny przebieg. Wszystkie wnioski
o vps/piha są dodatkowo podparte pełnymi 84 h historii `up{}` i brakiem
jakichkolwiek przejść liveness w eventach od 07-11.
## A. Rozkład czasowy mismatchy
**165/165 mismatchy leży w jednym zwartym oknie 2026-07-14 21:30:14 → 21:43:52 UTC.**
Zero rozproszonych wpisów w pozostałych ~20 h logów. Rozkład per węzeł:
| węzeł | wzorzec | n | okno (UTC) | last_seen_age |
|---|---|---|---|---|
| lustro | `event=fresh prom=down` | 22 | 21:30:14 → 21:32:39 | 29 s → 174 s (monotonicznie ↑) |
| lustro | `event=stale prom=down` | 61 | 21:32:46 → 21:39:43 | 181 s → 597 s (monotonicznie ↑) |
| solaria | `event=fresh prom=down` | 21 | 21:34:31 → 21:36:50 | 36 s → 175 s (monotonicznie ↑) |
| solaria | `event=stale prom=down` | 61 | 21:36:57 → 21:43:52 | 182 s → 597 s (monotonicznie ↑) |
| piha / vps | — | 0 | — | — |
Kadencja wpisów co ~6,9 s = jeden na cykl observera (5 s pętli + ~2 s
przetwarzania). Sekwencja per węzeł jest podręcznikowa: ostatni event węzła →
age rośnie liniowo → przy 180 s tier `fresh→stale` → przy 600 s tier
`stale→dead``event=dead prom=down` = zgoda → **mismatche ustają dokładnie
na granicy TTL-dead**. Okno mismatchy per wyłączenie ≈ 600 s (lag scrape
~1545 s) ≈ 9,5 min → ~82 wpisy. Bilans: 83 (lustro) + 82 (solaria) = 165. ✓
**Kluczowa obserwacja:** `last_seen_age` rośnie monotonicznie od pierwszego
wpisu. Węzeł **nie wysyłał** świeżych eventów w trakcie okna — jego *ostatni*
event był po prostu młodszy niż 180 s. „fresh" opisuje wiek ostatniego eventu,
nie bieżącą aktywność.
## B. Korelacje
**Pora nocna / harmonogram — TAK, to jest cała historia.** Pełna historia
`up{}` 07-12 → 07-15:
| węzeł | okna `up==0` (UTC) | charakter |
|---|---|---|
| lustro | 07-12 21:30→04:31 · 07-13 21:30→04:30 · 07-14 21:30→04:30 (każde równo 7,00 h) | **idealnie regularny nocny power-off 21:30 UTC = 23:30 lokalnie; wstaje 04:30 UTC = 06:30** |
| solaria | 07-12 00:00→16:58 · 07-12 22:28→17:11 · 07-13 19:22→12:46 · 07-14 21:34→07-15 12:20 | nieregularne, wielogodzinne — węzeł włączany „do pracy", off przez większość doby |
| piha | brak (100% up, 84,8 h) | always-on |
| vps | brak (100% up, 84,8 h) | always-on |
**Restarty Prometheusa/observera — NIE.** Prometheus up od 2026-06-30 bez
restartu. Observer odtworzony 07-14 16:30 — 5 h *przed* oknem mismatchy;
w logach zero `shadow-read: Prometheus query failed` (observer→9090 stabilne
przez całe 20 h).
**Solaria ↔ lustro nawzajem — NIE (przyczyny niezależne).** Onset 4 min osobno
(21:30:00 ostro co noc dla lustro — timer/smart-plug; solaria zmiennie: 19:22,
21:34, 22:28 w różne dni). Wspólna przyczyna infrastrukturalna wykluczona:
piha i vps scrape'owane bez zakłóceń przez te same okna, po tym samym
Tailscale, przez ten sam Prometheus.
**Krzyżowa weryfikacja obu torów** (eventy przejść vs `up{}`): każde
`node_stale`/`node_offline` w eventach = początek okna `up==0` + 2/9,5 min;
każde `node_online` = koniec okna `up==0` ± kilkanaście sekund. Przykład
(lustro 07-14): prom down 21:30, `node_stale` 21:32:46, `node_offline`
21:39:50; rano prom up 04:31, `node_online` 04:31:46. Oba tory opisują tę samą
rzeczywistość — różni je wyłącznie opóźnienie detekcji zgonu.
**Power-on nie generuje mismatchy** — w 20 h logów są dwa powroty węzłów
(lustro 07-15 04:31, solaria 07-15 12:21) i **zero** wpisów `event=dead
prom=up`. Po bootzie node-agent wysyła pierwszy event w ~tej samej chwili,
w której Prometheus zalicza pierwszy scrape — oba tory flipują w obrębie
jednego cyklu observera.
## C. Interpretacja `event=fresh prom=down`
Hipotezy z zadania wobec danych:
1. **node_exporter pada niezależnie od hosta — OBALONA.** Okna `up==0`
długie (719 h), zwarte, o ostrych krawędziach, bez flappingu; dla lustro
co do minuty zgodne z harmonogramem 21:30→04:30. Crash-loop exportera
dawałby krótkie, poszarpane dziury w losowych porach. Dodatkowo eventy
`service_healthy-node-exporter` płyną z lustro do ostatniego cyklu przed
wyłączeniem.
2. **Flaky scrape po Tailscale — OBALONA.** Brak pojedynczych/krótkich dropów
`up` poza oknami off (step 30 s wykryłby ≥1-minutowe); piha po tym samym
mesh ma 100% czystych scrape'ów; zero timeoutów observer→Prometheus.
3. **Węzeł w trakcie wyłączania (event jeszcze „fresh" z natury TTL) —
POTWIERDZONA, z doprecyzowaniem.** To nie „bufor eventów" — po prostu
definicja `fresh` = ostatni event < 180 s temu. Po fizycznym wyłączeniu
węzła jego ostatni heartbeat starzeje się przez 180 s jako „fresh"
i przez kolejne 420 s jako „stale", podczas gdy Prometheus widzi `up==0`
już przy pierwszym nieudanym scrape (≤1545 s). Mismatch = czysta
**asymetria opóźnień detekcji**, przewidziana w recon (E.3/E.4) jako znana
klasa rozbieżności semantyk.
Wniosek: w całym analizowanym oknie **nie wystąpił ani jeden przypadek
fałszywego `prom=down`** (żywy węzeł, którego Prometheus nie scrape'uje).
Kierunek błędu jest odwrotny do obawy z zadania: to tor eventowy przez
~9,5 min pokazywał „żywy/stale" dla węzła realnie martwego.
## D. Implikacje dla Etapu 3 (`PROM_LIVENESS_NODES`)
### vps, piha — GO
84 h nieprzerwanego `up==1`, zero mismatchy, zero przejść liveness od ≥ 07-11.
Oba źródła zgodne w 100%. Prometheus + istniejący alert `NodeDown`
(`up{node=~"vps|piha"}==0 for 5m`) dają im pełne pokrycie. **Kandydaci do
przełączenia bez zastrzeżeń.**
### solaria, lustro — GO, `prom=down` NIE dyskwalifikuje
Dane pokazują, że `up==0` dla tych węzłów zawsze znaczyło „węzeł naprawdę
wyłączony" — Prometheus nie wyprodukował ani jednego fałszywego down. Twardy
cutover klasyfikacji na `up` jest więc **bezpieczny i poprawia stan faktyczny**:
panel pokaże offline ~9,5 min wcześniej niż dziś.
Skutek uboczny do zaakceptowania świadomie: syntetyczne `node_stale`/
`node_offline` (→ alert_only supervisora) będą się emitować przy każdym nocnym
wyłączeniu **wcześniej, ale nie liczniej** — te eventy już dziś powstają co noc
(21:32/21:39 dla lustro, każdorazowo dla solaria). Cutover nie zwiększa wolumenu
alertów. Docelowe wyciszenie planowych okien off to wątek anomaly-detection
z backlogu (`docs/backlog.md:390-406`) — **niezależny od cutoveru i nieblokujący**;
`NodeDown` dla solaria/lustro słusznie pozostaje wyłączony.
### Rekomendowany mapping (potwierdzenie rekomendacji z recon F/Etap 2)
`prom-last_seen = timestamp(up)` wpuszczone w istniejące `compute_liveness`
z obecnymi TTL-ami — a nie surowe `up==0 → dead`. Uzasadnienie z danych:
- zachowuje tier `stale` i histerezę na krótkie dziury scrape (w oknie ich nie
było, ale 30-sekundowa rozdzielczość nie wyklucza pojedynczych timeoutów),
- odporne na restart samego Prometheusa (brak serii ≠ węzeł martwy → UNKNOWN
→ fail-open na tor eventowy, zgodnie z planem Etapu 3),
- przejścia liczone tym samym kodem co dziś → `_emit_node_transition`
i tor alertowy supervisora bez żadnych zmian.
### Kolejność włączania
Dane nie wskazują przeciwwskazań dla żadnego z 4 węzłów; kolejność z recon
(najpierw `solaria,lustro`, po tygodniu `vps,piha`) pozostaje rozsądna jako
minimalizacja blast-radius (brak NodeDown = pomyłka nie budzi nikogo w nocy).
Alternatywnie równie dobrze uzasadnione jest odwrotnie (vps/piha mają
mocniejszy dowód zgodności). **Rekomendacja: trzymać się kolejności z recon.**
### Warunki towarzyszące (z recon, potwierdzone jako nadal aktualne)
1. **Watchdog na sam Prometheus** (recon D.2 pkt 5) — po cutoverze `up{}` staje
się źródłem prawdy dla 4 węzłów; obecnie nikt nie alarmuje o jego śmierci.
Zrobić razem z Etapem 3.
2. **Fail-open na tor eventowy** przy braku odpowiedzi Prometheusa > TTL-fresh —
jak w planie Etapu 3; w 20 h obserwacji zero błędów zapytań, ale
`mem_limit 512m` + `oom_score_adj 200` czynią go ubijalnym przed control-plane.
3. **chelsty-infra pozostaje na torze eventowym** (brak serii `up`) — hybryda
per-node obowiązkowa, bez zmian względem recon.
### Braki dowodowe / follow-up przed „GO" formalnym
- Okno twardych danych log-level to ~20 h (recreate kontenera 07-14 16:30
zjadł wcześniejsze logi docker). Kryterium recon mówi o ≥ 7 dniach. Wnioski
są mocno podparte pośrednio (84 h `up{}` + eventy przejść od 07-11), ale
formalnie warto: **(a)** pociągnąć shadow-run do ~2026-07-20 i powtórzyć
zliczenie mismatchy (oczekiwane: wyłącznie okna power-off solaria/lustro,
~82/wyłączenie, zero na vps/piha), **(b)** rozważyć trwałość logów observera
(logging driver z rotacją / plik w `/opt/homelab/logs/`), żeby recreate
kontenera nie kasował materiału dowodowego Etapu 2.
- Scenariusz z recon Etap 1 „restart node-agenta przy żywym węźle"
(`event=dead prom=up` — zamierzona zmiana werdyktu po cutoverze) **nie
wystąpił naturalnie** w analizowanym oknie — jeśli ma być przetestowany,
wymaga kontrolowanego stopu node-agenta na solaria (czynność operatorska,
poza tym taskiem).
## Załącznik: pełna oś czasu przejść (tor eventowy, z eventów `source=observer`)
```
solaria:
07-11 22:36 stale → 22:43 dead | 07-12 16:58 online
07-12 22:30 stale → 22:37 dead | 07-13 17:11 online
07-13 19:24 stale → 19:31 dead | 07-14 12:46 online
07-14 21:36 stale → 21:43 dead | 07-15 12:20 online ← okno 165 mismatchy
lustro:
07-11 21:32 stale → 21:39 dead | 07-12 04:31 online
07-12 21:32 stale → 21:39 dead | 07-13 04:31 online
07-13 21:32 stale → 21:39 dead | 07-14 04:31 online
07-14 21:32 stale → 21:39 dead | 07-15 04:30 online ← okno 165 mismatchy
piha, vps: brak przejść (ciągłe fresh)
```
Każdy wiersz `stale→dead` odpowiada 1:1 początkowi okna `up==0` w Prometheusie
(przesunięcie: prom leaduje o ~2 min względem `stale` i ~9,5 min względem
`dead`); każdy `online` = koniec okna `up==0` ± kilkanaście sekund.