3.1 update broke backups

rahman · Oct 3, 2013

Hi,

Yesterday we upgraded our 3.0 servers to 3.1 (also switched to no-subscibtion repo and upgraded latest fixes). After upgrade some of the backups hanged last night. It seems that VMs with large disks fail to backup and hang at some point. I also tried to backup manually and it is the same.

Code:

root@kvm47:~# pveversion -v
proxmox-ve-2.6.32: 3.1-113 (running kernel: 2.6.32-25-pve)
pve-manager: 3.1-16 (running version: 3.1-16/6a143a40)
pve-kernel-2.6.32-20-pve: 2.6.32-100
pve-kernel-2.6.32-19-pve: 2.6.32-96
pve-kernel-2.6.32-25-pve: 2.6.32-113
pve-kernel-2.6.32-22-pve: 2.6.32-107
pve-kernel-2.6.32-14-pve: 2.6.32-74
pve-kernel-2.6.32-11-pve: 2.6.32-66
pve-kernel-2.6.32-23-pve: 2.6.32-109
lvm2: 2.02.98-pve4
clvm: 2.02.98-pve4
corosync-pve: 1.4.5-1
openais-pve: 1.1.4-3
libqb0: 0.11.1-2
redhat-cluster-pve: 3.2.0-2
resource-agents-pve: 3.9.2-4
fence-agents-pve: 4.0.0-2
pve-cluster: 3.0-7
qemu-server: 3.1-5
pve-firmware: 1.0-23
libpve-common-perl: 3.0-6
libpve-access-control: 3.0-6
libpve-storage-perl: 3.0-13
pve-libspice-server1: 0.12.4-2
vncterm: 1.1-4
vzctl: 4.0-1pve3
vzprocps: 2.0.11-2
vzquota: 3.1-2
pve-qemu-kvm: 1.4-17
ksm-control-daemon: 1.1-1
glusterfs-client: 3.4.0-2

Our backup target is a nexenta server shared via cifs:

Code:

//10.255.255.22/archives_proxmox /var/lib/vz/nexenta-cifs cifs username=admin,password=password,domain=WORKGROUP,_netdev 0 0

Here is syslog logs:

Code:

Oct  3 10:16:07 kvm47 pvedaemon[7938]: <rduran@acu> starting task UPID:kvm47:00001F2B:0004BE02:524D19B7:vzdump::rduran@acu:Oct  3 10:16:07 kvm47 pvedaemon[7979]: INFO: starting new backup job: vzdump 172 --remove 0 --mode snapshot --compress gzip --storage Nexenta-ISO-BACKUP --node kvm47
Oct  3 10:16:07 kvm47 pvedaemon[7979]: INFO: Starting Backup of VM 172 (qemu)
Oct  3 10:16:08 kvm47 qm[7984]: <root@pam> update VM 172: -lock backup
Oct  3 10:59:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 10:59:50 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 10:59:53 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 10:59:56 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 10:59:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 10:59:59 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:03 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:06 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:09 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:12 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:15 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:18 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:21 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:24 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:28 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:29 kvm47 pmxcfs[5860]: [status] notice: received log
Oct  3 11:00:31 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:34 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:37 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:40 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:43 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:46 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:00:49 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:33 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:36 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:40 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:43 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:46 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:49 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:52 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:55 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:01:58 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:02 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:05 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:08 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:11 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:14 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:17 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:20 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:24 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:27 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:30 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:33 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:36 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:39 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:42 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:45 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:02:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:10 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:13 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:16 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:20 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:23 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:26 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:29 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:32 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:35 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:38 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:42 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:45 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:48 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:51 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:54 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:57 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:03:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:00 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:03 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:07 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:10 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:13 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:16 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:19 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:22 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:25 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:28 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:32 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:35 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:38 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:41 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:44 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:47 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:50 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:04:54 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:19 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:51 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:54 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:57 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:05:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:00 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:04 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:07 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:10 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:13 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:16 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:20 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:23 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:26 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:29 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:32 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:36 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:39 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:42 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:45 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:48 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:52 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:55 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:06:58 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:01 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:04 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:08 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:11 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:14 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:17 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:20 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:24 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:27 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:30 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:33 kvm47 pvedaemon[9174]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:37 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:40 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:43 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:46 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:48 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:49 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:53 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:56 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:58 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:07:59 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:08:33 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:08:36 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:05 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:08 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:08 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:11 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:14 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:17 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:18 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:21 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:24 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:27 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:28 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:30 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:33 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:37 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:38 kvm47 pvestatd[6333]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:40 kvm47 pvedaemon[8709]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:43 kvm47 pvedaemon[8994]: WARNING: unable to connect to VM 172 socket - timeout after 31 retries
Oct  3 11:09:44 kvm47 pvedaemon[7979]: VM 172 qmp command failed - VM 172 qmp command 'query-backup' failed - got timeout
Oct  3 11:12:12 kvm47 pvestatd[6333]: status update time (7.701 seconds)
Oct  3 11:12:23 kvm47 pvestatd[6333]: status update time (7.229 seconds)
Oct  3 11:12:35 kvm47 pvestatd[6333]: status update time (10.098 seconds)
Oct  3 11:13:20 kvm47 pvestatd[6333]: status update time (5.188 seconds)
Oct  3 11:15:05 kvm47 kernel: CIFS VFS: Send error in Close = -512
Oct  3 11:15:07 kvm47 pvedaemon[7979]: ERROR: Backup of VM 172 failed - VM 172 qmp command 'query-backup' failed - got timeout
Oct  3 11:15:07 kvm47 pvedaemon[7979]: INFO: Backup job finished with errors
Oct  3 11:15:07 kvm47 pvedaemon[7979]: job errors
Oct  3 11:15:30 kvm47 pmxcfs[5860]: [status] notice: received log
Oct  3 11:17:01 kvm47 /USR/SBIN/CRON[10132]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Oct  3 11:19:32 kvm47 pvedaemon[6309]: worker 8994 finished
Oct  3 11:19:32 kvm47 pvedaemon[6309]: starting 1 worker(s)
Oct  3 11:19:32 kvm47 pvedaemon[6309]: worker 10216 started
Oct  3 11:20:03 kvm47 pvedaemon[6309]: worker 8709 finished
Oct  3 11:20:03 kvm47 pvedaemon[6309]: starting 1 worker(s)
Oct  3 11:20:03 kvm47 pvedaemon[6309]: worker 10233 started
Oct  3 11:22:04 kvm47 pveproxy[6338]: worker 8671 finished
Oct  3 11:22:04 kvm47 pveproxy[6338]: starting 1 worker(s)
Oct  3 11:22:04 kvm47 pveproxy[6338]: worker 10297 started
Oct  3 11:23:34 kvm47 pveproxy[6338]: worker 8983 finished
Oct  3 11:23:34 kvm47 pveproxy[6338]: starting 1 worker(s)
Oct  3 11:23:34 kvm47 pveproxy[6338]: worker 10348 started

vzdump log:

Code:

root@kvm47:~# cat /var/log/vzdump/qemu-172.log Oct 03 10:16:07 INFO: Starting Backup of VM 172 (qemu)
Oct 03 10:16:08 INFO: status = running
Oct 03 10:16:08 INFO: update VM 172: -lock backup
Oct 03 10:16:08 INFO: backup mode: snapshot
Oct 03 10:16:08 INFO: ionice priority: 7
Oct 03 10:16:08 INFO: creating archive '/var/lib/vz/nexenta-cifs/dump/vzdump-qemu-172-2013_10_03-10_16_07.vma.gz'
Oct 03 10:16:08 INFO: started backup task '2dd8bde6-ffe8-4f9a-b7a8-0f7023ab6fde'
Oct 03 10:16:11 INFO: status: 0% (91226112/91268055040), sparse 0% (217088), duration 3, 30/30 MB/s
Oct 03 10:16:47 INFO: status: 1% (953090048/91268055040), sparse 0% (15929344), duration 39, 23/23 MB/s
Oct 03 10:17:32 INFO: status: 2% (1832124416/91268055040), sparse 0% (16388096), duration 84, 19/19 MB/s
Oct 03 10:18:21 INFO: status: 3% (2744385536/91268055040), sparse 0% (25190400), duration 133, 18/18 MB/s
Oct 03 10:18:59 INFO: status: 4% (3667197952/91268055040), sparse 0% (30478336), duration 171, 24/24 MB/s
Oct 03 10:19:59 INFO: status: 5% (4565106688/91268055040), sparse 0% (32829440), duration 231, 14/14 MB/s
Oct 03 10:20:49 INFO: status: 6% (5494603776/91268055040), sparse 0% (43081728), duration 281, 18/18 MB/s
Oct 03 10:21:34 INFO: status: 7% (6393430016/91268055040), sparse 0% (50016256), duration 326, 19/19 MB/s
Oct 03 10:22:32 INFO: status: 8% (7309492224/91268055040), sparse 0% (53784576), duration 384, 15/15 MB/s
Oct 03 10:23:20 INFO: status: 9% (8229355520/91268055040), sparse 0% (76251136), duration 432, 19/18 MB/s
Oct 03 10:23:58 INFO: status: 10% (9128640512/91268055040), sparse 0% (81166336), duration 470, 23/23 MB/s
Oct 03 10:24:23 INFO: status: 11% (10095689728/91268055040), sparse 0% (85282816), duration 495, 38/38 MB/s
Oct 03 10:24:47 INFO: status: 12% (10977542144/91268055040), sparse 0% (85843968), duration 519, 36/36 MB/s
Oct 03 10:25:25 INFO: status: 13% (11874598912/91268055040), sparse 0% (85893120), duration 557, 23/23 MB/s
Oct 03 10:26:09 INFO: status: 14% (12798263296/91268055040), sparse 0% (85938176), duration 601, 20/20 MB/s
Oct 03 10:26:51 INFO: status: 15% (13699121152/91268055040), sparse 0% (85938176), duration 643, 21/21 MB/s
Oct 03 10:27:22 INFO: status: 16% (14653718528/91268055040), sparse 0% (85938176), duration 674, 30/30 MB/s
Oct 03 10:27:50 INFO: status: 17% (15531245568/91268055040), sparse 0% (87412736), duration 702, 31/31 MB/s
Oct 03 10:28:17 INFO: status: 18% (16439705600/91268055040), sparse 0% (87482368), duration 729, 33/33 MB/s
Oct 03 10:28:35 INFO: status: 19% (17402888192/91268055040), sparse 0% (88993792), duration 747, 53/53 MB/s
Oct 03 10:28:51 INFO: status: 20% (18264227840/91268055040), sparse 0% (89735168), duration 763, 53/53 MB/s
Oct 03 10:29:38 INFO: status: 21% (19176488960/91268055040), sparse 0% (95010816), duration 810, 19/19 MB/s
Oct 03 10:30:30 INFO: status: 22% (20082982912/91268055040), sparse 0% (105443328), duration 862, 17/17 MB/s
Oct 03 10:31:03 INFO: status: 23% (21023817728/91268055040), sparse 0% (107319296), duration 895, 28/28 MB/s
Oct 03 10:31:31 INFO: status: 24% (21914583040/91268055040), sparse 0% (107687936), duration 923, 31/31 MB/s
Oct 03 10:32:03 INFO: status: 25% (22836936704/91268055040), sparse 0% (108503040), duration 955, 28/28 MB/s
Oct 03 10:32:46 INFO: status: 26% (23745396736/91268055040), sparse 0% (110231552), duration 998, 21/21 MB/s
Oct 03 10:33:28 INFO: status: 27% (24650055680/91268055040), sparse 0% (113119232), duration 1040, 21/21 MB/s
Oct 03 10:34:10 INFO: status: 28% (25570639872/91268055040), sparse 0% (117772288), duration 1082, 21/21 MB/s
Oct 03 10:34:41 INFO: status: 29% (26519732224/91268055040), sparse 0% (118374400), duration 1113, 30/30 MB/s
Oct 03 10:35:02 INFO: status: 30% (27432452096/91268055040), sparse 0% (118579200), duration 1134, 43/43 MB/s
Oct 03 10:35:30 INFO: status: 31% (28314304512/91268055040), sparse 0% (120979456), duration 1162, 31/31 MB/s
Oct 03 10:36:14 INFO: status: 32% (29215162368/91268055040), sparse 0% (139878400), duration 1206, 20/20 MB/s
Oct 03 10:36:53 INFO: status: 33% (30127423488/91268055040), sparse 0% (140009472), duration 1245, 23/23 MB/s
Oct 03 10:37:29 INFO: status: 34% (31047286784/91268055040), sparse 0% (141660160), duration 1281, 25/25 MB/s
Oct 03 10:38:17 INFO: status: 35% (31963348992/91268055040), sparse 0% (160145408), duration 1329, 19/18 MB/s
Oct 03 10:39:04 INFO: status: 36% (32880066560/91268055040), sparse 0% (171511808), duration 1376, 19/19 MB/s
Oct 03 10:39:52 INFO: status: 37% (33772666880/91268055040), sparse 0% (182374400), duration 1424, 18/18 MB/s
Oct 03 10:40:37 INFO: status: 38% (34700132352/91268055040), sparse 0% (214540288), duration 1469, 20/19 MB/s
Oct 03 10:41:20 INFO: status: 39% (35611934720/91268055040), sparse 0% (226140160), duration 1512, 21/20 MB/s
Oct 03 10:41:52 INFO: status: 40% (36513251328/91268055040), sparse 0% (240701440), duration 1544, 28/27 MB/s
Oct 03 10:42:31 INFO: status: 41% (37424922624/91268055040), sparse 0% (242286592), duration 1583, 23/23 MB/s
Oct 03 10:43:18 INFO: status: 42% (38345375744/91268055040), sparse 0% (262307840), duration 1630, 19/19 MB/s
Oct 03 10:44:04 INFO: status: 43% (39261437952/91268055040), sparse 0% (282423296), duration 1676, 19/19 MB/s
Oct 03 11:15:05 ERROR: VM 172 qmp command 'query-backup' failed - got timeout
Oct 03 11:15:05 INFO: aborting backup job
Oct 03 11:15:07 ERROR: Backup of VM 172 failed - VM 172 qmp command 'query-backup' failed - got timeout

This is a VM with 85GB disk win 2008 srv. I just backup a win7 32 GB disk with success.

here is the logs of nightly backup jobs:
http://pastebin.com/UHGk49Jx

tom · Oct 3, 2013

can you do a backup to a local disk? (or any other backup location).

rahman · Oct 3, 2013

I did a backup to local /var/lib/vz/tmp_backup with success. So what changed about cifs with this new kernel or another package?

INFO: starting new backup job: vzdump 172 --remove 0 --mode snapshot --compress gzip --storage TMP_backup --node kvm47
INFO: Starting Backup of VM 172 (qemu)
INFO: status = running
INFO: update VM 172: -lock backup
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating archive '/var/lib/vz/tmp_backup/dump/vzdump-qemu-172-2013_10_03-11_51_53.vma.gz'
INFO: started backup task '4bf74171-3d29-4c49-87b9-93e703a5c22d'
INFO: status: 0% (91226112/91268055040), sparse 0% (217088), duration 3, 30/30 MB/s
INFO: status: 1% (913571840/91268055040), sparse 0% (15912960), duration 38, 23/23 MB/s
INFO: status: 2% (1828323328/91268055040), sparse 0% (16375808), duration 84, 19/19 MB/s
INFO: status: 3% (2755788800/91268055040), sparse 0% (25178112), duration 134, 18/18 MB/s
INFO: status: 4% (3668049920/91268055040), sparse 0% (30380032), duration 172, 24/23 MB/s
INFO: status: 5% (4576509952/91268055040), sparse 0% (32759808), duration 232, 15/15 MB/s
INFO: status: 6% (5492572160/91268055040), sparse 0% (42987520), duration 281, 18/18 MB/s
INFO: status: 7% (6391136256/91268055040), sparse 0% (50016256), duration 326, 19/19 MB/s
INFO: status: 8% (7305691136/91268055040), sparse 0% (53694464), duration 385, 15/15 MB/s
INFO: status: 9% (8223260672/91268055040), sparse 0% (76152832), duration 434, 18/18 MB/s
INFO: status: 10% (9137815552/91268055040), sparse 0% (81207296), duration 473, 23/23 MB/s
INFO: status: 11% (10042015744/91268055040), sparse 0% (85184512), duration 497, 37/37 MB/s
INFO: status: 12% (10962468864/91268055040), sparse 0% (85745664), duration 521, 38/38 MB/s
INFO: status: 13% (11870797824/91268055040), sparse 0% (85794816), duration 560, 23/23 MB/s
INFO: status: 14% (12794462208/91268055040), sparse 0% (85794816), duration 605, 20/20 MB/s
INFO: status: 15% (13699121152/91268055040), sparse 0% (85860352), duration 647, 21/21 MB/s
INFO: status: 16% (14621212672/91268055040), sparse 0% (85938176), duration 678, 29/29 MB/s
INFO: status: 17% (15531245568/91268055040), sparse 0% (87412736), duration 707, 31/31 MB/s
INFO: status: 18% (16437936128/91268055040), sparse 0% (87482368), duration 734, 33/33 MB/s
INFO: status: 19% (17405181952/91268055040), sparse 0% (88993792), duration 752, 53/53 MB/s
INFO: status: 20% (18264227840/91268055040), sparse 0% (89927680), duration 768, 53/53 MB/s
INFO: status: 21% (19172687872/91268055040), sparse 0% (95252480), duration 816, 18/18 MB/s
INFO: status: 22% (20081147904/91268055040), sparse 0% (105709568), duration 868, 17/17 MB/s
INFO: status: 23% (21025325056/91268055040), sparse 0% (107585536), duration 901, 28/28 MB/s
INFO: status: 24% (21928476672/91268055040), sparse 0% (107954176), duration 929, 32/32 MB/s
INFO: status: 25% (22833135616/91268055040), sparse 0% (108847104), duration 961, 28/28 MB/s
INFO: status: 26% (23736614912/91268055040), sparse 0% (110596096), duration 1004, 21/20 MB/s
INFO: status: 27% (24653856768/91268055040), sparse 0% (113569792), duration 1047, 21/21 MB/s
INFO: status: 28% (25580797952/91268055040), sparse 0% (118214656), duration 1088, 22/22 MB/s
INFO: status: 29% (26493583360/91268055040), sparse 0% (118804480), duration 1118, 30/30 MB/s
INFO: status: 30% (27413446656/91268055040), sparse 0% (119021568), duration 1139, 43/43 MB/s
INFO: status: 31% (28303032320/91268055040), sparse 0% (121552896), duration 1167, 31/31 MB/s
INFO: status: 32% (29222764544/91268055040), sparse 0% (140451840), duration 1212, 20/20 MB/s
INFO: status: 33% (30120476672/91268055040), sparse 0% (140582912), duration 1252, 22/22 MB/s
INFO: status: 34% (31043485696/91268055040), sparse 0% (142442496), duration 1288, 25/25 MB/s
INFO: status: 35% (31955746816/91268055040), sparse 0% (160890880), duration 1336, 19/18 MB/s
INFO: status: 36% (32875610112/91268055040), sparse 0% (172326912), duration 1383, 19/19 MB/s
INFO: status: 37% (33784070144/91268055040), sparse 0% (182689792), duration 1432, 18/18 MB/s
INFO: status: 38% (34701049856/91268055040), sparse 0% (214716416), duration 1477, 20/19 MB/s
INFO: status: 39% (35604791296/91268055040), sparse 0% (225308672), duration 1520, 21/20 MB/s
INFO: status: 40% (36541169664/91268055040), sparse 0% (238436352), duration 1552, 29/28 MB/s
INFO: status: 41% (37444517888/91268055040), sparse 0% (240115712), duration 1591, 23/23 MB/s
INFO: status: 42% (38341574656/91268055040), sparse 0% (259878912), duration 1637, 19/19 MB/s
INFO: status: 43% (39257636864/91268055040), sparse 0% (280006656), duration 1684, 19/19 MB/s
INFO: status: 44% (40204107776/91268055040), sparse 0% (293355520), duration 1715, 30/30 MB/s
INFO: status: 45% (41105293312/91268055040), sparse 0% (294510592), duration 1737, 40/40 MB/s
INFO: status: 46% (41984851968/91268055040), sparse 0% (294690816), duration 1755, 48/48 MB/s
INFO: status: 47% (42937090048/91268055040), sparse 0% (294711296), duration 1773, 52/52 MB/s
INFO: status: 48% (43813437440/91268055040), sparse 1% (1166438400), duration 1783, 87/0 MB/s
INFO: status: 49% (44723601408/91268055040), sparse 1% (1378709504), duration 1818, 26/19 MB/s
INFO: status: 50% (45675380736/91268055040), sparse 1% (1378799616), duration 1855, 25/25 MB/s
INFO: status: 51% (46567129088/91268055040), sparse 1% (1379115008), duration 1895, 22/22 MB/s
INFO: status: 52% (47463071744/91268055040), sparse 1% (1557643264), duration 1928, 27/21 MB/s
INFO: status: 53% (48418652160/91268055040), sparse 2% (2513223680), duration 1939, 86/0 MB/s
INFO: status: 54% (49330192384/91268055040), sparse 3% (3424763904), duration 1949, 91/0 MB/s
INFO: status: 55% (50228297728/91268055040), sparse 4% (4322869248), duration 1959, 89/0 MB/s
INFO: status: 56% (51135053824/91268055040), sparse 5% (5229625344), duration 1969, 90/0 MB/s
INFO: status: 57% (52029358080/91268055040), sparse 6% (6123929600), duration 1979, 89/0 MB/s
INFO: status: 58% (52946403328/91268055040), sparse 7% (7040974848), duration 1989, 91/0 MB/s
INFO: status: 59% (53889531904/91268055040), sparse 8% (7984103424), duration 2000, 85/0 MB/s
INFO: status: 60% (54854615040/91268055040), sparse 9% (8949186560), duration 2011, 87/0 MB/s
INFO: status: 61% (55746101248/91268055040), sparse 10% (9840672768), duration 2021, 89/0 MB/s
INFO: status: 62% (56622710784/91268055040), sparse 11% (10717282304), duration 2031, 87/0 MB/s
INFO: status: 63% (57582747648/91268055040), sparse 12% (11677319168), duration 2042, 87/0 MB/s
INFO: status: 64% (58487668736/91268055040), sparse 13% (12582240256), duration 2052, 90/0 MB/s
INFO: status: 65% (59403730944/91268055040), sparse 14% (13498302464), duration 2062, 91/0 MB/s
INFO: status: 66% (60282437632/91268055040), sparse 15% (14377009152), duration 2072, 87/0 MB/s
INFO: status: 67% (61162913792/91268055040), sparse 16% (15257485312), duration 2082, 88/0 MB/s
INFO: status: 68% (62124064768/91268055040), sparse 17% (16218636288), duration 2093, 87/0 MB/s
INFO: status: 69% (63014830080/91268055040), sparse 18% (17109401600), duration 2103, 89/0 MB/s
INFO: status: 70% (63925977088/91268055040), sparse 19% (18020548608), duration 2113, 91/0 MB/s
INFO: status: 71% (64839417856/91268055040), sparse 20% (18933989376), duration 2123, 91/0 MB/s
INFO: status: 72% (65744732160/91268055040), sparse 21% (19839303680), duration 2133, 90/0 MB/s
INFO: status: 73% (66657189888/91268055040), sparse 22% (20751761408), duration 2144, 82/0 MB/s
INFO: status: 74% (67553067008/91268055040), sparse 23% (21647638528), duration 2154, 89/0 MB/s
INFO: status: 75% (68542201856/91268055040), sparse 24% (22636773376), duration 2165, 89/0 MB/s
INFO: status: 76% (69426282496/91268055040), sparse 25% (23520854016), duration 2175, 88/0 MB/s
INFO: status: 77% (70326091776/91268055040), sparse 26% (24420663296), duration 2185, 89/0 MB/s
INFO: status: 78% (71228325888/91268055040), sparse 27% (25322897408), duration 2195, 90/0 MB/s
INFO: status: 79% (72137048064/91268055040), sparse 28% (26231619584), duration 2205, 90/0 MB/s
INFO: status: 80% (73038364672/91268055040), sparse 29% (27132936192), duration 2215, 90/0 MB/s
INFO: status: 81% (74007248896/91268055040), sparse 30% (28101820416), duration 2226, 88/0 MB/s
INFO: status: 82% (74888052736/91268055040), sparse 31% (28982624256), duration 2236, 88/0 MB/s
INFO: status: 83% (75806277632/91268055040), sparse 32% (29900849152), duration 2246, 91/0 MB/s
INFO: status: 84% (76708708352/91268055040), sparse 33% (30803279872), duration 2256, 90/0 MB/s
INFO: status: 85% (77591937024/91268055040), sparse 34% (31686508544), duration 2266, 88/0 MB/s
INFO: status: 86% (78571634688/91268055040), sparse 35% (32666206208), duration 2277, 89/0 MB/s
INFO: status: 87% (79463972864/91268055040), sparse 36% (33558544384), duration 2287, 89/0 MB/s
INFO: status: 88% (80333373440/91268055040), sparse 37% (34427944960), duration 2301, 62/0 MB/s
INFO: status: 89% (81277878272/91268055040), sparse 38% (35372449792), duration 2312, 85/0 MB/s
INFO: status: 90% (82197676032/91268055040), sparse 39% (36292247552), duration 2323, 83/0 MB/s
INFO: status: 91% (83089620992/91268055040), sparse 40% (37184192512), duration 2335, 74/0 MB/s
INFO: status: 92% (83969703936/91268055040), sparse 41% (38064275456), duration 2345, 88/0 MB/s
INFO: status: 93% (84882489344/91268055040), sparse 42% (38977060864), duration 2355, 91/0 MB/s
INFO: status: 94% (85873262592/91268055040), sparse 43% (39967834112), duration 2366, 90/0 MB/s
INFO: status: 95% (86739845120/91268055040), sparse 44% (40780058624), duration 2378, 72/4 MB/s
INFO: status: 96% (87692279808/91268055040), sparse 45% (41732493312), duration 2389, 86/0 MB/s
INFO: status: 97% (88581406720/91268055040), sparse 46% (42621620224), duration 2399, 88/0 MB/s
INFO: status: 98% (89470992384/91268055040), sparse 47% (43511205888), duration 2409, 88/0 MB/s
INFO: status: 99% (90367066112/91268055040), sparse 48% (44234391552), duration 2421, 74/14 MB/s
INFO: status: 100% (91268055040/91268055040), sparse 48% (44234461184), duration 2433, 75/75 MB/s
INFO: transferred 91268 MB in 2433 seconds (37 MB/s)
INFO: archive file size: 16.31GB
INFO: Finished Backup of VM 172 (00:40:34)
INFO: Backup job finished successfully
TASK OK

rahman · Oct 3, 2013

So I am sure now that it is a kernel problem. I boot up with the previous kernel (pve-kernel-2.6.32-23-pve: 2.6.32-109) and backup to the cifs mount with success:

INFO: starting new backup job: vzdump 172 --remove 0 --mode snapshot --compress gzip --storage Nexenta-ISO-BACKUP --node kvm47
INFO: Starting Backup of VM 172 (qemu)
INFO: status = running
INFO: update VM 172: -lock backup
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating archive '/var/lib/vz/nexenta-cifs/dump/vzdump-qemu-172-2013_10_03-12_47_14.vma.gz'
INFO: started backup task 'ae4604e9-1427-48fd-b0f0-f8d050125f49'
INFO: status: 0% (91226112/91268055040), sparse 0% (217088), duration 3, 30/30 MB/s
INFO: status: 1% (916062208/91268055040), sparse 0% (16158720), duration 37, 24/23 MB/s
INFO: status: 2% (1832124416/91268055040), sparse 0% (18399232), duration 80, 21/21 MB/s
INFO: status: 3% (2750545920/91268055040), sparse 0% (21774336), duration 130, 18/18 MB/s
INFO: status: 4% (3694657536/91268055040), sparse 0% (31510528), duration 167, 25/25 MB/s
INFO: status: 5% (4565106688/91268055040), sparse 0% (34709504), duration 223, 15/15 MB/s
INFO: status: 6% (5481168896/91268055040), sparse 0% (44199936), duration 275, 17/17 MB/s
INFO: status: 7% (6393430016/91268055040), sparse 0% (49229824), duration 320, 20/20 MB/s
INFO: status: 8% (7309492224/91268055040), sparse 0% (56893440), duration 369, 18/18 MB/s
INFO: status: 9% (8225554432/91268055040), sparse 0% (77680640), duration 424, 16/16 MB/s
INFO: status: 10% (9137815552/91268055040), sparse 0% (82726912), duration 462, 24/23 MB/s
INFO: status: 11% (10061479936/91268055040), sparse 0% (88571904), duration 489, 34/33 MB/s
INFO: status: 12% (10977542144/91268055040), sparse 0% (89141248), duration 511, 41/41 MB/s
INFO: status: 13% (11866603520/91268055040), sparse 0% (89194496), duration 544, 26/26 MB/s
INFO: status: 14% (12790530048/91268055040), sparse 0% (89194496), duration 587, 21/21 MB/s
INFO: status: 15% (13702922240/91268055040), sparse 0% (89194496), duration 627, 22/22 MB/s
INFO: status: 16% (14659813376/91268055040), sparse 0% (89194496), duration 663, 26/26 MB/s
INFO: status: 17% (15515975680/91268055040), sparse 0% (89387008), duration 684, 40/40 MB/s
INFO: status: 18% (16431710208/91268055040), sparse 0% (90738688), duration 713, 31/31 MB/s
INFO: status: 19% (17351966720/91268055040), sparse 0% (90857472), duration 732, 48/48 MB/s
INFO: status: 20% (18311806976/91268055040), sparse 0% (92336128), duration 748, 59/59 MB/s
INFO: status: 21% (19187892224/91268055040), sparse 0% (97918976), duration 789, 21/21 MB/s
INFO: status: 22% (20096352256/91268055040), sparse 0% (102617088), duration 839, 18/18 MB/s
INFO: status: 23% (21023817728/91268055040), sparse 0% (110198784), duration 876, 25/24 MB/s
INFO: status: 24% (21905670144/91268055040), sparse 0% (110575616), duration 901, 35/35 MB/s
INFO: status: 25% (22840737792/91268055040), sparse 0% (111214592), duration 931, 31/31 MB/s
INFO: status: 26% (23737794560/91268055040), sparse 0% (113225728), duration 973, 21/21 MB/s
INFO: status: 27% (24650055680/91268055040), sparse 0% (115380224), duration 1013, 22/22 MB/s
INFO: status: 28% (25575489536/91268055040), sparse 0% (118558720), duration 1057, 21/20 MB/s
INFO: status: 29% (26470776832/91268055040), sparse 0% (121094144), duration 1087, 29/29 MB/s
INFO: status: 30% (27398242304/91268055040), sparse 0% (121221120), duration 1109, 42/42 MB/s
INFO: status: 31% (28295299072/91268055040), sparse 0% (123174912), duration 1134, 35/35 MB/s
INFO: status: 32% (29215162368/91268055040), sparse 0% (142712832), duration 1178, 20/20 MB/s
INFO: status: 33% (30133125120/91268055040), sparse 0% (142729216), duration 1217, 23/23 MB/s
INFO: status: 34% (31035883520/91268055040), sparse 0% (144056320), duration 1251, 26/26 MB/s
INFO: status: 35% (31954042880/91268055040), sparse 0% (161972224), duration 1298, 19/19 MB/s
INFO: status: 36% (32864206848/91268055040), sparse 0% (166604800), duration 1344, 19/19 MB/s
INFO: status: 37% (33781710848/91268055040), sparse 0% (184033280), duration 1394, 18/18 MB/s
INFO: status: 38% (34696396800/91268055040), sparse 0% (208531456), duration 1437, 21/20 MB/s
INFO: status: 39% (35618881536/91268055040), sparse 0% (226451456), duration 1480, 21/21 MB/s
INFO: status: 40% (36513513472/91268055040), sparse 0% (239808512), duration 1512, 27/27 MB/s
INFO: status: 41% (37429313536/91268055040), sparse 0% (241377280), duration 1547, 26/26 MB/s
INFO: status: 42% (38333972480/91268055040), sparse 0% (260104192), duration 1593, 19/19 MB/s
INFO: status: 43% (39257636864/91268055040), sparse 0% (281370624), duration 1640, 19/19 MB/s
INFO: status: 44% (40173699072/91268055040), sparse 0% (294682624), duration 1670, 30/30 MB/s
INFO: status: 45% (41104965632/91268055040), sparse 0% (295837696), duration 1693, 40/40 MB/s
INFO: status: 46% (42005102592/91268055040), sparse 0% (296017920), duration 1712, 47/47 MB/s
INFO: status: 47% (42954326016/91268055040), sparse 0% (305971200), duration 1731, 49/49 MB/s
INFO: status: 48% (43898699776/91268055040), sparse 1% (1250340864), duration 1742, 85/0 MB/s
INFO: status: 49% (44723601408/91268055040), sparse 1% (1380036608), duration 1775, 24/21 MB/s
INFO: status: 50% (45635862528/91268055040), sparse 1% (1380118528), duration 1810, 26/26 MB/s
INFO: status: 51% (46559526912/91268055040), sparse 1% (1380442112), duration 1849, 23/23 MB/s
INFO: status: 52% (47528673280/91268055040), sparse 1% (1621950464), duration 1882, 29/22 MB/s
INFO: status: 53% (48390275072/91268055040), sparse 2% (2483552256), duration 1892, 86/0 MB/s
INFO: status: 54% (49309220864/91268055040), sparse 3% (3402498048), duration 1902, 91/0 MB/s
INFO: status: 55% (50216304640/91268055040), sparse 4% (4309581824), duration 1912, 90/0 MB/s
INFO: status: 56% (51169722368/91268055040), sparse 5% (5262999552), duration 1923, 86/0 MB/s
INFO: status: 57% (52031127552/91268055040), sparse 6% (6124404736), duration 1933, 86/0 MB/s
INFO: status: 58% (53005254656/91268055040), sparse 7% (7098531840), duration 1944, 88/0 MB/s
INFO: status: 59% (53898248192/91268055040), sparse 8% (7991525376), duration 1954, 89/0 MB/s
INFO: status: 60% (54775316480/91268055040), sparse 9% (8868593664), duration 1964, 87/0 MB/s
INFO: status: 61% (55730569216/91268055040), sparse 10% (9823846400), duration 1975, 86/0 MB/s
INFO: status: 62% (56607899648/91268055040), sparse 11% (10701176832), duration 1985, 87/0 MB/s
INFO: status: 63% (57556205568/91268055040), sparse 12% (11649482752), duration 1996, 86/0 MB/s
INFO: status: 64% (58471415808/91268055040), sparse 13% (12564692992), duration 2006, 91/0 MB/s
INFO: status: 65% (59361853440/91268055040), sparse 14% (13455130624), duration 2016, 89/0 MB/s
INFO: status: 66% (60288204800/91268055040), sparse 15% (14381481984), duration 2026, 92/0 MB/s
INFO: status: 67% (61198303232/91268055040), sparse 16% (15291580416), duration 2036, 91/0 MB/s
INFO: status: 68% (62110236672/91268055040), sparse 17% (16203513856), duration 2046, 91/0 MB/s
INFO: status: 69% (63017451520/91268055040), sparse 18% (17110728704), duration 2056, 90/0 MB/s
INFO: status: 70% (63948521472/91268055040), sparse 19% (18041798656), duration 2069, 71/0 MB/s
INFO: status: 71% (64851279872/91268055040), sparse 20% (18944557056), duration 2082, 69/0 MB/s
INFO: status: 72% (65729331200/91268055040), sparse 21% (19822608384), duration 2092, 87/0 MB/s
INFO: status: 73% (66654896128/91268055040), sparse 22% (20748173312), duration 2103, 84/0 MB/s
INFO: status: 74% (67608182784/91268055040), sparse 23% (21701459968), duration 2114, 86/0 MB/s
INFO: status: 75% (68517298176/91268055040), sparse 24% (22610575360), duration 2125, 82/0 MB/s
INFO: status: 76% (69378703360/91268055040), sparse 25% (23471980544), duration 2135, 86/0 MB/s
INFO: status: 77% (70349750272/91268055040), sparse 26% (24443027456), duration 2146, 88/0 MB/s
INFO: status: 78% (71224393728/91268055040), sparse 27% (25317670912), duration 2156, 87/0 MB/s
INFO: status: 79% (72161361920/91268055040), sparse 28% (26254639104), duration 2167, 85/0 MB/s
INFO: status: 80% (73094135808/91268055040), sparse 29% (27187412992), duration 2179, 77/0 MB/s
INFO: status: 81% (73963667456/91268055040), sparse 30% (28056944640), duration 2189, 86/0 MB/s
INFO: status: 82% (74910334976/91268055040), sparse 31% (29003612160), duration 2200, 86/0 MB/s
INFO: status: 83% (75799986176/91268055040), sparse 32% (29893263360), duration 2210, 88/0 MB/s
INFO: status: 84% (76712902656/91268055040), sparse 33% (30806179840), duration 2220, 91/0 MB/s
INFO: status: 85% (77629161472/91268055040), sparse 34% (31722438656), duration 2230, 91/0 MB/s
INFO: status: 86% (78521958400/91268055040), sparse 35% (32615235584), duration 2240, 89/0 MB/s
INFO: status: 87% (79432056832/91268055040), sparse 36% (33525334016), duration 2251, 82/0 MB/s
INFO: status: 88% (80403759104/91268055040), sparse 37% (34497036288), duration 2262, 88/0 MB/s
INFO: status: 89% (81276829696/91268055040), sparse 38% (35370106880), duration 2272, 87/0 MB/s
INFO: status: 90% (82147540992/91268055040), sparse 39% (36240818176), duration 2282, 87/0 MB/s
INFO: status: 91% (83101876224/91268055040), sparse 40% (37195153408), duration 2293, 86/0 MB/s
INFO: status: 92% (84019445760/91268055040), sparse 41% (38112722944), duration 2304, 83/0 MB/s
INFO: status: 93% (84957790208/91268055040), sparse 42% (39051067392), duration 2315, 85/0 MB/s
INFO: status: 94% (85837873152/91268055040), sparse 43% (39931150336), duration 2325, 88/0 MB/s
INFO: status: 95% (86785720320/91268055040), sparse 44% (40825765888), duration 2338, 72/4 MB/s
INFO: status: 96% (87650336768/91268055040), sparse 45% (41690382336), duration 2348, 86/0 MB/s
INFO: status: 97% (88603230208/91268055040), sparse 46% (42643275776), duration 2359, 86/0 MB/s
INFO: status: 98% (89519554560/91268055040), sparse 47% (43559600128), duration 2370, 83/0 MB/s
INFO: status: 99% (90363265024/91268055040), sparse 48% (44234219520), duration 2381, 76/15 MB/s
INFO: status: 100% (91268055040/91268055040), sparse 48% (44234293248), duration 2393, 75/75 MB/s
INFO: transferred 91268 MB in 2393 seconds (38 MB/s)
INFO: archive file size: 16.32GB
INFO: Finished Backup of VM 172 (00:39:56)
INFO: Backup job finished successfully
TASK OK

dietmar · Oct 3, 2013

Is it always reproducible, or does it only happens sometimes?

rahman · Oct 3, 2013

Reproducible with VMs with disks bigger than 60 GB size. 32 GB and bellow VMs OK. Did not try disks between 32 GB and 60 GB as we have none.

pero · Oct 19, 2013

I've got similar problem. Yesterday I upgraded from 3.0 to 3.1.
After that the nightly backup of a KVM guest to a CIFS share failed. After 3% it hanged and in the KVM guest load average went up to several hundreds, and stopped responding. There is an openvz CT too on the server, it's backup works perfectly.
I did some investigation, and I realized, that I can not copy to the CIFS share with midnight commander neither. It copies only about 2349M and hangs. So It really must be a kernel issue.
My previous kernel is 2.6.32-20-pve. Is it save to reboot with it? I only want to reboot with this kernel if it is completly safe, because the server is in production.
Thank you!

proxmox-ve-2.6.32: 3.1-114 (running kernel: 2.6.32-26-pve)
pve-manager: 3.1-20 (running version: 3.1-20/c3aa0f1a)
pve-kernel-2.6.32-20-pve: 2.6.32-100
pve-kernel-2.6.32-26-pve: 2.6.32-114
lvm2: 2.02.98-pve4
clvm: 2.02.98-pve4
corosync-pve: 1.4.5-1
openais-pve: 1.1.4-3
libqb0: 0.11.1-2
redhat-cluster-pve: 3.2.0-2
resource-agents-pve: 3.9.2-4
fence-agents-pve: 4.0.0-2
pve-cluster: 3.0-8
qemu-server: 3.1-8
pve-firmware: 1.0-23
libpve-common-perl: 3.0-7
libpve-access-control: 3.0-7
libpve-storage-perl: 3.0-17
pve-libspice-server1: 0.12.4-2
vncterm: 1.1-4
vzctl: 4.0-1pve4
vzprocps: 2.0.11-2
vzquota: 3.1-2
pve-qemu-kvm: 1.4-17
ksm-control-daemon: 1.1-1
glusterfs-client: 3.4.1-1

snowman66 · Oct 20, 2013

Same here. After 11. october backup does not work as it should:

edit:
1. image format: RAW; 32GB (about 20GB is the size of backup file)
2. VM settings:

Code:

bootdisk: ide0
cores: 1
cpuunits: 20000
ide0: local:103/vm-103-disk-1.raw,format=raw,cache=none,size=32G
ide2: none,media=cdrom
memory: 768
name: Ubuntu-Apache
net0: virtio=7A:B1:87:CC:6D:8E,bridge=vmbr0
onboot: 1
ostype: l26
scsihw: virtio-scsi-pci
sockets: 1
startup: order=4,up=60
tablet: 0

Code:

 103: okt 20 06:47:11 INFO: Starting Backup of VM 103 (qemu)
  103: okt 20 06:47:11 INFO: status = running
  103: okt 20 06:47:12 INFO: update VM 103: -lock backup
  103: okt 20 06:47:12 INFO: backup mode: snapshot
  103: okt 20 06:47:12 INFO: ionice priority: 7
  103: okt 20 06:47:12 INFO: creating archive '/mnt/cifs/dump/vzdump-qemu-103-2013_10_20-06_47_11.vma.lzo'
  103: okt 20 06:47:12 INFO: started backup task '56170f25-aaba-47fa-9aa3-3cb210f91506'
  103: okt 20 06:47:15 INFO: status: 1% (414711808/34359738368), sparse 0% (219594752), duration 3, 138/65 MB/s
  103: okt 20 06:47:19 INFO: status: 2% (760217600/34359738368), sparse 0% (231120896), duration 7, 86/83 MB/s
  103: okt 20 06:47:23 INFO: status: 3% (1094385664/34359738368), sparse 0% (254836736), duration 11, 83/77 MB/s
  103: okt 20 06:47:27 INFO: status: 4% (1441333248/34359738368), sparse 0% (267640832), duration 15, 86/83 MB/s
  103: okt 20 06:47:32 INFO: status: 5% (1739653120/34359738368), sparse 0% (282206208), duration 20, 59/56 MB/s
  103: okt 20 06:47:38 INFO: status: 6% (2063990784/34359738368), sparse 0% (282365952), duration 26, 54/54 MB/s
  103: okt 20 07:16:46 ERROR: VM 103 qmp command 'query-backup' failed - got timeout
  103: okt 20 07:16:46 INFO: aborting backup job
  103: okt 20 07:16:52 ERROR: Backup of VM 103 failed - VM 103 qmp command 'query-backup' failed - got timeout

Backup for CT is OK:

Code:

vzdump 103 100 --quiet 1 --mailto XXXXX --mode snapshot --compress lzo --storage backupNAS
  
  100: okt 20 06:45:10 INFO: Starting Backup of VM 100 (openvz)
  100: okt 20 06:45:10 INFO: CTID 100 exist mounted running
  100: okt 20 06:45:10 INFO: status = running
  100: okt 20 06:45:10 INFO: backup mode: snapshot
  100: okt 20 06:45:10 INFO: ionice priority: 7
  100: okt 20 06:45:10 INFO: creating lvm snapshot of /dev/mapper/pve-data ('/dev/pve/vzsnap-XXXXX-pve1-0')
  100: okt 20 06:45:10 INFO:   Logical volume "vzsnap-XXXXX-pve1-0" created
  100: okt 20 06:45:10 INFO: creating archive '/mnt/cifs/dump/vzdump-openvz-100-2013_10_20-06_45_02.tar.lzo'
  100: okt 20 06:46:10 INFO: Total bytes written: 1591326720 (1.5GiB, 29MiB/s)
  100: okt 20 06:47:09 INFO: archive file size: 1018MB
  100: okt 20 06:47:10 INFO: delete old backup '/mnt/cifs/dump/vzdump-openvz-100-2013_10_06-06_45_02.tar.lzo'
  100: okt 20 06:47:11 INFO: Finished Backup of VM 100 (00:02:09)

deludi · Oct 21, 2013

Hello,

i have a similar problem.
When i backup large vm's (~100GB) the backup stalls and the proxmox node crashes.
I am on proxmox 3.1.3.
The vm is on an NFS share and the backup target also is an NFS share.
Small vm's (~10GB) are backed up without problems.
Will revert to proxmox 3 and test again.

Best regards,

Dirk Adamsky

snowman66 · Oct 21, 2013

edit:
1. image format: RAW; 32GB (about 20GB is the size of backup file)
2. VM settings:

Code:

bootdisk: ide0
cores: 1
cpuunits: 20000
ide0: local:103/vm-103-disk-1.raw,format=raw,cache=none,size=32G
ide2: none,media=cdrom
memory: 768
name: Ubuntu-Apache
net0: virtio=7A:B1:87:CC:6D:8E,bridge=vmbr0
onboot: 1
ostype: l26
[B]scsihw: virtio-scsi-pci[/B]
sockets: 1
startup: order=4,up=60
tablet: 0

I changed scsihw to default lsi and backup is working again.

Search

Search

3.1 update broke backups

rahman

Renowned Member

tom

Proxmox Staff Member

rahman

Renowned Member

rahman

Renowned Member

dietmar

Proxmox Staff Member

rahman

Renowned Member

pero

Renowned Member

snowman66

Active Member

deludi

New Member

snowman66

Active Member