Backup failure when using "Stop" and "ZFSRAID2"

[tomc]

Hi
I have just installed latest release of Proxmox on a Dell R710, with 48 GB ram, 6 x 4TB Seagate HDD under ZFS raid 2.
This is NOT a Production Server, so if you would like me to try something, I am willing to give it a go.
I get failures on both Manual and scheduled backup when using Stop.
Backups work when using Snapshot.
doing manual backups the failure is not consistent. It may work 2 or 3 times then fail. Once failed the VM will not restart until I restart Proxmox itself, restarting the physical server.
automating the backup.
The VM is Windows 10 Pro size is total of 900GB.
For testing I have set the backups to run every 3 hours.
All backups are using "Stop".
times 0200, 0500, 0800, 1100, 1400, 1700, 2000, 2300. Monday to Sunday.
I did a reboot of the Proxmox server at 0100.
The first backup (0200) runs successfully, the second backup (0500) fails.
Unable to restart the VM, So we restart Proxmox Server.
0800 backup runs OK, 1100 backup fails.
This time let two more backups run 1400, 1700, both these fail.
I try manually running a Snapshot backup, it also fails.
This procedure was tried over a period of 5 days, with consistent results.
I now have set the backups to alternate, first backup 0200 is snapshot, second backup is stop.
This alternates through the 8 backups.
This has been running for 2 days, all snapshot backups run OK, some stop backups fail, BUT the following snapshot backup works.
Here is the VM config file:
==========================
agent: 1,fstrim_cloned_disks=1
balloon: 0
boot: cd
bootdisk: virtio0
cores: 7
ide2: local:iso/virtio-win-0.1.141.iso,media=cdrom,size=309208K
memory: 32000
name: CCD-Data
net1: virtio=42:93:38:97:A6:39,bridge=vmbr0
numa: 0
onboot: 1
ostype: win10
scsihw: virtio-scsi-pci
smbios1: uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3
sockets: 2
virtio0: local-zfs:vm-100-disk-0,size=900G
==========================
Below are result of free and pveversion -v.
=======================================================
20190102-1251
Debian GNU/Linux comes with ABSOLUTELY NO WARRANTY, to the extent
permitted by applicable law.
root@pve01:~# free
total used free shared buff/cache available
Mem: 49441012 37144716 12086172 59380 210124 11866424
Swap: 0 0 0
root@pve01:~# pveversion -v
proxmox-ve: 5.3-1 (running kernel: 4.15.18-9-pve)
pve-manager: 5.3-6 (running version: 5.3-6/37b3c8df)
pve-kernel-4.15: 5.2-12
pve-kernel-4.15.18-9-pve: 4.15.18-30
corosync: 2.4.4-pve1
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.1-3
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-43
libpve-guest-common-perl: 2.0-18
libpve-http-server-perl: 2.0-11
libpve-storage-perl: 5.0-34
libqb0: 1.0.3-1~bpo9
lvm2: 2.02.168-pve6
lxc-pve: 3.0.2+pve1-5
lxcfs: 3.0.2-2
novnc-pve: 1.0.0-2
proxmox-widget-toolkit: 1.0-22
pve-cluster: 5.0-31
pve-container: 2.0-31
pve-docs: 5.3-1
pve-edk2-firmware: 1.20181023-1
pve-firewall: 3.0-16
pve-firmware: 2.0-6
pve-ha-manager: 2.0-5
pve-i18n: 1.0-9
pve-libspice-server1: 0.14.1-1
pve-qemu-kvm: 2.12.1-1
pve-xtermjs: 1.0-5
qemu-server: 5.0-43
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.12-pve1~bpo1
root@pve01:~#
=================================================================================================
20190102 - 1347
Just ran
aptr-get update & apt-get dist-upgrade
root@pve01:~# free
total used free shared buff/cache available
Mem: 49441012 37361008 11861660 59380 218344 11646024
Swap: 0 0 0
root@pve01:~# pveversion -v
proxmox-ve: 5.3-1 (running kernel: 4.15.18-9-pve)
pve-manager: 5.3-6 (running version: 5.3-6/37b3c8df)
pve-kernel-4.15: 5.2-12
pve-kernel-4.15.18-9-pve: 4.15.18-30
corosync: 2.4.4-pve1
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.1-3
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-43
libpve-guest-common-perl: 2.0-18
libpve-http-server-perl: 2.0-11
libpve-storage-perl: 5.0-34
libqb0: 1.0.3-1~bpo9
lvm2: 2.02.168-pve6
lxc-pve: 3.0.2+pve1-5
lxcfs: 3.0.2-2
novnc-pve: 1.0.0-2
proxmox-widget-toolkit: 1.0-22
pve-cluster: 5.0-31
pve-container: 2.0-31
pve-docs: 5.3-1
pve-edk2-firmware: 1.20181023-1
pve-firewall: 3.0-16
pve-firmware: 2.0-6
pve-ha-manager: 2.0-5
pve-i18n: 1.0-9
pve-libspice-server1: 0.14.1-1
pve-qemu-kvm: 2.12.1-1
pve-xtermjs: 1.0-5
qemu-server: 5.0-43
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.12-pve1~bpo1
root@pve01:~#
==============================================================================
This is log for OK first Stop backup.
I have deleted from 10% to 90% to save space.
Detailed backup logs:

vzdump 100 --mailnotification always --mailto tomc@html.com.au --mode stop --quiet 1 --compress lzo --storage local
100: 2018-12-30 08:00:02 INFO: Starting Backup of VM 100 (qemu)
100: 2018-12-30 08:00:02 INFO: status = running
100: 2018-12-30 08:00:04 INFO: update VM 100: -lock backup
100: 2018-12-30 08:00:04 INFO: backup mode: stop
100: 2018-12-30 08:00:04 INFO: ionice priority: 7
100: 2018-12-30 08:00:04 INFO: VM Name: CCD-Data
100: 2018-12-30 08:00:04 INFO: include disk 'virtio0' 'local-zfs:vm-100-disk-0' 900G
100: 2018-12-30 08:00:04 INFO: stopping vm
100: 2018-12-30 08:00:14 INFO: creating archive '/var/lib/vz/dump/vzdump-qemu-100-2018_12_30-08_00_02.vma.lzo'
100: 2018-12-30 08:00:14 INFO: starting kvm to execute backup task
100: 2018-12-30 08:00:15 INFO: started backup task '89ad33d7-46a4-4108-8fae-687660820ec1'
100: 2018-12-30 08:00:15 INFO: resume VM
100: 2018-12-30 08:00:18 INFO: status: 0% (291504128/966367641600), sparse 0% (4997120), duration 3, read/write 97/95 MB/s
100: 2018-12-30 08:02:07 INFO: status: 1% (9703981056/966367641600), sparse 0% (106106880), duration 112, read/write 86/85 MB/s
100: 2018-12-30 08:03:50 INFO: status: 2% (19332530176/966367641600), sparse 0% (154939392), duration 215, read/write 93/93 MB/s
100: 2018-12-30 08:05:38 INFO: status: 3% (29062922240/966367641600), sparse 0% (183177216), duration 323, read/write 90/89 MB/s
100: 2018-12-30 08:07:34 INFO: status: 4% (38675939328/966367641600), sparse 0% (242008064), duration 439, read/write 82/82 MB/s
100: 2018-12-30 08:09:26 INFO: status: 5% (48377233408/966367641600), sparse 0% (267956224), duration 551, read/write 86/86 MB/s
100: 2018-12-30 08:11:34 INFO: status: 6% (58042482688/966367641600), sparse 0% (332967936), duration 679, read/write 75/75 MB/s
100: 2018-12-30 08:13:25 INFO: status: 7% (67651371008/966367641600), sparse 0% (520421376), duration 790, read/write 86/84 MB/s
100: 2018-12-30 08:15:09 INFO: status: 8% (77333135360/966367641600), sparse 0% (546660352), duration 894, read/write 93/92 MB/s
100: 2018-12-30 08:16:57 INFO: status: 9% (87002316800/966367641600), sparse 0% (583761920), duration 1002, read/write 89/89 MB/s
100: 2018-12-30 08:18:50 INFO: status: 10% (96688275456/966367641600), sparse 0% (610381824), duration 1115, read/write 85/85 MB/s
100: 2018-12-30 10:05:52 INFO: status: 89% (860092563456/966367641600), sparse 28% (270911610880), duration 7537, read/write 397/0 MB/s
100: 2018-12-30 10:06:16 INFO: status: 90% (869859196928/966367641600), sparse 29% (280678244352), duration 7561, read/write 406/0 MB/s
100: 2018-12-30 10:06:40 INFO: status: 91% (879654404096/966367641600), sparse 30% (290473451520), duration 7585, read/write 408/0 MB/s
100: 2018-12-30 10:07:03 INFO: status: 92% (889069436928/966367641600), sparse 31% (299888484352), duration 7608, read/write 409/0 MB/s
100: 2018-12-30 10:07:29 INFO: status: 93% (899027763200/966367641600), sparse 32% (309846810624), duration 7634, read/write 383/0 MB/s
100: 2018-12-30 10:07:54 INFO: status: 94% (908781092864/966367641600), sparse 33% (319600140288), duration 7659, read/write 390/0 MB/s
100: 2018-12-30 10:08:17 INFO: status: 95% (918171484160/966367641600), sparse 34% (328990531584), duration 7682, read/write 408/0 MB/s
100: 2018-12-30 10:08:41 INFO: status: 96% (928082427904/966367641600), sparse 35% (338901475328), duration 7706, read/write 412/0 MB/s
100: 2018-12-30 10:09:04 INFO: status: 97% (937492742144/966367641600), sparse 36% (348311789568), duration 7729, read/write 409/0 MB/s
100: 2018-12-30 10:09:28 INFO: status: 98% (947281788928/966367641600), sparse 37% (358100836352), duration 7753, read/write 407/0 MB/s
100: 2018-12-30 10:09:51 INFO: status: 99% (957087940608/966367641600), sparse 38% (367906988032), duration 7776, read/write 426/0 MB/s
100: 2018-12-30 10:10:17 INFO: status: 100% (966367641600/966367641600), sparse 38% (376804990976), duration 7802, read/write 356/14 MB/s
100: 2018-12-30 10:10:17 INFO: transferred 966367 MB in 7802 seconds (123 MB/s)
100: 2018-12-30 10:10:17 INFO: archive file size: 462.02GB
100: 2018-12-30 10:10:19 INFO: vm is online again after 7815 seconds
100: 2018-12-30 10:10:19 INFO: Finished Backup of VM 100 (02:10:17)
==============================================
This is log for Failed first Stop backup.
=====
Detailed backup logs:


vzdump 100 --mailnotification always --compress lzo --mode stop --quiet 1 --mailto tomc@html.com.au --storage local


100: 2018-12-30 11:00:02 INFO: Starting Backup of VM 100 (qemu)
100: 2018-12-30 11:00:02 INFO: status = running
100: 2018-12-30 11:00:04 INFO: update VM 100: -lock backup
100: 2018-12-30 11:00:04 INFO: backup mode: stop
100: 2018-12-30 11:00:04 INFO: ionice priority: 7
100: 2018-12-30 11:00:04 INFO: VM Name: CCD-Data
100: 2018-12-30 11:00:04 INFO: include disk 'virtio0' 'local-zfs:vm-100-disk-0' 900G
100: 2018-12-30 11:00:04 INFO: stopping vm
100: 2018-12-30 11:00:16 INFO: creating archive '/var/lib/vz/dump/vzdump-qemu-100-2018_12_30-11_00_02.vma.lzo'
100: 2018-12-30 11:00:16 INFO: starting kvm to execute backup task
100: 2018-12-30 11:00:19 INFO: restarting vm
100: 2018-12-30 11:00:22 ERROR: Backup of VM 100 failed - start failed: command '/usr/bin/kvm -id 100 -name CCD-Data -chardev 'socket,id=qmp,path=/var/run/qemu-server/100.qmp,server,nowait' -mon 'chardev=qmp,mode=control' -chardev 'socket,id=qmp-event,path=/var/run/qmeventd.sock,reconnect=5' -mon 'chardev=qmp-event,mode=control' -pidfile /var/run/qemu-server/100.pid -daemonize -smbios 'type=1,uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3' -smp '14,sockets=2,cores=7,maxcpus=14' -nodefaults -boot 'menu=on,strict=on,reboot-timeout=1000,splash=/usr/share/qemu-server/bootsplash.jpg' -vnc unix:/var/run/qemu-server/100.vnc,x509,password -no-hpet -cpu 'kvm64,+lahf_lm,+sep,+kvm_pv_unhalt,+kvm_pv_eoi,hv_spinlocks=0x1fff,hv_vapic,hv_time,hv_reset,hv_vpindex,hv_runtime,hv_relaxed,hv_synic,hv_stimer,enforce' -m 32000 -device 'pci-bridge,id=pci.1,chassis_nr=1,bus=pci.0,addr=0x1e' -device 'pci-bridge,id=pci.2,chassis_nr=2,bus=pci.0,addr=0x1f' -device 'piix3-usb-uhci,id=uhci,bus=pci.0,addr=0x1.0
x2' -device 'usb-tablet,id=tablet,bus=uhci.0,port=1' -device 'VGA,id=vga,bus=pci.0,addr=0x2' -chardev 'socket,path=/var/run/qemu-server/100.qga,server,nowait,id=qga0' -device 'virtio-serial,id=qga0,bus=pci.0,addr=0x8' -device 'virtserialport,chardev=qga0,name=org.qemu.guest_agent.0' -iscsi 'initiator-name=iqn.1993-08.org.debian:01:ca29aa295e91' -drive 'if=none,id=drive-ide2,media=cdrom,aio=threads' -device 'ide-cd,bus=ide.1,unit=0,drive=drive-ide2,id=ide2,bootindex=200' -drive 'file=/dev/zvol/rpool/data/vm-100-disk-0,if=none,id=drive-virtio0,format=raw,cache=none,aio=native,detect-zeroes=on' -device 'virtio-blk-pci,drive=drive-virtio0,id=virtio0,bus=pci.0,addr=0xa,bootindex=100' -netdev 'type=tap,id=net1,ifname=tap100i1,script=/var/lib/qemu-server/pve-bridge,downscript=/var/lib/qemu-server/pve-bridgedown,vhost=on' -device 'virtio-net-pci,mac=42:93:38:97:A6:39,netdev=net1,bus=pci.0,addr=0x13,id=net1' -rtc 'driftfix=slew,base=localtime' -machine 'type=pc' -global 'kvm-pit.lost_tick_policy=discard' -S' failed: exit code 1

 

[tomc]

This is the log from a failed manual restart of the VM.
kvm: cannot set up guest memory 'pc.ram': Cannot allocate memory
TASK ERROR: start failed: command '/usr/bin/kvm -id 100 -name CCD-Data -chardev 'socket,id=qmp,path=/var/run/qemu-server/100.qmp,server,nowait' -mon 'chardev=qmp,mode=control' -chardev 'socket,id=qmp-event,path=/var/run/qmeventd.sock,reconnect=5' -mon 'chardev=qmp-event,mode=control' -pidfile /var/run/qemu-server/100.pid -daemonize -smbios 'type=1,uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3' -smp '14,sockets=2,cores=7,maxcpus=14' -nodefaults -boot 'menu=on,strict=on,reboot-timeout=1000,splash=/usr/share/qemu-server/bootsplash.jpg' -vnc unix:/var/run/qemu-server/100.vnc,x509,password -no-hpet -cpu 'kvm64,+lahf_lm,+sep,+kvm_pv_unhalt,+kvm_pv_eoi,hv_spinlocks=0x1fff,hv_vapic,hv_time,hv_reset,hv_vpindex,hv_runtime,hv_relaxed,hv_synic,hv_stimer,enforce' -m 32000 -device 'pci-bridge,id=pci.2,chassis_nr=2,bus=pci.0,addr=0x1f' -device 'pci-bridge,id=pci.1,chassis_nr=1,bus=pci.0,addr=0x1e' -device 'piix3-usb-uhci,id=uhci,bus=pci.0,addr=0x1.0x2' -device 'usb-tablet,id=tablet,bus=uhci.0,port=1' -device 'VGA,id=vga,bus=pci.0,addr=0x2' -chardev 'socket,path=/var/run/qemu-server/100.qga,server,nowait,id=qga0' -device 'virtio-serial,id=qga0,bus=pci.0,addr=0x8' -device 'virtserialport,chardev=qga0,name=org.qemu.guest_agent.0' -iscsi 'initiator-name=iqn.1993-08.org.debian:01:ca29aa295e91' -drive 'file=/var/lib/vz/template/iso/virtio-win-0.1.141.iso,if=none,id=drive-ide2,media=cdrom,aio=threads' -device 'ide-cd,bus=ide.1,unit=0,drive=drive-ide2,id=ide2,bootindex=200' -drive 'file=/dev/zvol/rpool/data/vm-100-disk-0,if=none,id=drive-virtio0,format=raw,cache=none,aio=native,detect-zeroes=on' -device 'virtio-blk-pci,drive=drive-virtio0,id=virtio0,bus=pci.0,addr=0xa,bootindex=100' -netdev 'type=tap,id=net1,ifname=tap100i1,script=/var/lib/qemu-server/pve-bridge,downscript=/var/lib/qemu-server/pve-bridgedown,vhost=on' -device 'virtio-net-pci,mac=42:93:38:97:A6:39,netdev=net1,bus=pci.0,addr=0x13,id=net1' -rtc 'driftfix=slew,base=localtime' -machine 'type=pc' -global 'kvm-pit.lost_tick_policy=discard'' failed: exit code 1.

 

[wolfgang]

Hi,

please try again with scsi as disk interface and use virtio as SCSI controller card.

 

[tomc]

Hi Wolfgang
Under options, of the VM,
Under SCSI Controller it is already VirtiO SCSI.
Where can I change the settings you require?

Tom

 

[sb-jw]

You have to go to "Hardware" unmount your disk and attach it again as "SCSI" (Bus Type). You can do this Online, but you have to stop the VM and start it again to take effect of this.

 

[tomc]

Hi Wolfgang and sb-jw
I tried that
Here is my config file and pveversion file
===============================
config
agent: 1,fstrim_cloned_disks=1
balloon: 0
boot: cd
bootdisk: scsi0
cores: 7
ide2: local:iso/virtio-win-0.1.141.iso,media=cdrom,size=309208K
memory: 32000
name: CCD-Data
net1: virtio=42:93:38:97:A6:39,bridge=vmbr0
numa: 0
onboot: 1
ostype: win10
scsi0: local-zfs:vm-100-disk-0,size=900G
scsihw: virtio-scsi-pci
smbios1: uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3
sockets: 2
======================
pveversion
root@pve01:~# pveversion -v
proxmox-ve: 5.3-1 (running kernel: 4.15.18-9-pve)
pve-manager: 5.3-6 (running version: 5.3-6/37b3c8df)
pve-kernel-4.15: 5.2-12
pve-kernel-4.15.18-9-pve: 4.15.18-30
corosync: 2.4.4-pve1
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.1-3
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-43
libpve-guest-common-perl: 2.0-18
libpve-http-server-perl: 2.0-11
libpve-storage-perl: 5.0-34
libqb0: 1.0.3-1~bpo9
lvm2: 2.02.168-pve6
lxc-pve: 3.0.2+pve1-5
lxcfs: 3.0.2-2
novnc-pve: 1.0.0-2
proxmox-widget-toolkit: 1.0-22
pve-cluster: 5.0-31
pve-container: 2.0-31
pve-docs: 5.3-1
pve-edk2-firmware: 1.20181023-1
pve-firewall: 3.0-16
pve-firmware: 2.0-6
pve-ha-manager: 2.0-5
pve-i18n: 1.0-9
pve-libspice-server1: 0.14.1-1
pve-qemu-kvm: 2.12.1-1
pve-xtermjs: 1.0-5
qemu-server: 5.0-43
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.12-pve1~bpo1
root@pve01:~#
==========================================
I then restart the Windows 10 VM.
I get the Win 10 boot screen Then blue screen with message
"Your PC ran into a problem and needs to restart, we will restart it for you.
Stop code inaccessible boot device.
======================================
I restarted a few times, same result.
I have now reset to original config.
Any other ideas?

 

[tomc]

HI
I did change the boot order to scsi0.

 

[sb-jw]

Did you installed the SCSI driver from the VirtIO ISO?

 

[tomc]

Hi sp-jw
No I didn't, that problem now corrected.
Windows 10 boots.
I have changed all backups to stop.
We just wait now and see how they run.
Thank you for your assistance.

 

[tomc]

HI
First backup runs OK.
Here is the Log
from 10% to 90% removed
Second backup failed with same error
log is second below
========================================
Successful backup
INFO: starting new backup job: vzdump 100 --mode stop --quiet 1 --mailto tomc@html.com.au --compress lzo --mailnotification always --storage local
INFO: Starting Backup of VM 100 (qemu)
INFO: status = running
INFO: update VM 100: -lock backup
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: CCD-Data
INFO: include disk 'scsi0' 'local-zfs:vm-100-disk-0' 900G
INFO: stopping vm
INFO: creating archive '/var/lib/vz/dump/vzdump-qemu-100-2019_01_03-17_00_02.vma.lzo'
INFO: starting kvm to execute backup task
INFO: started backup task 'a6c1e734-3e60-41d8-afca-80d606692166'
INFO: resume VM
INFO: status: 0% (304021504/966367641600), sparse 0% (4677632), duration 3, read/write 101/99 MB/s
INFO: status: 1% (9666166784/966367641600), sparse 0% (239489024), duration 127, read/write 75/73 MB/s
INFO: status: 2% (19378798592/966367641600), sparse 0% (294281216), duration 260, read/write 73/72 MB/s
INFO: status: 3% (29007806464/966367641600), sparse 0% (316170240), duration 368, read/write 89/88 MB/s
INFO: status: 4% (38722863104/966367641600), sparse 0% (396075008), duration 495, read/write 76/75 MB/s
INFO: status: 5% (48331751424/966367641600), sparse 0% (422002688), duration 601, read/write 90/90 MB/s
INFO: status: 6% (58057424896/966367641600), sparse 0% (483586048), duration 730, read/write 75/74 MB/s
INFO: status: 7% (67691216896/966367641600), sparse 0% (658702336), duration 839, read/write 88/86 MB/s
INFO: status: 8% (77365575680/966367641600), sparse 0% (684384256), duration 942, read/write 93/93 MB/s
INFO: status: 9% (86988161024/966367641600), sparse 0% (721195008), duration 1047, read/write 91/91 MB/s
INFO: status: 90% (870094733312/966367641600), sparse 28% (279625371648), duration 7365, read/write 405/0 MB/s
INFO: status: 91% (879402942464/966367641600), sparse 29% (288933580800), duration 7387, read/write 423/0 MB/s
INFO: status: 92% (889453150208/966367641600), sparse 30% (298983788544), duration 7411, read/write 418/0 MB/s
INFO: status: 93% (898829975552/966367641600), sparse 31% (308360613888), duration 7435, read/write 390/0 MB/s
INFO: status: 94% (908434472960/966367641600), sparse 32% (317965111296), duration 7459, read/write 400/0 MB/s
INFO: status: 95% (918166568960/966367641600), sparse 33% (327697207296), duration 7482, read/write 423/0 MB/s
INFO: status: 96% (928012238848/966367641600), sparse 34% (337542877184), duration 7506, read/write 410/0 MB/s
INFO: status: 97% (937517645824/966367641600), sparse 35% (347048284160), duration 7529, read/write 413/0 MB/s
INFO: status: 98% (947216449536/966367641600), sparse 36% (356747087872), duration 7553, read/write 404/0 MB/s
INFO: status: 99% (956748726272/966367641600), sparse 37% (366279364608), duration 7576, read/write 414/0 MB/s
INFO: status: 100% (966367641600/966367641600), sparse 38% (375516569600), duration 7602, read/write 369/14 MB/s
INFO: transferred 966367 MB in 7602 seconds (127 MB/s)
INFO: archive file size: 459.50GB
INFO: delete old backup '/var/lib/vz/dump/vzdump-qemu-100-2019_01_02-02_00_03.vma.lzo'
INFO: vm is online again after 7636 seconds
INFO: Finished Backup of VM 100 (02:07:18)
INFO: Backup job finished successfully
TASK OK
==========================================
This is failed log
VMID NAME STATUS TIME SIZE FILENAME
100 CCD-Data FAILED 00:00:19 start failed: command '/usr/bin/kvm -id 100 -name CCD-Data -chardev 'socket,id=qmp,path=/var/run/qemu-server/100.qmp,server,nowait' -mon 'chardev=qmp,mode=control' -chardev 'socket,id=qmp-event,path=/var/run/qmeventd.sock,reconnect=5' -mon 'chardev=qmp-event,mode=control' -pidfile /var/run/qemu-server/100.pid -daemonize -smbios 'type=1,uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3' -smp '14,sockets=2,cores=7,maxcpus=14' -nodefaults -boot 'menu=on,strict=on,reboot-timeout=1000,splash=/usr/share/qemu-server/bootsplash.jpg' -vnc unix:/var/run/qemu-server/100.vnc,x509,password -no-hpet -cpu 'kvm64,+lahf_lm,+sep,+kvm_pv_unhalt,+kvm_pv_eoi,hv_spinlocks=0x1fff,hv_vapic,hv_time,hv_reset,hv_vpindex,hv_runtime,hv_relaxed,hv_synic,hv_stimer,enforce' -m 32000 -device 'pci-bridge,id=pci.1,chassis_nr=1,bus=pci.0,addr=0x1e' -device 'pci-bridge,id=pci.2,chassis_nr=2,bus=pci.0,addr=0x1f' -device 'piix3-usb-uhci,id=uhci,bus=pci.0,addr=0x1.0x2' -device 'usb-tablet,id=tablet,bus=uhci.0,port=1' -device 'VGA,id=vga,bus=pci.0,addr=0x2' -chardev 'socket,path=/var/run/qemu-server/100.qga,server,nowait,id=qga0' -device 'virtio-serial,id=qga0,bus=pci.0,addr=0x8' -device 'virtserialport,chardev=qga0,name=org.qemu.guest_agent.0' -iscsi 'initiator-name=iqn.1993-08.org.debian:01:ca29aa295e91' -drive 'if=none,id=drive-ide2,media=cdrom,aio=threads' -device 'ide-cd,bus=ide.1,unit=0,drive=drive-ide2,id=ide2,bootindex=200' -device 'virtio-scsi-pci,id=scsihw0,bus=pci.0,addr=0x5' -drive 'file=/dev/zvol/rpool/data/vm-100-disk-0,if=none,id=drive-scsi0,format=raw,cache=none,aio=native,detect-zeroes=on' -device 'scsi-hd,bus=scsihw0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0,id=scsi0,bootindex=100' -netdev 'type=tap,id=net1,ifname=tap100i1,script=/var/lib/qemu-server/pve-bridge,downscript=/var/lib/qemu-server/pve-bridgedown,vhost=on' -device 'virtio-net-pci,mac=42:93:38:97:A6:39,netdev=net1,bus=pci.0,addr=0x13,id=net1' -rtc 'driftfix=slew,base=localtime' -machine 'type=pc' -global 'kvm-pit.lost_tick_policy=discard' -S' failed: exit code 1
TOTAL 00:00:19 0KB


Detailed backup logs:


vzdump 100 --mailto tomc@html.com.au --mode stop --storage local --quiet 1 --mailnotification always --compress lzo


100: 2019-01-03 20:00:02 INFO: Starting Backup of VM 100 (qemu)
100: 2019-01-03 20:00:02 INFO: status = running
100: 2019-01-03 20:00:04 INFO: update VM 100: -lock backup
100: 2019-01-03 20:00:04 INFO: backup mode: stop
100: 2019-01-03 20:00:04 INFO: ionice priority: 7
100: 2019-01-03 20:00:04 INFO: VM Name: CCD-Data
100: 2019-01-03 20:00:04 INFO: include disk 'scsi0' 'local-zfs:vm-100-disk-0' 900G
100: 2019-01-03 20:00:04 INFO: stopping vm
100: 2019-01-03 20:00:15 INFO: creating archive '/var/lib/vz/dump/vzdump-qemu-100-2019_01_03-20_00_02.vma.lzo'
100: 2019-01-03 20:00:15 INFO: starting kvm to execute backup task
100: 2019-01-03 20:00:18 INFO: restarting vm
100: 2019-01-03 20:00:21 ERROR: Backup of VM 100 failed - start failed: command '/usr/bin/kvm -id 100 -name CCD-Data -chardev 'socket,id=qmp,path=/var/run/qemu-server/100.qmp,server,nowait' -mon 'chardev=qmp,mode=control' -chardev 'socket,id=qmp-event,path=/var/run/qmeventd.sock,reconnect=5' -mon 'chardev=qmp-event,mode=control' -pidfile /var/run/qemu-server/100.pid -daemonize -smbios 'type=1,uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3' -smp '14,sockets=2,cores=7,maxcpus=14' -nodefaults -boot 'menu=on,strict=on,reboot-timeout=1000,splash=/usr/share/qemu-server/bootsplash.jpg' -vnc unix:/var/run/qemu-server/100.vnc,x509,password -no-hpet -cpu 'kvm64,+lahf_lm,+sep,+kvm_pv_unhalt,+kvm_pv_eoi,hv_spinlocks=0x1fff,hv_vapic,hv_time,hv_reset,hv_vpindex,hv_runtime,hv_relaxed,hv_synic,hv_stimer,enforce' -m 32000 -device 'pci-bridge,id=pci.1,chassis_nr=1,bus=pci.0,addr=0x1e' -device 'pci-bridge,id=pci.2,chassis_nr=2,bus=pci.0,addr=0x1f' -device 'piix3-usb-uhci,id=uhci,bus=pci.0,addr=0x1.0
x2' -device 'usb-tablet,id=tablet,bus=uhci.0,port=1' -device 'VGA,id=vga,bus=pci.0,addr=0x2' -chardev 'socket,path=/var/run/qemu-server/100.qga,server,nowait,id=qga0' -device 'virtio-serial,id=qga0,bus=pci.0,addr=0x8' -device 'virtserialport,chardev=qga0,name=org.qemu.guest_agent.0' -iscsi 'initiator-name=iqn.1993-08.org.debian:01:ca29aa295e91' -drive 'if=none,id=drive-ide2,media=cdrom,aio=threads' -device 'ide-cd,bus=ide.1,unit=0,drive=drive-ide2,id=ide2,bootindex=200' -device 'virtio-scsi-pci,id=scsihw0,bus=pci.0,addr=0x5' -drive 'file=/dev/zvol/rpool/data/vm-100-disk-0,if=none,id=drive-scsi0,format=raw,cache=none,aio=native,detect-zeroes=on' -device 'scsi-hd,bus=scsihw0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0,id=scsi0,bootindex=100' -netdev 'type=tap,id=net1,ifname=tap100i1,script=/var/lib/qemu-server/pve-bridge,downscript=/var/lib/qemu-server/pve-bridgedown,vhost=on' -device 'virtio-net-pci,mac=42:93:38:97:A6:39,netdev=net1,bus=pci.0,addr=0x13,id=net1' -rtc 'driftfix=slew,base=localtime' -machine 'type=pc' -global 'kvm-pit.lost_tick_policy=discard' -S' failed: exit code 1
==========================================

 

[sb-jw]

Do you installed the QEMU Guest Agent in the Windows VM too and after this you have stop the whole VM and start it again (a reboot isn't enough)? AFAICS you have enabled the Guest Agent under Options in the VM, but your Log isn't really clear for me:

name=org.qemu.guest_agent.0

So im not sure, if the Guest Agent works correctly. You should see the IP address of the VM in PVE on the Overview of the VM itself.

 

[tomc]

Hi
I have done a shut down of Win 10 VM, then shut down Proxmox VE server.
Then restarted Proxmox VE, which auto starts Windows 10 VM
I go into the Windows 10VM, I was running 2 (two) ips 10.0.0.x and 192.168.0.x on the same NIC, so I can easily switch between internet connections.
I have 2 internet connections, so i have now removed the 192.168.0.x ip address.
The VE only has one ip address 10.0.0.10 gateway for VM and VE is 10.0.0.1.
I saw another post saying they changed to using GZip and that fixed the problem.
So I am trying that. as well.
Re Guest agent.
If I watch the summery section of the Windows 10 VM while it is starting until the VM fully starts up,
Under IP,s it says "Guest agent not running" once started it says "No Network information"
In services under the VM I have both Qemu Guest Agent (Automatic) running and "Qemu Guest Agent (Automatic) VSS Provider Running.
Prior to installing guest agent I could not shut down the Windows 10 VM from Proxmox GUI, even though following config settings to do so.
Here is my settings again.
I am waiting for 1400 backup to start ( all backups set to stop, alternating between stop and snapshot still had intermittent failures)
=========================================================
free
root@pve01:~# free
total used free shared buff/cache available
Mem: 49441012 37060008 12217432 53136 163572 11977608
Swap: 0 0 0
root@pve01:~#
=========================================================
pveversion -v
proxmox-ve: 5.3-1 (running kernel: 4.15.18-9-pve)
pve-manager: 5.3-6 (running version: 5.3-6/37b3c8df)
pve-kernel-4.15: 5.2-12
pve-kernel-4.15.18-9-pve: 4.15.18-30
corosync: 2.4.4-pve1
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.1-3
libpve-apiclient-perl: 2.0-5
libpve-common-perl: 5.0-43
libpve-guest-common-perl: 2.0-18
libpve-http-server-perl: 2.0-11
libpve-storage-perl: 5.0-34
libqb0: 1.0.3-1~bpo9
lvm2: 2.02.168-pve6
lxc-pve: 3.0.2+pve1-5
lxcfs: 3.0.2-2
novnc-pve: 1.0.0-2
proxmox-widget-toolkit: 1.0-22
pve-cluster: 5.0-31
pve-container: 2.0-31
pve-docs: 5.3-1
pve-edk2-firmware: 1.20181023-1
pve-firewall: 3.0-16
pve-firmware: 2.0-6
pve-ha-manager: 2.0-5
pve-i18n: 1.0-9
pve-libspice-server1: 0.14.1-1
pve-qemu-kvm: 2.12.1-1
pve-xtermjs: 1.0-5
qemu-server: 5.0-43
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3
zfsutils-linux: 0.7.12-pve1~bpo1
root@pve01:~#
=========================================================
Config
agent: 1
balloon: 0
boot: cd
bootdisk: scsi0
cores: 7
ide2: none,media=cdrom
memory: 32000
name: CCD-Data
net1: virtio=42:93:38:97:A6:39,bridge=vmbr0
numa: 0
onboot: 1
ostype: win10
scsi0: local-zfs:vm-100-disk-0,size=900G
scsihw: virtio-scsi-pci
smbios1: uuid=1a62c16f-e881-435a-9b9f-1d4e3842cfa3
sockets: 2
=========================================================

 

[sb-jw]

virtio-win-0.1.141.iso

Please try the latest, not the stable. IIRC it doesn't worked by me too with older Version, but im not sure, what Version i installed. But mean it was the latest.

 

[tomc]

Hi sb-jw
I updated the Client to the latest Virtio (0.1.60)
I now have IP addresses showing in the GUI.
BUT
Second backup still fails with same error.
Found this article.
https://forums.unraid.net/topic/46006-error-starting-vm/
and from that ran these commands
=============================================================
sudo sysctl -w vm.drop_caches=3
and
sudo sync && echo 3 | sudo tee /proc/sys/vm/drop_caches
=============================================================
I can now start the VM which I could not do before unless I restarted the VE.
I will now see how the Backups run.

I don't know if the setting from those commands stick??
But we will find out as I do more testing.