diff --git a/README.md b/README.md index da5d2cb..8ac5b87 100644 --- a/README.md +++ b/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-`, 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 ``` diff --git a/config/pvesnap.conf.example b/config/pvesnap.conf.example index bfe2c73..1280207 100644 --- a/config/pvesnap.conf.example +++ b/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} diff --git a/pvesnap/cli.py b/pvesnap/cli.py index d407b0b..e9ca155 100644 --- a/pvesnap/cli.py +++ b/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, - task_timeout=config.globals.task_timeout) + proxmox = Proxmox.from_config(config) 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, - task_timeout=config.globals.task_timeout) + proxmox = Proxmox.from_config(config) guests = proxmox.inventory() failed = False with SingleInstanceLock(config.globals.lock_file, wait=600, diff --git a/pvesnap/config.py b/pvesnap/config.py index 8021309..ba6eb21 100644 --- a/pvesnap/config.py +++ b/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) diff --git a/pvesnap/daemon.py b/pvesnap/daemon.py index 3eff233..96d3f72 100644 --- a/pvesnap/daemon.py +++ b/pvesnap/daemon.py @@ -182,8 +182,7 @@ class Daemon: state.save() return [] - proxmox = Proxmox(dry_run=config.globals.dry_run, - task_timeout=config.globals.task_timeout) + proxmox = Proxmox.from_config(config) results = [] # Die Arbeitssperre wird nur waehrend des Laufs gehalten, damit diff --git a/pvesnap/engine.py b/pvesnap/engine.py index 40b0a43..fb4dadf 100644 --- a/pvesnap/engine.py +++ b/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) diff --git a/pvesnap/proxmox.py b/pvesnap/proxmox.py index d977df3..f5fb89d 100644 --- a/pvesnap/proxmox.py +++ b/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) - return self._wait_task(guest.node, stdout, "Snapshot %s fuer %s" % (name, guest.label)) + what = "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)]) - return self._wait_task(guest.node, stdout, - "Loeschen von %s bei %s" % (name, guest.label)) + args = ["delete", "%s/%s" % (self._base_path(guest), name)] + what = "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(): diff --git a/pvesnap/tui.py b/pvesnap/tui.py index 3353e7f..f99faf2 100644 --- a/pvesnap/tui.py +++ b/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"))