PBS 2.4-1: Ein fehlerhaftes Backup macht alle Backups einer VM unbrauchbar.

Der Punkt war mir noch nicht bekannt, danke für den Hinweis. Nach dem Reverifizieren, wird das Bild klarer aber leider nicht verständlicher.
Jetzt kann kein einziges Backup mehr verifiziert werden. Es fehlen sehr viele Chunks. Das ist der Teil der Klarer ist. Wieso dem so ist, das verstehe ich allerdings immer noch nicht.
Die Retension Zeit der Backups ist noch nicht abgelaufen, der Purge-Job dürfte somit nichts als gelöscht makiert haben und das die Chunks durch ein korruptes Filesystem verschwunden sind ist nahezu ausgeschlossen, das FS läuft auf einem Isilon OneFS Cluster.
 
Hm, eine Idee: Der purge löscht ja alles, was über einen Tag lang nicht angefaßt wurde. Deswegen schaut sich der garbage collector vorher an, welche chunks noch von Backups referenziert werden, und geht bei denen dann mit touch bei. Wenn nun Dein nfs abgeraucht ist, bevor die Metadatenänderung dieser touches auf der Platte gelandet ist, und dann gerade rechtzeitig zum zweiten Teil, wo er alles unge-touch-te abräumt, wieder da war ...
 
Du meinst also sowas wie eine Race-Kondition, möglich. Nach dem Reverify ergibt sich zumindest insofern ein stimmigeres Bild warum ich keine Restore durchführen kann. Wenn alle Backups fehlerhaft sind vermundert das nicht.
Das Reverify wird im Produktivbetrieb öfter, vielleicht täglich laufen um Probleme schnell zu erkennen.

Ich werden mich nochmal mit unserem Team zusammensetzten um weiter zu erforschen was auf der Storage Seite genau passiert ist. Das Bild ist für mich jetzt konsistent genug um meine Eingangsfrage als Beantwortet zu sehen.

Danke an Dich und natürlich auch an Fabian für die Hilfe.

Grüße Ariston
 
Nicht ganz race, mehr ein Folge-Fehler, weil ja ein "echter" Fehler, der bereits zum Verlust von (Meta-)Daten geführt hat, zugrundeliegt, aber ähnlich genug. Existieren irgendwo noch Logs von der GC/Prune?
 
Hm, eine Idee: Der purge löscht ja alles, was über einen Tag lang nicht angefaßt wurde. Deswegen schaut sich der garbage collector vorher an, welche chunks noch von Backups referenziert werden, und geht bei denen dann mit touch bei. Wenn nun Dein nfs abgeraucht ist, bevor die Metadatenänderung dieser touches auf der Platte gelandet ist, und dann gerade rechtzeitig zum zweiten Teil, wo er alles unge-touch-te abräumt, wieder da war ...
Soweit ich das veratanden habe löscht das Prune nur die Index Dateien, welche die Chunks referenzieren. Der GC geht dann alle Index Dateien durch, toucht dann dessen referenzierte Chunks in der ersten Phase und geht dann in der zweiten Phase einfach alle Chunks durch und löscht alles, was 24h+5min nicht getoucht wurde.

Dann wäre die Frage, ob gerade ein GC in Phase 1 lief, als der NFS Share ausgefallen ist, dass da nicht alle Chunks getoucht werden konnten und Phase 2 zu viel gelöscht hat.
Aber ich vermute, für so einen Fall wird das Proxmox Team schon eine Prüfung eingebaut haben, dass da Phase 2 nicht ausgeführt wirdm wenn Phase 1 nicht erfolgreich abgeschlossen werden konnte?
 
Last edited:
Soweit ich das veratanden habe löscht das Prune nur die Index Dateien, welche die Chunks referenzieren. Der GC geht dann alle Index Dateien durch, toucht dann dessen referenzierte Chunks in der ersten Phase und geht dann in der zweiten Phase einfach alle Chunks durch und löscht alles, was 24h+5min nicht getoucht wurde.

genau.
prune == logisches loeschen auf backup/snapshot meta ebene
GC == tatsaechliches loeschen nicht mehr benoetigter daten (mittels "mark & sweep" -> erst wird "markiert" was noch referenziert wird, dann wird geloescht was nicht markiert worden ist)

Dann wäre die Frage, ob gerade ein GC in Phase 1 lief, als der NFS Share ausgefallen ist, dass da nicht alle Chunks getoucht werden konnten und Phase 2 zu viel gelöscht hat.
Aber ich vermute, für so einen Fall wird das Proxmox Team schon eine Prüfung eingebaut haben, dass da Phase 2 nicht ausgeführt wirdm wenn Phase 1 nicht erfolgreich abgeschlossen werden konnte?
ja, wenn in phase 1 ein problem auftritt wird die GC natuerlich abgebrochen, weil eine unvollstaendige markierung ein loeschen von moeglicherweise noch benoetigten daten nach sich ziehen wuerde. es gibt eine einzige ausnahme - wenn das auflisten der indizes noch problemlos funktioniert hat, aber der index nachher nicht mehr existiert, dann wird das ignoriert (weil ein paralleles loeschen von indizes ja kein fehler ist - sonst muessten wir fuer die gesamte dauer der GC keinerlei prunes erlauben..). das betrifft aber wirklich nur den fehler dass die datei nicht mehr existiert. bei einem totalausfall des storages gibts zwei moeglichkeiten:
- er blockiert (dann gibts kein not found, also auch kein ueberspringen dieser indizes)
- er ist unmounted (dann gibts ein not found, aber auch keine chunks die geloescht werden koennen)

wir braeuchten also folgendes "race" und fehlerverhalten (gegen das PBS auch nichts tun kann - wenn der datastore von normal auf leer auf voll springt ohne irgendwelche fehler zu schmeissen ist dass definitiv schuld des storages!):
- mark phase beginnt
- listing der indizes geht noch ohne fehler
- storage faellt so aus, dass storage noch lesbar ist, aber indizes "verschwunden" sind
- mark phase fertig (hat zuwenig markiert)
- sweep phase beginnt
- storage wieder da
- chunks sind jetzt sichtbar, wurden aber nicht markiert, daher werden sie geloescht
- sweep fertig

in jedem fall sollte das ersichtlich sein, falls eine GC gemacht worden ist (im Log steht ja, wieviel "garbage" entfernt worden ist ;)). falls GC gelaufen ist, bitte die logs von allen GC tasks anhaengen.
 
  • Like
Reactions: Dunuin
Hallo
ich habe ein paar Logs gefunden und angehängt. Als gzip, weil mein Mac sonst keine Meinung auf die Dateinamen hatte. In denen musste ich auch das '\' durch ein '_' ersetzen.
Das VerificationCollection Log sind nur die ersten 200 Zeilen, die anderen 35522 sahen ziemlich gleich aus.

Der GC run am 6.5/7.5. hat ordentlich aufgeräumt, nur leider wohl zu ordentlich. Der GC run am 14.5. fand dann ganz viele Chunks nicht mehr, die offensichtlich noch referenziert waren.

Grüße Ariston
 

Attachments

  • UPID:pbackup:00000320:000004EB:0000005E:64600734:garbage_collection:pbackup_x2dnfs:root@pam:.gz
    802.6 KB · Views: 2
  • UPID:pbackup:00000320:000004EB:00000019:6456CDE0:verificationjob:pbackup_x2dnfs_x3av_x2d705a25c...gz
    7.9 KB · Views: 1
  • UPID:pbackup:00000320:000004EB:00000018:6456CCB4:garbage_collection:pbackup_x2dnfs:root@pam:.gz
    1.9 KB · Views: 1
  • UPID:pbackup:00000320:000004EB:00000017:6456A416:backup:pbackup_x2dnfs_x3avm-667:pbackup-user@p...gz
    713 bytes · Views: 1
die beiden GC runs haben ungefaehr gleich viel entfernt (ca 80k chunks, ca 160GB chunk daten), dass sieht fuer mich eher nach regulaerem pruning aus? aber schwer zu sagen, zumindest sind beim ersten GC (die ja nach dem storage problem war?) keine storage bezogenen fehler gelogged..

waren dass die einzigen beiden GCs die je gelaufen sind? wenn die task listen noch vollstaendig sind, muesste sich ja auch die anzahl der indizes verifizieren lassen..
 
Ein weiteren Lauf vom 20.5. gibt es noch, der hat allerdings gepackt 27 MB ob das Zielführend ist? Ich paste mal die ersten Zeilen.

2023-05-20T23:55:00+02:00: starting garbage collection on store pbackup-nfs
2023-05-20T23:55:00+02:00: task triggered by schedule 'sat 23:55'
2023-05-20T23:55:00+02:00: Start GC phase1 (mark used chunks)
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk aceb0c23c5a6c450cdf2174622af065ae798b10fa22fd2b0c687eda7dae9dd86, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk ef95c9c1af0247f4a265232bdf4fe650a538e08d20388a90de36108c7e881765, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk 7631beb368b46f7abe7427c04ee834dafe79cc3d66bda2df29aa2a009a582505, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk c0a17bbb9516486d50d11314e5206220a2d9bf9d91ab09c9d4b404ddf50b28a7, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk b6e344991347fbe8459fd77c6f10b607bf5f24eff0112e587707f9b2f3c83f14, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
[...]
2023-05-21T00:16:56+02:00: Start GC phase2 (sweep unused chunks)
2023-05-21T00:17:15+02:00: processed 45% (0 chunks)
2023-05-21T00:17:22+02:00: processed 64% (1 chunks)
2023-05-21T00:17:36+02:00: Removed garbage: 5.744 KiB
2023-05-21T00:17:36+02:00: Removed chunks: 2
2023-05-21T00:17:36+02:00: Original data usage: 5.065 TiB
2023-05-21T00:17:36+02:00: On-Disk usage: 0 B (0.00%)
2023-05-21T00:17:36+02:00: On-Disk chunks: 0
2023-05-21T00:17:36+02:00: Deduplication factor: 1.00
2023-05-21T00:17:36+02:00: TASK WARNINGS: 673803
 
ja, wenn in phase 1 ein problem auftritt wird die GC natuerlich abgebrochen, weil eine unvollstaendige markierung ein loeschen von moeglicherweise noch benoetigten daten nach sich ziehen wuerde. es gibt eine einzige ausnahme - wenn das auflisten der indizes noch problemlos funktioniert hat, aber der index nachher nicht mehr existiert, dann wird das ignoriert (weil ein paralleles loeschen von indizes ja kein fehler ist - sonst muessten wir fuer die gesamte dauer der GC keinerlei prunes erlauben..). das betrifft aber wirklich nur den fehler dass die datei nicht mehr existiert. bei einem totalausfall des storages gibts zwei moeglichkeiten:
- er blockiert (dann gibts kein not found, also auch kein ueberspringen dieser indizes)
- er ist unmounted (dann gibts ein not found, aber auch keine chunks die geloescht werden koennen)

wir braeuchten also folgendes "race" und fehlerverhalten (gegen das PBS auch nichts tun kann - wenn der datastore von normal auf leer auf voll springt ohne irgendwelche fehler zu schmeissen ist dass definitiv schuld des storages!):
Ich hätte da noch ein Szenario:
  • nfs hard mount (d.h. Zugriffe hängen, bis der Server wieder da ist, egal wie lange das dauert)
  • nfs-Server ist länger als 24h5m weg
  • Server ist wieder da, GC macht fröhlich weiter, aber jetzt ist alles was vor dem Hänger passiert ist länger als 24h5m her ...
 
Hallo Mow,
ein Interessantes Szenario. Im meinem konkreten Fall, trifft es wohl nicht zu aber es zeigt einen Grund auf zu überlegen ob es nicht vielleicht besser ist in diesem Fall einen Softmount zu verwenden.
Danke fuer die Anregung.

Bisher sind keine weiteren, nicht behebaren Fehler beim Backup aufgetreten. Ein fehlerhaftes Backup ist mit dem nächsten Backuplauf korregiert worden, so Fabian es beschrieben hat.
Ich werde einfach öfter Reverify-Läufe machen um auf der sichereren Seite zu sein.

Grüße Ariston
 
ein Interessantes Szenario. Im meinem konkreten Fall, trifft es wohl nicht zu aber es zeigt einen Grund auf zu überlegen ob es nicht vielleicht besser ist in diesem Fall einen Softmount zu verwenden.
Softmount hat aber wieder den Nachteil, daß nach einem Netzwerkhänger die (Meta-)Datenintegrität nicht gewährleistet ist. Dann kann das vorher genannte Szenario auftreten, daß der Storage gerade so ausfällt, daß ein Teil der Metadatenänderungen der touch-Phase verlorengeht, und dann der Teil, der effektiv ein find <datastorage> -amin +1445 -exec rm {}; durchführt, den Storage gründlich abräumt.
 
Das stimmt schon allerdings sollte bei einem Softmount sofort beim Schreib/Lesen ein Fehler ausgelöst werden, wenn der Mount nicht mehr verfügbar ist. Es kommt dann darauf an, wie der Fehler behandelt wird.
Fabian schrieb, das ein Fehler bei der Ausführung des GC in Phase 1 zum Abbruch führt um eine fehlerhafte Markierung zu verhindern.

Am Ende steht dann die Abwegung, welches Risiko eingegangen werden soll. Einerseits nicht zu erkennen, dass es ein NFS Hänger gab und keinen zeitnahen Hinweis zu bekommen wodurch einen Datenverlust der daraus resultiert erst später, vielleicht zu spät, erkannt wird;
Oder die andere Option ist den Fehler zeitnah gemeldet zu bekommen und je nach Zeitpunkt vielleicht einen Datenverlust verhindern zu können, weil der Fehler bemerkt wurde. Zu dem Preis, das die Gefahr eines Datenverlustes größer ist.
Das führt dann allerdings schnell vom bisherigen Thema weg und hin zu der (off Topic) Frage, wie ein Monitoring aussehen muss um diese Fehler zuverlässig zu erkennen und wie implizite Abhängigkeiten sinnvoll abgebildet werden können.

Wir haben im Team beschlossen, dass wir den PBS als sicher erachten und produktiv einsetzen werden.

Grüße Ariston
 
Ich hätte da noch ein Szenario:
  • nfs hard mount (d.h. Zugriffe hängen, bis der Server wieder da ist, egal wie lange das dauert)
  • nfs-Server ist länger als 24h5m weg
  • Server ist wieder da, GC macht fröhlich weiter, aber jetzt ist alles was vor dem Hänger passiert ist länger als 24h5m her ...
dieses szenario ist absolut kein problem. der cutoff ist ja nicht "aelter als 24h5m im vergleich zum zeitpunkt des loeschens", sondern "aelter als 24h5m im vergleich zum starten der GC". sonst wuerde das alles keinen sinn ergeben ;) der cutoff ist auch nicht immer 24h5m, sondern mind. 24h5m, wenn beim starten noch backups laufen die vor dem mindest cutoff gestartet worden sind, dann gilt der startzeitpunkt des "aeltesten" backup tasks.
 
Ein weiteren Lauf vom 20.5. gibt es noch, der hat allerdings gepackt 27 MB ob das Zielführend ist? Ich paste mal die ersten Zeilen.

2023-05-20T23:55:00+02:00: starting garbage collection on store pbackup-nfs
2023-05-20T23:55:00+02:00: task triggered by schedule 'sat 23:55'
2023-05-20T23:55:00+02:00: Start GC phase1 (mark used chunks)
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk aceb0c23c5a6c450cdf2174622af065ae798b10fa22fd2b0c687eda7dae9dd86, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk ef95c9c1af0247f4a265232bdf4fe650a538e08d20388a90de36108c7e881765, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk 7631beb368b46f7abe7427c04ee834dafe79cc3d66bda2df29aa2a009a582505, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk c0a17bbb9516486d50d11314e5206220a2d9bf9d91ab09c9d4b404ddf50b28a7, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
2023-05-20T23:55:00+02:00: WARN: warning: unable to access non-existent chunk b6e344991347fbe8459fd77c6f10b607bf5f24eff0112e587707f9b2f3c83f14, required by "/nfs/vm/103/2023-05-11T19:00:16Z/drive-scsi0.img.fidx"
[...]
2023-05-21T00:16:56+02:00: Start GC phase2 (sweep unused chunks)
2023-05-21T00:17:15+02:00: processed 45% (0 chunks)
2023-05-21T00:17:22+02:00: processed 64% (1 chunks)
2023-05-21T00:17:36+02:00: Removed garbage: 5.744 KiB
2023-05-21T00:17:36+02:00: Removed chunks: 2
2023-05-21T00:17:36+02:00: Original data usage: 5.065 TiB
2023-05-21T00:17:36+02:00: On-Disk usage: 0 B (0.00%)
2023-05-21T00:17:36+02:00: On-Disk chunks: 0
2023-05-21T00:17:36+02:00: Deduplication factor: 1.00
2023-05-21T00:17:36+02:00: TASK WARNINGS: 673803

das ist insofern interessant, als das hier schon chunks zu fehlen scheinen? hat der NFS storage vielleicht davor schonmal probleme gemacht? du koenntest noch die fehlenden chunks hier mit denen spaeter gegenueberstellen, ich vermute es wird hier starke ueberschneidungen geben..

edit: zu schnell gelesen, diese GC war ja *spaeter*, nicht *frueher*. sorry!
 
Hallo Ariston,

habt ihr schon neue Erkenntnisse gewonnen? Wir kämpfen mit ähnlichen Problemen.

Da wir kein separaten Storage mit ZFS haben müssen wir notgedrungen auch auf Isilon sichern (NFS Share).
Wir haben hier 2 unterschiedliche Isilon-Systeme, einen schnellen Flash Cluster und einen langsamen Archiv Cluster (nur HDDs).

Installiert sind 2 PBS, der primäre sichert auf den Flash Cluster und das funktioniert alles wunderbar. Der sekundäre zieht sich via Sync alle Backups rüber und dient als Fallback.
Nun haben wir das Problem, dass quasi von heute auf morgen alle Chunks gelöscht werden, in der Garbage Collection steht dann diese Info:
Code:
Original Data usage:  89.354 TiB
On-Disk usage:        0 B (0.00%)
On-Disk chunks:       0
Interessanterweise stört das dem Verify Job überhaupt nicht, er behauptet trotzdem "Verification successful" und alles VMs haben einen grünen Haken.

Zuvor hatten wir das primäre Backup auf der HDD Isilon laufen, das war auch eine Katastrophe da die geringen IOPS den NFS-Server ausgebremst haben und dadurch scheinbar nicht sauber die Daten geschrieben wurden (gleichzeitiges Backup von 5 PVE Nodes).
Der Mount erfolgt über die fstab mit "nfs nfsvers=3,defaults,_netdev,rw", auch mit NFSv4.2 keine Änderung.
 
Hallo maik_n,

wir haben leider keine echte Lösung für das Problem gefunden, sondern nur den Workaround den Garbage Collector Job nicht laufen zu lassen.
Das ist für uns ein im Moment gangbarer Weg, weil wir in ein paar Wochen das Backup auf ein System mit lokalem Storage umziehen.

Zu Deiner Beobachtung, dass die Backups weiterhin grün sind. Soweit ich das herausgefunden habe, bleibt der Status des Backups nach dem initialen Verify bis zum nächsten Verify unverändert.
Wenn Du die Backups manuell überprüfst, ist meine Erwartung, das dann das Backup auf Failed (rot) wechselt. Wir haben daher die Frequenz für das "reverify" auf täglich gelegt. Das erneute Verify dauert natürlich etwas, hält sich bei unserer Anzahl und Größe der VMs noch im Rahmen.

Wenn Ihr die VMs noch laufen habt die gesichert werden, dann sind zumindest bei uns, die fehlenden Chunks beim nächsten Backup wieder erstellt worden. Inwieweit das jetzt bei knapp 90 TBit klappt und in welcher Zeit und ob der GC dann die Daten nicht gleich wieder löscht, sei mal dahingestellt.

Leider kann ich Dir nicht wirklich weiterhelfen. Wir haben keine befriedigende Antwort für das Verhalten gefunden. Wenn Ihr im Prinzip das gleiche Problem habt und auch Isilons verwendet, dann könnte das ja ein Hinweis sein, das die Quelle des Problems vielleicht die NFS Implementierung des
Isilon ist.
Ich hatte im Zusammenhang mit der NDMP Implementierung vom Isilon schon Probleme mit unserem Backupprogramm und die konnten wir ursächlich dem Isilon zuordnen.

Viele Grüße,
Ariston
 
Guter Hinweis, ich schalte auf der Replica auch mal GC ab und schaue wie lange wir mit dem Storage auskommen...

Das Problem ist, der Sync zieht über die Index Datei nur die Chunks nach die ihm offiziell fehlen, da steht dann z.B. "skipped: 20 snapshot(s) (2023-06-11T19:00:02Z .. 2023-08-01T19:00:00Z) - older than the newest local snapshot".
Sollte aber ein alter Chunk fehlen dann weiß der Sync davon nichts! Eigentlich auch nicht so zufriedenstellend für einen "Sync"
 
Hallo maik_n,

Hast Du schon mal versucht, das Backup auf dem sekundären PBS manuell zu verifizieren und dann zu schauen ob der Sync die fehlenden Chunks nachzieht. Ich unterstelle jetzt, das das Backup nach dem manuellen Verify nicht mehr grün ist.
Eigentlich sollten dann ja die fehlenden Chunks "offiziell" bekannt sein.

Grüße,
Ariston
 
Da ihr beide Isilon OneFS benutzt: Gibt es irgendwelche Logs auf Isilon-Seite?
@maik_n und was steht eigentlich im GC-Log?
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!