Another vzdump problem. VERY STRANGE!

J

jcpham

New Member
Apr 12, 2009
19
0
1
The problem is essentially vzdump is filling up every bit of disk space on my external USB drive while trying to backup to KVM VM's. The USB drive is 500GB (/mnt/ext), and this process worked fine prior to my last dist-upgrade to pve 1.4. Here's all the good info:

volt:~# pveversion -v
pve-manager: 1.4-10 (pve-manager/1.4/4403)
qemu-server: 1.1-8
pve-kernel: 2.6.24-18
pve-qemu-kvm: 0.11.0-2
pve-firmware: 1
vncterm: 0.9-2
vzctl: 3.0.23-1pve3
vzdump: 1.2-5
vzprocps: 2.0.11-1dso2
vzquota: 3.0.11-1

volt:~# qm list
VMID NAME STATUS MEM(MB) BOOTDISK(GB) PID
101 SBS running 4096 300.00 12586
102 SQL running 2048 80.00 4210

volt:/var/lib/vz/images# ls -lnh
total 8.0K
drwxr-xr-x 2 0 0 4.0K 2009-01-05 07:23 101
drwxr-xr-x 2 0 0 4.0K 2009-01-06 06:02 102

volt:/var/lib/vz/images# df -H /var/lib/vz
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/pve-data 870G 370G 501G 43% /var/lib/vz

volt:/var/lib/vz/images/101# ls -lnh
total 267G
-rw-r--r-- 1 0 0 267G 2010-01-11 15:31 vm-101-disk.qcow2

volt:/var/lib/vz/images/102# ls -lnh
total 78G
-rw-r--r-- 1 0 0 78G 2010-01-11 15:31 vm-102-disk.qcow2

So that's it on this box. 2 KVM VM's. Nothing else.


volt:~#cat /etc/cron.d/vzdump
# Atomatically generated file - do not edit

PATH="/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin"

00 20 * * 1,2,3,4,5 root vzdump --quiet --snapshot --dumpdir /mnt/ext --tmpdir /mnt/ext --bwlimit 7500 --maxfiles 1 --mailto xyz@domain.com 101 102

Finally, the vzdump log:
 Detailed backup logs:
vzdump --quiet --snapshot --dumpdir /mnt/ext --tmpdir /mnt/ext --bwlimit 7500 --maxfiles 1 --mailto xyz@domain.com 101 102 101: Jan 08 20:00:02 INFO: Starting Backup of VM 101 (qemu)101: Jan 08 20:00:02 INFO: running101: Jan 08 20:00:02 INFO: status = running101: Jan 08 20:00:03 INFO: backup mode: snapshot101: Jan 08 20:00:03 INFO: bandwidth limit: 7500 KB/s101: Jan 08 20:00:03 INFO: Logical volume "vzsnap-volt-0" created101: Jan 08 20:00:03 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_08-20_00_02.tar'101: Jan 08 20:00:03 INFO: adding '/mnt/ext/vzdumptmp658/qemu-server.conf' to archive ('qemu-server.conf')101: Jan 08 20:00:03 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')101: Jan 09 13:47:44 INFO: 491568132096 B 457.8 GB 64060.6 s (17:47 h) 7673492 B/s 7.32 MB/s101: Jan 09 13:47:44 INFO: write: No space left on device101: Jan 09 13:47:44 INFO: received signal - terminate process101: Jan 09 13:47:45 INFO: /dev/dm-3: read failed after 0 of 4096 at 0: Input/output error101: Jan 09 13:47:55 INFO: Logical volume "vzsnap-volt-0" successfully removed101: Jan 09 14:00:09 ERROR: Backup of VM 101 failed - command '/usr/lib/qemu-server/vmtar '/mnt/ext/vzdumptmp658/qemu-server.conf' 'qemu-server.conf' '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' 'vm-disk-ide0.qcow2' |cstream -t 7680000 >/mnt/ext/vzdump-qemu-101-2010_01_08-20_00_02.dat' failed with exit code 2 102: Jan 09 14:00:09 INFO: Starting Backup of VM 102 (qemu)102: Jan 09 14:00:10 INFO: running102: Jan 09 14:00:10 INFO: status = running102: Jan 09 14:00:25 INFO: backup mode: snapshot102: Jan 09 14:00:25 INFO: bandwidth limit: 7500 KB/s102: Jan 09 14:00:25 INFO: Logical volume "vzsnap-volt-0" created102: Jan 09 14:00:26 INFO: creating archive '/mnt/ext/vzdump-qemu-102-2010_01_09-14_00_09.tar'102: Jan 09 14:00:26 INFO: adding '/mnt/ext/vzdumptmp658/qemu-server.conf' to archive ('qemu-server.conf')102: Jan 09 14:00:26 INFO: adding '/mnt/vzsnap0/images/102/vm-102-disk.qcow2' to archive ('vm-disk-ide0.qcow2')102: Jan 10 07:48:06 INFO: 491568128000 B 457.8 GB 64060.6 s (17:47 h) 7673488 B/s 7.32 MB/s102: Jan 10 07:48:06 INFO: write: No space left on device102: Jan 10 07:48:06 INFO: received signal - terminate process102: Jan 10 07:48:07 INFO: /dev/dm-3: read failed after 0 of 4096 at 0: Input/output error102: Jan 10 07:48:16 INFO: Logical volume "vzsnap-volt-0" successfully removed102: Jan 10 08:00:01 ERROR: Backup of VM 102 failed - command '/usr/lib/qemu-server/vmtar '/mnt/ext/vzdumptmp658/qemu-server.conf' 'qemu-server.conf' '/mnt/vzsnap0/images/102/vm-102-disk.qcow2' 'vm-disk-ide0.qcow2' |cstream -t 7680000 >/mnt/ext/vzdump-qemu-102-2010_01_09-14_00_09.dat' failed with exit code 2
Any help would be much appreciated. Some of the things that vzdump is doing - well, I don't understand them. Why it's writing 457.8 GB to backup a 80GB VM is very confusing to me.

 
Seems the LVM snapshot runs out of space. Plesase create the file /etc/vzdump.conf and add 'size: 2048' (see 'man vzdump') - Does that solve the problem?
 
Added!

root@volt ~# cat /etc/vzdump.conf
size: 2048

I've read the man pages serveral times on vzdump. I know it's your perl script, Diet. I've seen references to /etc/vzdump.conf in the actual /usr/sbin/vzdump script itself, but the manpages don't really explain anything about vzdump.conf.

Is their a wiki or extensive documentation on what ( or what else) the contents of vzdump.conf do?

What does "size: 2048" do? this is not mentioned in the manpages for vzdump either.

I'll have to wait until tonight to test this, but I'd love to know more about vzdump.conf.

With the vzdump backups being named daily now, I have to add --maxfiles 1 to /etc/cron.d/vzdump, because our backup drive only has room for 1 days worth of backups - we just swap the drives every day.
 
jcpham said:
Added!

root@volt ~# cat /etc/vzdump.conf
size: 2048

I've read the man pages serveral times on vzdump. I know it's your perl script, Diet. I've seen references to /etc/vzdump.conf in the actual /usr/sbin/vzdump script itself, but the manpages don't really explain anything about vzdump.conf.

Is their a wiki or extensive documentation on what ( or what else) the contents of vzdump.conf do?

What does "size: 2048" do? this is not mentioned in the manpages for vzdump either.

I'll have to wait until tonight to test this, but I'd love to know more about vzdump.conf.

With the vzdump backups being named daily now, I have to add --maxfiles 1 to /etc/cron.d/vzdump, because our backup drive only has room for 1 days worth of backups - we just swap the drives every day.
Click to expand...

the man pages describes it all - do you use the latest vzdump release (vzdump: 1.2-5)?

post your:

Code: 
pveversion -v
 
jcpham said:
What does "size: 2048" do? this is not mentioned in the manpages for vzdump either.
Click to expand...

It is the size allocated for the LVM snapshot (consult LVM documentation for that).

jcpham said:
With the vzdump backups being named daily now, I have to add --maxfiles 1 to /etc/cron.d/vzdump,
Click to expand...

that is the default anyways.

jcpham said:
because our backup drive only has room for 1 days worth of backups - we just swap the drives every day.
Click to expand...

even with maxfiles set to 1, you need two times the space. Because the old backup is deleted after the new one sucessfully finished.
 
dietmar said:
It is the size allocated for the LVM snapshot (consult LVM documentation for that).



that is the default anyways.



even with maxfiles set to 1, you need two times the space. Because the old backup is deleted after the new one sucessfully finished.
Click to expand...

Thanks, this did the trick. I went back and re-read the man pages again and found everything I needed. Sorry, I was wrong about this. Any chance you guys could explain the INFO messages about removing stale snapshots below:

Code: 
Jan 12 22:00:03 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-volt-0'
Jan 12 22:00:03 INFO:   Logical volume "vzsnap-volt-0" successfully removed
Jan 12 22:00:03 INFO:   /dev/dm-4: stat failed: No such file or directory
Jan 12 22:00:03 INFO:   Path /dev/dm-4 no longer valid for device(254,4)
Jan 12 22:00:03 INFO:   /dev/block/254:4: stat failed: No such file or directory
Jan 12 22:00:03 INFO:   Path /dev/block/254:4 no longer valid for device(254,4)
Jan 12 22:00:03 INFO:   /dev/disk/by-id/dm-name-pve-data-real: stat failed: No such file or directory
Jan 12 22:00:03 INFO:   Path /dev/disk/by-id/dm-name-pve-data-real no longer valid for device(254,4)
Jan 12 22:00:03 INFO:   /dev/disk/by-id/dm-uuid-LVM-DKuxPfKc43djsO52l68ZZDaS3bDFeAjSa61QNUrTYjG4Cvy1fQ4zQ7Rdm7GS9VMh-real: stat failed: No such file or directory
Jan 12 22:00:03 INFO:   Path /dev/disk/by-id/dm-uuid-LVM-DKuxPfKc43djsO52l68ZZDaS3bDFeAjSa61QNUrTYjG4Cvy1fQ4zQ7Rdm7GS9VMh-real no longer valid for device(254,4)
Jan 12 22:00:03 INFO:   Logical volume "vzsnap-volt-0" created
Jan 12 22:00:03 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_12-22_00_02.tar'
Jan 12 22:00:03 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_12-22_00_02.tmp/qemu-server.conf' to archive ('qemu-server.conf')
Jan 12 22:00:03 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
Jan 13 03:08:48 INFO: Total bytes written: 284523182080 (14.65 MiB/s)
Jan 13 03:08:48 INFO: archive file size: 264.98GB
Jan 13 03:08:54 INFO:   Logical volume "vzsnap-volt-0" successfully removed
Jan 13 03:08:54 INFO: Finished Backup of VM 101 (05:08:52)

Either way, thanks again. I'm back on track. I'll figure out how to deal with the vzdump .tar files and the new naming convention.
 
jcpham said:
Thanks, this did the trick. I went back and re-read the man pages again and found everything I needed. Sorry, I was wrong about this. Any chance you guys could explain the INFO messages about removing stale snapshots below:
Click to expand...

Seems there is an LVM snapshot from previous vzdump '/dev/pve/vzsnap-volt-0' (caused by aborting the backup?) , but underlying device is no longer there (you deleted the VM?).
 
Seems there is an LVM snapshot from previous vzdump '/dev/pve/vzsnap-volt-0' (caused by aborting the backup?) , but underlying device is no longer there (you deleted the VM?).
Click to expand...
Nope, haven't deleted any VM's, PVE host has always just had the same two KVM VM's. Still having very Strange things happening with vzdump.

Newest backup logs:

January 18th, Backup begins at 8:00 PM CST:

Code: 
root@volt ext# cat  vzdump-qemu-101-2010_01_18-20_09_46.log
  Jan 18 20:09:46 INFO: Starting Backup of VM 101 (qemu)
  Jan 18 20:09:46 INFO: running
  Jan 18 20:09:46 INFO: status = running
  Jan 18 20:09:47 INFO: backup mode: snapshot
  Jan 18 20:09:47 INFO: bandwidth limit: 10000 KB/s
  Jan 18 20:09:47 INFO: HOOK: pre-stop snapshot 101
  Jan 18 20:09:47 INFO: HOOK: snapshot 101
  Jan 18 20:09:47 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.log
  Jan 18 20:09:47 INFO: HOOK: pre-restart snapshot 101
  Jan 18 20:09:47 INFO: HOOK: snapshot 101
  Jan 18 20:09:47 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.log
  Jan 18 20:09:47 INFO:   Logical volume "vzsnap-volt-0" created
  Jan 18 20:09:47 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tar'
  Jan 18 20:09:47 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tmp/qemu-server.conf' to archive ('qemu-server.conf')
  Jan 18 20:09:47 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
  Jan 19 09:30:59 INFO: 491568132096 B 457.8 GB 48071.1 s (13:21 h) 10225859 B/s 9.75 MB/s
  Jan 19 09:30:59 INFO: write: No space left on device
  Jan 19 09:30:59 INFO: received signal - terminate process
  Jan 19 09:31:00 INFO:   Logical volume "vzsnap-volt-0" successfully removed
  Jan 19 09:43:37 ERROR: Backup of VM 101 failed - command '/usr/lib/qemu-server/vmtar '/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tmp/qemu-server.conf' 'qemu-server.conf' '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' 'vm-disk-ide0.qcow2' |cstream -t 10240000 >/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.dat' failed with exit code 2
  Jan 19 09:43:37 INFO: HOOK: backup-abort snapshot 101
  Jan 19 09:43:37 INFO: HOOK: snapshot 101
  Jan 19 09:43:37 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.log
So the backup fails because it writes to all 457.8 GB trying to archive a 291GB .qcow2 VM drive image. I think this is strange.

Code: 
[root@volt:/var/lib/vz/images/101]$ list
total 291G
-rw-r--r-- 1 0 0 291G 2010-01-20 15:59 vm-101-disk.qcow2
January 19th, Backup begins at 8:00 PM CST:

Code: 
101: Jan 19 20:00:36 INFO: Starting Backup of VM 101 (qemu)
101: Jan 19 20:00:37 INFO: running
101: Jan 19 20:00:37 INFO: status = running
101: Jan 19 20:00:38 INFO: backup mode: snapshot
101: Jan 19 20:00:38 INFO: bandwidth limit: 10000 KB/s
101: Jan 19 20:00:38 INFO: HOOK: pre-stop snapshot 101
101: Jan 19 20:00:38 INFO: HOOK: snapshot 101
101: Jan 19 20:00:38 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.log
101: Jan 19 20:00:38 INFO: HOOK: pre-restart snapshot 101
101: Jan 19 20:00:38 INFO: HOOK: snapshot 101
101: Jan 19 20:00:38 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.log
101: Jan 19 20:00:38 INFO: trying to remove stale snapshot '/dev/pve/vzsnap-volt-0'
101: Jan 19 20:00:38 INFO: umount: /mnt/vzsnap0: not mounted
101: Jan 19 20:00:38 ERROR: command 'umount /mnt/vzsnap0' failed with exit code 1
101: Jan 19 20:00:38 INFO:   Logical volume "vzsnap-volt-0" successfully removed
101: Jan 19 20:00:38 INFO:   Logical volume "vzsnap-volt-0" created
101: Jan 19 20:00:38 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.tar'
101: Jan 19 20:00:38 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.tmp/qemu-server.conf' to archive ('qemu-server.conf')
101: Jan 19 20:00:38 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
101: Jan 20 03:57:08 INFO: Total bytes written: 292745939968 (9.77 MiB/s)
101: Jan 20 03:57:08 INFO: archive file size: 272.64GB101: Jan 20 03:57:08 INFO: HOOK: backup-end snapshot 101
101: Jan 20 03:57:08 INFO: HOOK: snapshot 101
101: Jan 20 03:57:08 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_19-20_00_36.log
101: Jan 20 03:57:11 INFO:   Logical volume "vzsnap-volt-0" successfully removed
101: Jan 20 03:57:11 INFO: Finished Backup of VM 101 (07:56:35) 
102: Jan 20 03:57:11 INFO: Starting Backup of VM 102 (qemu)
102: Jan 20 03:57:11 INFO: running
102: Jan 20 03:57:11 INFO: status = running
102: Jan 20 03:57:12 INFO: setting parameters failed - VM is locked (backup)
102: Jan 20 03:57:12 ERROR: Backup of VM 102 failed - command 'qm set 102 --lock backup' failed with exit code 255
102: Jan 20 03:57:12 INFO: Use of uninitialized value $hostname in concatenation (.) or string at /root/script/rmrfusb.pl line 41.
102: Jan 20 03:57:12 INFO: HOOK: backup-abort 102
102: Jan 20 03:57:12 INFO: HOOK: 102
102: Jan 20 03:57:12 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=;tarfile=/mnt/ext/vzdump-qemu-102-2010_01_20-03_57_11.tar;logfile=/mnt/ext/vzdump-qemu-102-2010_01_20-03_57_11.log
Looks like this time it fails because of my hook script syntax. Nothing was changed between the time these 2 backups ran. No config file changes, nothing. Hook script is the same on both days.

vzdump.conf and hook-script:

Code: 
[root@volt:/var/lib/vz/images/101]$ cat /etc/vzdump.conf
script: /root/script/rmrfusb.pl
size: 2048
dumpdir: /mnt/ext
#mode: suspend
bwlimit: 10000
maxfiles: 1


[root@volt:/var/lib/vz/images/101]$ cat /root/script/rmrfusb.pl
#!/usr/bin/perl -w

# example hook script for vzdump (--script option)

use strict;

print "HOOK: " . join (' ', @ARGV) . "\n";

my $phase = shift;

if ($phase eq 'job-start') {

# rm -rf /mnt/ext
system ("rm -rf /mnt/ext/*") == 0 ||
            die "deletion of all files on external-usb failed";

} elsif ($phase eq 'job-end'  ||
         $phase eq 'job-abort' ||
         $phase eq 'backup-start' ||
         $phase eq 'backup-end' ||
         $phase eq 'backup-abort' ||
         $phase eq 'pre-stop' ||
         $phase eq 'pre-restart') {

    print "HOOK: " . join (' ', @ARGV) . "\n";

    my $mode = shift; # stop/suspend/snapshot

    my $vmid = shift;

    my $vmtype = $ENV{VMTYPE}; # openvz/qemu

    my $dumpdir = $ENV{DUMPDIR};

    my $hostname = $ENV{HOSTNAME};

    my $tarfile = $ENV{TARFILE};

    my $logfile = $ENV{LOGFILE};

    print "HOOK-ENV: vmtype=$vmtype;dumpdir=$dumpdir;hostname=$hostname;tarfile=$tarfile;logfile=$logfile\n";

    # example: copy resulting files to another host using scp
    #if ($phase eq 'backup-end') {
    #   system ("scp $tarfile $logfile backup-host:/backup-dir") == 0 ||
    #       die "copy to backup-host failed";
    #   unlink $tarfile;
    #   unlink $logfile;
    #}

} else {

    die "got unknown phase '$phase'";

}

exit (0);
All I need to do is "rm -rf /mnt/ext/*" when the vzdump backup STARTS. So is this a job-start hook, or a backup-start hook?

Can anyone explain why this happened two days ago:

Code: 
  Jan 18 20:09:47 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tar'
  Jan 18 20:09:47 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_18-20_09_46.tmp/qemu-server.conf' to archive ('qemu-server.conf')
  Jan 18 20:09:47 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
  Jan 19 09:30:59 INFO: 491568132096 B 457.8 GB 48071.1 s (13:21 h) 10225859 B/s 9.75 MB/s
  Jan 19 09:30:59 INFO: write: No space left on device
 
Code: 
102: Jan 20 03:57:12 INFO: setting parameters failed - VM is locked (backup)

The VM is locked by another vzdump backup process (maybe you killed another vzdump). Use 'qm unlock <vmid>' to force unlocking.

Code: 
 Jan 19 09:30:59 INFO: write: No space left on device

No space left on device? Or what is the question?
 
Last night's backup:

Code: 
101: Jan 20 19:15:01 INFO: Starting Backup of VM 101 (qemu)
101: Jan 20 19:15:01 INFO: running
101: Jan 20 19:15:01 INFO: status = running
101: Jan 20 19:15:02 INFO: backup mode: snapshot
101: Jan 20 19:15:02 INFO: bandwidth limit: 14000 KB/s
101: Jan 20 19:15:02 INFO: HOOK: pre-stop snapshot 101
101: Jan 20 19:15:02 INFO: HOOK: snapshot 101
101: Jan 20 19:15:02 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
101: Jan 20 19:15:02 INFO: HOOK: pre-restart snapshot 101
101: Jan 20 19:15:02 INFO: HOOK: snapshot 101
101: Jan 20 19:15:02 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
101: Jan 20 19:15:02 INFO:   Logical volume "vzsnap-volt-0" created
101: Jan 20 19:15:02 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar'
101: Jan 20 19:15:02 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tmp/qemu-server.conf' to archive ('qemu-server.conf')
101: Jan 20 19:15:02 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
101: Jan 21 04:47:42 INFO: 491568132096 B 457.8 GB 34359.8 s (9:32 h) 14306500 B/s 13.64 MB/s
101: Jan 21 04:47:42 INFO: write: No space left on device
101: Jan 21 04:47:42 INFO: received signal - terminate process
101: Jan 21 04:47:45 INFO:   Logical volume "vzsnap-volt-0" successfully removed
101: Jan 21 05:00:21 ERROR: Backup of VM 101 failed - command '/usr/lib/qemu-server/vmtar '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tmp/qemu-server.conf' 'qemu-server.conf' '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' 'vm-disk-ide0.qcow2' |cstream -t 14336000 >/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.dat' failed with exit code 2
101: Jan 21 05:00:21 INFO: HOOK: backup-abort snapshot 101
101: Jan 21 05:00:21 INFO: HOOK: snapshot 101
101: Jan 21 05:00:21 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log

I did unlock VM 102 yesterday after posting, that VM's backup completed successfuly.

My question is why is the backup of VM 101 failing by using all available space on the external USB drive? The VM image is ONLY 291GB in size!

Code: 
[root@volt:/var/lib/vz/images/101]$ list *.qcow2
-rw-r--r-- 1 0 0 291G 2010-01-21 11:12 vm-101-disk.qcow2

This doesn't make sense to me.
 
jcpham said:
Last night's backup:

Code: 
101: Jan 20 19:15:01 INFO: Starting Backup of VM 101 (qemu)
101: Jan 20 19:15:01 INFO: running
101: Jan 20 19:15:01 INFO: status = running
101: Jan 20 19:15:02 INFO: backup mode: snapshot
101: Jan 20 19:15:02 INFO: bandwidth limit: 14000 KB/s
101: Jan 20 19:15:02 INFO: HOOK: pre-stop snapshot 101
101: Jan 20 19:15:02 INFO: HOOK: snapshot 101
101: Jan 20 19:15:02 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
101: Jan 20 19:15:02 INFO: HOOK: pre-restart snapshot 101
101: Jan 20 19:15:02 INFO: HOOK: snapshot 101
101: Jan 20 19:15:02 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
101: Jan 20 19:15:02 INFO:   Logical volume "vzsnap-volt-0" created
101: Jan 20 19:15:02 INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar'
101: Jan 20 19:15:02 INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tmp/qemu-server.conf' to archive ('qemu-server.conf')
101: Jan 20 19:15:02 INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')
101: Jan 21 04:47:42 INFO: 491568132096 B 457.8 GB 34359.8 s (9:32 h) 14306500 B/s 13.64 MB/s
101: Jan 21 04:47:42 INFO: write: No space left on device
101: Jan 21 04:47:42 INFO: received signal - terminate process
101: Jan 21 04:47:45 INFO:   Logical volume "vzsnap-volt-0" successfully removed
101: Jan 21 05:00:21 ERROR: Backup of VM 101 failed - command '/usr/lib/qemu-server/vmtar '/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tmp/qemu-server.conf' 'qemu-server.conf' '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' 'vm-disk-ide0.qcow2' |cstream -t 14336000 >/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.dat' failed with exit code 2
101: Jan 21 05:00:21 INFO: HOOK: backup-abort snapshot 101
101: Jan 21 05:00:21 INFO: HOOK: snapshot 101
101: Jan 21 05:00:21 INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
I did unlock VM 102 yesterday after posting, that VM's backup completed successfuly.

My question is why is the backup of VM 101 failing by using all available space on the external USB drive? The VM image is ONLY 291GB in size!

Code: 
[root@volt:/var/lib/vz/images/101]$ list *.qcow2
-rw-r--r-- 1 0 0 291G 2010-01-21 11:12 vm-101-disk.qcow2
This doesn't make sense to me.
Click to expand...

depending on your settings, you need at least double space on the backup target as the old backup is still there. the old backup will be deleted after the new backup is successful.
 
I'm using a hook-script. The drive is emptied as the backup begins. I'm not using --maxfiles anymore, because it's useless with the limited size of the USB drive combined with the new vzdump naming convention.

We rotate the usb drives daily and I have a cron script to mount them by UUID to /mnt/ext.

The log from last night didn't display the hook script, because the drive was already empty when the scheduled backup began.

Code: 
[root@volt:~/script]$ list /mnt/ext/*
[B]-rw-r--r-- 1 0 0 2.1K 2010-01-21 05:00 /mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log
-rw-r--r-- 1 0 0  693 2010-01-21 05:00 /mnt/ext/vzdump-qemu-102-2010_01_21-05_00_21.log[/B]

[root@volt:~/script]$ perl -wc usb-rm.pl
usb-rm.pl syntax OK

[root@volt:~/script]$ backupall
INFO: starting new backup job: vzdump --snapshot --dumpdir /mnt/ext --bwlimit 15000 --mailto logmail@xzy.com 102 101
[B]INFO: HOOK: job-start
INFO: Deleting /mnt/ext/vzdump-qemu-101-2010_01_20-19_15_01.log ... deleted
INFO: Deleting /mnt/ext/vzdump-qemu-102-2010_01_21-05_00_21.log ... deleted[/B]
INFO: Starting Backup of VM 101 (qemu)
INFO: running
INFO: status = running
INFO: backup mode: snapshot
INFO: bandwidth limit: 15000 KB/s
INFO: HOOK: pre-stop snapshot 101
INFO: HOOK: snapshot 101
INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.log
INFO: HOOK: pre-restart snapshot 101
INFO: HOOK: snapshot 101
INFO: HOOK-ENV: vmtype=qemu;dumpdir=/mnt/ext;hostname=SBS;tarfile=/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.tar;logfile=/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.log
INFO:   Logical volume "vzsnap-volt-0" created
INFO: creating archive '/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.tar'
INFO: adding '/mnt/ext/vzdump-qemu-101-2010_01_21-12_24_21.tmp/qemu-server.conf' to archive ('qemu-server.conf')
INFO: adding '/mnt/vzsnap0/images/101/vm-101-disk.qcow2' to archive ('vm-disk-ide0.qcow2')

[B]and so on ...............[/B]
And here is my hook script:

Code: 
[root@volt:~/script]$ cat usb-rm.pl
#!/usr/bin/perl -w

use strict;

print "HOOK: " . join (' ', @ARGV) . "\n";

my $BACKUP_DIR = "/mnt/ext";
my @files =  <$BACKUP_DIR/*>;
my $phase = shift;

if ($phase eq 'job-start') {
for (@files) {
   print "Deleting $_ ... ";
   if (unlink $_) {
      print "deleted\n";
   } else {
      warn $!;
   }
}

} elsif ($phase eq 'job-end'  ||
         $phase eq 'job-abort'  ||
         $phase eq 'backup-start' ||
         $phase eq 'backup-end' ||
         $phase eq 'backup-abort' ||
         $phase eq 'pre-stop' ||
         $phase eq 'pre-restart') {

    print "HOOK: " . join (' ', @ARGV) . "\n";

    my $mode = shift; # stop/suspend/snapshot

    my $vmid = shift;

    my $vmtype = $ENV{VMTYPE}; # openvz/qemu

    my $dumpdir = $ENV{DUMPDIR};

    my $hostname = $ENV{HOSTNAME};

    my $tarfile = $ENV{TARFILE};

    my $logfile = $ENV{LOGFILE};

    print "HOOK-ENV: vmtype=$vmtype;dumpdir=$dumpdir;hostname=$hostname;tarfile=$tarfile;logfile=$logfile\n";

}  else {

    die "got unknown phase '$phase'";

}

exit (0);
So what I'm doing is esentially doing a "rm -rf on /mnt/ext/*" and echoing the files being deleted to the vzdump log output.

/mnt/ext, my USB drive starts empty. It's 468GB of free space ext3 formatted.

Code: 
[root@volt:~/script]$ df -H /mnt/ext
Filesystem             Size   Used  Avail Use% Mounted on
/dev/sdb1              493G   208M   468G   1% /mnt/ext
I'm backing up 2 KVM virtual servers. They are both Windows Server 2008. The only thing we use this PVE host for is these two servers. It's a production system that has been functioning fine since PVE .9. The hardware is exactly 1 year old and it's a Dell Poweredge 2900.

Code: 
[root@volt:~/script]$ df -H /var/lib/vz/images
[B]Filesystem             Size   Used  Avail Use% Mounted on
/dev/mapper/pve-data   870G   397G   474G  46% /var/lib/vz[/B]
[root@volt:~/script]$ list /var/lib/vz/images/101/
total 291G
-rw-r--r-- 1 0 0 [B]291G 2010-01-21 12:38 vm-101-disk.qcow2[/B]
[root@volt:~/script]$ list /var/lib/vz/images/102/
total 78G
-rw-r--r-- 1 0 0 [B]78G 2010-01-21 12:38 vm-102-disk.qcow2[/B]
VM101 = 291GB
VM102 = 78GB

397GB < 468GB
/var/lib/vz/* Used Disk space < /mnt/ext Unused Disk Space

This problem with VM 101 using up all the space on my external usb drive during the tar process began with the latest vzdump version, when vmtar cam into the picture.
 
You must log in or register to reply here.

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!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

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!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back