From 4c2331563c0c6346a7dd8359b598a04c8a2db1d6 Mon Sep 17 00:00:00 2001 From: Hitonabi Date: Sun, 26 Jul 2026 14:40:31 +0200 Subject: [PATCH] docs(savepoint): v3.18 - Auswurf, externer Worker, und die Mount-Ursache Stellt eine Aussage aus v3.17 richtig: Dort stand die Mount-Sache als "Ursache liegt beim NAS, nicht gefunden". Gemessen liegt sie bei uns - die CIFS-Verbindung lebt in der Netz-Namespace des api-Containers und stirbt mit ihm. Das NAS ist unschuldig. AGENTS.md bekommt die Lehre, die diesen Abend zweimal gekostet hat: Ein Rueckgabewert ist kein Beweis, wo die Wirkung pruefbar ist. CDROMEJECT quittiert Erfolg auf einem verriegelten Laufwerk, `mount` quittiert Erfolg auf einer Verbindung, die Sekunden spaeter stirbt. Co-Authored-By: Claude Opus 5 --- AGENTS.md | 12 ++++ SAVEPOINT.md | 200 ++++++++++++++++++++++++++++++++++++++++++++++++++- 2 files changed, 211 insertions(+), 1 deletion(-) diff --git a/AGENTS.md b/AGENTS.md index 4ff3c41..f6c0ea8 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -78,6 +78,11 @@ Bibliotheks-APIs: `--help`/Doku prüfen und die Fundstelle im Commit nennen. es selbst; Presets kommen vom Worker statt aus dem Quelltext; Dashboard ohne Placebos, mit Restzeit. Dazu vier Bestandsfehler, alle live gemessen (u. a. „Neu komprimieren" ging nie, und `os.path.isdir` hing im Kernel) +- ✅ **Etappe 22 (v3.18):** Auswurf wirkt endlich (MakeMKV verriegelt die Tür — + erst entriegeln, dann prüfen statt glauben), externer Worker meldet sein Log + nach Rippy, zeigt den laufenden Job und nimmt mehrere Aufträge an. Dazu **die + Mount-Ursache**: Die CIFS-Verbindung lebt in der Netz-Namespace des + api-Containers und stirbt mit ihm — eine Wache heilt das jetzt selbst - 📝 **Details immer in SAVEPOINT.md** — diese Sektion nennt nur die Etappe ## Was diese Sitzungen wiederholt gekostet hat @@ -102,6 +107,13 @@ blockiert). Jede Hintergrund-Schleife MELDET ihren Fehler, und wer einen Vorrat anlegt, macht sein Alter abfragbar (`GET /health/vorraete`) — sonst ist am Endpunkt selbst nichts zu sehen. +**Ein Rückgabewert ist kein Beweis, wo die Wirkung prüfbar ist** (26.07.2026, +zweimal am selben Abend). `CDROMEJECT` quittiert Erfolg auf einem verriegelten +Laufwerk und wirft nichts aus; `mount` quittiert Erfolg auf einer Verbindung, die +Sekunden später stirbt. Beide Fehler waren monatelang unsichtbar, weil der Code +dem Rückgabewert glaubte. Nach einer Aktion den ZUSTAND fragen — und wenn er +flattert, zweimal mit Abstand. + **Netz-Pfade nie ungebremst anfassen.** `os.path.isdir`/`open` auf einem toten CIFS-Mount blockieren im Kernel und lassen sich aus Python NICHT abbrechen. Ein Kind-Prozess lässt sich abbrechen: `timeout N ls -d ` (Muster in diff --git a/SAVEPOINT.md b/SAVEPOINT.md index 3bc6c76..43625ea 100644 --- a/SAVEPOINT.md +++ b/SAVEPOINT.md @@ -1,6 +1,204 @@ # SAVEPOINT — Rippy -## Aktueller Stand: v3.17 — der Blocker ist zu, neun Punkte abgearbeitet (26.07.2026) +## Aktueller Stand: v3.18 — Auswurf, externer Worker, und DIE Mount-Ursache (26.07.2026, Abend) + +> **Deployt und live gegengeprüft.** Zwei Commander-Meldungen: Das Laufwerk geht +> nach dem Rip nicht auf, und der externe Worker „ist ein bisschen dünn". Beide +> abgearbeitet — und unterwegs ist die Ursache gefallen, die v3.17 noch als +> „liegt beim NAS, nicht gefunden" führte. Sie lag bei uns. + +### ZUSTAND, gemessen + +| | | +|---|---| +| Repo + VM | `4cf7acb`, Ampel **grün**, deployt | +| Tests | **228** grün (Sitzungsbeginn: 130) | +| Freigabe nach dem Deploy | **heilt sich selbst in ~150 s**, ohne Handgriff | +| Job `95afdc89` | `can_retry = true`, 74,1 GB erreichbar | +| ⚠️ Laufwerks-Schublade | **steht OFFEN** — vom Auswurf-Test, per Software nicht schließbar (siehe unten) | + +### 1. DER AUSWURF: das ioctl meldete Erfolg und tat nichts + +Commander: *„Den Button gibt es in den Settings, aber es passiert nicht, das +Laufwerk geht nicht auf."* An der Disc, die gerade drin lag, nachgestellt: + +``` +wirf_disc_aus("/dev/sr0") → True +CDROM_DRIVE_STATUS danach → 4 (Disc drin) +``` + +Das ioctl wird **angenommen und tut nichts**. Ursache: MakeMKV verriegelt während +des Rips die Laufwerkstür (`CDROM_LOCKDOOR 1`) und entriegelt sie nicht wieder. +Ein verriegeltes Laufwerk quittiert den Auswurf trotzdem mit Erfolg. Gegenprobe +an derselben Disc: + +``` +CDROM_LOCKDOOR 0 + CDROMEJECT → Status 2 (SCHUBLADE OFFEN) +``` + +Genau das macht das Werkzeug `eject` immer: erst entriegeln, dann auswerfen. + +**Die wichtigere Hälfte des Fixes:** Das Ergebnis wird jetzt GEPRÜFT statt +geglaubt (bis zu 5 s, die Schublade braucht ein bis zwei; „kein Datenträger" +zählt mit, weil ein Slot-Laufwerk keine Schublade hat). Deshalb ist der Fehler +in v3.14 durchgerutscht: Dort wurde richtig festgestellt, dass die Einstellung +von niemandem gelesen wurde — danach WURDE sie gelesen, ausgeworfen wurde +weiterhin nicht, und im Log stand „Disc ausgeworfen". Dieselbe Lücke steckte im +Auswurf-Knopf der API. + +**Live bewiesen** (API-Weg, also der Knopf im UI): aus „Disc drin" wurde in +**0,67 s** „Schublade offen". + +**Zum eigentlichen Ziel — zweite Disc parallel:** Das war nur am Laufwerk +gescheitert. `has_active_job` blockiert ausschließlich bei `pending`/`running`, +ein Job in `transcoding` gibt das Gerät also längst frei, und der Worker läuft +ohne `--concurrency`, also mit 4 Slots. Der Auswurf sitzt auch an der richtigen +Stelle: nach dem Rip, VOR dem Einreihen der Kompression. + +⚠️ **Die Schublade der VM steht jetzt offen.** Der Test hat sie geöffnet, und +`CDROMCLOSETRAY` bleibt wirkungslos (viermal versucht, mit bis zu 15 s Wartezeit +je Versuch) — das BU40N will von Hand zugeschoben werden. Deshalb ist der +AUTOMATISCHE Weg (`wirf_disc_aus` nach einem Rip) nicht noch einmal live +gemessen: identischer Code, durch Tests gedeckt, aber der Live-Beweis steht nur +für den API-Weg. + +### 2. DER EXTERNE WORKER: Log nach Rippy, Anzeige, Slots + +Commander: *„der externe Encoder Worker ist ein bisschen dünn — der könnte noch +viel mehr"*, dazu ausdrücklich *„bessere Log-Ansichten (kein txt file → direkt +von Rippy Logs)"*. + +**Log geht nach Rippy** (`worker/logbruecke.py`). Vorher schrieb das Tray nach +`%LOCALAPPDATA%` und öffnete die Datei im Editor — wer wissen wollte, warum der +Worker nichts tut, musste sich an den PC setzen. Jetzt landen die wichtigen +Zeilen in Rippys Log-Tabelle (Quelle `w:`), und die Logs-Seite hat Knöpfe +je Quelle: „was macht mein PC" ist ein Klick. + +Durchgelassen wird **wenig**, und das mit Grund: Die Job-Meldungen stehen längst +in Rippy (`tasks.py` schreibt sie selbst). Es fehlte, was DANEBEN passiert und +den Worker unbrauchbar macht, ohne dass ein Job existiert — hochgefahren oder +nicht, Verbindung zu Redis/Postgres, Abstürze. Alles andere fliegt weg: Celery +ist bei `--loglevel=info` gesprächig, die `logs`-Tabelle hat **keine** +automatische Aufräumung. Dazu eine Drossel (30 Zeilen/Minute), die MELDET, +wieviel sie verschluckt hat. Das Zeilenformat ist wörtlich aus dem laufenden +Container abgenommen (Celery 5.4.0). Die lokale Datei bleibt — sie ist genau dann +die einzige Auskunft, wenn Rippy nicht erreichbar ist. + +**Das Tray zeigt, was läuft.** Vorher stand dort „läuft" oder „gestoppt" — auf +einer Maschine, die stundenlang an einem Film rechnet, ist das keine Auskunft. +Jetzt Titel, Prozent und Restzeit, geholt von Rippys `/jobs`. Bewusst dieselbe +Quelle wie das Dashboard, damit im Tray nicht eine zweite, abweichende Schätzung +steht. Dazu: **Windows schläft nicht mehr mitten im Encode ein** +(`SetThreadExecutionState`, ohne `ES_DISPLAY_REQUIRED` — der Bildschirm darf +ausgehen). Die Sperre wird zurückgenommen, sobald nichts läuft, und auch bei +einem harten Ende des Trays — sonst schläft der PC nie wieder ein und niemand +weiß warum. + +**Mehrere Encodes gleichzeitig.** Der Worker lief fest mit `--pool=solo` und nahm +genau EINEN Auftrag an. Der Installer fragt die Zahl jetzt (Feld neben dem Namen, +erkannte Kernzahl daneben), Vorbelegung ab 12 Kernen zwei, sonst einer: HandBrake +nutzt schon alle Kerne, aber x265 skaliert nicht linear. Auf Windows gibt es +keinen prefork-Pool (kein `fork`) — deshalb `--pool=threads`, was hier passt, +weil die Arbeit ein Kind-Prozess ist und der Thread nur wartet. + +**Zur Frage des Commanders** *„würden wir mit ‚auch rippen können' nicht den Sinn +von Rippy aushebeln?"* — teilweise ja, und die Antwort steht als Empfehlung: +Ein Windows-Ripper bräuchte eine **zweite komplette Laufwerks-Erkennung** +(`detection.py` steckt voller Linux-ioctls), also einen zweiten Unterbau mit +eigenen Fehlern. Der einzige harte Vorteil ist, dass MakeMKV unter Windows die +4K-Disc-Schlüssel selbst holt. Das ist viel billiger zu haben: ein kleiner +Helfer, der bei eingelegter Disc MakeMKV öffnen lässt und `_private_data.tar` +automatisch zu Rippy hochlädt. **Entscheidung steht beim Commander, nichts +gebaut.** + +### 3. DIE MOUNT-URSACHE — sie lag nicht am NAS, sondern bei uns + +v3.17 führte das als „Ursache liegt beim NAS, nicht gefunden". Gemessen in +`/proc/fs/cifs/DebugData`: + +``` +Mount-Verbindung → Net namespace: 4026532653 +api-Container → net:[4026532653] ← DIESELBE +worker-Container → net:[4026532540] ← andere +``` + +**Die CIFS-Verbindung lebt in der Netz-Namespace des api-Containers** — dort wird +sie eingehängt, weil nur dieser Container `CAP_SYS_ADMIN` hat. Wird der Container +neu gebaut, stirbt sein Netz-Namespace und mit ihm der Socket. Der Mount steht +danach weiter in `/proc/mounts` (per rshared auf den Host propagiert) und sieht +vollkommen gesund aus — aber jeder Zugriff läuft in den CIFS-Timeout. + +Damit erklärt sich alles, was vorher widersprüchlich aussah: warum es nach JEDEM +Deploy passiert, warum `mount` Erfolg meldet, warum genau eine korrekte Schicht +in `/proc/mounts` steht, und warum nur ein echtes Neu-Verbinden hilft. **Das NAS +ist unschuldig** — eine Sitzung, alles Status 1, 630 Credits, Ping 0,47 ms. + +**Zweiter Fund, der den Rest erklärt:** Direkt nach einem frischen Mount +antwortete die Freigabe — und Sekunden später nicht mehr. Das ist ein Wettlauf +mit `umount -l`: lazy heißt, der Abbau passiert später, und fällt er samt +Propagation hinter den neuen Mount, zeigt der Pfad wieder auf die Leiche. Eine +einzige Probe kann das nicht sehen — deshalb prüft `wirklich_erreichbar()` +**zweimal mit drei Sekunden Abstand**. + +**Gebaut:** eine Mount-Wache (erste Prüfung nach 10 s, dann minütlich), die +stumme Freigaben neu verbindet. Zwei Dinge daran sind wichtiger als die Heilung: +Sie rührt **nie** etwas an, solange irgendein Job nicht durch ist (neu verbinden +heißt `umount -l`; mitten in einem Rip wäre das Datenverlust — `db.hat_arbeit()`, +`pending` zählt mit), und sie meldet nur den **Übergang**, nicht jede Minute +(ein ausgeschaltetes NAS wäre sonst ein Log-Wasserfall). + +**Live bewiesen, ohne einen Handgriff:** Nach `docker compose up -d --build` war +die Freigabe stumm; nach rund 150 s stand im Log „antwortet nicht — wird neu +verbunden" → „neu verbunden", und `can_retry` war wieder `true`. Vorher heilte +das **nie** von selbst. + +### NOCH OFFEN + +**1. Der api-Container HÄLT die NAS-Verbindung.** Startet er mitten in einem Rip +neu, verliert auch der Worker sein Ziel — das ist die strukturelle Folge des +Namespace-Befunds. Das saubere Gegenmittel wäre ein Mount auf dem HOST +(systemd/fstab) statt im Container; das ist ein eigener Umbau und widerspräche +„Speicherziele über das UI einhängen" (Commander-Anforderung 23.07.). **Zu +entscheiden.** Bis dahin gilt: nicht deployen, während ein Rip läuft. + +**2. Die Schublade der VM steht offen** und braucht einen Handgriff (siehe oben). + +**3. Der Auswurf nach einem echten Rip ist nicht live gemessen** — identischer +Code wie der bewiesene API-Weg, durch Tests gedeckt, aber der Beweis fehlt, weil +die Schublade sich nicht per Software schließen lässt. + +**4. Der externe Worker läuft weiter mit altem Code.** Er braucht einen Lauf des +neuen Installers, um Pfad-Mapping, Preset-Meldung, Log-Brücke, Tray-Anzeige und +Slots zu bekommen. Danach ist auch die Live-Gegenprobe von „mehrere Encodes +gleichzeitig" möglich — bisher ist das nur die richtige Celery-Option, kein +gemessener Durchsatz. + +**5. „Auch rippen können"** — Entscheidung steht beim Commander (siehe oben). + +**6. Unverändert offen aus v3.17:** Live-Gegenprobe der Metadaten-Kette +(MyAnimeList war die ganze Sitzung weg, HTTP 504); ISO-Sicherung und +Mehr-Laufwerk-Betrieb; Klartext-Geheimnisse in der settings-Tabelle; VM-CPU-Typ +auf `qemu64`; `install.sh` nie als root gelaufen; kein TypeScript-Typcheck. + +### FALLEN DIESER RUNDE + +- **Ein ioctl-Rückgabewert beweist nichts.** Zweimal in einer Sitzung dasselbe + Muster: `CDROMEJECT` quittiert Erfolg auf einem verriegelten Laufwerk, `mount` + quittiert Erfolg auf einer Verbindung, die gleich stirbt. Wo eine Wirkung + prüfbar ist, prüfe die Wirkung. +- **`/proc/fs/cifs/DebugData` ist die Antwort auf „warum hängt der Mount".** + Sitzungen, Shares, Credits, TCP-Status — und die Netz-Namespace, die hier den + Fall gelöst hat. +- **Tests, die `main` importieren, gehören in `test_api_smoke.py`** — nur dieses + Modul überspringt sich unter Windows selbst. In `test_mounts_helpers.py` + brachen sie den lokalen Lauf. +- **Ein Stub muss zur neuen Aufrufzahl passen.** `iter([False, True])` lief in + StopIteration, als eine Prüfung zu zwei wurde. Besser die HÖHERE Funktion + stubben als die Anzahl der Aufrufe nachzählen. + +--- + +## Vorheriger Stand: v3.17 — der Blocker ist zu, neun Punkte abgearbeitet (26.07.2026) > **Deployt und live gegengeprüft.** Auftrag war „lies den Savepoint und lass uns > das Projekt endlich beenden". Die neun Commander-Punkte aus v3.16 sind