14 KiB
| 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_result → completed. 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 recommendation → pending/ |
10:24:00.66 | +71 s |
approval operatora (mv → approved/) |
~10:38:5x | — |
executor: Executing action → running/ |
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 action → running/ |
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 20–30 s; wąskim gardłem jest wyłącznie człowiek (dziś ~15 i ~30 min).
container_restartjest 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_autokasuje 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 wrunning/, 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 nowyaction_idna 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 brakservices/<svc>/docker-compose.yml. Dla watchtowera dałoby towatchtowerzamiastpi-watchtower-1— akcja wygenerowana organicznie zakończyłaby sięfailed. W trybie automatycznym to stały szum porażek.
Warunki wstępne do poluzowania:
- Naprawa wycieku plików dispatch (niżej) — inaczej automat stoi na jednej bramce.
- Budżet restartów per serwis + eskalacja do
alert_onlypo jego wyczerpaniu. - Poluzowanie tylko dla
container_restarti tylko dla serwisów obecnych w desired state;redeployidisk_cleanupzostają 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):
docker pull containrrr/watchtower:latest+ recreate — aktualne wydania negocjują nowsze API. Najprostsze.- Obejście:
DOCKER_API_VERSION=1.41w env kontenera. - 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
- Wyciek plików dispatch (nowy defekt, potwierdzony). Executor tworzy
actions/dispatch/<node>/z uprawnieniami 755 (aerbot:aerbot), a rsync-pull leci jakooskar(grupaaerbot) — brak prawa zapisu w katalogu, więc--remove-source-filesnie kasuje źródła. Dla porównaniadispatch/pihama 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ść. Docstringpull_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. _get_container_name()— cichy fallback na nazwę serwisu przy brakuservices/<svc>/docker-compose.yml; produkuje akcje celujące w nieistniejące kontenery.- Okno ~60 s, w którym po udanej remediacji powstaje duplikat akcji (opóźnienie observera).
- Root cause watchtowera — patrz KROK 4b.
- Zdjęcie M1 (
NODE_TYPE=lte_node) na SOLARII i VPS — do tego czasu zero cleanupu Dockera na obu nodach. - 17 zwietrzałych akcji w
pending/z czerwca i lipca (16×alert-*,redeploy-vps-gokapi) — nikt ich nie zamyka, zaśmiecają kolejkę operatora. 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_resultzsuccess: false) oraz timeout akcji wrunning/nie zostały przetestowane. - Gałąź prune obrazów wykonała się na zerze —
0 MB reclaimedprzy 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