Backup Error Directory not empty (os error 39) / -5 - Input/output error

[Gjoker86]

Hallo Zusammen

Gerne möchte ich euch nach Rat fragen. Ich habe in meiner Homelab Umgebung 14 VM's und 12 LXC's am laufen. EIne Backupjob sichert alle Systeme auf einen lokalen Backupserver, welcher dann an einen entfernten Standort repliziert. Leider habe ich nun seit gut 2 Wochen ein Problem mit einer einzigen VM, welche sich nicht mehr sichern lässt. Ich erhalte leider immer wieder den selben Fehler. Vielleicht hatte dieses Probelm ja bereits schon mal jemand?

Hier der Log-Auszug vom Proxmox VE Server:

INFO: starting new backup job: vzdump 1040 --notes-template '{{guestname}}' --fleecing 0 --quiet 1 --mode snapshot --storage QNAP-pbsX --prune-backups 'keep-daily=5'
INFO: Starting Backup of VM 1040 (qemu)
INFO: Backup started at 2024-10-10 02:30:02
INFO: status = running
INFO: VM Name: WebSrv02-GremiCloud
INFO: include disk 'virtio0' 'SSD4:vm-1040-disk-0' 400G
INFO: include disk 'virtio1' 'SSD4:vm-1040-disk-1' 1000G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/1040/2024-10-10T00:30:02Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'df22d45f-3324-4629-9423-a908dd95d05d'
INFO: resuming VM again
INFO: virtio0: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO: virtio1: dirty-bitmap status: existing bitmap was invalid and has been cleared
INFO:   0% (1.0 GiB of 1.4 TiB) in 3s, read: 353.3 MiB/s, write: 12.0 MiB/s
INFO:   1% (14.1 GiB of 1.4 TiB) in 47s, read: 303.1 MiB/s, write: 8.7 MiB/s
INFO:   2% (28.2 GiB of 1.4 TiB) in 1m 33s, read: 314.1 MiB/s, write: 3.9 MiB/s
INFO:   3% (42.1 GiB of 1.4 TiB) in 2m 19s, read: 309.1 MiB/s, write: 623.3 KiB/s
INFO:   4% (56.2 GiB of 1.4 TiB) in 3m 6s, read: 307.9 MiB/s, write: 1.6 MiB/s
INFO:   5% (70.2 GiB of 1.4 TiB) in 3m 51s, read: 319.0 MiB/s, write: 3.0 MiB/s
INFO:   6% (84.2 GiB of 1.4 TiB) in 4m 37s, read: 310.9 MiB/s, write: 4.3 MiB/s
INFO:   7% (98.0 GiB of 1.4 TiB) in 5m 23s, read: 308.4 MiB/s, write: 2.7 MiB/s
INFO:   8% (112.1 GiB of 1.4 TiB) in 6m 8s, read: 319.6 MiB/s, write: 6.0 MiB/s
INFO:   9% (126.1 GiB of 1.4 TiB) in 6m 52s, read: 326.4 MiB/s, write: 558.5 KiB/s
INFO:  10% (140.1 GiB of 1.4 TiB) in 7m 36s, read: 326.5 MiB/s, write: 1.7 MiB/s
INFO:  11% (154.1 GiB of 1.4 TiB) in 8m 22s, read: 311.9 MiB/s, write: 356.2 KiB/s
INFO:  12% (168.1 GiB of 1.4 TiB) in 9m 10s, read: 297.6 MiB/s, write: 45.2 MiB/s
INFO:  13% (182.2 GiB of 1.4 TiB) in 10m 6s, read: 258.0 MiB/s, write: 28.4 MiB/s
INFO:  13% (183.1 GiB of 1.4 TiB) in 10m 10s, read: 242.0 MiB/s, write: 5.0 MiB/s
ERROR: job failed with err -5 - Input/output error
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 1040 failed - job failed with err -5 - Input/output error
INFO: Failed at 2024-10-10 02:40:14
INFO: Backup job finished with errors
TASK ERROR: job errors

Und hier das Log vom Backup-Server:

2024-10-10T02:30:03+02:00: starting new backup on datastore 'QNAP' from ::ffff:10.0.0.14: "vm/1040/2024-10-10T00:30:02Z"
2024-10-10T02:30:03+02:00: download 'index.json.blob' from previous backup.
2024-10-10T02:30:03+02:00: register chunks in 'drive-virtio0.img.fidx' from previous backup.
2024-10-10T02:30:03+02:00: download 'drive-virtio0.img.fidx' from previous backup.
2024-10-10T02:30:03+02:00: created new fixed index 1 ("vm/1040/2024-10-10T00:30:02Z/drive-virtio0.img.fidx")
2024-10-10T02:30:03+02:00: register chunks in 'drive-virtio1.img.fidx' from previous backup.
2024-10-10T02:30:03+02:00: download 'drive-virtio1.img.fidx' from previous backup.
2024-10-10T02:30:03+02:00: created new fixed index 2 ("vm/1040/2024-10-10T00:30:02Z/drive-virtio1.img.fidx")
2024-10-10T02:30:03+02:00: add blob "/mnt/qnap/vm/1040/2024-10-10T00:30:02Z/qemu-server.conf.blob" (396 bytes, comp: 396)
2024-10-10T02:40:13+02:00: backup ended and finish failed: backup ended but finished flag is not set.
2024-10-10T02:40:13+02:00: removing unfinished backup
2024-10-10T02:40:13+02:00: TASK ERROR: removing backup snapshot "/mnt/qnap/vm/1040/2024-10-10T00:30:02Z" failed - Directory not empty (os error 39)

Kennt das jemand? Mit dem PVE Server bin ich auf der Version 8.2.7 und mit dem PBS auf der Version 3.2-7.


Wäre um jeden Tipp dankbar.

Beste Grüsse an euch alle und allen einen erfolgreichen Tag!

 

[fabian]

koennte ein hinweis auf ein disk problem auf PVE seite sein.. was fuer einen storage verwendest du dort denn?

 

[Gjoker86]

Hallo Fabian

Der Pool, auf welchem die VM liegt ist ein ZFS RaidZ1 mit 2x4TB ssd's. aber ich glaube du hast recht:

root@pveX:~# zpool status SSD4 -v
  pool: SSD4
 state: ONLINE
status: One or more devices has experienced an error resulting in data
        corruption.  Applications may be affected.
action: Restore the file in question if possible.  Otherwise restore the
        entire pool from backup.
   see: https://openzfs.github.io/openzfs-docs/msg/ZFS-8000-8A
  scan: scrub repaired 0B in 01:20:06 with 0 errors on Sun Sep  8 01:44:11 2024
config:

        NAME                                             STATE     READ WRITE CKSUM
        SSD4                                             ONLINE       0     0     0
          mirror-0                                       ONLINE       0     0     0
            ata-Samsung_SSD_870_QVO_4TB_S5STNF0W401296B  ONLINE       0     0    12
            ata-Samsung_SSD_870_QVO_4TB_S5STNF0W401290A  ONLINE       0     0    12

errors: Permanent errors have been detected in the following files:

        SSD4/vm-1040-disk-1:<0x1>
root@pveX:~#

das habe ich bis jetzt noch nicht angeschaut. Jetzt sehe ich , dass die Disk wohl im Eimer ist der VM 1040.... oder was denkst du?

Beste Grüsse und vielen Dank schonmal..

 

[fabian]

checksum fehler auf beiden disks ist eher ungewoehnlich, wuerde zur sicherheit auch den RAM und die kabel durchchecken..

 

[Gjoker86]

spannend... die VM funktioniert, die Daten sind alle da und lesbar. Keine andere VM macht Probleme. Nun habe ich eine weitere Disk aus einem anderen Pool an die VM angeschlossen, die Daten mit rsync kopiert und die alte Disk weggeschmissen. Nun läuft alles wieder, wie es sollte..

Merkwürdig, dass, obwohl es anscheinend ein Problem mit dem Pool gab, nur die eine VM betroffen war. Es sind, resp. waren mehrere VM's und LXC's in dem Pool... Naja, läuft wieder wie es sollte.

Danke für die Hilfe, Fabian,

 

[Falk R.]

Hallo Fabian

Der Pool, auf welchem die VM liegt ist ein ZFS RaidZ1 mit 2x4TB ssd's. aber ich glaube du hast recht:

root@pveX:~# zpool status SSD4 -v
  pool: SSD4
 state: ONLINE
status: One or more devices has experienced an error resulting in data
        corruption.  Applications may be affected.
action: Restore the file in question if possible.  Otherwise restore the
        entire pool from backup.
   see: https://openzfs.github.io/openzfs-docs/msg/ZFS-8000-8A
  scan: scrub repaired 0B in 01:20:06 with 0 errors on Sun Sep  8 01:44:11 2024
config:

        NAME                                             STATE     READ WRITE CKSUM
        SSD4                                             ONLINE       0     0     0
          mirror-0                                       ONLINE       0     0     0
            ata-Samsung_SSD_870_QVO_4TB_S5STNF0W401296B  ONLINE       0     0    12
            ata-Samsung_SSD_870_QVO_4TB_S5STNF0W401290A  ONLINE       0     0    12

errors: Permanent errors have been detected in the following files:

        SSD4/vm-1040-disk-1:<0x1>
root@pveX:~#

das habe ich bis jetzt noch nicht angeschaut. Jetzt sehe ich , dass die Disk wohl im Eimer ist der VM 1040.... oder was denkst du?

Beste Grüsse und vielen Dank schonmal..

Ich gehe davon aus, die Fehler kommen ganz einfach daher, dass es QLC SSDs sind. QLC und ZFS ist eine tödliche Kombination und da die SSDs dazu neigen extreme Latenzen zu erzeugen unter Last, kommen die Fehler vermutlich daher.