Snapshot-Laeufe gegen cfs-Sperren des Storages absichern

Auf einem echten Host schlugen Snapshots reihenweise mit
"cfs-lock 'storage-NAME' error: got lock request timeout" fehl.

Ursache: 'pvesh create .../snapshot' lief mit dem allgemeinen
Kommando-Zeitlimit von 60s. Genau so lange wartet Proxmox aber auf den
Storage-Lock. Lief der Aufruf in unser Zeitlimit, ging es mit der naechsten
VM weiter, waehrend der Task noch lief - und die naechste VM scheiterte
dann an derselben Sperre. Eine VM konnte so einen ganzen Lauf umwerfen.

* Snapshot-Aktionen laufen jetzt mit dem langen task_timeout statt mit dem
  kurzen Zeitlimit fuer Lesezugriffe.
* Ohne UPID in der Antwort wird ersatzweise gewartet, bis der Gast nicht
  mehr gesperrt ist, statt sofort weiterzumachen.
* Sperr-Fehler gelten als voruebergehend und werden 'retries'-mal mit
  'retry_delay' Abstand wiederholt; echte Fehler wie "storage does not
  support snapshots" nicht.
* Neu: 'pause_between' fuer eine Pause zwischen zwei Gaesten.

Ausserdem: Kommentare hinter einem Wert ("retries = 2  # ...") wurden nicht
abgeschnitten und machten die Konfiguration ungueltig - das eigene
Beispiel war davon betroffen. 'description' bleibt bewusst unangetastet,
damit ein '#' in der Beschreibung erhalten bleibt.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

README.md

@@ -84,6 +84,9 @@ check_interval = 60s               # wie oft der Dienst nach Fälligem schaut
 state_file = /var/lib/pvesnap/state.json
 log_level = INFO
 task_timeout = 15m
+retries = 2                        # Wiederholungen, wenn eine Sperre belegt ist
+retry_delay = 60s
+pause_between = 0s                 # Pause zwischen zwei Gästen
 run_on_start = no                  # beim Start sofort einen Durchlauf machen?
 dry_run = no                       # yes = nichts wirklich tun, nur protokollieren
 description = pvesnap | Gruppe: {group} | erstellt: {datetime} | Vorhaltezeit: {keep_time}
@@ -255,6 +258,46 @@ z. B. zum Ausprobieren.
 
 ---
 
+## Wenn Snapshots am Storage-Lock scheitern
+
+```
+trying to acquire cfs lock 'storage-data' ...
+TASK ERROR: cfs-lock 'storage-data' error: got lock request timeout
+```
+
+`storage-data` ist dabei kein falsch gelesener Name — in pmxcfs heißen
+Storage-Sperren immer `storage-<name>`, gemeint ist also das Storage `data`.
+Proxmox nimmt diese Sperre beim Anlegen eines Snapshots und gibt nach 60 s auf,
+wenn sie jemand anderes hält.
+
+pvesnap geht damit so um:
+
+* Der Aufruf wartet, bis der Snapshot-Task in Proxmox **wirklich fertig** ist,
+  bevor die nächste VM drankommt — sonst würden sich die Läufe gegenseitig
+  aussperren.
+* Sperr-Fehler gelten als vorübergehend und werden `retries`-mal mit
+  `retry_delay` Abstand wiederholt. Echte Fehler (etwa „storage does not support
+  snapshots") werden **nicht** wiederholt.
+* Mit `pause_between = 10s` lässt sich zusätzlich Druck vom Storage nehmen, wenn
+  viele VMs auf demselben Storage liegen.
+
+Hält die Sperre dauerhaft, liegt die Ursache außerhalb von pvesnap. Diese
+Kommandos helfen beim Eingrenzen:
+
+```bash
+pvesm status                      # ist das Storage online und erreichbar?
+grep -A6 "^[a-z]*: data" /etc/pve/storage.cfg
+pvesh get /cluster/tasks --output-format json | head    # hängt noch ein Task?
+systemctl status pvestatd pve-cluster
+journalctl -u pvestatd -n 50
+```
+
+Häufigste Ursachen: ein hängender Backup- oder Replikationsjob auf demselben
+Storage, ein nicht erreichbares NFS/CIFS-Storage (dann blockiert `pvestatd`),
+oder ein abgebrochener Task, der die Sperre nicht freigegeben hat.
+
+---
+
 ## Aufbau
 
 ```

config/pvesnap.conf.example

@@ -28,6 +28,17 @@ log_level = INFO
 # Maximale Wartezeit auf einen einzelnen Snapshot-Task in Proxmox.
 task_timeout = 15m
 
+# Proxmox sperrt beim Anlegen eines Snapshots kurz das Storage
+# ("cfs-lock 'storage-NAME'"). Ist es gerade belegt, laeuft der Task nach 60s
+# in "got lock request timeout". Solche Faelle sind voruebergehend - pvesnap
+# versucht es dann noch einmal:
+retries = 2                        # zusaetzliche Versuche je Snapshot
+retry_delay = 60s                  # Wartezeit vor dem naechsten Versuch
+
+# Pause zwischen zwei Gaesten. Bei vielen VMs auf demselben Storage nimmt das
+# Druck vom Storage-Lock; 0 = ohne Pause.
+pause_between = 0s
+
 # yes = beim Dienststart sofort einen Durchlauf machen,
 # no  = auf den naechsten regulaeren Termin warten.
 run_on_start = no
@@ -35,6 +46,10 @@ run_on_start = no
 # yes = nichts wirklich anlegen/loeschen, nur protokollieren.
 dry_run = no
 
+# Hinweis: Hinter jedem Wert darf ein Kommentar stehen ("keep_time = 7d  # …").
+# Einzige Ausnahme ist "description" - dort bleibt die Zeile unveraendert
+# stehen, damit ein '#' in der Beschreibung erhalten bleibt.
+#
 # Beschreibung, die an jedem Snapshot haengt (in der Proxmox-Oberflaeche
 # sichtbar). Platzhalter:
 #   {group} {group_slug} {vmid} {name} {node} {type} {pool} {tags}

pvesnap/cli.py

@@ -130,8 +130,7 @@ def cmd_run(args):
         print("Zurzeit ist keine Gruppe faellig. (--force erzwingt den Lauf)")
         return 0
 
-    proxmox = Proxmox(dry_run=config.globals.dry_run,
+    proxmox = Proxmox.from_config(config)
-                      task_timeout=config.globals.task_timeout)
     guests = proxmox.inventory()
 
     failed = False
@@ -162,8 +161,7 @@ def cmd_prune(args):
             return 2
         groups.append(group)
 
-    proxmox = Proxmox(dry_run=config.globals.dry_run,
+    proxmox = Proxmox.from_config(config)
-                      task_timeout=config.globals.task_timeout)
     guests = proxmox.inventory()
     failed = False
     with SingleInstanceLock(config.globals.lock_file, wait=600,

pvesnap/config.py

@@ -152,9 +152,18 @@ class GlobalConfig:
     run_on_start: bool = False
     description: str = DEFAULT_DESCRIPTION
     lock_file: str = "/run/pvesnap.lock"
+    retries: int = 2                  # Wiederholungen bei belegten Sperren
+    retry_delay: int = 60             # Wartezeit dazwischen
+    pause_between: int = 0            # Pause zwischen zwei Gaesten
 
     def validate(self):
         problems = []
+        if self.retries < 0:
+            problems.append("[global] 'retries' darf nicht negativ sein")
+        if self.retry_delay < 1:
+            problems.append("[global] 'retry_delay' muss mindestens 1 Sekunde betragen")
+        if self.pause_between < 0:
+            problems.append("[global] 'pause_between' darf nicht negativ sein")
         if not re.match(r"^[A-Za-z][A-Za-z0-9]{0,15}$", self.prefix):
             problems.append("[global] 'prefix' muss mit einem Buchstaben beginnen und darf "
                             "nur Buchstaben/Ziffern enthalten (max. 16 Zeichen)")
@@ -228,6 +237,19 @@ _KEY_ALIASES = {
 }
 
 
+# Kommentar am Zeilenende abschneiden ("keep_time = 7d   # eine Woche").
+# Absichtlich nicht ueber configparser: in Beschreibungs-Vorlagen soll ein '#'
+# erhalten bleiben, deshalb wird dieser Schnitt dort nicht angewandt.
+_INLINE_COMMENT = re.compile(r"\s+[#;].*$", re.DOTALL)
+
+# Schluessel, deren Wert unangetastet bleibt (freier Text).
+_VERBATIM_KEYS = {"description", "description_template"}
+
+
+def _strip_comment(value):
+    return _INLINE_COMMENT.sub("", str(value)).strip()
+
+
 def _canonical_key(key):
     key = key.strip().lower().replace("-", "_")
     return _KEY_ALIASES.get(key, key)
@@ -288,8 +310,9 @@ def _parse_global(section, errors):
     def take(key, parser_fn, target=None):
         if key not in section:
             return
+        raw = section[key] if key in _VERBATIM_KEYS else _strip_comment(section[key])
         try:
-            setattr(result, target or key, parser_fn(section[key]))
+            setattr(result, target or key, parser_fn(raw))
         except ValueError as exc:
             errors.append("[global] %s: %s" % (key, exc))
 
@@ -303,6 +326,9 @@ def _parse_global(section, errors):
     take("task_timeout", lambda v: parse_duration(v, default_unit="s"))
     take("run_on_start", parse_bool)
     take("description", lambda v: str(v).strip())
+    take("retries", lambda v: int(str(v).strip()))
+    take("retry_delay", lambda v: parse_duration(v, default_unit="s"))
+    take("pause_between", lambda v: parse_duration(v, default_unit="s"))
     # Synonyme
     if "description_template" in section:
         result.description = str(section["description_template"]).strip()
@@ -315,7 +341,8 @@ def _parse_global(section, errors):
     for key in section:
         if key not in ("prefix", "check_interval", "state_file", "log_level", "log_file",
                        "lock_file", "dry_run", "task_timeout", "run_on_start", "description",
-                       "description_template", "testlauf"):
+                       "description_template", "testlauf", "retries", "retry_delay",
+                       "pause_between"):
             errors.append("[global] unbekannter Schluessel: %s" % key)
     return result
 
@@ -327,7 +354,7 @@ def _parse_group(name, section, errors):
     def take(key, parser_fn, target=None):
         if key not in section:
             return
-        raw = section[key]
+        raw = section[key] if key in _VERBATIM_KEYS else _strip_comment(section[key])
         try:
             setattr(group, target or key, parser_fn(raw))
         except ValueError as exc:
@@ -456,6 +483,9 @@ def dump_config(config):
     if g.log_file:
         lines.append("log_file = %s" % g.log_file)
     lines.append("task_timeout = %s" % format_duration(g.task_timeout, zero="900s"))
+    lines.append("retries = %d" % g.retries)
+    lines.append("retry_delay = %s" % format_duration(g.retry_delay, zero="60s"))
+    lines.append("pause_between = %s" % format_duration(g.pause_between, zero="0"))
     lines.append("run_on_start = %s" % format_bool(g.run_on_start))
     lines.append("dry_run = %s" % format_bool(g.dry_run))
     lines.append("description = %s" % g.description)

pvesnap/daemon.py

@@ -182,8 +182,7 @@ class Daemon:
             state.save()
             return []
 
-        proxmox = Proxmox(dry_run=config.globals.dry_run,
+        proxmox = Proxmox.from_config(config)
-                          task_timeout=config.globals.task_timeout)
 
         results = []
         # Die Arbeitssperre wird nur waehrend des Laufs gehalten, damit

pvesnap/engine.py

@@ -4,6 +4,7 @@ from __future__ import annotations
 
 import fnmatch
 import logging
+import time
 from dataclasses import dataclass, field
 from datetime import datetime
 
@@ -131,8 +132,16 @@ def run_group(proxmox, config, group, now=None, create=True, prune=True, guests=
 
     snapshot_name = build_name(prefix, group.slug, now)
     template = group.description or config.globals.description
+    pause = config.globals.pause_between
+    first = True
 
     for guest in selected:
+        # Kurz durchatmen zwischen zwei Gaesten - entlastet den Storage-Lock,
+        # wenn viele VMs auf demselben Storage liegen.
+        if pause and not first and not config.globals.dry_run:
+            time.sleep(pause)
+        first = False
+
         if group.skip_stopped and not guest.running:
             result.skipped.append("%s (gestoppt)" % guest.label)
             log.info("Gruppe '%s': %s uebersprungen (gestoppt)", group.name, guest.label)

pvesnap/proxmox.py

@@ -61,12 +61,21 @@ def _pvesh_binary():
 class Proxmox:
     """Zugriff auf die Proxmox-API ueber das Kommando `pvesh`."""
 
-    def __init__(self, dry_run=False, task_timeout=900, command_timeout=60):
+    def __init__(self, dry_run=False, task_timeout=900, command_timeout=60,
+                 retries=2, retry_delay=60):
         self.dry_run = dry_run
         self.task_timeout = task_timeout
         self.command_timeout = command_timeout
+        self.retries = retries
+        self.retry_delay = retry_delay
         self._inventory_cache = None
 
+    @classmethod
+    def from_config(cls, config):
+        globals_ = config.globals
+        return cls(dry_run=globals_.dry_run, task_timeout=globals_.task_timeout,
+                   retries=globals_.retries, retry_delay=globals_.retry_delay)
+
     # -- unterste Ebene ---------------------------------------------------
 
     def _run(self, args, timeout=None):
@@ -159,29 +168,73 @@ class Proxmox:
         if self.dry_run:
             log.info("[TESTLAUF] wuerde Snapshot anlegen: %s -> %s", guest.label, name)
             return None
-        stdout, _ = self._run(args)
+        what = "Snapshot %s fuer %s" % (name, guest.label)
-        return self._wait_task(guest.node, stdout, "Snapshot %s fuer %s" % (name, guest.label))
+        return self._retry(what, lambda: self._task(guest, args, what))
 
     def delete_snapshot(self, guest, name):
         if self.dry_run:
             log.info("[TESTLAUF] wuerde Snapshot loeschen: %s -> %s", guest.label, name)
             return None
-        stdout, _ = self._run(["delete", "%s/%s" % (self._base_path(guest), name)])
+        args = ["delete", "%s/%s" % (self._base_path(guest), name)]
-        return self._wait_task(guest.node, stdout,
+        what = "Loeschen von %s bei %s" % (name, guest.label)
-                               "Loeschen von %s bei %s" % (name, guest.label))
+        return self._retry(what, lambda: self._task(guest, args, what))
+
+    def _task(self, guest, args, what):
+        """Fuehrt eine Snapshot-Aktion aus und wartet, bis sie wirklich fertig ist.
+
+        Wichtig: hier gilt das lange Task-Zeitlimit, nicht das kurze fuer
+        Lesezugriffe. Proxmox wartet beim Anlegen bis zu 60s auf den
+        Storage-Lock; liefen wir vorher in unser eigenes Zeitlimit, wuerde die
+        naechste VM losgeschickt, waehrend der Task noch laeuft - und genau das
+        laesst dann alle folgenden Snapshots am cfs-Lock scheitern.
+        """
+        stdout, _ = self._run(args, timeout=self.task_timeout)
+        return self._wait_task(guest, stdout, what)
+
+    # -- Wiederholung bei belegten Sperren --------------------------------
+
+    # Solche Meldungen sind voruebergehend - da lohnt ein zweiter Versuch.
+    _TRANSIENT = ("cfs-lock", "lock request timeout", "trying to acquire",
+                  "can't lock file", "got lock timeout", "unable to acquire lock",
+                  "resource temporarily unavailable", "storage is locked",
+                  "vm is locked", "ct is locked")
+
+    @classmethod
+    def _is_transient(cls, message):
+        text = str(message).lower()
+        return any(marker in text for marker in cls._TRANSIENT)
+
+    def _retry(self, what, action):
+        attempt = 0
+        while True:
+            try:
+                return action()
+            except ProxmoxError as exc:
+                if attempt >= self.retries or not self._is_transient(exc):
+                    raise
+                attempt += 1
+                log.warning("%s: %s - Versuch %d von %d in %ds",
+                            what, exc, attempt + 1, self.retries + 1, self.retry_delay)
+                time.sleep(self.retry_delay)
 
     # -- Task-Verfolgung --------------------------------------------------
 
-    def _wait_task(self, node, output, what):
+    def _wait_task(self, guest, output, what):
         """pvesh liefert bei Snapshot-Aktionen eine UPID; darauf warten wir."""
         upid = self._extract_upid(output)
         if not upid:
+            # Ohne UPID koennen wir den Task nicht verfolgen - dann warten wir
+            # ersatzweise, bis der Gast nicht mehr gesperrt ist. Sonst wuerde
+            # die naechste Aktion in eine noch laufende hineinlaufen.
+            log.debug("%s: keine UPID in der Antwort von pvesh", what)
+            self._wait_unlocked(guest)
             return None
 
         deadline = time.time() + self.task_timeout
         delay = 0.5
         while True:
-            status = self._json(["get", "/nodes/%s/tasks/%s/status" % (node, upid)]) or {}
+            status = self._json(["get", "/nodes/%s/tasks/%s/status"
+                                 % (guest.node, upid)]) or {}
             if status.get("status") == "stopped":
                 exit_status = status.get("exitstatus") or "unbekannt"
                 if exit_status != "OK":
@@ -193,6 +246,23 @@ class Proxmox:
             time.sleep(delay)
             delay = min(delay * 1.5, 5.0)
 
+    def _wait_unlocked(self, guest, timeout=None):
+        """Wartet, bis der Gast keine laufende Sperre mehr hat."""
+        deadline = time.time() + (timeout or self.task_timeout)
+        path = "/nodes/%s/%s/%d/status/current" % (guest.node, guest.type, guest.vmid)
+        while True:
+            try:
+                status = self._json(["get", path]) or {}
+            except ProxmoxError:
+                return  # lieber weitermachen als haengen bleiben
+            if not status.get("lock"):
+                return
+            if time.time() > deadline:
+                raise ProxmoxError("%s ist seit %ds gesperrt (%s)"
+                                   % (guest.label, timeout or self.task_timeout,
+                                      status.get("lock")))
+            time.sleep(2.0)
+
     @staticmethod
     def _extract_upid(output):
         for line in (output or "").splitlines():

pvesnap/tui.py

@@ -906,6 +906,12 @@ class Editor:
                 ("Zusaetzliche Logdatei", globals_.log_file or "-", "text", "log_file"),
                 ("Zeitlimit je Snapshot-Task", format_duration(globals_.task_timeout),
                  "duration", "task_timeout"),
+                ("Wiederholungen bei belegter Sperre", str(globals_.retries),
+                 "int", "retries"),
+                ("Wartezeit vor Wiederholung", format_duration(globals_.retry_delay),
+                 "duration", "retry_delay"),
+                ("Pause zwischen zwei VMs", format_duration(globals_.pause_between, zero="keine"),
+                 "duration", "pause_between"),
                 ("Beim Start sofort ausfuehren", "ja" if globals_.run_on_start else "nein",
                  "bool", "run_on_start"),
                 ("Testlauf (nichts wirklich tun)", "ja" if globals_.dry_run else "nein",
@@ -950,6 +956,16 @@ class Editor:
                 globals_.log_level = chosen
                 self.dirty = True
             return
+        if kind == "int":
+            raw = self._prompt(win, label, str(getattr(globals_, attribute)))
+            if raw is None:
+                return
+            try:
+                setattr(globals_, attribute, max(0, int(raw.strip() or 0)))
+                self.dirty = True
+            except ValueError:
+                self._message(win, "Bitte eine ganze Zahl eingeben.", error=True)
+            return
         if kind == "duration":
             raw = self._prompt(win, label, format_duration(getattr(globals_, attribute),
                                                            zero="0"))