homelab-codex-ws/docs/sessions/2026-08-06.md
oskar f6fcf6b97a docs: session 2026-08-06 — weryfikacja safe-cleanup na LUSTRO + pierwszy cykl HITL
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-06 13:16:26 +02:00

14 KiB
Raw Permalink Blame History

okf type visibility status updated links
0.1 session-log private active 2026-08-06

Session log 2026-08-06

Session 13:20

Produkcyjna weryfikacja pierwszego cyklu safe-cleanup na LUSTRO (R1/R2/R3, deploy 2026-08-05) oraz pierwszy pełny cykl HITL: approval → dispatch → wykonanie na nodzie → action_resultcompleted. Sesja supervised, checkpointy zatwierdzane przez operatora, approvale wykonywane wyłącznie przez operatora. Incydent źródłowy: docs/incidents/2026-07-30-ollama-solaria-vanish.md.

Commits

Ta sesja nie wprowadziła żadnych commitów poza niniejszym logiem — zero zmian w kodzie i konfiguracji repo. Cała praca to recon read-only + kontrolowane zapisy runtime na LUSTRO i VPS (kanarki testowe, plik akcji), wszystkie sprzątnięte lub udokumentowane niżej.

Poprzedni log sesji: 67aa092 docs: session 2026-08-05 22:47 — potwierdzony na origin/master (ahead/behind 0/0) na starcie sesji.

Files changed

Brak — poza tym plikiem.


KROK 1 — safe-cleanup na LUSTRO: obie gałęzie potwierdzone produkcyjnie

Stan wyjściowy

Marker /opt/homelab/state/last-docker-cleanup = 1785925612 (2026-08-05 12:26:52 CEST), sprzed deployu (obraz node-agenta utworzony 22:42:05 CEST). Bramka _cleanup_rate_ok() (CLEANUP_INTERVAL_SECS = 86_400) trzymała pierwszy cykl nowego kodu do 12:26:52 dnia 2026-08-06. Brak linii cleanup w logach do tego momentu był więc zachowaniem poprawnym, nie awarią.

Kod w runtime zweryfikowany: md5(/app/src/node_agent.py) == md5(repo HEAD) = c9ac64e10b42b3e0ed9e4c168579bfaa, brak wykonywalnego containers.prune(), NODE_TYPE=sd_card.

Pułapka interpretacyjna: logi kontenera node-agent są w UTC, host w CEST. Pozorna 6-godzinna dziura w logach to nocny halt (root cron 30 23 * * * /usr/sbin/halt, boot 06:30) — LUSTRO ma duty cycle jak SOLARIA, zgodnie z inventory/topology.yaml (duty_cycle: nightly).

Test w oknie prune

Do okna przygotowano trzy kontenery exited pokrywające obie gałęzie filtra:

Kontener Polityka / label Oczekiwane Wynik
prune-disposable restart=no, brak compose usunięty usunięty
prune-canary restart=unless-stopped, brak compose zachowany przeżył
node-exporter (realny serwis) restart=always, brak compose zachowany przeżył

Log z okna (12:27:49 CEST / 10:27:49 UTC):

INFO    - Pruned dangling images (0 MB reclaimed)
WARNING - Removed 1 disposable stopped container(s): prune-disposable (kept 2 managed)

Marker zaktualizowany na 1786012069. kept 2 = prune-canary + node-exporter. Wszystkie kontenery produkcyjne nietknięte.

Werdykt: obie gałęzie filtra działają na produkcji — gałąź ochronna (kontener zatrzymany przez operatora z polityką restartu przeżywa prune; dokładny scenariusz incydentu ollamy) oraz gałąź usuwania (filtr nie jest no-opem, faktycznie kasuje jednorazowe resztki).

Korekta wniosku z 2026-08-05

Wczorajszy test kanarka na SOLARII (przeżył 151 s) nie dowodził działania filtra — SOLARIA ma NODE_TYPE=lte_node (mitygacja M1), gdzie run_safe_cleanup() kończy się return przed jakimkolwiek prune. Ten test potwierdził M1, nie R1. Dowód dla R1 powstał dopiero dziś na LUSTRO.

Stan cleanupu na flocie

Node NODE_TYPE Cleanup
PIHA sd_card działa (2026-08-05 16:27 CEST: kept 0 managed)
LUSTRO sd_card działa (2026-08-06 12:27:49, jw.)
SOLARIA lte_node (M1) wyłączony w całości, brak markera
VPS lte_node (M1) wyłączony w całości, brak markera

M1 nadal zdjęte do zrobienia na SOLARII i VPS — do tego czasu te nody nie sprzątają Dockera wcale.


KROK 2 — dlaczego crash-loop watchtowera nie generował akcji

Eventy płynęły poprawnie: evt-lustro-<ts>-containers_not_running-watchtower.json co ~60 s, 11 317 plików w events/lustro/ na VPS (node-agent rsyncuje z --remove-source-files, stąd pusty katalog lokalny). To nie był problem transportu ani emisji.

Przyczyna: supervisor.reconcile() iteruje wyłącznie po desired_state["services"] ładowanym z hosts/<node>/services.yaml (supervisor.py:380). hosts/lustro/services.yaml deklaruje node-agent, node-exporter, piper-tts — watchtowera tam nie ma. Brak wpisu w desired state ⇒ brak driftu ⇒ brak rekomendacji. Ponad 11 tys. eventów dead-enduje. Observer natomiast zna lustro/watchtower (incydent inc-1786007596-lustro-watchtower, status unhealthy) — rozjazd dotyczy wyłącznie supervisora.

Wykluczone: shadow_mode (dotyczy tylko HA_DIAG_SHADOW_MODE, ścieżka HA-diag), duty_cycle (tłumi wyłącznie liveness node'a), progi/cooldown (containers_not_running jest w CONTAINER_RESTART_TRIGGERS, dedup po stabilnym ID).

Konsekwencja druga: akcja wstawiona ręcznie do pending/ dla serwisu spoza desired state żyje jeden cykl supervisora. _cancel_resolved_pending_actions() (supervisor.py:560) skasował ją po 15 s z powodem service_removed_from_desired_state. Kasowanie dotyczy wyłącznie pending/approved/ i running/ są z założenia nietykalne. Dlatego akcja ręczna dla watchtowera trafiła ostatecznie prosto do approved/.


KROK 3 — dwa pełne cykle HITL

Wszystkie znaczniki UTC (CEST = +2). Pętla executora: 10 s. Pętla node-agenta: 60 s.

Cykl 1 — node-exporter (ścieżka w pełni organiczna)

Etap Timestamp Δ
docker stop node-exporter (trigger) 10:22:49
event → observer → incydent inc-1786011821-lustro-node-exporter ~10:23:41 +52 s
supervisor: Generated recommendationpending/ 10:24:00.66 +71 s
approval operatora (mvapproved/) ~10:38:5x
executor: Executing actionrunning/ 10:39:00.650 ≤10 s
executor: Dispatched … to node-agent on lustro 10:39:00.657 +7 ms
node-agent: rsync-pull + bramki + docker restart 10:39:23.15 +22,5 s
event action_result (success: true) 10:39:23.293 +0,14 s
executor: completed 10:39:30.752 +7,5 s

Approval → completed: 30,1 s.

Cykl 2 — pi-watchtower-1 (akcja utworzona ręcznie, zatwierdzona przez operatora)

Etap Timestamp Δ
operator zapisuje akcję do approved/ 11:08:38
executor: Executing actionrunning/ 11:08:40.829 +2,8 s
executor: Dispatched … (container=pi-watchtower-1) 11:08:40.838 +9 ms
node-agent: Restarted container 'pi-watchtower-1' 11:08:51.002 +10,2 s
event action_result (success: true) 11:08:51.002
executor: completed 11:09:00.909 +9,9 s

Approval → completed: 20,1 s. Watchtower wrócił do crash-loopa — zgodnie z założeniem; sukcesem było przejście pipeline'u i poprawny action_result, nie uzdrowienie kontenera.

Bramki agenta

  • Whitelista typu i node scoping — przeszły; logują się tylko przy odrzuceniu, więc dowodem przejścia jest sama egzekucja.
  • Self-restart guard — nie dotyczył (cel ≠ node-agent).
  • Idempotencja — zadziałała na żywo i wielokrotnie: Action … already processed — skipping (idempotency), markery /opt/homelab/state/processed-actions/<action_id>.done.

Obserwacja uboczna: regeneracja i auto-cancel

O 10:39:48 (18 s po udanym restarcie) supervisor wygenerował ponownie akcję dla node-exportera, bo world state jeszcze pokazywał unhealthy (opóźnienie observera). O 10:40:49 sam ją skasował (drift_resolved_auto). Podwójnego restartu nie było, ale istnieje ~60-sekundowe okno, w którym po udanej remediacji potrafi powstać duplikat.


KROK 4a — rekomendacja ws. poluzowania bramek HITL

Rekomendacja: jeszcze nie, ale wąskie poluzowanie jest obronialne po trzech warunkach.

Za:

  • Pipeline przeszedł end-to-end dwukrotnie, w tym raz w pełni organicznie (event → observer → supervisor → approval → executor → node-agent → wynik).
  • Czas maszynowy to 2030 s; wąskim gardłem jest wyłącznie człowiek (dziś ~15 i ~30 min).
  • container_restart jest tanie i odwracalne, wykonanie jest scoped do node'a, whitelisty jednego typu akcji i guardu self-restartu; egzekutor nigdy nie wchodzi na node po SSH.
  • Kolejka sama się czyści: drift_resolved_auto kasuje akcje, które przestały być potrzebne, więc opóźniony approval nie powoduje zbędnego restartu.
  • Idempotencja obroniła się w warunkach bojowych (patrz defekt dispatch niżej).

Przeciw:

  • Próbka: 2 wykonania, 1 node, 1 typ akcji, obie ścieżki udane. Ani razu nie zaobserwowano ścieżki porażki (success: false), timeoutu akcji w running/, ani odrzucenia przez bramkę node/whitelisty. Dowód dotyczy szczęśliwej ścieżki.
  • Restart nie leczy przyczyn źródłowych. Watchtower ma 1000+ restartów dziennie — automat restartowałby go w kółko, maskując problem. Bez budżetu restartów (np. max 3/24 h na serwis, potem eskalacja do alert_only) auto-remediacja produkuje pętlę zamiast naprawy.
  • Otwarty defekt dispatch (niżej) w trybie automatycznym oznacza, że jedynym zabezpieczeniem przed powtórnym wykonaniem jest marker idempotencji per action_id. Wystarczy nowy action_id na ten sam objaw, by restart poszedł ponownie.
  • Okno duplikatu (~60 s) po udanej remediacji — dziś skasowane w porę, ale to kwestia wyścigu, nie gwarancji.
  • _get_container_name() po cichu zwraca nazwę serwisu, gdy brak services/<svc>/docker-compose.yml. Dla watchtowera dałoby to watchtower zamiast pi-watchtower-1 — akcja wygenerowana organicznie zakończyłaby się failed. W trybie automatycznym to stały szum porażek.

Warunki wstępne do poluzowania:

  1. Naprawa wycieku plików dispatch (niżej) — inaczej automat stoi na jednej bramce.
  2. Budżet restartów per serwis + eskalacja do alert_only po jego wyczerpaniu.
  3. Poluzowanie tylko dla container_restart i tylko dla serwisów obecnych w desired state; redeploy i disk_cleanup zostają w pełnym HITL.

KROK 4b — root cause crash-loopa watchtowera

Log kontenera, każde uruchomienie:

level=error msg="Error response from daemon: client version 1.25 is too old.
Minimum supported API version is 1.40, please upgrade your client to a newer version"

pi-watchtower-1 (containrrr/watchtower, obraz c352868a1654, kontener utworzony 2025-04-15) rozmawia z socketem Dockera przez API 1.25. Demon na LUSTRO wymaga minimum 1.40 i odrzuca połączenie, watchtower kończy się exit 1, restart=always uruchamia go ponownie — cykl ~60 s. Licznik restartów kasuje się przy nocnym halt/boot, stąd „973 restarty" to dorobek jednego dnia pracy, a nie narastająca awaria.

Co by go naprawiło (do backlogu, nie wykonane w tej sesji):

  1. docker pull containrrr/watchtower:latest + recreate — aktualne wydania negocjują nowsze API. Najprostsze.
  2. Obejście: DOCKER_API_VERSION=1.41 w env kontenera.
  3. Preferowane: usunąć watchtowera z LUSTRO. To relikt spoza GitOps, a automatyczne podmienianie obrazów na edge'owym Pi kłóci się z modelem repo jako źródła prawdy. Jeśli ma zostać — dopisać go do hosts/lustro/services.yaml, bo dopiero wtedy stanie się widoczny dla supervisora.

Efekt uboczny do rozważenia niezależnie: watchtower generuje ~1440 eventów/dobę, które nigdzie nie prowadzą, i jest głównym powodem, dla którego events/lustro/ ma 11 tys. plików.


Follow-upy

  1. Wyciek plików dispatch (nowy defekt, potwierdzony). Executor tworzy actions/dispatch/<node>/ z uprawnieniami 755 (aerbot:aerbot), a rsync-pull leci jako oskar (grupa aerbot) — brak prawa zapisu w katalogu, więc --remove-source-files nie kasuje źródła. Dla porównania dispatch/piha ma 775. Dodatkowo rsync zwraca wtedy kod 23, który node-agent traktuje jako benign (returncode not in (0, 23, 24)) → cicha porażka, zero ostrzeżeń. Skutek: LUSTRO re-pulluje te same akcje co 60 s i odbija się od bramki idempotencji — w nieskończoność. Docstring pull_dispatched_actions() twierdzi, że plik jest kasowany po pobraniu; nie jest. Fix: mkdir(mode=0o775) w executorze + osobna obsługa rc=23 przy --remove-source-files. Do czasu naprawy na LUSTRO trwa zombie re-pull dwóch plików co 60 s.
  2. _get_container_name() — cichy fallback na nazwę serwisu przy braku services/<svc>/docker-compose.yml; produkuje akcje celujące w nieistniejące kontenery.
  3. Okno ~60 s, w którym po udanej remediacji powstaje duplikat akcji (opóźnienie observera).
  4. Root cause watchtowera — patrz KROK 4b.
  5. Zdjęcie M1 (NODE_TYPE=lte_node) na SOLARII i VPS — do tego czasu zero cleanupu Dockera na obu nodach.
  6. 17 zwietrzałych akcji w pending/ z czerwca i lipca (16× alert-*, redeploy-vps-gokapi) — nikt ich nie zamyka, zaśmiecają kolejkę operatora.
  7. events/lustro/ — 11 tys. plików, rosnące głównie przez watchtowera.

Pominięte / niepewne

  • Bramki node-scoping i whitelisty typu potwierdzone tylko pośrednio (przez udaną egzekucję), bez testu negatywnego.
  • Ścieżka porażki (action_result z success: false) oraz timeout akcji w running/ nie zostały przetestowane.
  • Gałąź prune obrazów wykonała się na zerze — 0 MB reclaimed przy 0 dangling images przed i po. Potwierdza, że kod się wykonuje, nie że potrafi cokolwiek odzyskać.
  • Wycieknięte pliki dispatch na VPS usunięte ręcznie przez operatora na koniec sesji. Sam defekt (uprawnienia 755 + połknięty rc=23) pozostaje — wyciek wróci przy następnej akcji dispatchowanej na LUSTRO.
  • Cykl HITL sprawdzony wyłącznie na LUSTRO. PIHA (jedyny inny node z aktywnym dispatch) nie był testowany.

Sprzątanie

  • prune-canary — usunięty po weryfikacji (12:29:25).
  • prune-disposable — usunięty przez sam cleanup, zgodnie z zamysłem testu.
  • Obraz alpine (ściągnięty na potrzeby kanarków) — usunięty.
  • node-exporter — działa, podniesiony przez pipeline HITL, nie ręcznie.
  • actions/dispatch/lustro/ na VPS — opróżniony przez operatora (zombie re-pull ustał).
  • LUSTRO na koniec: node-agent (healthy), node-exporter (up), piper-tts (up), pi-watchtower-1 (restarting — bez zmian, świadomie).

Narrative

user-provided summary