homelab-codex-ws/kb/incidents/2026-07-30-ollama-solaria-vanish.md
oskar 1ef193dc5f feat(kb): przenosiny type=incident do kb/incidents/ (1 plik)
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>
2026-08-04 16:53:57 +02:00

15 KiB
Raw Blame History

okf type visibility status updated links
0.1 incident private active 2026-07-30

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 = CEST2h)

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:4416: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:0017: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

# 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)")
# 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()
# 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:0019: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.pyzero 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 7678 + 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:

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_runningcontainer_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 cykldocker 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.