homelab-codex-ws/docs/infra/prometheus-shadow-etap2-analiza-2026-07-15.md
oskar 8fec62d509 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>
2026-07-15 14:54:27 +02:00

12 KiB
Raw Permalink Blame History

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→deadevent=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 są 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.