S3 Datastore Garbage Collection Phase 2 schlägt fehlt (os error 2)

[zemaphore]

Hey PBS Team,

anbei ein Fehler-Report zu meinem Testing des S3 Datastore Features.

Seit heute schlägt die Garbage Collection leider fehl. Die Phase 1 des GC wird erfolgreich abgeschlossen, aber Phase 2 bricht mit dem folgenden Fehlerbild ab:

...
marked 100% (84 of 84 index files)
Start GC phase2 (sweep unused chunks)
queued notification (id=aa611254-a09a-4abf-91d9-f275745cf6d6)
TASK ERROR: No such file or directory (os error 2)
Error: task failed (status No such file or directory (os error 2))

Leider gibt es keine Details welche Datei hier fehlt.... Ein "strace" gegen den "proxmox-backup-proxy":

strace -ff   -e trace=open,openat,stat,lstat,rename,unlink,unlinkat   -s 2000   -p 654   -o /root/pbs-proxy.strace

Liefert folgende ENOENTs:

/root/pbs-proxy.strace.1351:324:openat(AT_FDCWD, "/mnt/hetzner-s3-cache/nbg1-pbsfra01/ns/cloud/ns", O_RDONLY) = -1 ENOENT (No such file or directory)
/root/pbs-proxy.strace.1351:30569:openat(AT_FDCWD, "/mnt/hetzner-s3-cache/nbg1-pbsfra01/ns/pve01.fra-daily/ns", O_RDONLY) = -1 ENOENT (No such file or directory)
/root/pbs-proxy.strace.1351:42357:openat(AT_FDCWD, "/mnt/hetzner-s3-cache/nbg1-pbsfra01/ns/pve01.fra-longterm/ns", O_RDONLY) = -1 ENOENT (No such file or directory)
/root/pbs-proxy.strace.1351:49232:openat(AT_FDCWD, "/mnt/hetzner-s3-cache/nbg1-pbsfra01/ns/pve01.fra-general/ns", O_RDONLY) = -1 ENOENT (No such file or directory)
/root/pbs-proxy.strace.1351:49246:unlink("/mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/000a05976e7a8bc21d9a2b7498c523c17b51eeef8415d9c3ff0a19aae78a873e.using") = -1 ENOENT (No such file or directory)
/root/pbs-proxy.strace.1351:49247:unlink("/mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/000a05976e7a8bc21d9a2b7498c523c17b51eeef8415d9c3ff0a19aae78a873e") = -1 ENOENT (No such file or directory)

Hier fehlen scheinbar erwartete chunks. Ich habe danach den S3 Cache sowie Datastore einmal komplett entfernt und aus dem S3 content wieder neu aufgebaut/eingehangen, aber das Problem besteht weiterhin. Gibt es einen Weg - über Modifikationen im S3 content oder im S3 Cache - den Store wieder zu reparieren?

Kernel

Linux pbs01 6.14.11-4-pve #1 SMP PREEMPT_DYNAMIC PMX 6.14.11-4 (2025-10-10T08:04Z) x86_64 GNU/Linux

PBS

proxmox-backup-server 4.0.20-1 running version: 4.0.20

 

[Chris]

Hallo,

was liefert ein stat /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/ direkt nach der fehlgeschlagenen garbage collection? Bitte auch den output von ls -l /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/ posten.

Edit: Welche schritte wurden gemacht um den store und die cache wiederherzustellen?

 

[zemaphore]

Hey Chris,

sehr gerne...

root@pbs01.fra: ~ stat /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/
  File: /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/
  Size: 4096          Blocks: 8          IO Block: 4096   directory
Device: 8,17    Inode: 262158      Links: 2
Access: (0750/drwxr-x---)  Uid: (   34/  backup)   Gid: (   34/  backup)
Access: 2025-11-22 09:12:01.563617721 +0000
Modify: 2025-11-22 09:11:59.128458830 +0000
Change: 2025-11-22 09:11:59.128458830 +0000
 Birth: 2025-11-22 07:21:59.137748758 +0000

root@pbs01.fra: ~ ls -l /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/
total 0

 

[Chris]

Okay, ich kann das problem reproduzieren, scheint dann aufzutreten wenn ein chunk zwar am object store vorhanden, jedoch von keinem backup index file mehr verwendet wird. Ein einmaliges

touch /mnt/hetzner-s3-cache/nbg1-pbsfra01/.chunks/000a/000a05976e7a8bc21d9a2b7498c523c17b51eeef8415d9c3ff0a19aae78a873e

sollte als workaround reichen bis ein fix verfügbar ist (auch für andere chunks falls dies bei weiteren auftritt).

 

[zemaphore]

Das ging extrem schnell, Chris. Vielen Dank schon mal.

Ich versuche mich mal mit strace an den Chunks fort zu hangeln. Der erste touch hat geholfen, aber jetzt fehlt der nächste chunk. Für die Zukunft wäre es eventuell auch hilfreich, wenn der GC task selbst die vermisste Datei im Log reporten könnte.

Schönes Wochenende wünsch ich noch

 

[Chris]

Das ging extrem schnell, Chris. Vielen Dank schon mal.

Vielen Dank noch für den Report!

Ich versuche mich mal mit strace an den Chunks fort zu hangeln. Der erste touch hat geholfen, aber jetzt fehlt der nächste chunk. Für die Zukunft wäre es eventuell auch hilfreich, wenn der GC task selbst die vermisste Datei im Log reporten könnte.

Ja, in der tat braucht es hier noch an Verbesserungen beim error logging. Für den Bug selbst gibt es nun einen bugfix patch auf der developer mailing list https://lore.proxmox.com/pbs-devel/20251122104118.205994-1-c.ebner@proxmox.com/T/

Schönes Wochenende wünsch ich noch

Danke, ebenso!

 

[zemaphore]

Hatte gesehen du hast im Patch geschrieben:

This should not happen under
normal datastore operation anyways, most likely to appear after
re-creation of the datastore from existing bucket contents containing
such unreferenced chunks.

Vielleicht noch als Hintergrund wie die Situation entstanden ist. Ich hab nach den fehlenden Chunks in den letzten Backup Logs gesucht und ein fehlgeschlagenes Backup gefunden.

Dort sieht man:

2025-11-22T03:14:02+00:00: Upload new chunk 000a05976e7a8bc21d9a2b7498c523c17b51eeef8415d9c3ff0a19aae78a873e

2025-11-22T03:14:35+00:00: Caching of chunk 000a05976e7a8bc21d9a2b7498c523c17b51eeef8415d9c3ff0a19aae78a873e

Und etwas später Upload-Fehler in den S3 Bucket die zum Abbruch des Backups führen.

2025-11-22T03:17:21+00:00: backup ended and finish failed: backup ended but finished state is not set.
2025-11-22T03:17:21+00:00: removing unfinished backup
2025-11-22T03:17:23+00:00: removing backup snapshot "/mnt/hetzner-s3-cache/nbg1-pbsfra01/ns/pve01.fra-general/vm/107/2025-11-22T03:10:53Z"
2025-11-22T03:17:23+00:00: TASK ERROR: backup ended but finished state is not set.

Das erklärt wieso die Chunks im Bucket liegen und eventuell im Cache verworfen wurden.

 

[Chris]

Das erklärt wieso die Chunks im Bucket liegen und eventuell im Cache verworfen wurden.

Ein Abbruch des backup jobs kann sicher dazu geführt haben, dass der chunk am s3 hochgeladen und nicht referenziert wird. Jedoch sollte dennoch der marker im local store cache vorhanden sein. Erst durch das neu erstellen der cache sollte dieser lokal nicht mehr vorhanden sein und daher zum genannten Fehlverhalten führen.