fix(mounts): 3 min 15 s hingen in EINER Zeile - os.makedirs auf dem toten Mount
Ampel / ampel (push) Successful in 29s

Nachtrag, weil die letzte Runde die Wiederanbindung nicht schneller machte
(202 s statt 150 s). Die Zeitstempel im Log zeigten, wo die Zeit sitzt:

  12:53:56  API gestartet
  12:54:03  "antwortet nicht - wird neu verbunden"    <- Erkennung: 7 s, gut
  12:57:18  "eingehaengt"                             <- Reparatur: 3 min 15 s

Die Erkennung war also schon schnell; die REPARATUR fraess die Zeit. Und zwar
nicht in den Mount-Versuchen, sondern in der ersten Zeile von mounten():

  os.makedirs(ziel, exist_ok=True)

`exist_ok` prueft mit os.path.isdir, und ein `stat` auf einen toten CIFS-Mount
blockiert im Kernel bis zum SMB-Timeout. Ausgerechnet der Aufruf, der nur "lege
den Ordner an, falls er fehlt" bedeutet, hing drei Minuten - BEVOR irgendeine der
sorgfaeltig begrenzten Pruefungen dran war. Dritter Fund derselben Sorte an einem
Tag: os-Aufruf auf einen Netzpfad ohne Zeitgrenze.

Jetzt klaert `pfad_lage()` die Lage mit einem abbrechbaren Kind-Prozess
(`timeout 4 ls -d`, drei Antworten: da / weg / unklar), und makedirs laeuft nur
bei "weg". Dieselbe Falle in `reparieren()` (os.path.ismount als Vorbedingung -
gebraucht wird es nicht, `umount -l` auf einen leeren Pfad kostet nichts) und in
`aushaengen()` (ismount + rmdir).

Dazu steht die DAUER jetzt im Log ("neu verbunden (4.2s)"). Sie war die
entscheidende Spur; wer sie ablesen kann, muss sie nicht rekonstruieren.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Hitonabi
2026-07-26 15:01:09 +02:00
parent 2a90538473
commit 58f4991d92
3 changed files with 170 additions and 28 deletions
+10 -2
View File
@@ -447,6 +447,7 @@ def _mounts_nachsehen() -> None:
if vorher is not False: if vorher is not False:
db.add_log("warning", "mounts", db.add_log("warning", "mounts",
f"{name}: antwortet nicht — wird neu verbunden") f"{name}: antwortet nicht — wird neu verbunden")
begonnen = time.monotonic()
try: try:
mount_verwaltung.reparieren( mount_verwaltung.reparieren(
name, eintrag["typ"], eintrag["quelle"], name, eintrag["typ"], eintrag["quelle"],
@@ -454,9 +455,16 @@ def _mounts_nachsehen() -> None:
eintrag.get("passwort") or "", eintrag.get("passwort") or "",
) )
_MOUNT_STAND[name] = True _MOUNT_STAND[name] = True
db.add_log("success", "mounts", f"{name}: neu verbunden") # Die DAUER mit ins Log: Sie war die entscheidende Spur, als eine
# Wiederanbindung drei Minuten brauchte (ein `stat` auf dem toten
# Mount). Steht sie da, muss man sie nicht erst rekonstruieren.
db.add_log("success", "mounts",
f"{name}: neu verbunden ({time.monotonic() - begonnen:.1f}s)")
except Exception as e: except Exception as e:
db.add_log("warning", "mounts", f"{name}: Neuverbinden fehlgeschlagen — {e}") db.add_log(
"warning", "mounts",
f"{name}: Neuverbinden fehlgeschlagen nach "
f"{time.monotonic() - begonnen:.1f}s — {e}")
async def _rohdaten_schleife(): async def _rohdaten_schleife():
+63 -26
View File
@@ -67,6 +67,37 @@ def ist_erreichbar(name: str) -> bool:
return False return False
def pfad_lage(ziel: str) -> str:
"""Existiert dieses Verzeichnis? „da" | „weg" | „unklar" — mit Zeitgrenze.
⚠️ Der Grund, warum es das gibt (Befund 26.07.2026, an Zeitstempeln gemessen):
Eine Wiederanbindung brauchte **3 Minuten 15 Sekunden**, und die Zeit ging
nicht in die Mount-Versuche, sondern in die allererste Zeile von `mounten()`:
os.makedirs(ziel, exist_ok=True)
`exist_ok` prüft mit `os.path.isdir()`, und ein `stat` auf einen TOTEN
CIFS-Mount blockiert im Kernel bis zum SMB-Timeout. Ausgerechnet der Aufruf,
der nur „lege den Ordner an, falls er fehlt" bedeutet, hing also drei Minuten
— bevor irgendeine der sorgfältig begrenzten Prüfungen überhaupt dran war.
Dritter Fund derselben Sorte an einem Tag: os-Aufruf auf einen Netzpfad ohne
Zeitgrenze.
Deshalb wird die Lage jetzt mit einem Kind-Prozess erfragt (`timeout 4 ls`),
der sich abbrechen lässt. „unklar" heißt: existiert, antwortet aber nicht —
dann ist ein makedirs weder nötig noch möglich.
"""
try:
ergebnis = subprocess.run(
["timeout", "4", "ls", "-d", ziel], capture_output=True, timeout=6
)
except (OSError, subprocess.TimeoutExpired):
return "unklar"
if ergebnis.returncode == 0:
return "da"
return "unklar" if ergebnis.returncode == 124 else "weg"
def wirklich_erreichbar(name: str, warten=None) -> bool: def wirklich_erreichbar(name: str, warten=None) -> bool:
"""Antwortet die Freigabe auch noch DREI SEKUNDEN später? (zweimal geprüft) """Antwortet die Freigabe auch noch DREI SEKUNDEN später? (zweimal geprüft)
@@ -273,12 +304,14 @@ def mounten(name: str, typ: str, quelle: str, optionen: str = "",
Mount-Fehlern. Mount-Fehlern.
""" """
ziel = _mountpoint(name) ziel = _mountpoint(name)
# exist_ok fängt „Ordner da" NICHT, wenn ein toter Mount os.path.isdir # Den Ordner NUR anlegen, wenn er wirklich fehlt — und das mit Zeitgrenze
# täuschen lässt (FileExistsError, Befund 24.07.) — deshalb tolerant. # klären (siehe pfad_lage): `os.makedirs(..., exist_ok=True)` hing auf einem
try: # toten CIFS-Mount drei Minuten im Kernel, weil `exist_ok` ein `stat` macht.
os.makedirs(ziel, exist_ok=True) if pfad_lage(ziel) == "weg":
except FileExistsError: try:
pass os.makedirs(ziel, exist_ok=True)
except OSError:
pass # Rennen mit einem anderen Aufruf oder Rechte — mount sagt es
# ⚠️ ERREICHBARKEIT VOR ismount — nicht umgekehrt (Befund 26.07.2026). # ⚠️ ERREICHBARKEIT VOR ismount — nicht umgekehrt (Befund 26.07.2026).
# #
# Vorher stand hier `if os.path.ismount(ziel): return schreibtest(ziel)`. # Vorher stand hier `if os.path.ismount(ziel): return schreibtest(ziel)`.
@@ -387,22 +420,25 @@ def _lazy_umount(ziel: str) -> None:
def aushaengen(name: str) -> None: def aushaengen(name: str) -> None:
"""Freigabe abhängen und den Mountpunkt aufräumen.
Ohne `os.path.ismount`/`os.rmdir` als erste Schritte: Beide `stat`en den
Pfad, und auf einem toten CIFS-Mount blockiert das im Kernel (siehe
pfad_lage). Ein `umount` auf einen Pfad ohne Mount kostet dagegen nichts.
"""
ziel = _mountpoint(name) ziel = _mountpoint(name)
try: ergebnis = subprocess.run(
noch_mount = os.path.ismount(ziel) ["umount", ziel], capture_output=True, text=True, timeout=30
except OSError: )
noch_mount = True # stale if ergebnis.returncode != 0:
if noch_mount: # Toter/beschäftigter Mount → lazy detach (klappt immer)
ergebnis = subprocess.run( _lazy_umount(ziel)
["umount", ziel], capture_output=True, text=True, timeout=30 # Erst wenn der Pfad wieder antwortet, darf rmdir ihn anfassen.
) if pfad_lage(ziel) == "da":
if ergebnis.returncode != 0: try:
# Toter/beschäftigter Mount → lazy detach (klappt immer) os.rmdir(ziel)
_lazy_umount(ziel) except OSError:
try: pass # nicht leer oder weg — egal
os.rmdir(ziel)
except OSError:
pass # nicht leer oder weg — egal
def reparieren(name: str, typ: str, quelle: str, optionen: str = "", def reparieren(name: str, typ: str, quelle: str, optionen: str = "",
@@ -411,13 +447,14 @@ def reparieren(name: str, typ: str, quelle: str, optionen: str = "",
Nötig, wenn ein NAS-Mount stale geworden ist (Rebuild, NAS-Schlaf) — das Nötig, wenn ein NAS-Mount stale geworden ist (Rebuild, NAS-Schlaf) — das
normale mounten() würde am „ist schon Mountpoint" hängenbleiben. normale mounten() würde am „ist schon Mountpoint" hängenbleiben.
`os.path.ismount` stand hier vorher als Vorbedingung — auf einem toten
CIFS-Mount blockiert dieses `stat` im Kernel (siehe pfad_lage). Gefragt wird
es gar nicht mehr: `umount -l` auf einen Pfad, an dem nichts hängt, kostet
nichts und meldet nur einen Rückgabewert, den hier niemand braucht.
""" """
ziel = _mountpoint(name) ziel = _mountpoint(name)
try: _lazy_umount(ziel)
if os.path.ismount(ziel):
_lazy_umount(ziel)
except OSError:
_lazy_umount(ziel)
return mounten(name, typ, quelle, optionen, username, passwort) return mounten(name, typ, quelle, optionen, username, passwort)
+97
View File
@@ -184,6 +184,9 @@ def test_mounten_geht_bei_totem_mount_den_reparatur_weg(monkeypatch):
ablauf = [] ablauf = []
monkeypatch.setattr(mounts.os, "makedirs", lambda *a, **k: None) monkeypatch.setattr(mounts.os, "makedirs", lambda *a, **k: None)
# pfad_lage gestubbt: Sie ruft selbst `timeout ls` auf, und hier geht es um
# die Reihenfolge von Loesen und Mounten.
monkeypatch.setattr(mounts, "pfad_lage", lambda ziel: "da")
# Vorher tot (der Vor-Check), nach dem Mount dauerhaft erreichbar. Die # Vorher tot (der Vor-Check), nach dem Mount dauerhaft erreichbar. Die
# Doppelprobe wird hier gestubbt, damit der Test nicht 3 s echt wartet. # Doppelprobe wird hier gestubbt, damit der Test nicht 3 s echt wartet.
monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False) monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False)
@@ -217,6 +220,7 @@ def test_mounten_prueft_das_ergebnis_und_versucht_es_zweimal(monkeypatch):
ablauf = [] ablauf = []
# nie erreichbar: vorher, nach Versuch 1, nach Versuch 2 # nie erreichbar: vorher, nach Versuch 1, nach Versuch 2
monkeypatch.setattr(mounts.os, "makedirs", lambda *a, **k: None) monkeypatch.setattr(mounts.os, "makedirs", lambda *a, **k: None)
monkeypatch.setattr(mounts, "pfad_lage", lambda ziel: "da")
monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False) monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False)
monkeypatch.setattr(mounts, "wirklich_erreichbar", lambda name: False) monkeypatch.setattr(mounts, "wirklich_erreichbar", lambda name: False)
monkeypatch.setattr(mounts, "_stale_mounts_loesen", lambda ziel: None) monkeypatch.setattr(mounts, "_stale_mounts_loesen", lambda ziel: None)
@@ -322,3 +326,96 @@ def test_stale_loesen_wartet_nicht_wenn_nichts_zu_loesen_war(monkeypatch):
lambda cmd, **k: types.SimpleNamespace(returncode=1, stdout=b"", stderr=b"")) lambda cmd, **k: types.SimpleNamespace(returncode=1, stdout=b"", stderr=b""))
assert mounts._stale_mounts_loesen("/app/media/x") == 0 assert mounts._stale_mounts_loesen("/app/media/x") == 0
assert gewartet == [] assert gewartet == []
def test_pfad_lage_unterscheidet_da_weg_unklar(monkeypatch):
"""DER Fund vom 26.07.2026: Eine Wiederanbindung brauchte 3 min 15 s, und die
Zeit ging in die ERSTE Zeile von mounten() - `os.makedirs(ziel,
exist_ok=True)`. `exist_ok` prueft mit os.path.isdir, und ein `stat` auf einen
toten CIFS-Mount blockiert im Kernel bis zum SMB-Timeout. Deshalb wird die
Lage jetzt mit einem abbrechbaren Kind-Prozess erfragt."""
import types
import mounts
def antwort(rc):
return lambda cmd, **k: types.SimpleNamespace(returncode=rc, stdout=b"", stderr=b"")
monkeypatch.setattr(mounts.subprocess, "run", antwort(0))
assert mounts.pfad_lage("/app/media/rippy") == "da"
monkeypatch.setattr(mounts.subprocess, "run", antwort(2))
assert mounts.pfad_lage("/app/media/neu") == "weg"
# 124 = `timeout` hat abgeschossen: existiert, antwortet aber nicht
monkeypatch.setattr(mounts.subprocess, "run", antwort(124))
assert mounts.pfad_lage("/app/media/totes-nas") == "unklar"
def test_pfad_lage_nutzt_eine_zeitgrenze(monkeypatch):
import types
import mounts
gesehen = {}
monkeypatch.setattr(
mounts.subprocess, "run",
lambda cmd, **k: (gesehen.update(cmd=cmd, kw=k),
types.SimpleNamespace(returncode=0))[1])
mounts.pfad_lage("/x")
assert gesehen["cmd"][0] == "timeout"
assert gesehen["kw"]["timeout"] is not None
def test_mounten_legt_den_ordner_nur_an_wenn_er_fehlt(monkeypatch):
"""Bei "unklar" (toter Mount) darf makedirs NICHT laufen - genau dort hing es
drei Minuten. Der Ordner ist dann ohnehin da."""
import types
import mounts
angelegt = []
monkeypatch.setattr(mounts, "pfad_lage", lambda ziel: "unklar")
monkeypatch.setattr(mounts.os, "makedirs",
lambda *a, **k: angelegt.append(a[0] if a else ""))
monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False)
monkeypatch.setattr(mounts, "wirklich_erreichbar", lambda name: True)
monkeypatch.setattr(mounts, "_stale_mounts_loesen", lambda ziel: 0)
monkeypatch.setattr(mounts, "schreibtest", lambda p: True)
monkeypatch.setattr(
mounts.subprocess, "run",
lambda cmd, **k: types.SimpleNamespace(returncode=0, stdout="", stderr=""))
assert mounts.mounten("rippy", "cifs", "//nas/rippy") is True
assert angelegt == []
def test_mounten_legt_den_ordner_bei_erstinstallation_an(monkeypatch):
import types
import mounts
angelegt = []
monkeypatch.setattr(mounts, "pfad_lage", lambda ziel: "weg")
monkeypatch.setattr(mounts.os, "makedirs",
lambda *a, **k: angelegt.append(a[0] if a else ""))
monkeypatch.setattr(mounts, "ist_erreichbar", lambda name: False)
monkeypatch.setattr(mounts, "wirklich_erreichbar", lambda name: True)
monkeypatch.setattr(mounts, "_stale_mounts_loesen", lambda ziel: 0)
monkeypatch.setattr(mounts, "schreibtest", lambda p: True)
monkeypatch.setattr(
mounts.subprocess, "run",
lambda cmd, **k: types.SimpleNamespace(returncode=0, stdout="", stderr=""))
mounts.mounten("rippy", "cifs", "//nas/rippy")
assert angelegt == ["/app/media/rippy"]
def test_reparieren_fragt_ismount_nicht_mehr(monkeypatch):
"""os.path.ismount ist ein `stat` und blockiert auf einem toten CIFS-Mount.
Gebraucht wird es nicht: `umount -l` auf einen leeren Pfad kostet nichts."""
import mounts
monkeypatch.setattr(mounts.os.path, "ismount",
lambda p: (_ for _ in ()).throw(AssertionError("nicht fragen!")))
monkeypatch.setattr(mounts, "_lazy_umount", lambda ziel: None)
monkeypatch.setattr(mounts, "mounten", lambda *a, **k: True)
assert mounts.reparieren("rippy", "cifs", "//nas/rippy") is True