[SOLVED] Backup VM mit OS Error 2

[chriswol]

Hallo,

im Forum sind zwar einige Leute, die auch den OS error 2 bekommen, allerdings passt deren Szenario nicht zu meinem.

Wir nutzen PBS schon seit längerer Zeit (noch vor dem Final Release mit 0.xx angefangen) und haben bisher nie Probleme irgendwelcher Art gehabt.
Seit letzter Woche allerdings, bricht das Backup einer bestimmten VM nach knapp 58% - 60% immer mit derselben Fehlermeldung ab:

Log des PBS:

POST /fixed_chunk: 400 Bad Request: No such file or directory (os error 2)

Log des PVE:

ERROR: backup write data failed: command error: write_data upload error: pipelined request failed: No such file or directory (os error 2)

Alle anderen VM's laufen geräuschlos durch, nur diese eine nicht mehr (nachdem es zuvor immer funktionierte).
Ich habe auch bereits alle vorherigen Backups der VM gelöscht, in der Annahme, dass ein neues Full Backup ohne vorherige Inkremente Abhilfe schafft.
Das Backup der VM mit PVE Bordmittel auf lokalen Speicher des PVE Hosts funktioniert reibungslos.

Der Backupspeicher ist eine via USB an den PBS Host angebundene HDD über ZFS verwaltet.

Ich bin dankbar über Ansätze oder Verweise auf andere Forenbeiträge, die mich auf die richtige Fährte bringen. Ich habe leider nichts passendes bei meiner Suche gefunden.

Beste Grüße
Christian

 

[dcsapak]

gibt es im journal (journalctl) / syslog (/var/log/syslog) vielleicht mehr informationen ?
auch der ganze task log wäre interessant (von beiden seiten)
vm config und versionen auch

 

[chriswol]

Hallo Dominik,

danke für die schnelle Rückmeldung.

Das Log vom PVE Host sieht so aus:

INFO: starting new backup job: vzdump 101 --mode stop --remove 0 --storage store01 --node pve-00-01
INFO: Starting Backup of VM 101 (qemu)
INFO: Backup started at 2021-06-01 14:15:22
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: srv-00-01
INFO: include disk 'scsi0' 'local-lvm:vm-101-disk-0' 32G
INFO: stopping vm
INFO: creating Proxmox Backup Server archive 'vm/101/2021-06-01T12:15:22Z'
INFO: starting kvm to execute backup task
INFO: started backup task 'f9f39a77-1d8d-4268-920b-88f1d4aef212'
INFO: resuming VM again after 20 seconds
INFO: scsi0: dirty-bitmap status: created new
INFO: 0% (156.0 MiB of 32.0 GiB) in 3s, read: 52.0 MiB/s, write: 52.0 MiB/s
< snip >
INFO: 58% (18.6 GiB of 32.0 GiB) in 4m 39s, read: 70.4 MiB/s, write: 49.6 MiB/s
INFO: 58% (18.9 GiB of 32.0 GiB) in 4m 44s, read: 51.2 MiB/s, write: 37.6 MiB/s
ERROR: backup write data failed: command error: write_data upload error: pipelined request failed: No such file or directory (os error 2)
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM 101 failed - backup write data failed: command error: write_data upload error: pipelined request failed: No such file or directory (os error 2)
INFO: Failed at 2021-06-01 14:20:26
INFO: Backup job finished with errors
TASK ERROR: job errors

Auf Seite vom PBS sieht es so aus:

2021-06-01T14:15:41+02:00: starting new backup on datastore 'store01': "vm/101/2021-06-01T12:15:22Z"
2021-06-01T14:15:41+02:00: GET /previous: 400 Bad Request: no valid previous backup
2021-06-01T14:15:41+02:00: created new fixed index 1 ("vm/101/2021-06-01T12:15:22Z/drive-scsi0.img.fidx")
2021-06-01T14:15:42+02:00: add blob "/store01/vm/101/2021-06-01T12:15:22Z/qemu-server.conf.blob" (375 bytes, comp: 375)
2021-06-01T14:20:25+02:00: POST /fixed_chunk: 400 Bad Request: No such file or directory (os error 2)
2021-06-01T14:20:25+02:00: backup ended and finish failed: backup ended but finished flag is not set.
2021-06-01T14:20:25+02:00: removing unfinished backup
2021-06-01T14:20:25+02:00: POST /fixed_chunk: 400 Bad Request: error reading a body from connection: protocol error: stream no longer needed
2021-06-01T14:20:25+02:00: TASK ERROR: backup ended but finished flag is not set.

VM config der betroffenen VM:

agent: 1
boot: order=scsi0;ide2;net0
cores: 4
ide2: none,media=cdrom
memory: 4096
name: srv-00-01
net0: virtio=EE:32:F4:28:1C:A2,bridge=vmbr1,firewall=1
numa: 0
onboot: 1
ostype: l26
scsi0: local-lvm:vm-101-disk-0,size=32G
scsihw: virtio-scsi-pci
smbios1: uuid=0570cb84-1833-41b2-baf6-324db56e6623
sockets: 1
startup: order=1
vmgenid: fce21038-6399-47e8-996b-95effd6bcacb

PVE und PBS Version:

Linux version 5.4.114-1-pve (build@proxmox) (gcc version 8.3.0 (Debian 8.3.0-6)) #1 SMP PVE 5.4.114-1 (Sun, 09 May 2021 17:13:05 +0200)

Journalctl/Syslog gibt leider nicht mehr Infos her, als die Task Logs.

 

[dcsapak]

mhmmm... ich habe eine vermutung, nämlich dass nicht alle chunk ordner existieren...

was sagt denn

ls -lh <datastore-pfad>/.chunks| wc -l

?

 

[chriswol]

mhmmm... ich habe eine vermutung, nämlich dass nicht alle chunk ordner existieren...

was sagt denn

ls -lh <datastore-pfad>/.chunks| wc -l

?

65536

 

[dcsapak]

ok, bin mir nicht ganz sicher, aber es scheint ein directory zu fehlen.
kannst du den output in ein file packen und hier raufladen?

ls -lh  <datastore-pfad>/.chunks > /tmp/output.txt

wird ca. ein paar MB groß

 

[chriswol]

Musste es komprimieren, Anhang ist zu groß

 

[chriswol]

Hmm, heute Nacht trat das Problem dann auch bei einer zweiten virtuellen Maschine auf, die bis dato immer anstandsfrei gesichert wurde. Lässt das eventuell auf einen Hardwaredefekt der angeschlossenen USB Festplatte schließen?

 

[dcsapak]

ok habe mir die liste angeschaut, und es scheint das directory mit dem namen '0480' zu fehlen. der fehler tritt offenbar immer dann auf wenn ein chunk mit '0480' beginnt
kannst du mal versuchen

mkdir <datastore-pfad>/.chunks/0480

auszuführen um das fehlende directory anzulegen und dann das backup nochmal zu machen?

 

[chriswol]

Du bist mein Held des Tages (mindestens)! Vielen, vielen Dank für die schnelle Hilfe. Auch das fehlerhafte Backup der zweiten VM von heute nacht ist damit gelöst.
Es mussten allerdings vorher noch die Besitzverhältnisse des Ordners auf backup:backup geändert werden (ansonsten gibt es ein OS error 13 - permission denied).

Bist Du die Liste jetzt nachts als Einschlafhilfe visuell durchgegangen oder hast Du da ein Skript drüber laufen lassen? Würde mich ja interessieren, wieso dieser Ordner nicht angelegt war, bzw. angelegt werden konnte. Kann ich da in irgendwelchen Logfiles "graben"?

 

[dcsapak]

Bist Du die Liste jetzt nachts als Einschlafhilfe visuell durchgegangen oder hast Du da ein Skript drüber laufen lassen?

ich hab die liste mit der echten liste 'gedifft' (hab mir nur die letzte spalte rausgeholt) mit dem tool 'diff'
die directories sind ja nur alle zahlen von 0x0000 - 0xFFFF

Würde mich ja interessieren, wieso dieser Ordner nicht angelegt war, bzw. angelegt werden konnte. Kann ich da in irgendwelchen Logfiles "graben"?

das einzige was mir in den sinn kommt dass die platte was komisches macht, also mal nach disk errors suchen? smart checken?

 

[chriswol]

das einzige was mir in den sinn kommt dass die platte was komisches macht, also mal nach disk errors suchen? smart checken?

So wie ich die Dokumentation verstehe, werden die Verzeichnisse bei der Neuanlage des datastores erstellt. Ich habe dummerweise nicht darauf geachtet, ob auch alle Verzeichnisse damals tatsächlich erstellt wurden. Ist es nach eurer Erfahrung denn schon einmal vorgekommen, dass nachträglich Ordner gelöscht wurden (durch Bugs oder was weiß ich)?
Wie geschrieben, hatte ich den Backupserver bereits aufgesetzt, als das Ganze noch in der 0.xx Version zur Verfügung stand.

 

[dcsapak]

Ist es nach eurer Erfahrung denn schon einmal vorgekommen, dass nachträglich Ordner gelöscht wurden (durch Bugs oder was weiß ich)?

soweit ich weiß nicht. die einzigen fälle in denen nicht alle directories angelegt wurden, war als wir (unbeabsichtigt) ext3 im installer erlaubt hatten. ext3 kann nicht soviele
einträge in einem verzeichnis haben und hier wäre das erstellen des datastores ganz fehlgeschlagen