docs(savepoint): v3.20 - die Bremse war das Problem, nicht die Last
Ampel / ampel (push) Successful in 31s

SAVEPOINT v3.20 mit den Messwerten: /jobs und /capabilities byteweise identisch
ueber zwanzig Sekunden (es lud also nichts neu), 97 Antworten mit HTTP 429 im
nginx-Log, 812 von 876 Anfragen scheinbar von einer IP, und die Rechnung, die
zeigt warum: ein offener Tab braucht 123 Anfragen/min, erlaubt waren 100.

Dazu drei neue Lehren in AGENTS.md:
- Ein verpasster Abruf ist keine Nachricht ueber die Welt (`catch(() => [])`).
- Eine eigene Schutzbremse gegen die eigene Last rechnen - und jedes Greifen
  protokollieren, sonst ist sie unsichtbar.
- Eine geschluckte Warnung ist eine Falle (`|| echo` in einem 200-Zeilen-Log).
- Und: wenn der Commander eine Korrelation nennt, ist das eine Spur, auch wenn
  seine vermutete Erklaerung daneben liegt.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Hitonabi
2026-07-26 17:06:56 +02:00
parent 9156e8a4a9
commit 163216a68e
2 changed files with 184 additions and 1 deletions
+39
View File
@@ -87,6 +87,11 @@ Bibliotheks-APIs: `--help`/Doku prüfen und die Fundstelle im Commit nennen.
einstellbar), Auswurf wirkt wirklich (MakeMKV verriegelt die Tür), externer einstellbar), Auswurf wirkt wirklich (MakeMKV verriegelt die Tür), externer
Worker mit Verwaltungsfenster/Deinstaller/Slots, Schlüssel-Automatik für 4K, Worker mit Verwaltungsfenster/Deinstaller/Slots, Schlüssel-Automatik für 4K,
Mount-Wiederanbindung 202 s → 8 s, Weitergabe an einem frischen Klon geprüft Mount-Wiederanbindung 202 s → 8 s, Weitergabe an einem frischen Klon geprüft
-**Etappe 24 (v3.20):** Rippy bremste sich selbst aus — das Rate-Limit lag
unter der eigenen Last (100/min gegen 123/min), hinter dem Proxy teilten alle
Clients einen Eimer, und ein abgewiesener Abruf leerte das UI. Dazu: der
„Neu"-Knopf kennt jetzt die Phase (Rip oder Kompression) und fragt, wo er es
nicht weiß; zwei Fehler im Deploy-Weg behoben
- 📝 **Details immer in SAVEPOINT.md** — diese Sektion nennt nur die Etappe - 📝 **Details immer in SAVEPOINT.md** — diese Sektion nennt nur die Etappe
## Was diese Sitzungen wiederholt gekostet hat ## Was diese Sitzungen wiederholt gekostet hat
@@ -131,3 +136,37 @@ Kind-Prozess lässt sich abbrechen: `timeout N ls -d <pfad>` (Muster in
`mounts.ist_erreichbar` und `rohdaten.verzeichnis_da`). Und „konnte nicht `mounts.ist_erreichbar` und `rohdaten.verzeichnis_da`). Und „konnte nicht
nachsehen" ist etwas anderes als „ist nicht da" — beides zu vermischen erzeugt nachsehen" ist etwas anderes als „ist nicht da" — beides zu vermischen erzeugt
falsche Aussagen im UI. falsche Aussagen im UI.
**Ein verpasster Abruf ist keine Nachricht über die Welt** (26.07.2026). Im UI
stand fünfmal `catch(() => [])`: Jeder fehlgeschlagene Abruf hieß damit „es gibt
keine Jobs, keine Laufwerke, keine Ablagen" — die Liste leerte sich für einen
Takt und füllte sich vier Sekunden später wieder. Der Commander meldete das als
„wird oft neu geladen", und die Ursache war unsichtbar, weil der Fehlerzweig
nichts protokollierte. Wer nichts Neues weiß, behält, was er wusste: bei
Fehlschlag `null` und den alten Stand stehen lassen — nie einen leeren Wert, der
als Aussage gelesen wird.
**Eine eigene Schutzbremse gegen die eigene Last rechnen** (26.07.2026). Das
Rate-Limit stand auf 100 Anfragen/min, während ein einziger offener Tab 111/min
verursacht (Dashboard 75 + Log-Kasten 24 + Laufwerke 12). Rippy bremste sich
also permanent selbst aus, und niemand sah es: Der 429 stand in keinem Log, und
das UI verbuchte ihn als Leermeldung. Dazu der zweite Fehler — hinter einem
Reverse-Proxy ist `request.client.host` IMMER der Proxy, also hatten Browser,
zweiter Tab und Windows-Tray EINEN gemeinsamen Eimer (812 von 876 Anfragen kamen
scheinbar von einer IP). Wer eine Grenze setzt, rechnet die eigene Grundlast vor,
schreibt sie als Kommentar dazu und lässt jedes Greifen protokollieren.
**Eine geschluckte Warnung ist eine Falle** (26.07.2026). `cp "$ENV_SRC" .env
2>/dev/null || echo "WARNUNG: …"` scheiterte auf der Ziel-VM bei JEDEM Deploy,
weil die .env dort anders lag. Die Zeile scrollte im Build-Rauschen vorbei,
gebaut wurde still mit einer zwei Tage alten Kopie — mit einem toten
Download-Notbehelf darin, an dem jeder worker-Build abbrach. Entweder abbrechen
oder so laut werden, dass es nicht zu übersehen ist (Dateidatum, Kandidatenliste);
ein `|| echo` in einem 200-Zeilen-Log ist keins von beidem.
**Wenn der Commander eine Korrelation nennt, ist das eine Spur.** „Wenn der
Worker installiert ist, wird der Bereich oft neu geladen" klang nach Bauchgefühl
und war exakt richtig: `tray.py` fragt `/api/jobs` über Port 80, landet damit im
Rate-Limit-Eimer des Browsers und drückt ihn über die Grenze. Dieselbe Lehre wie
bei „auf Windows ginge das sofort" (Disc-Schlüssel) — die Beobachtung ernst
nehmen, auch wenn die vermutete Erklärung („Celery-Ping?") daneben liegt.
+145 -1
View File
@@ -1,6 +1,150 @@
# SAVEPOINT — Rippy # SAVEPOINT — Rippy
## Aktueller Stand: v3.19Sprachwahl, Verwaltungsfenster, Schlüssel-Automatik (26.07.2026, spät) ## Aktueller Stand: v3.20Rippy bremste sich selbst aus (26.07.2026, Nacht)
> **Zwei Commander-Meldungen, eine gemeinsame Wurzel: Rippy behinderte sich
> selbst und schwieg darüber.** Dazu zwei Fehler im Deploy-Weg, die jeden
> `worker`-Build zum Absturz brachten — gefunden, weil ich selbst darüber fiel.
### ZUSTAND, gemessen
| | |
|---|---|
| Repo + VM | `9156e8a`, Ampel **grün**, deployt |
| Tests | **289** grün (Sitzungsbeginn heute: 130) |
| Rate-Limit-Eimer | PC bei 590, VM gleichzeitig bei 599 — **getrennt** (vorher einer für alle) |
| Anfragen des Dashboards | 75/min → **30/min** |
| Phasen-Marke | live gesetzt: `rip_fertig: false` beim Rip-Start |
### 1. „Wird oft neu geladen" — es lud gar nichts neu
Erst gemessen, dann geglaubt. Über zwanzig Sekunden:
```
/jobs byteweise IDENTISCH über 5 Abfragen
/capabilities byteweise IDENTISCH über 5 Abfragen
alle Endpunkte ≤ 30 ms
```
Es wurde also nichts neu geladen — es wurde **geleert**. Im nginx-Log standen 97
Antworten mit **HTTP 429**. Drei Fehler griffen ineinander:
**(a) Die Bremse lag unter der eigenen Last.** `MAX_REQUESTS_PER_MINUTE = 100`,
während ein einziger offener Tab verursacht:
| Taktgeber | Rechnung | pro Minute |
|---|---|---|
| Dashboard | 5 Endpunkte alle 4 s | 75 |
| Log-Kasten | 2 Endpunkte alle 5 s | 24 |
| Laufwerks-Suche | 1 Endpunkt alle 5 s | 12 |
| Windows-Tray | `/jobs` alle 5 s | 12 je Worker |
| | **Summe** | **123** |
**(b) Alle Clients teilten einen Eimer.** Hinter dem nginx ist
`request.client.host` immer der Proxy: 812 von 876 Anfragen kamen scheinbar von
`172.19.0.6`. Der nginx gab die echte Adresse nicht weiter.
**Das ist die Erklärung für die Kopplung an den Worker**, die der Commander
gesehen hat: [`tray.py`](docker/worker/tray.py) fragt `http://<host>/api/jobs`
über Port 80, also durch denselben Proxy. Der Tray zahlte aus dem Geldbeutel des
Browsers. Seine vermutete Ursache („Celery-Ping?") lag daneben, seine Beobachtung
war exakt richtig.
**(c) Ein abgewiesener Abruf leerte das UI.** Fünfmal stand im Dashboard
`catch(() => [])`. Das heißt „es gibt keine Jobs" — gemeint war „ich weiß gerade
nichts Neues". Für einen Takt stand „Keine Jobs in diesem Tab", die Zähler
sprangen auf (0), vier Sekunden später war alles zurück.
Behoben: `X-Real-IP` im nginx, Grenze auf 600/min **mit vorgerechneter
Herleitung im Quelltext**, ein Test hält die Grenze gegen die eigene Last fest,
jedes Greifen steht im Log (gedrosselt auf eine Meldung pro Client und Minute),
`null` statt `[]` bei Fehlschlag, 20-s-Zeitgrenze für axios, und das Dashboard
trennt schnelle Daten (Jobs/Laufwerke, 4 s) von langsamen (Hardware/Worker/
Ablagen, 12 s).
**Bewiesen:** fünf Anfragen vom PC → `X-RateLimit-Remaining` 594→590; die VM
durch denselben nginx gleichzeitig bei 599/598. Zwei Clients, zwei Eimer.
### 2. „Der Button Neu' — WAS wird da gemacht?"
Immer die Kompression. Auch bei einem Job, dessen **Rip** abgebrochen war: Am
Nachmittag lagen 4,8 GB von rund 40 GB da, und „Neu" hätte daraus brav einen Film
komprimiert, der bei 12 % aufhört.
Das Problem war nicht der Knopf, sondern fehlendes Wissen: Sobald `status =
"failed"` in der Zeile steht, ist die Phase fort — die Spalte hat nur einen Wert.
`zombies.war_im_rip()` sieht sie im Moment des Aufräumens, die API später nie.
Also wird sie vermerkt ([`phasen.py`](docker/api/phasen.py)):
| Zeitpunkt | Marke |
|---|---|
| Rip-Start | `rip_fertig = false` |
| Rip fertig, Kompression eingereiht | `rip_fertig = true` |
| Start eines Transcodes | `rip_fertig = true` (heilt Bestandsjobs) |
Daraus folgen **drei** Antworten, nicht zwei:
- `transcode`**„Neu komprimieren"** · Disc bleibt draußen, Stunde gespart
- `rip`**„Neu rippen"** · `POST /jobs/{id}/retry-rip`, neuer Job mit neuer ID
- `unklar`**Dialog**, der beide Wege erklärt und die Rohdaten-Größe als
Entscheidungshilfe nennt („eine Blu-ray bringt roh 2545 GB mit")
Der dritte Fall ist der Grund, warum nicht geraten wird: Bestandsjobs tragen die
Marke nicht, und dem Commander an einem Job mit 74 GB intakter Rohdaten das
Komprimieren wegzunehmen wäre genauso falsch wie ein Bruchstück anzubieten.
Warum ein **neuer** Job und nicht der alte wiederbelebt: Das Roh-Verzeichnis
heißt `<Arbeitsverzeichnis>/<job_id>`. Bei gleicher ID läge das alte Bruchstück
im neuen Verzeichnis, und die Kompression sammelt am Ende ALLE MKV-Dateien darin
ein — sie würde es mitverarbeiten.
### 3. Zwei Fehler im Deploy-Weg (gefunden, weil ich selbst darüber fiel)
`./deploy.sh` ohne Argumente — der dokumentierte Normalfall — endete mit
`line 5: $4: unbound variable`. **Leere Argumente überleben ssh nicht:** Die
Gegenseite bekommt die Befehlszeile als EINEN String und parst sie neu, `""`
verschwindet dabei ersatzlos. Jetzt `${4:-}`.
Danach brach jeder `worker`-Build am MakeMKV-Download ab. Ursache war nicht der
Download, sondern eine **geschluckte Warnung**: Die echte `.env` liegt auf der VM
unter `~/projects/rippy/.env`, der Default zeigte auf `~/rippy/.env`. Das `cp`
scheiterte bei jedem Deploy, die Warnung scrollte im Build-Rauschen vorbei, und
gebaut wurde mit der Kopie im Klon — zwei Tage alt, darin ein
`MAKEMKV_URL_BASE`-Notbehelf auf einen web.archive.org-Schnappschuss. Der liefert
inzwischen **525**, während `makemkv.com/download` wieder **200** gibt. Der
Notbehelf von vorgestern war die Ursache von heute.
Jetzt: `.env` übernommen → es steht da. Quelle fehlt, Klon hat eine → laute
Warnung mit Dateidatum und Kandidatenliste. Keine von beiden → Abbruch, statt mit
leerem DB-Passwort zu bauen.
**Für die nächste Sitzung:**
```
RIPPY_VM=arcane@192.168.178.162 \
RIPPY_REPO_URL=<gitea> \
RIPPY_ENV_SRC=/home/arcane/projects/rippy/.env ./deploy.sh
```
### 4. Was noch offen ist
- **Voller Durchlauf läuft gerade** (Job `bfb7a946`, über den neuen
`retry-rip`-Weg gestartet): Akira-BD → Auswurf → Kompression auf
`tobisnicerpc` mit Wunschsprache `deu` (Ton **und** Untertitel). Das ist die
Kette, die noch nie komplett durchlief — Sprachwahl war bisher nur bis zum
Scan belegt, nie durch einen echten Encode.
- **Job `2182d525` trägt einen falschen Fehlertext.** Das Aufräumen lief, bevor
der phasenbewusste Text deployt war; dort steht noch „mit Neu komprimieren'
läuft die Kompression erneut" für einen Rip, der bei 12 % starb. Der Knopf
fragt inzwischen nach, der Text im Detail-Popup lügt weiter. Der Eintrag samt
4,8-GB-Bruchstück kann über den Papierkorb weg — der Neu-Rip ersetzt ihn.
- **`sudo ./install.sh` auf einem FRISCHEN Host ist weiter unbelegt.** Der
Prüfpfad (`--nur-pruefen`) läuft auf der VM sauber durch, alle fünf Prüfungen
grün. Ein echter Root-Lauf hier hätte den laufenden Rip getötet.
---
## Vorheriger Stand: v3.19 — Sprachwahl, Verwaltungsfenster, Schlüssel-Automatik (26.07.2026, spät)
> **Deployt und live gegengeprüft.** Sieben Commander-Meldungen, alle gemessen > **Deployt und live gegengeprüft.** Sieben Commander-Meldungen, alle gemessen
> statt vermutet. Drei davon waren echte Fehler, die niemand gesehen hatte, und > statt vermutet. Drei davon waren echte Fehler, die niemand gesehen hatte, und