From 4eb432ae1a88d3d8a1bb78b841125ac041660fe1 Mon Sep 17 00:00:00 2001 From: Johannes Rest Date: Tue, 15 Sep 2026 10:42:04 +0200 Subject: [PATCH] Bound and retry complete remote readback checks --- Dokumentation.md | 14 ++- README.md | 4 + REMOTE_READBACK.md | 161 +++++++++++++++++++++++++++++++++ SPEICHER.md | 4 + UPDATE_ANLEITUNG.md | 14 +++ etc/app-backup/app-backup.conf | 7 ++ install.sh | 1 + lib/common.sh | 52 ++++++++++- lib/space.sh | 2 +- tests/test_backup.py | 98 +++++++++++++++++++- tools/build-update-package.py | 2 +- usr-local-sbin/app-backup.sh | 2 +- 12 files changed, 353 insertions(+), 8 deletions(-) create mode 100644 REMOTE_READBACK.md diff --git a/Dokumentation.md b/Dokumentation.md index 708c614..5c1a65e 100644 --- a/Dokumentation.md +++ b/Dokumentation.md @@ -59,6 +59,10 @@ Sie gehen nach stderr; Marker und Dateilisten auf stdout bleiben maschinell auswertbar. Alte Konfigurationen erhalten den Intervallstandard automatisch. Eine Anpassung wirkt erst beim nächsten rclone-Prozess. Die bestehende I/O-Leerlauffrist `RCLONE_TIMEOUT="1h"` ist keine Gesamtlaufzeitbegrenzung. +Für vollständige Rücklesevergleiche gelten seit 15.09.2026 eigene kürzere +Leerlauffristen, eine Prozessfrist je Versuch und mehrere vollständige Versuche. +Dort zeigen mehrzeilige Statistiken aktive Prüfungen und ein Ergebnis pro Datei +den tatsächlichen Fortschritt. Details: [Rückleseprüfung](REMOTE_READBACK.md). Beim Betreiberlauf am 10.09.2026 ab 15:30 Uhr wurden die geschützte Kopierphase, Dienstwiederaufnahme und ein vollständiger lokaler Satz bestätigt. Danach meldete @@ -199,7 +203,7 @@ Quelle: [rclone 1.74.3 Inhaltsprüfung](https://github.com/rclone/rclone/blob/v1 | --- | --- | | Vorübergehender Upload-Fehler | rclone wiederholt den Kopierauftrag bis zu `RCLONE_RETRIES=6` Versuche, soweit der Fehler wiederholbar ist; Wartezeit standardmäßig `RCLONE_RETRIES_SLEEP=30s`, zusätzlich gegebenenfalls Provider-Backoff. Kein erneuter DB-Dump oder Writer-Stopp innerhalb dieser Versuche. | | Upload endgültig fehlgeschlagen | Fehlerexit; lokaler vollständiger Satz bleibt erhalten; Staging wird nach erfolgreichem Dienstwiederanlauf bereinigt. Kein neuer Remote-Abschlussmarker und keine nachgelagerte Altersretention. | -| Rückleseprüfung findet andere oder fehlende Inhalte | Fehlerexit; keine Veröffentlichung des Abschlussmarkers. Auch gleich große Dateien werden inhaltlich verglichen. | +| Rückleseprüfung scheitert oder hängt | Bis zu drei vollständige Prüfanläufe, jeweils maximal 3600 Sekunden plus bis zu 10 Sekunden Abbruchfrist, 30 Sekunden Pause dazwischen. Jeder Versuch vergleicht alle ausgewählten Inhalte erneut. Bleibt ein Fehler, Fehlerexit und kein Abschlussmarker. Auch gleich große Dateien werden inhaltlich verglichen. | | Abschlussmarker kann nicht geschrieben oder bestätigt werden | Fehlerexit; kein lokales `UPLOADED`, kein neuer Erfolgsstatus, keine Retention. Der Vergleich prüft die exakten Bytes einschließlich abschließender Zeilenumbrüche, passend zum strikten Restore-Parser. Ist der Marker schon geschrieben und nur seine Bestätigung fehlgeschlagen, kann der Remote-Satz vollständig vorliegen; der Lauf meldet konservativ trotzdem einen Fehler. | | Wiederholungen erfolgreich und Rücklesen bestanden | Remote-Marker wird zuletzt geschrieben und zurückgelesen; erst danach gilt der Upload als erfolgreich. Ein früheres `ERROR` im Log allein ist kein Endergebnis. | | Prozess hängt oder wird abgebrochen | systemd begrenzt den regulären Backup-Dienst auf 12 Stunden, den Update-Auftrag auf 24 Stunden, mit 5 Minuten Stop-Frist. Direkte CLI-/Foreground-Aufrufe besitzen diese systemd-Gesamtfrist nicht. | @@ -215,8 +219,12 @@ serverseitiger WORM-/Ransomware-Schutz gegen andere berechtigte Zugriffe. Die sechs Gesamtversuche gelten nicht pauschal für jeden rclone-Befehl: `check --download` verwendet in rclone 1.74.3 keine Wiederholung des ganzen Befehls, -jedoch Wiederholungen fehlgeschlagener Datei-Leseoperationen. Ein verbleibender -Prüffehler beendet das Backup sichtbar. Quellen: +jedoch Wiederholungen fehlgeschlagener Datei-Leseoperationen. Deshalb verwendet +app-backup jetzt einen eigenen begrenzten Wrapper nur für vollständige +Rücklesevergleiche (Backup und Platzbereinigung). Er greift auch mit alten +Konfigurationen. Die einzelnen Restore-Downloads und Uploads behalten ihre +bisherigen Einstellungen. Ein verbleibender Prüffehler beendet das Backup +sichtbar. Quellen: [Kopierversuche](https://github.com/rclone/rclone/blob/v1.74.3/cmd/cmd.go), [Check-Aufruf](https://github.com/rclone/rclone/blob/v1.74.3/cmd/check/check.go), [Immutable](https://rclone.org/docs/#immutable). diff --git a/README.md b/README.md index e175cdf..26cdd5f 100644 --- a/README.md +++ b/README.md @@ -4,6 +4,10 @@ Sichert WordPress, Nextcloud, native Gitea-Installationen mit MariaDB, Maildaten Die vollständige Analyse, Architektur, Konfiguration, Betriebsanleitung und verbleibenden Grenzen stehen in [Dokumentation.md](Dokumentation.md). +Der [Vorfall vom 15.09.2026 und die korrigierte Rückleseprüfung](REMOTE_READBACK.md) +sind dokumentiert: begrenzte vollständige Prüfanläufe, eigene Zeitlimits, +sichtbare Dateiergebnisse und eindeutiger Hinweis auf erhaltene lokale Archive. + Neu: [Monatlicher Offsite-Restore-Test](RESTORE_TEST.md) mit vollständiger Prüfung aller Komponenten, isoliertem MariaDB-Import und Bereinigung auch bei Fehlern. Für knappen Speicher wird jeweils nur eine Komponente verarbeitet. Das Update diff --git a/REMOTE_READBACK.md b/REMOTE_READBACK.md new file mode 100644 index 0000000..acc570e --- /dev/null +++ b/REMOTE_READBACK.md @@ -0,0 +1,161 @@ +# Rücklesefehler am 15.09.2026 + +## Befund und Grenzen + +Lauf: `appbackup_2026-09-15_00-30-51_ed205bcf` auf Gemini. +Die Laufnamen verwenden UTC: 00:30:51 entspricht 02:30:51 MESZ. Das Ende +06:53:01 MESZ und die gemeldeten 15730 Sekunden (4 h 22 min 10 s) passen zusammen. + +Der übermittelte Bericht zeigt erfolgreiche lokale Archiverstellung und das +Erreichen der Remote-Rückleseprüfung nach dem Kopierauftrag. Das beweist noch +keine erfolgreiche Offsite-Sicherung. Beim Öffnen von `nextcloud-data.tar.zst` +meldet rclone `not an encrypted file - bad magic string`. Der Crypt-Leser hat +keinen gültigen Dateikopf mit der Signatur `RCLONE\0\0` erhalten. Das ist keine +Diagnose eines beschädigten lokalen zstd-Archivs und auch kein eindeutiger +Nachweis falscher Schlüssel. Quelle: +[Crypt-Dateiformat und Headerprüfung](https://github.com/rclone/rclone/blob/v1.74.3/backend/crypt/cipher.go). + +Die Zahlen lassen sich aus dem Bericht nachvollziehen: + +- Die 13 Archive ohne `nextcloud-data.tar.zst` ergeben 1.670.479.162 Bytes, + also 1,555755 GiB. rclone erfasst beim Inhaltsvergleich beide Leseströme: + rund 3,111510 GiB, gerundet die angezeigten **3,112 GiB**; das kleine Manifest + verändert diese Rundung nicht. +- **14 passende Dateien** passen zu diesen 13 Archiven plus `manifest.json`. + `COMPLETE` und `UPLOADED` sind bewusst vom Vergleich ausgeschlossen. +- **0 Unterschiede** und **2 Fehler** widersprechen sich nicht: Ein Lesefehler + ist kein erfolgreich festgestellter Inhaltsunterschied. Die Fehlerzählung + belegt nicht zwei beschädigte Dateien. +- Die Statistik passt damit dazu, dass alle übrigen Dateien fertig waren und + das große Nextcloud-Datenarchiv beim Öffnen hängen blieb. „100 %“ ist hier + kein Fortschritt über alle 6,6 GiB Archive. Quelle: + [rclone 1.74.3 Vergleich, Statistik und Fehlerzählung](https://github.com/rclone/rclone/blob/v1.74.3/fs/operations/check.go). + +Der konkrete Auslöser bleibt offen: ein falsches/beschädigtes gespeichertes +Objekt oder eine vorübergehend falsche Antwort im Downloadpfad sind mögliche +Erklärungen. Der Bericht enthält keine HTTP-Antwort oder frühen Retry-Meldungen, +mit denen sich das unterscheiden ließe. Ein früherer HTTP-409 vom 10.09. ist +kein Beleg für dieselbe Ursache. SSH bestätigte am 15.09. rclone 1.74.3 auf +Rocky 10.2. Die geschützten Originallogs und Archive waren ohne interaktive +sudo-Anmeldung nicht lesbar; eine erneute OneDrive-Prüfung wurde nicht ausgeführt. + +## Was im Code korrigiert wurde + +`rclone check` aktiviert in 1.74.3 keine Wiederholung des gesamten Befehls. +`RCLONE_RETRIES=6` bedeutete daher bisher nicht sechs vollständige Rückleseversuche. +Die gemeinsame Leerlauffrist von einer Stunde und 20 Low-Level-Versuche konnten +lange Wartezeiten begünstigen; aus dem Auszug lässt sich die genaue Folge der +Wartezeiten nicht rekonstruieren. Quellen: +[check-Aufruf](https://github.com/rclone/rclone/blob/v1.74.3/cmd/check/check.go), +[Retry-Steuerung](https://github.com/rclone/rclone/blob/v1.74.3/cmd/cmd.go), +[I/O-Leerlauffrist](https://rclone.org/docs/#timeout-duration). + +Der neue Wrapper gilt für den vollständigen Backup-Rücklesevergleich und die +Offsite-Prüfung vor einer lokalen Platzbereinigung: + +| Einstellung | Default | Bedeutung | +| --- | ---: | --- | +| `RCLONE_CHECK_ATTEMPTS` | 3 | Gesamtzahl vollständiger Versuche, zulässig 1–10 | +| `RCLONE_CHECK_RETRY_DELAY` | 30 | Sekunden Pause, zulässig 0–3600 | +| `RCLONE_CHECK_TIMEOUT` | 300 | Sekunden I/O-Leerlauf, zulässig 1–3600 | +| `RCLONE_CHECK_DEADLINE` | 3600 | Sekunden Prozesslaufzeit je Versuch, zulässig 1–86400 | +| `RCLONE_CHECK_LOW_LEVEL_RETRIES` | 3 | Interne Leseversuche, zulässig 1–20 | + +Die neuen Einstellungen sind Ganzzahlen. Sie gelten auch, wenn sie in einer +alten Konfiguration fehlen. Die Prozessfrist verwendet GNU `timeout` und +bezieht Backend-Wartezeiten mit ein. Nach Fristablauf sendet es TERM, nach +weiteren zehn Sekunden nötigenfalls KILL an die Prozessgruppe. Exit 124 wird +als Fristüberschreitung protokolliert; ein durch Signal beendeter Versuch +(einschließlich KILL nach Ablauf der Abbruchfrist) wird nicht erneut gestartet. +Bei drei normalen Fristüberschreitungen beträgt die maximale Prüfzeit ungefähr +3 Stunden plus zwei Pausen und Abbruchfristen. Die systemd-Gesamtfrist bleibt +zusätzlich wirksam. Für größere Sätze oder begrenzte Bandbreite die Frist +passend zum vollständigen Vergleich erhöhen; ein langsamer, aber intakter +Transfer kann sonst korrekt als nicht abgeschlossen abgebrochen werden. + +Jeder neue Prozess liest sämtliche ausgewählten Dateien erneut. Ein Fehler +wird erst durch einen späteren **vollständigen** erfolgreichen Vergleich +überwunden. Mehrzeilige Statistiken zeigen aktive Prüfungen; pro Datei erscheint +ein Ergebnis (`=` identisch, `!` Lesefehler, `*` unterschiedlich, `+`/`-` fehlend). +Quelle: [rclone-Prüfberichte](https://rclone.org/commands/rclone_check/). + +Bei bleibendem Fehler gibt es keinen neuen Remote-Abschlussmarker, kein lokales +`UPLOADED` und keine nachgelagerte Altersretention. Die lokalen vollständigen +Archive bleiben erhalten. Die bisherige Meldung `Retained work: none` bezog +sich allein auf temporäres Staging; jetzt nennt das Fehlerlog zusätzlich den +erhaltenen lokalen Sicherungssatz. Die Speicherbereinigung entfernt keine +lokale Kopie, deren Offsite-Prüfung scheitert. + +Uploads, einzelne Restore-Downloads und deren Einstellungen bleiben beim +bisherigen Verfahren. Das Update repariert weder ein beschädigtes OneDrive-Objekt +noch veröffentlicht es alte fehlgeschlagene Läufe automatisch. Insbesondere +werden keine Crypt-Schlüssel geändert und keine Inhaltsprüfungen abgeschwächt. + +## Den betroffenen Satz prüfen + +Auf Gemini zunächst den vorhandenen lokalen Satz ohne zusätzliche Archivkopie +prüfen; dabei werden keine Anwendungsdaten verändert: + +```bash +sudo /usr/local/sbin/app-restore.sh \ + --local-run /var/backups/app-backup/archives/appbackup_2026-09-15_00-30-51_ed205bcf \ + --verify-only +``` + +Eine erneute rein lesende Offsite-Prüfung ist auch ohne Remote-`COMPLETE` +möglich. Der folgende **einmalige Diagnosevergleich** lädt die Inhalte als +Stream, schreibt keine Archive auf Platte und veröffentlicht keinen Marker. +Er nutzt die gemeinsame Standardsperre; bei angepasstem `LOCKFILE` und +`RCLONE_CONFIG` die tatsächlichen Pfade einsetzen. Exit 0 bestätigt nur diesen +Vergleich, Exit 124 einen Timeout. Während laufender Backup-/Restore-/Update-Jobs +wird die Sperre nicht übernommen: + +```bash +sudo flock -n /run/app-backup.lock timeout --kill-after=10s 3600s \ + rclone --ask-password=false --config /root/.config/rclone/rclone.conf \ + check /var/backups/app-backup/archives/appbackup_2026-09-15_00-30-51_ed205bcf \ + OneDriveCrypt:gemini/appbackup_2026-09-15_00-30-51_ed205bcf \ + --download --exclude /COMPLETE --exclude /UPLOADED \ + --timeout 300s --contimeout 30s --low-level-retries 3 \ + --stats 1m --stats-log-level NOTICE --combined - +``` + +Schlägt derselbe Header erneut fehl, den lokalen Satz erhalten und die +vollständigen Logs, betroffene Datei und rclone-Version für die weitere +Provideranalyse verwenden. Ein einzelner weiterer Fehlschlag beweist noch nicht, +dass das gespeicherte Objekt dauerhaft beschädigt ist. Keine Zugangsdaten, +`config show`-Ausgaben oder HTTP-Dumps mit Tokens weitergeben. + +## Deployment und Abnahme + +Das aus dem Commit gebaute `.run`-Paket mit `.sha256` übertragen und im +Wartungsfenster starten; konkrete Schritte stehen in +[UPDATE_ANLEITUNG.md](UPDATE_ANLEITUNG.md). Der Installer erhält Konfiguration +und Zugangsdaten, erstellt Rollback-Dateien und führt ein neues Backup mit +anschließender separater Restore-Prüfung aus. Dadurch entsteht ein neuer +Sicherungssatz; der oben untersuchte bleibt als fehlgeschlagener Lauf erkennbar. + +Für die Abnahme müssen `result.txt` **SUCCESS**, der neue Backupstatus Exit 0 +und das Log `Remote backup fully read back and verified` zeigen. Im Rückleselog +müssen alle Dateien erfolgreich geprüft worden sein. Der Backup-Timer wird +erst nach erfolgreicher Update-Abnahme aktiviert. Der konkrete Rollback-Pfad +steht im Update-Ergebnisordner (`rollback-update.sh`); bei einem Rollback +kehren auch die bisherigen Grenzen der Rückleseprüfung zurück. + +Regressionstests verwenden echte lokale Crypt-Transfers, tar/zstd und isolierte +MariaDB. Sie prüfen vorübergehende Fehler, echte beschädigte Crypt-Dateiköpfe, +bleibende Fehler, Fristablauf mit Wiederholung, Signalabbruch, erhaltene lokale +Sätze und das Zurückhalten von Abschlussmarkern. systemd und Providerfehler +werden simuliert; ein erfolgreicher lokaler Test belegt keine OneDrive-Abnahme. + +Validierung am 15.09.2026: + +- `tests/run.sh` im netzlosen Testcontainer: Bash-Syntax und ShellCheck erfolgreich; + 106 Tests entdeckt, 101 bestanden, fünf optionale Docker-in-Docker-Tests + ausgelassen. Crypt-Transfers mit rclone 1.60.1-DEV, echte lokale MariaDB ohne TCP. +- Acht gezielte Integrationstests zusätzlich mit der lesend von Gemini kopierten + rclone-1.74.3-Binärdatei: alle bestanden. Darunter vorübergehender Lesefehler, + beschädigter Crypt-Header, Fristablauf mit erneutem Erfolg, dauerhafter Stillstand, + Signalabbruch, gleich große Inhaltsbeschädigung, geschützte Platzbereinigung + sowie Paketinstallation und kombiniertes Rollback. +- Das Produktionssystem wurde nicht verändert; die OneDrive-Abnahme steht aus. diff --git a/SPEICHER.md b/SPEICHER.md index 6f4391e..9182526 100644 --- a/SPEICHER.md +++ b/SPEICHER.md @@ -34,6 +34,10 @@ oder der Update-Vorbereitung werden folgende Schritte ausgeführt: Kopie entfernt. Ein nicht mehr lesbarer oder veränderter Remote-Satz bleibt lokal erhalten. Es wird nur so lange bereinigt, bis der geplante Platz reicht. +Diese Offsite-Vergleiche verwenden ebenfalls die begrenzten Prüfanläufe und +Zeitlimits aus [REMOTE_READBACK.md](REMOTE_READBACK.md). Ein fehlgeschlagener +Vergleich erlaubt auch nach mehreren Versuchen keine lokale Löschung. + Die Platzbereinigung benötigt keinen vorherigen neuen Sicherungslauf. Sie darf das lokale Aufbewahrungsalter unterschreiten, **niemals die Mindestanzahl**. Sie verändert keine Offsite-Daten. Die normale Altersretention nach einem neuen diff --git a/UPDATE_ANLEITUNG.md b/UPDATE_ANLEITUNG.md index 9b0729a..9034a8b 100644 --- a/UPDATE_ANLEITUNG.md +++ b/UPDATE_ANLEITUNG.md @@ -1,5 +1,19 @@ # Automatisches Update-Paket +## Korrektur vom 15.09.2026: hängende Rückleseprüfung + +Das aktuelle Paket ergänzt drei vollständige Rückleseversuche mit eigenen +Zeitlimits und Dateiergebnissen. Bestehende Konfigurationen erhalten die neuen +Defaults automatisch; `RCLONE_TIMEOUT="1h"` für sonstige rclone-Aufrufe wird +dabei nicht umgeschrieben. Analyse, Grenzwerte und Prüfung des fehlgeschlagenen +Satzes stehen in [REMOTE_READBACK.md](REMOTE_READBACK.md). + +Das Paket wie unten beschrieben im Wartungsfenster starten. Ein bereits +aktivierter monatlicher Restore-Test bleibt aktiv und wird bei der Abnahme +ausgeführt. Für diese Korrektur ist `--enable-restore-test` nicht zusätzlich nötig. +Erst `SUCCESS` in `result.txt` bestätigt die gesamte Abnahme. Der fehlgeschlagene +Satz vom 15.09. wird durch die Installation nicht nachträglich veröffentlicht. + ## Neu: monatlicher Restore-Test Das Paket enthält jetzt den automatischen vollständigen Offsite-Restore-Test. diff --git a/etc/app-backup/app-backup.conf b/etc/app-backup/app-backup.conf index 4abe83f..81c5d3b 100644 --- a/etc/app-backup/app-backup.conf +++ b/etc/app-backup/app-backup.conf @@ -31,6 +31,13 @@ RCLONE_TIMEOUT="1h" RCLONE_CONTIMEOUT="30s" # Periodic transfer/check statistics in journald, including otherwise quiet uploads. RCLONE_STATS_INTERVAL="1m" +# Full readback attempts, independent of upload retries. All times are seconds. +# Deadline includes backend waits; raise it for larger/slower full comparisons. +RCLONE_CHECK_ATTEMPTS=3 +RCLONE_CHECK_RETRY_DELAY=30 +RCLONE_CHECK_TIMEOUT=300 +RCLONE_CHECK_DEADLINE=3600 +RCLONE_CHECK_LOW_LEVEL_RETRIES=3 RCLONE_TRANSFERS=2 RCLONE_CHECKERS=4 # OneDrive chunks must be multiples of 320 KiB; 80 MiB satisfies this. diff --git a/install.sh b/install.sh index ef9a11f..96e12b9 100755 --- a/install.sh +++ b/install.sh @@ -85,6 +85,7 @@ add Dokumentation.md /usr/local/share/doc/app-backup/Dokumentation.md 644 add UPDATE_ANLEITUNG.md /usr/local/share/doc/app-backup/UPDATE_ANLEITUNG.md 644 add RESTORE_TEST.md /usr/local/share/doc/app-backup/RESTORE_TEST.md 644 add SPEICHER.md /usr/local/share/doc/app-backup/SPEICHER.md 644 +add REMOTE_READBACK.md /usr/local/share/doc/app-backup/REMOTE_READBACK.md 644 # Save the exact replaced files plus a rollback inventory; do not dereference links. : > "$SNAPSHOT/present.txt"; : > "$SNAPSHOT/absent.txt" for i in "${!TARGETS[@]}"; do diff --git a/lib/common.sh b/lib/common.sh index cb3f167..ed68e18 100644 --- a/lib/common.sh +++ b/lib/common.sh @@ -33,6 +33,8 @@ load_config() { : "${RCLONE_RETRIES:=6}" "${RCLONE_LOW_LEVEL_RETRIES:=20}" : "${RCLONE_RETRIES_SLEEP:=30s}" "${RCLONE_TIMEOUT:=1h}" "${RCLONE_CONTIMEOUT:=30s}" : "${RCLONE_STATS_INTERVAL:=1m}" + : "${RCLONE_CHECK_ATTEMPTS:=3}" "${RCLONE_CHECK_RETRY_DELAY:=30}" + : "${RCLONE_CHECK_TIMEOUT:=300}" "${RCLONE_CHECK_DEADLINE:=3600}" "${RCLONE_CHECK_LOW_LEVEL_RETRIES:=3}" : "${RCLONE_TRANSFERS:=2}" "${RCLONE_CHECKERS:=4}" "${RCLONE_ONEDRIVE_CHUNK_SIZE:=80Mi}" : "${RCLONE_BWLIMIT:=0}" "${ENABLE_MAIL_REPORT:=true}" "${MAIL_TO:=johannes}" # Keep the old report settings; an empty sender uses app-backup@. @@ -71,6 +73,12 @@ load_config() { [[ ${!v} =~ ^(0|[1-9][0-9]*)$ ]] || die "$v must be a non-negative integer" done (( RETENTION_KEEP_LAST >= 2 )) || die "RETENTION_KEEP_LAST must be >= 2" + # Seconds/counts only: never permit disabled deadlines or unbounded retries. + for v in RCLONE_CHECK_ATTEMPTS RCLONE_CHECK_LOW_LEVEL_RETRIES RCLONE_CHECK_TIMEOUT RCLONE_CHECK_DEADLINE RCLONE_CHECK_RETRY_DELAY; do + [[ ${!v} =~ ^(0|[1-9][0-9]{0,5})$ ]] || die "$v must be a bounded integer" + done + (( RCLONE_CHECK_ATTEMPTS >= 1 && RCLONE_CHECK_ATTEMPTS <= 10 && RCLONE_CHECK_LOW_LEVEL_RETRIES >= 1 && RCLONE_CHECK_LOW_LEVEL_RETRIES <= 20 )) || die 'Invalid readback retry limits' + (( RCLONE_CHECK_TIMEOUT >= 1 && RCLONE_CHECK_TIMEOUT <= 3600 && RCLONE_CHECK_DEADLINE >= 1 && RCLONE_CHECK_DEADLINE <= 86400 && RCLONE_CHECK_RETRY_DELAY <= 3600 )) || die 'Invalid readback time limits' (( MIN_FREE_GB <= 1000000 )) || die 'MIN_FREE_GB must not exceed 1000000' (( ZSTD_LEVEL >= 1 && ZSTD_LEVEL <= 19 && ZSTD_THREADS >= 1 )) || die "Invalid zstd settings" [[ $ARCHIVE_PREFIX =~ ^[a-zA-Z0-9][a-zA-Z0-9_-]*$ ]] || die "Unsafe ARCHIVE_PREFIX" @@ -259,6 +267,7 @@ check_space() { check_remote() { need "$RCLONE_BIN" + need timeout [[ $RCLONE_REMOTE_BASE =~ ^[a-zA-Z0-9_-]+:[^:]+$ ]] || die "Use a named crypt remote with a dedicated non-empty path" [[ $RCLONE_REMOTE_BASE != *$'\n'* ]] || die "Invalid remote path" secure_file "$RCLONE_CONFIG" @@ -278,6 +287,7 @@ check_remote() { case $key in RCLONE_BIN|RCLONE_CONFIG|RCLONE_CONFIG_PASS|RCLONE_REMOTE_BASE|RCLONE_RETRIES|\ RCLONE_LOW_LEVEL_RETRIES|RCLONE_RETRIES_SLEEP|RCLONE_TIMEOUT|RCLONE_CONTIMEOUT|\ + RCLONE_CHECK_ATTEMPTS|RCLONE_CHECK_RETRY_DELAY|RCLONE_CHECK_TIMEOUT|RCLONE_CHECK_DEADLINE|RCLONE_CHECK_LOW_LEVEL_RETRIES|\ RCLONE_STATS_INTERVAL|RCLONE_TRANSFERS|RCLONE_CHECKERS|RCLONE_ONEDRIVE_CHUNK_SIZE|RCLONE_BWLIMIT) ;; *) die "Unsupported rclone environment override: $key; use documented app-backup settings and the remote config" ;; esac @@ -298,6 +308,38 @@ check_remote() { # by callers. NOTICE makes periodic progress visible without verbose HTTP logs. rc() { "$RCLONE_BIN" "${RCLONE_ARGS[@]}" "$@"; } +remote_readback() { + local attempt code=1 + # rclone check uses cmd.Run(false, ...): --retries does NOT repeat the whole + # check. A fresh process also refreshes backend/download state after failures. + # Always recheck every file; never turn a partial match report into success. + for ((attempt=1; attempt<=RCLONE_CHECK_ATTEMPTS; attempt++)); do + echo "-- Remote readback attempt $attempt/$RCLONE_CHECK_ATTEMPTS (deadline ${RCLONE_CHECK_DEADLINE}s, idle ${RCLONE_CHECK_TIMEOUT}s)" + # GNU timeout bounds backend pacing/retries as well as stalled I/O. It owns + # a process group so TERM/KILL cannot leave an old check running on retry. + # Multiline stats expose active checks; byte totals alone can say 100% while + # a crypt header is still pending. Combined output names each check result. + if timeout --kill-after=10s "${RCLONE_CHECK_DEADLINE}s" \ + "$RCLONE_BIN" "${RCLONE_ARGS[@]}" check "$@" --download \ + --timeout "${RCLONE_CHECK_TIMEOUT}s" --low-level-retries "$RCLONE_CHECK_LOW_LEVEL_RETRIES" \ + --stats-one-line=false --stats-one-line-date=false --combined -; then + echo "-- Remote readback attempt $attempt passed (all selected files)" + return 0 + else + code=$? + fi + echo "WARNING: Remote readback attempt $attempt/$RCLONE_CHECK_ATTEMPTS failed (exit $code; 124 means deadline exceeded)" + # Preserve cancellation semantics, including a forced kill after the grace + # period. Do not restart a command an operator/service manager has stopped. + if (( code >= 128 )); then return "$code"; fi + if (( attempt < RCLONE_CHECK_ATTEMPTS )); then + sleep "$RCLONE_CHECK_RETRY_DELAY" || return $? + fi + done + echo 'ERROR: Remote readback exhausted; remote contents remain unverified' + return "$code" +} + # Exclusions are rooted so a nested directory named data is not accidentally lost. exclusions() { EXCLUDES=() @@ -517,7 +559,15 @@ finish() { elif [[ ( $code == 0 || ( $OPERATION == restore && ${MODE:-} == verify ) ) && -n ${STAGING_DIR:-} ]]; then rm -rf -- "$STAGING_DIR" && STAGING_DIR='' || code=1 fi - if [[ $code != 0 ]]; then echo "FAILED (exit $code). Retained work: ${STAGING_DIR:-none}"; fi + if [[ $code != 0 ]]; then + echo "FAILED (exit $code). Retained work: ${STAGING_DIR:-none} (temporary staging only)" + if [[ $OPERATION == backup && -n ${RUN_DIR:-} && -f $RUN_DIR/COMPLETE ]]; then + echo "Retained local backup: $RUN_DIR" + if [[ $ENABLE_UPLOAD == true && ! -f $RUN_DIR/UPLOADED ]]; then + echo 'Remote publication not confirmed; local backup retained for recovery.' + fi + fi + fi # Close the logger's writers and wait for EOF so the mail tail includes the # final recovery/status messages. Reporting itself uses the original stdout. exec 1>&"$REPORT_STDOUT" 2>&"$REPORT_STDERR" diff --git a/lib/space.sh b/lib/space.sh index 0cf9fa8..f48ea40 100644 --- a/lib/space.sh +++ b/lib/space.sh @@ -21,7 +21,7 @@ ensure_space() { [[ -z ${LOCAL_RUN:-} || $(realpath -m "$LOCAL_RUN") != "$dir" ]] || continue echo "-- Space recovery: verifying offsite copy before local removal: $name" if helper verify "$dir" >/dev/null && - rc check "$dir" "${RCLONE_REMOTE_BASE%/}/$name" --download --exclude /UPLOADED; then + remote_readback "$dir" "${RCLONE_REMOTE_BASE%/}/$name" --exclude /UPLOADED; then python3 "$LIB_DIR/space.py" remove "$dir" echo "-- Space recovery: removed local copy $name; verified offsite copy retained" else diff --git a/tests/test_backup.py b/tests/test_backup.py index 75e991b..42e5c99 100644 --- a/tests/test_backup.py +++ b/tests/test_backup.py @@ -217,6 +217,7 @@ COMPRESSOR=zstd ENABLE_UPLOAD=false ENABLE_MAIL_REPORT=false ENABLE_REMOTE_RETENTION=false +RCLONE_CHECK_RETRY_DELAY=0 ENABLE_WORDPRESS=true WP_DIR='{self.wp}' ENABLE_NEXTCLOUD=true @@ -1178,12 +1179,100 @@ REPORT_SECRET='config-content-must-not-enter-the-mail' def test_failed_readback_does_not_publish_remote_marker(self): self.crypt_config() - self.run_script('app-backup.sh',ok=False,TEST_FAIL_CHECK='true') + result=self.run_script('app-backup.sh',ok=False,TEST_FAIL_CHECK='true') + self.assertEqual(result.returncode,43) + self.assertIn('attempt 3/3 failed',result.stdout) run=next((self.base/'work/archives').glob('appbackup_*')) + self.assertIn('Retained local backup: '+str(run),result.stdout) + HELPER.load_set(run) self.assertFalse((run/'UPLOADED').exists()) proc=subprocess.run(['/usr/bin/rclone','--config',str(self.base/'rclone.conf'),'cat',f'crypt:sets/{run.name}/COMPLETE'],capture_output=True) self.assertNotEqual(proc.returncode,0) + def inject_readback_failure(self, mode): + # The first check fails/stalls before real crypt I/O. Subsequent checks + # use real rclone; event order proves COMPLETE was withheld until success. + wrapper=self.bin/'rclone' + wrapper.write_text('''#!/usr/bin/env python3 +import os, pathlib, subprocess, sys, time +args=sys.argv[1:] +events=pathlib.Path(os.environ['TEST_EVENTS']) +if 'check' in args: + with events.open('a') as log: log.write('readback-check\\n') + count=events.read_text().count('readback-check') + mode=os.environ['TEST_READBACK_MODE'] + if mode=='signal': sys.exit(143) + if mode=='hang' or (mode=='hang-once' and count==1): time.sleep(30) + if mode=='fail-once' and count==1: + print('not an encrypted file - bad magic string',file=sys.stderr) + sys.exit(1) +if 'copyto' in args: + with events.open('a') as log: log.write('publish-marker\\n') +sys.exit(subprocess.call(['/usr/bin/rclone',*args])) +''') + wrapper.chmod(0o755) + self.env['TEST_READBACK_MODE']=mode + + def test_transient_readback_error_rechecks_before_publishing(self): + self.crypt_config() + self.inject_readback_failure('fail-once') + result=self.run_script('app-backup.sh') + self.assertIn('attempt 2 passed',result.stdout) + events=self.events.read_text() + self.assertEqual(events.count('readback-check'),2) + self.assertLess(events.rindex('readback-check'),events.index('publish-marker')) + run=next((self.base/'work/archives').glob('appbackup_*')) + self.assertTrue((run/'UPLOADED').exists()) + self.run_script('app-restore.sh','--remote-run',run.name,'--verify-only') + + def test_stalled_readback_is_terminated_then_retried(self): + self.crypt_config() + self.inject_readback_failure('hang-once') + with self.config.open('a') as f: f.write('RCLONE_CHECK_DEADLINE=2\n') + result=self.run_script('app-backup.sh') + self.assertIn('exit 124',result.stdout) + self.assertIn('attempt 2 passed',result.stdout) + + def test_persistent_stall_is_bounded_and_preserves_local_backup(self): + self.crypt_config() + self.inject_readback_failure('hang') + with self.config.open('a') as f: f.write('RCLONE_CHECK_DEADLINE=1\nRCLONE_CHECK_ATTEMPTS=2\n') + started=time.monotonic() + result=self.run_script('app-backup.sh',ok=False) + self.assertLess(time.monotonic()-started,20) + self.assertEqual(result.returncode,124) + self.assertEqual(self.events.read_text().count('readback-check'),2) + self.assert_remote_failure_retained(result) + + def test_cancelled_readback_is_not_retried(self): + self.crypt_config() + self.inject_readback_failure('signal') + result=self.run_script('app-backup.sh',ok=False) + self.assertEqual(result.returncode,143) + self.assertEqual(self.events.read_text().count('readback-check'),1) + self.assert_remote_failure_retained(result) + + def test_readback_limits_reject_unbounded_or_invalid_values(self): + for key,value in [('RCLONE_CHECK_ATTEMPTS','0'),('RCLONE_CHECK_ATTEMPTS','11'), + ('RCLONE_CHECK_DEADLINE','0'),('RCLONE_CHECK_DEADLINE','1h'), + ('RCLONE_CHECK_TIMEOUT','0'),('RCLONE_CHECK_LOW_LEVEL_RETRIES','0'), + ('RCLONE_CHECK_RETRY_DELAY','-1')]: + with self.subTest(key=key,value=value): + original=self.config.read_text() + self.config.write_text(original+f'\n{key}={value}\n') + try: + self.run_script('app-backup.sh','--check',ok=False) + self.assertNotIn('systemctl stop',self.events.read_text()) + finally: + self.config.write_text(original) + + def test_invalid_crypt_header_stays_failed_after_retries(self): + self.crypt_config() + result=self.remote_failure('bad-header') + self.assertIn('bad magic string',result.stdout) + self.assertIn('attempt 3/3 failed',result.stdout) + self.assert_remote_failure_retained(result) + def remote_failure(self, mode, **env): # Keep real crypt transfers. Inject errors at the command boundary, not # a pretend OneDrive server: provider retry behaviour is checked separately. @@ -1210,6 +1299,13 @@ if 'copy' in args: if mode=='upload': # Models an unsuccessful command even though the remote received bytes. sys.exit(44) + if mode=='bad-header': + # Damage the real encrypted header in place without changing object size. + from pathlib import Path + root=Path(os.environ['TEST_EVENTS']).parent/'encrypted' + for path in root.rglob('*'): + if path.is_file(): + with path.open('r+b') as f: f.write(b'BADMAGIC') if mode=='corrupt': config=args[args.index('--config')+1] remote=args[args.index('copy')+2]+'/wordpress.tar.zst' diff --git a/tools/build-update-package.py b/tools/build-update-package.py index f9eb321..9767df8 100644 --- a/tools/build-update-package.py +++ b/tools/build-update-package.py @@ -15,7 +15,7 @@ FILES = ['install.sh', 'update.sh', 'README.md', 'Dokumentation.md', 'UPDATE_ANL 'usr-local-sbin/app-backup.sh', 'usr-local-sbin/app-restore.sh', 'systemd/app-backup.service', 'systemd/app-backup.timer', 'logrotate/app-backup', 'etc/app-backup/app-backup.conf'] -FILES += ['RESTORE_TEST.md', 'SPEICHER.md', 'usr-local-sbin/app-restore-test.sh', 'lib/restore_test.py', 'lib/restore-test-remote.sh', +FILES += ['RESTORE_TEST.md', 'SPEICHER.md', 'REMOTE_READBACK.md', 'usr-local-sbin/app-restore-test.sh', 'lib/restore_test.py', 'lib/restore-test-remote.sh', 'lib/space.sh', 'lib/space.py', 'lib/prepare-restore-test.sh', 'systemd/app-restore-test.service', 'systemd/app-restore-test.timer', 'systemd/app-restore-test-cleanup.service'] diff --git a/usr-local-sbin/app-backup.sh b/usr-local-sbin/app-backup.sh index 282cc2c..328e36a 100755 --- a/usr-local-sbin/app-backup.sh +++ b/usr-local-sbin/app-backup.sh @@ -120,7 +120,7 @@ if [[ $ENABLE_UPLOAD == true ]]; then rc copy "$RUN_DIR" "$remote_run" --exclude /COMPLETE --exclude /UPLOADED --immutable echo '-- Remote upload finished; reading all uploaded files back for verification' BACKUP_PHASE='Remote-Rückleseprüfung'; UPLOAD_STATUS=CHECK - rc check "$RUN_DIR" "$remote_run" --download --exclude /COMPLETE --exclude /UPLOADED + remote_readback "$RUN_DIR" "$remote_run" --exclude /COMPLETE --exclude /UPLOADED echo '-- Remote readback passed; publishing completion marker' BACKUP_PHASE='Remote-Abschlussmarker'; UPLOAD_STATUS=MARKER rc copyto "$RUN_DIR/COMPLETE" "$remote_run/COMPLETE" --immutable