Compare commits

..

2 commits

Author SHA1 Message Date
oskar a14909d921 eval(retrieval): przekwalifikuj N2 na mail_query M5, nowa kontrolka N3
Regresja po zamknieciu Etapu B fazy mailowej dala FAIL wylacznie na
kryterium 3: kontrolka N2 "piaskownica plastikowa" spadla do 0.4924
(flat/hybrid) na mail przedszkolny "Materialy plastyczne" -- kolizja
leksykalna ponizej progu 0.50. Rownoczesnie odrzucone w Etapie A
zapytanie "piaskownica plac zabaw wspolnota" ma dzis realne odpowiedzi
(maile administracji wspolnoty holc.waw.pl, 2023). To nie regresja
retrievalu -- korpus urosl o tresc, ktorej w Etapie A nie bylo, wiec
kontrolka negatywna stracila waznosc.

- N2 wycofana; pelna historia decyzji (pilot, 2026-07-23, 2026-08-06)
  zachowana jako komentarz w queries.yaml, nie skasowana.
- M5: "wymiana piasku w piaskownicy na placu zabaw wspolnoty",
  expected_envelope 6ab218df-...@holc.waw.pl, d1=0.2858, hit3=y.
  Wariant z "wymiana piasku" zamiast doslownego sformulowania operatora,
  bo tamto daje 0.4562/0.4597 -- oba nad HIT_THRESHOLD 0.45.
- N3: "sterylizacja kota cennik kliniki weterynaryjnej", bar 0.50 bez
  zmian, 0.5257/0.5799/0.5257. Dwaj odrzuceni kandydaci i lista tematow
  majacych realna odpowiedz w korpusie udokumentowane w komentarzu.
- retrieval_eval.py: tylko komentarz -- mail_hit nadal ocenia sie
  source-matchem, expected_envelope M5 jest dokumentacyjne.

Weryfikacja: retrieval_eval.py --transport http --base-url
http://192.168.31.5:8230 --gate-n 10 -> OVERALL PASS (exit 0),
kryteria 1/2/3 PASS, kryterium 4 = 5/5 (wymagane >= 4).

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
2026-08-06 13:22:23 +02:00
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

291
docs/sessions/2026-08-06.md Normal file
View file

@ -0,0 +1,291 @@
---
okf: "0.1"
type: session-log
visibility: private
status: active
updated: 2026-08-06
links: []
---
# 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 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_