f577e46281
Jedyny jawny incident-doc w repo. Pozostale incydenty siedza wtopione w docs/backlog.md, services/home-assistant/DESIGN.md i lustro-shipping-recon — wychodza w grupie SPLIT-ow. git mv + frontmatter, tresc nietknieta. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
258 lines
15 KiB
Markdown
258 lines
15 KiB
Markdown
---
|
||
okf: "0.1"
|
||
type: incident
|
||
visibility: private
|
||
status: active
|
||
updated: 2026-07-30
|
||
links: []
|
||
---
|
||
|
||
# Incydent: zniknięcie kontenera `ollama` na SOLARII — 2026-07-30
|
||
|
||
**Status:** root-cause ustalony, potwierdzony logiem i kodem. Fix NIE zaimplementowany (świadomie — patrz §7).
|
||
**Dotknięty serwis:** `ollama` @ SOLARIA. Dane przetrwały (bind `/opt/homelab/data/ollama`).
|
||
**Klasa:** utrata zasobu przez automatykę (destructive cleanup), nie awaria serwisu.
|
||
**Werdykt jednym zdaniem:** `node-agent` na SOLARII wywołuje `docker container prune` **bez filtrów co 60 s** — 19 sekund po operatorskim `docker stop ollama` prune usunął kontener.
|
||
|
||
---
|
||
|
||
## 1. TL;DR
|
||
|
||
Operator zatrzymał `ollama` celowo (test „sol-down" dla KB). Kontener miał `restart: unless-stopped`,
|
||
czyli w Dockerze status `exited`. W następnym cyklu (19 s później) `node-agent` wykonał
|
||
`docker_client.containers.prune()` — API Dockera usuwa **każdy** kontener nie-`running`,
|
||
niezależnie od restart policy, labeli compose czy intencji operatora. Kontener przestał istnieć.
|
||
|
||
To **nie jest** kolejna odsłona backlogowego `ollama-solaria-start-race` (reboot / network-detach /
|
||
bind-race z tailscale0). To osobna, nowa przyczyna, która **uzbroiła się dzień wcześniej**:
|
||
prune istniał w kodzie od zawsze, ale na SOLARII `node-agent` nie miał dostępu do `docker.sock`
|
||
(GID 996 vs 999) aż do commita `ddae57c` (2026-07-29), wdrożonego na node 2026-07-30 o 15:58.
|
||
|
||
Skutek uboczny do zapamiętania: **`docker stop <serwis>` jest teraz na SOLARII i VPS operacją
|
||
destrukcyjną** — kontener znika w ≤60 s. Wzorzec „stop bez rm jako bezpieczny rollback",
|
||
używany w tym repo (por. `docker stop homeassistant5` … „Rollback: `docker start homeassistant5`"),
|
||
przestał działać.
|
||
|
||
---
|
||
|
||
## 2. Timeline (czas lokalny CEST; logi kontenerów są w UTC = CEST−2h)
|
||
|
||
| Czas (CEST) | Zdarzenie | Źródło dowodu |
|
||
|---|---|---|
|
||
| 2026-07-29 19:20 | commit `ddae57c fix(solaria): node-agent group_add for host docker gid 996` | `git log -1 ddae57c` |
|
||
| 2026-07-30 15:58:55 | `node-agent` odtworzony na SOLARII (z działającym docker.sock) | `docker ps -a` CreatedAt |
|
||
| 2026-07-30 15:59:05 | `node-agent starting: node=solaria type=ai_node` / `Docker SDK connected` | logi node-agent |
|
||
| 2026-07-30 15:59:06 | **pierwszy** `Pruned stopped containers` — mina uzbrojona, cykl 60 s | logi node-agent |
|
||
| 2026-07-30 18:45:14 | operator: `docker ps --filter name=ollama … && docker stop ollama` | `~/.zsh_history` epoch `1785429914` |
|
||
| **18:45:33.528** | `WARNING - Container exited: ollama (restart=unless-stopped)` | logi node-agent |
|
||
| **18:45:33.563** | `INFO - Pruned stopped containers (57 MB reclaimed)` ← **usunięcie** | logi node-agent |
|
||
| 2026-07-30 18:51:48 | operator: `docker start ollama && …` → `No such container` | `~/.zsh_history` epoch `1785430308` |
|
||
| 2026-07-30 18:53:56 | `docker ps -a --filter name=ollama` → pusto | `~/.zsh_history` epoch `1785430436` |
|
||
| 2026-07-30 18:55:39 | odtworzenie: `docker compose -f services/ollama/docker-compose.yml … up -d` | `~/.zsh_history` epoch `1785430539` |
|
||
| 2026-07-30 18:55:39 | `dockerd: sbJoin … ep=ollama net=ollama_default` — kontener wstał | `journalctl -u docker` |
|
||
|
||
**Korekta względem zgłoszenia:** przerwa między `stop` a nieudanym `start` wyniosła
|
||
**6 min 34 s**, nie ~1,5 h. Okno ekspozycji było jeszcze krótsze — **19 sekund**.
|
||
Kontener zniknął natychmiast, nie „gdzieś przez półtorej godziny".
|
||
|
||
---
|
||
|
||
## 3. Dowód bezpośredni
|
||
|
||
Log `node-agent`, ten sam cykl, dwie kolejne linie (pełny fragment okna 16:44–16:47 UTC):
|
||
|
||
```
|
||
2026-07-30 16:44:30,760 - INFO - Pruned dangling images (0 MB reclaimed)
|
||
2026-07-30 16:44:30,763 - INFO - Pruned stopped containers (0 MB reclaimed)
|
||
2026-07-30 16:44:30,786 - INFO - Pruned build cache (0 MB reclaimed)
|
||
2026-07-30 16:45:33,528 - WARNING - Container exited: ollama (restart=unless-stopped)
|
||
2026-07-30 16:45:33,536 - INFO - Pruned dangling images (0 MB reclaimed)
|
||
2026-07-30 16:45:33,563 - INFO - Pruned stopped containers (57 MB reclaimed)
|
||
2026-07-30 16:45:33,574 - INFO - Pruned build cache (0 MB reclaimed)
|
||
2026-07-30 16:46:37,004 - INFO - Pruned dangling images (0 MB reclaimed)
|
||
2026-07-30 16:46:37,004 - INFO - Pruned stopped containers (0 MB reclaimed)
|
||
```
|
||
|
||
Trzy niezależne potwierdzenia, że to właśnie ta linia usunęła `ollamę`:
|
||
|
||
1. **Wartość.** `SpaceReclaimed` jest **0 MB w każdym innym cyklu dnia** (setki linii) — i **57 MB
|
||
dokładnie w tym jednym**. 57 MB = writable layer kontenera ollama (modele siedzą w bindzie, nie w warstwie).
|
||
2. **Korelacja.** W całym oknie 16:00–17:10 UTC log `node-agent` ma **dokładnie jedną** linię
|
||
nie-prune: `Container exited: ollama`. Żaden inny kontener nie był wtedy zatrzymany —
|
||
`docker ps` pokazuje pozostałe cztery z ciągłym uptime obejmującym okno incydentu
|
||
(`node-agent` Up 4 h, `planner-agent`/`stability-agent`/`node_exporter` Up 5 h).
|
||
3. **Kolejność w kodzie.** `check_containers()` (wykrycie `exited`) jest wołane w `run_once()`
|
||
linia po linii przed `run_safe_cleanup()` — stąd 35 ms między WARNING a prune.
|
||
|
||
---
|
||
|
||
## 4. Root cause w kodzie
|
||
|
||
`services/node-agent/src/node_agent.py`
|
||
|
||
```python
|
||
# linia 625
|
||
def _prune_stopped_containers(self):
|
||
if not self.docker_client:
|
||
return
|
||
try:
|
||
result = self.docker_client.containers.prune() # ← BEZ filtrów
|
||
reclaimed = result.get("SpaceReclaimed", 0) // (1024 * 1024)
|
||
logger.info(f"Pruned stopped containers ({reclaimed} MB reclaimed)")
|
||
```
|
||
|
||
```python
|
||
# linia 646
|
||
def run_safe_cleanup(self):
|
||
if self.node_type == "lte_node":
|
||
return # chelsty-* — nic nie robi
|
||
if self.node_type == "sd_card":
|
||
if not self._sd_card_rate_ok(): # piha/saturn — limit 24 h
|
||
return
|
||
self._prune_dangling_images()
|
||
self._prune_stopped_containers()
|
||
self._mark_cleanup_done()
|
||
return
|
||
# ai_node (solaria) i standard (vps): BEZ ŻADNEGO rate-limitu
|
||
self._prune_dangling_images()
|
||
self._prune_stopped_containers()
|
||
self._prune_build_cache()
|
||
```
|
||
|
||
```python
|
||
# linia 1071 — run_safe_cleanup w każdym cyklu pętli
|
||
def run_once(self):
|
||
...
|
||
self.check_containers()
|
||
self.run_safe_cleanup()
|
||
...
|
||
# linia 1101: loop(interval=HEALTH_CHECK_INTERVAL), CHECK_INTERVAL=60 (override solarii)
|
||
```
|
||
|
||
Trzy niezależne defekty składają się na incydent:
|
||
|
||
1. **`containers.prune()` bez filtrów.** docker-py przekazuje to 1:1 do
|
||
`POST /containers/prune`. Docker usuwa **wszystkie** kontenery w stanie innym niż `running`.
|
||
API nie zna pojęcia „zatrzymany celowo": nie patrzy na `RestartPolicy`, nie patrzy na labele
|
||
`com.docker.compose.*`. `restart: unless-stopped` to dosłownie zapisana intencja operatora
|
||
(„zatrzymany świadomie — nie ruszaj") i prune ją ignoruje.
|
||
2. **Brak rate-limitu dla `ai_node`/`standard`.** Rate-limit 24 h (`CLEANUP_INTERVAL_SECS = 86_400`)
|
||
istnieje **wyłącznie** dla `sd_card`. Na SOLARII prune leci co 60 s — okno na uratowanie
|
||
zatrzymanego kontenera to maksymalnie jeden cykl. Logi dowodzą, że ta częstotliwość jest
|
||
zresztą bezużyteczna: `0 MB reclaimed` w praktycznie każdym cyklu.
|
||
3. **Logowanie nie mówi, co usunięto.** `prune_containers()` zwraca `ContainersDeleted`
|
||
(lista ID) obok `SpaceReclaimed`, ale kod loguje tylko megabajty. Dlatego usunięcie
|
||
`ollamy` było w logu niewidzialne — wyglądało jak każdy inny wiersz „Pruned stopped containers".
|
||
Gdyby logowano nazwy, diagnoza trwałaby 30 sekund zamiast całej sesji.
|
||
|
||
**Dlaczego dopiero teraz.** Funkcja pochodzi z `01b7758 feat(node-agent): implement health monitor
|
||
and safe cleanup policy` — jest w repo od początku istnienia agenta. Na SOLARII nie strzelała,
|
||
bo `node-agent` startował z `Docker unavailable: Permission denied` na `/var/run/docker.sock`
|
||
(host ma docker GID **996**, base compose zakładał 999) — `self.docker_client` był `None`
|
||
i `_prune_stopped_containers()` wychodziło pierwszym `return`. Commit `ddae57c`
|
||
(2026-07-29 19:20) dołożył `group_add: ["996"]` w `hosts/solaria/runtime/node-agent/docker-compose.override.yml`.
|
||
Naprawiając monitoring, uzbroił prune. Pierwszy `Pruned stopped containers` na SOLARII:
|
||
2026-07-30 15:59:06 CEST — **2 h 46 min przed incydentem**.
|
||
|
||
---
|
||
|
||
## 5. Hipotezy wykluczone
|
||
|
||
| # | Hipoteza | Werdykt | Dowód |
|
||
|---|---|---|---|
|
||
| 1 | `docker events` / journal wskaże inicjatora | **Bez danych** (nie wyklucza ani nie potwierdza) | bufor `docker events` sięga tylko 19:42 (in-memory ring); `journalctl -u docker` w oknie 17:00–19:30 to **3 linie**, jedyna istotna to `sbJoin … ep=ollama` z 18:55:39, czyli już odtworzenie. Daemon na poziomie `info` nie loguje usunięć kontenerów. |
|
||
| 2 | Remediation pipeline (akcja z control-plane wykonana przez node-agent) | **Wykluczone** | `/opt/homelab/actions/dispatch/solaria/` **pusty**; w logach node-agent zero linii wykonania akcji; whitelist `ALLOWED_DISPATCH_ACTION_TYPES = {"container_restart"}` (linia 105, egzekwowana w 951) nie zawiera niczego, co usuwa kontener — a `container_restart` i tak by go nie skasował. |
|
||
| 3 | `stability-agent` usuwa zatrzymane kontenery | **Wykluczone** | `grep -n "prune\|\.remove(\|docker rm\|force=True\|down\b" services/stability-agent/src/stability_agent.py` → **zero trafień**. Brak jakiejkolwiek ścieżki usuwającej. |
|
||
| 4 | Config compose (auto-remove / `compose down`) | **Wykluczone** | `docker inspect`: `AutoRemove=false`, `RestartPolicy={"Name":"unless-stopped"}`; brak `--rm` w `services/ollama/docker-compose.yml`; brak `docker compose down` w `~/.zsh_history` w okolicy okna. **Uwaga poboczna:** `hosts/solaria/runtime/ollama/docker-compose.override.yml` **nie istnieje** — komenda odtwarzająca miała guard `test -f`, więc po cichu użyła samego base compose. |
|
||
| 5 | Cron / systemd timer z `docker prune` | **Wykluczone** | crontab root (tylko `@reboot /root/update.sh`), crontab oskar (pusty), `/etc/cron.{d,daily,hourly}` + `/etc/crontab` — jedyne trafienia `prune` to `find -prune` w `/etc/cron.daily/apport`. 19 systemd timerów + 4 user timery — żaden nie dotyka Dockera. |
|
||
|
||
---
|
||
|
||
## 6. Zasięg (blast radius)
|
||
|
||
Wyliczony z kodu (`_resolve_node_type`, linie 76–78 + `run_safe_cleanup`), **nie weryfikowany
|
||
na żywo na innych nodach** — SOLARIA to jedyny node, do którego ta sesja miała dostęp.
|
||
|
||
| Node | node_type | Zachowanie | Ryzyko |
|
||
|---|---|---|---|
|
||
| **SOLARIA** | `ai_node` | prune bez filtrów **co 60 s** | **Krytyczne** — potwierdzone w boju |
|
||
| **VPS** | `standard` (fallback) | prune bez filtrów, **bez rate-limitu**, cykl = `CHECK_INTERVAL` | **Krytyczne** — ta sama ścieżka kodu, w tym npm/outline/joplin/ai-cluster |
|
||
| **PIHA, SATURN** | `sd_card` | ten sam prune bez filtrów, ale gated 24 h | Wysokie, ale okno wąskie (1 strzał/dobę) |
|
||
| **CHELSTY-INFRA/HA** | `lte_node` | `return` przed cleanupem | Brak |
|
||
|
||
Konsekwencja operacyjna: na 4 z 6 nodów `docker stop <serwis>` — standardowy ruch
|
||
diagnostyczny i rollbackowy — jest operacją niszczącą. Na VPS dodatkowo dotyczy to
|
||
kontenerów spoza repo (`humanai-mailer`, `humanai-landing` odtwarzane ręcznie z `docker inspect`,
|
||
bez pliku compose) — tam utrata kontenera oznacza utratę jedynej definicji konfiguracji.
|
||
|
||
---
|
||
|
||
## 7. Rekomendacje (świadomie NIE zaimplementowane w tej sesji)
|
||
|
||
Zgodnie ze zleceniem: root-cause wskazał kod w repo → opis fixa, bez zmiany kodu.
|
||
|
||
**R1 (krytyczne) — `_prune_stopped_containers` nie może kasować kontenerów zarządzanych.**
|
||
`containers.prune()` bez filtrów jest nie do uratowania parametrami (`until` filtruje po czasie
|
||
utworzenia, nie po czasie zatrzymania — nie chroni długo żyjącego serwisu). Zamiast tego jawna enumeracja:
|
||
|
||
```python
|
||
for c in self.docker_client.containers.list(all=True, filters={"status": "exited"}):
|
||
if c.attrs["HostConfig"]["RestartPolicy"]["Name"] in ("unless-stopped", "always", "on-failure"):
|
||
continue # intencja operatora — nie ruszaj
|
||
if c.labels.get("com.docker.compose.project"):
|
||
continue # zarządzane przez compose
|
||
# dopiero teraz: c.remove()
|
||
```
|
||
Uzasadnienie: docstring modułu już deklaruje listę „NEVER TOUCHED" (`data/`, `config/`,
|
||
`state/`, żywa kolejka akcji). Kontener z `restart: unless-stopped` należy do tej samej klasy —
|
||
jest zapisaną intencją, nie śmieciem. Prune dangling images i build cache może zostać bez zmian.
|
||
|
||
**R2 (wysokie) — rate-limit dla `ai_node` i `standard`.** Obecnie `CLEANUP_INTERVAL_SECS`
|
||
działa wyłącznie dla `sd_card`. Prune co 60 s odzyskuje `0 MB` w praktycznie każdym cyklu —
|
||
to czysty koszt I/O i 1440 okazji dziennie na przypadkowe skasowanie. Ten sam guard
|
||
(`_sd_card_rate_ok` → przemianować na `_cleanup_rate_ok`) powinien objąć wszystkie typy nodów.
|
||
|
||
**R3 (średnie) — logować, co zostało usunięte.** `result.get("ContainersDeleted")` do linii
|
||
logu, poziom WARNING gdy lista niepusta. Bez tego każde następne takie zdarzenie znów będzie
|
||
niewidzialne.
|
||
|
||
**R4 (proces) — osobny task w backlogu.** Ten incydent **nie należy** do
|
||
`ollama-solaria-start-race` (reboot 15.07 / network-detach 21.07 / bind-race 22.07 —
|
||
wszystkie o *starcie* kontenera). Tutaj kontener wstawał bez zarzutu; problem jest w
|
||
*cleanupie node-agenta* i dotyczy każdego serwisu na każdym nodzie. Sklejenie obu
|
||
zamaskuje jedno albo drugie.
|
||
|
||
**M1 — mitygacja doraźna do czasu R1** (do decyzji operatora, nie zastosowana):
|
||
na czas prac utrzymaniowych albo `docker stop node-agent`, albo tymczasowo
|
||
`NODE_TYPE=lte_node` w `hosts/solaria/runtime/node-agent/docker-compose.override.yml`.
|
||
Zweryfikowane: `self.node_type` jest używane wyłącznie w `run_safe_cleanup()` (linie 648, 654)
|
||
i w dwóch liniach logu (250, 1103) — podmiana wyłącza cleanup i **nic poza nim**
|
||
(monitoring, eventy, dispatch akcji działają dalej).
|
||
|
||
---
|
||
|
||
## 8. Co wymaga dostępu do VPS (poza zakresem tej sesji)
|
||
|
||
Root-cause jest kompletny bez tego — poniższe domyka jedynie obraz skutków ubocznych.
|
||
|
||
1. **Los eventu `containers_not_running` dla `ollama`** (wyemitowanego 16:45:33 UTC).
|
||
Lokalnie `/opt/homelab/events/solaria/` jest **pusty**, bo `_ship_events_to_vps()` używa
|
||
`rsync -az --remove-source-files` (linia 792) — event fizycznie przeniósł się na VPS.
|
||
Do sprawdzenia: `/opt/homelab/events/solaria/` **na VPS**, grep `ollama` z 2026-07-30.
|
||
2. **Czy supervisor wygenerował akcję.** Wg tabeli routingu w `CLAUDE.md`
|
||
`containers_not_running` → `container_restart`. Jeśli akcja powstała i została zatwierdzona,
|
||
executor/node-agent trafiłby na nieistniejący kontener → `failed`.
|
||
Do sprawdzenia na VPS: `/opt/homelab/actions/{pending,approved,failed}/` z 2026-07-30 wieczór.
|
||
3. **Czy VPS-owy `node-agent` też prune'uje co cykl** — `docker logs node-agent | grep "Pruned stopped"`
|
||
na VPS. Potwierdzenie/zaprzeczenie wiersza „VPS = krytyczne" z §6.
|
||
|
||
---
|
||
|
||
## 9. Stan końcowy
|
||
|
||
- `ollama` działa: odtworzony 18:55:39, `Up`, `curl localhost:11434/api/tags` OK.
|
||
- Dane nienaruszone — modele w bindzie `/opt/homelab/data/ollama:/root/.ollama`,
|
||
prune nigdy nie dotyka bind mountów.
|
||
- **Przyczyna nadal aktywna.** Do czasu R1 każdy kontener zatrzymany na SOLARII
|
||
lub VPS znika w ≤60 s.
|