Hitonabi
87484d6863
Ampel / ampel (push) Successful in 28s
Commander 26.07.2026: "der externe Encoder Worker ist ein bisschen duenn - der koennte noch viel mehr." Drei Punkte, alle am Tray. 1. LOG IN RIPPY STATT TXT-DATEI (ausdruecklich gewuenscht). Das Tray schrieb sein Log nach %LOCALAPPDATA% und oeffnete es im Editor - wer wissen wollte, warum der Worker nichts tut, musste sich an den PC setzen. Neue Bruecke (logbruecke.py) meldet die wichtigen Zeilen nach Rippy, Quelle "w:<name>", und die Logs-Seite hat jetzt Knoepfe je Quelle: "was macht mein PC" ist ein Klick. Der Filter konnte Quellen schon immer, es gab nur keinen Knopf. Durchgelassen wird WENIG und mit Grund: Die Job-Meldungen stehen laengst 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, Abstuerze. Alles andere fliegt weg: Celery ist bei --loglevel=info gespraechig, die logs-Tabelle hat keine Aufraeumung, und ein zugemuelltes Log ist so unbrauchbar wie keins. Dazu eine Drossel (30 Zeilen/Minute), die MELDET, wieviel sie verschluckt hat. Zeilenformat woertlich 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. 2. DAS TRAY ZEIGT, WAS LAEUFT. Vorher stand dort "laeuft" 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 Schaetzung steht. Dazu: Windows schlaeft nicht mehr mitten im Encode ein (SetThreadExecutionState, ohne ES_DISPLAY_REQUIRED - der Bildschirm darf ausgehen). Die Sperre wird zurueckgenommen, sobald nichts laeuft, und auch bei einem harten Ende des Trays - sonst schlaeft der PC nie wieder ein und niemand weiss warum. 3. MEHRERE ENCODES GLEICHZEITIG. Der Worker lief fest mit --pool=solo und nahm genau EINEN Auftrag an. Der Installer fragt die Zahl jetzt (GUI: Feld neben dem Namen, mit der erkannten 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. GUI-Layout headless gerendert und angesehen (nichts ueberlappt, 16 Kerne korrekt erkannt), beide .ps1 mit echtem PowerShell 5.1 geprueft, BOM und CRLF erhalten, .exe neu gebaut. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
128 lines
4.9 KiB
Python
128 lines
4.9 KiB
Python
"""Tests der Log-Brücke — reine Funktionen, keine Datenbank, keine Uhr.
|
|
|
|
Die Beispielzeilen sind WÖRTLICH aus dem laufenden Worker-Container abgenommen
|
|
(26.07.2026, Celery 5.4.0) — AGENTS Regel D. Erfundene Formate hätten hier
|
|
keinen Wert: Genau am geratenen Format scheitert so eine Brücke.
|
|
"""
|
|
|
|
import logbruecke
|
|
|
|
# Aus `docker compose logs worker`, unverändert.
|
|
ECHT_CONNECTED = "[2026-07-26 12:04:18,060: INFO/MainProcess] Connected to redis://redis:6379/0"
|
|
ECHT_MINGLE = "[2026-07-26 12:04:18,063: INFO/MainProcess] mingle: searching for neighbors"
|
|
ECHT_ALLEIN = "[2026-07-26 12:04:19,071: INFO/MainProcess] mingle: all alone"
|
|
ECHT_READY = "[2026-07-26 12:04:19,082: INFO/MainProcess] celery@ced31798928d ready."
|
|
ECHT_WARNUNG = (
|
|
"[2026-07-26 12:06:19,094: WARNING/MainProcess] Zombie-Erkennung: "
|
|
"{'geprueft': 0, 'aufgeraeumt': [], 'uebersprungen': ''}"
|
|
)
|
|
ECHT_BANNER = " -------------- celery@ced31798928d v5.4.0 (opalescent)"
|
|
|
|
|
|
def test_ready_ist_die_meldung_auf_die_man_wartet():
|
|
"""Wenn der Worker nichts tut, ist „ready." die Zeile, die man sehen will —
|
|
deshalb als Erfolg, nicht als Info im Grundrauschen."""
|
|
assert logbruecke.einordnen(ECHT_READY) == ("success", "celery@ced31798928d ready.")
|
|
|
|
|
|
def test_verbindung_kommt_durch():
|
|
level, text = logbruecke.einordnen(ECHT_CONNECTED)
|
|
assert level == "info"
|
|
assert "redis" in text
|
|
|
|
|
|
def test_warnungen_und_fehler_kommen_immer_durch():
|
|
level, text = logbruecke.einordnen(ECHT_WARNUNG)
|
|
assert level == "warning"
|
|
assert "Zombie-Erkennung" in text
|
|
assert logbruecke.einordnen(
|
|
"[2026-07-26 12:00:00,000: ERROR/MainProcess] kaputt")[0] == "error"
|
|
assert logbruecke.einordnen(
|
|
"[2026-07-26 12:00:00,000: CRITICAL/MainProcess] ganz kaputt")[0] == "error"
|
|
|
|
|
|
def test_grundrauschen_wird_verworfen():
|
|
"""Celery ist bei --loglevel=info gesprächig, und die logs-Tabelle hat keine
|
|
automatische Aufräumung. Ein zugemülltes Log ist so unbrauchbar wie keins."""
|
|
assert logbruecke.einordnen(ECHT_MINGLE) is None
|
|
assert logbruecke.einordnen(ECHT_ALLEIN) is None
|
|
assert logbruecke.einordnen(ECHT_BANNER) is None
|
|
assert logbruecke.einordnen("") is None
|
|
assert logbruecke.einordnen(None) is None
|
|
assert logbruecke.einordnen(
|
|
"[2026-07-26 12:00:00,000: DEBUG/MainProcess] kleinteiliges Zeug") is None
|
|
|
|
|
|
def test_absturz_ohne_celery_klammer_kommt_durch():
|
|
"""Ein Traceback trägt kein Celery-Präfix — und ist das Wichtigste, was
|
|
passieren kann."""
|
|
assert logbruecke.einordnen("Traceback (most recent call last):")[0] == "error"
|
|
assert logbruecke.einordnen(
|
|
"ConnectionRefusedError: [Errno 111] Connection refused")[0] == "error"
|
|
|
|
|
|
def test_quelle_wird_auf_32_zeichen_gekappt():
|
|
"""`logs.source` ist String(32). Ohne Kappen scheitert das Insert STILL bei
|
|
einem langen Worker-Namen — und dann fehlt genau das Log, das man sucht."""
|
|
assert logbruecke.quelle_fuer("tobisnicerpc") == "w:tobisnicerpc"
|
|
lang = logbruecke.quelle_fuer("x" * 100)
|
|
assert len(lang) == 32
|
|
assert lang.startswith("w:")
|
|
assert logbruecke.quelle_fuer("") == "w:worker"
|
|
assert logbruecke.quelle_fuer(None) == "w:worker"
|
|
|
|
|
|
# --- Drosselung -------------------------------------------------------------
|
|
|
|
|
|
def _bruecke(uhr):
|
|
geschrieben = []
|
|
b = logbruecke.Bruecke(
|
|
"testpc",
|
|
schreiber=lambda level, quelle, text: geschrieben.append((level, text)),
|
|
jetzt=lambda: uhr[0],
|
|
)
|
|
return b, geschrieben
|
|
|
|
|
|
def test_drosselung_haelt_bei_30_zeilen_die_minute():
|
|
uhr = [0.0]
|
|
b, geschrieben = _bruecke(uhr)
|
|
for i in range(40):
|
|
b.zeile(f"[2026-07-26 12:00:00,000: ERROR/MainProcess] Fehler {i}")
|
|
assert len(geschrieben) == logbruecke.MAX_ZEILEN_JE_MINUTE
|
|
|
|
|
|
def test_naechste_minute_meldet_wieviel_verschluckt_wurde():
|
|
"""Stilles Verschlucken wäre genau der Fehler, den diese Sitzung schon
|
|
einmal eine Stunde gekostet hat."""
|
|
uhr = [0.0]
|
|
b, geschrieben = _bruecke(uhr)
|
|
for i in range(40):
|
|
b.zeile(f"[2026-07-26 12:00:00,000: ERROR/MainProcess] Fehler {i}")
|
|
uhr[0] = 61.0
|
|
b.zeile("[2026-07-26 12:01:01,000: ERROR/MainProcess] naechster Fehler")
|
|
|
|
unterdrueckt = [t for lvl, t in geschrieben if "unterdrückt" in t]
|
|
assert len(unterdrueckt) == 1
|
|
assert "10 weitere" in unterdrueckt[0]
|
|
|
|
|
|
def test_kaputter_schreiber_bringt_den_worker_nicht_um():
|
|
"""Rippy nicht erreichbar → die lokale Log-Datei bleibt der Rückfall. Der
|
|
Worker muss weiterarbeiten."""
|
|
def kaputt(level, quelle, text):
|
|
raise RuntimeError("Datenbank weg")
|
|
|
|
b = logbruecke.Bruecke("testpc", schreiber=kaputt, jetzt=lambda: 0.0)
|
|
assert b.zeile("[2026-07-26 12:00:00,000: ERROR/MainProcess] Fehler") is False
|
|
|
|
|
|
def test_verworfene_zeilen_zaehlen_nicht_gegen_die_drossel():
|
|
uhr = [0.0]
|
|
b, geschrieben = _bruecke(uhr)
|
|
for _ in range(100):
|
|
b.zeile(ECHT_MINGLE)
|
|
b.zeile(ECHT_READY)
|
|
assert geschrieben == [("success", "celery@ced31798928d ready.")]
|