Proxmox 2.1 hangs on qmrestore

[Marvin]

Every time i try to restore a .tar.lzo backup from command line:
root@proxmox2b:~# qmrestore /mnt/iSCSI_Backup/dump/TestWin7-64-2012_07_31.tar.lzo 121 -storage ImageLVM
extracting archive '/mnt/iSCSI_Backup/dump/TestWin7-64-2012_07_31.tar.lzo'
extracting 'qemu-server.conf' from archive
extracting 'vm-disk-virtio0.raw' from archive
Rounding up size to full physical extent 32.01 GiB
Logical volume "vm-121-disk-1" created
new volume ID is 'ImageLVM:vm-121-disk-1'
restore data to '/dev/drbd0/vm-121-disk-1' (34363932672 bytes)

Midway through the restore these errors starts repeating on the proxmox console:
INFO: task vgs:36060 blocked for more than 120 seconds.

Syslog shows this repeating once a minute:
Sep 12 12:14:03 proxmox2b kernel: INFO: task vgs:36045 blocked for more than 120 seconds.
Sep 12 12:14:03 proxmox2b kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 12 12:14:03 proxmox2b kernel: vgs D ffff880336d96b80 0 36045 2975 0 0x00000000
Sep 12 12:14:03 proxmox2b kernel: ffff880336d9baa8 0000000000000082 0000000000000000 ffffffff8140d87c
Sep 12 12:14:03 proxmox2b kernel: 0000000000000008 0000000000001000 0000000000000000 000000000000000c
Sep 12 12:14:03 proxmox2b kernel: ffff880336d9ba98 ffff880336d97120 ffff880336d9bfd8 ffff880336d9bfd8
Sep 12 12:14:03 proxmox2b kernel: Call Trace:
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8140d87c>] ? dm_table_unplug_all+0x5c/0x100
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81513e33>] io_schedule+0x73/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cd46e>] __blockdev_direct_IO_newtrunc+0x6ee/0xb80
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811642af>] ? __vmalloc_area_node+0x5f/0x190
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a86a9>] ? dput+0xc9/0x1d0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cd95e>] __blockdev_direct_IO+0x5e/0xd0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca230>] ? blkdev_get_blocks+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cb087>] blkdev_direct_IO+0x57/0x60
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca230>] ? blkdev_get_blocks+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81120000>] mapping_direct_IO+0x50/0x60
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81122e6b>] generic_file_read_iter+0x60b/0x680
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cb8b9>] ? __blkdev_get+0x1a9/0x3c0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cbaf0>] ? blkdev_open+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cbae0>] ? blkdev_get+0x10/0x20
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81122f6b>] generic_file_aio_read+0x8b/0xa0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8118f62a>] do_sync_read+0xfa/0x140
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a1140>] ? do_filp_open+0x6f0/0xca0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81094610>] ? autoremove_wake_function+0x0/0x40
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca66c>] ? block_ioctl+0x3c/0x40
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a304a>] ? do_vfs_ioctl+0x8a/0x5d0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81190005>] vfs_read+0xb5/0x1a0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81190141>] sys_read+0x51/0x90
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8100b182>] system_call_fastpath+0x16/0x1b
Sep 12 12:14:03 proxmox2b kernel: INFO: task vgs:36060 blocked for more than 120 seconds.
Sep 12 12:14:03 proxmox2b kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Sep 12 12:14:03 proxmox2b kernel: vgs D ffff880336d960c0 0 36060 2952 0 0x00000000
Sep 12 12:14:03 proxmox2b kernel: ffff880241f67aa8 0000000000000082 ffff880241f67a68 ffffffff8140d87c
Sep 12 12:14:03 proxmox2b kernel: 0000000000000008 0000000000001000 0000000000000000 000000000000000c
Sep 12 12:14:03 proxmox2b kernel: ffff880241f67a98 ffff880336d96660 ffff880241f67fd8 ffff880241f67fd8
Sep 12 12:14:03 proxmox2b kernel: Call Trace:
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8140d87c>] ? dm_table_unplug_all+0x5c/0x100
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81513e33>] io_schedule+0x73/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cd46e>] __blockdev_direct_IO_newtrunc+0x6ee/0xb80
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a86a9>] ? dput+0xc9/0x1d0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cd95e>] __blockdev_direct_IO+0x5e/0xd0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca230>] ? blkdev_get_blocks+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cb087>] blkdev_direct_IO+0x57/0x60
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca230>] ? blkdev_get_blocks+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81120000>] mapping_direct_IO+0x50/0x60
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81122e6b>] generic_file_read_iter+0x60b/0x680
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cb8b9>] ? __blkdev_get+0x1a9/0x3c0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cbaf0>] ? blkdev_open+0x0/0xc0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811cbae0>] ? blkdev_get+0x10/0x20
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81122f6b>] generic_file_aio_read+0x8b/0xa0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8118f62a>] do_sync_read+0xfa/0x140
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a1140>] ? do_filp_open+0x6f0/0xca0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81094610>] ? autoremove_wake_function+0x0/0x40
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811ca66c>] ? block_ioctl+0x3c/0x40
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff811a304a>] ? do_vfs_ioctl+0x8a/0x5d0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81190005>] vfs_read+0xb5/0x1a0
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff81190141>] sys_read+0x51/0x90
Sep 12 12:14:03 proxmox2b kernel: [<ffffffff8100b182>] system_call_fastpath+0x16/0x1b

Anyone?

 

[dietmar]

What is the output of

# pveversion -v

 

[Marvin]

root@proxmox2b:~# pveversion -v
pve-manager: 2.1-1 (pve-manager/2.1/f9b0f63a)
running kernel: 2.6.32-12-pve
proxmox-ve-2.6.32: 2.1-68
pve-kernel-2.6.32-11-pve: 2.6.32-66
pve-kernel-2.6.32-12-pve: 2.6.32-68
lvm2: 2.02.95-1pve2
clvm: 2.02.95-1pve2
corosync-pve: 1.4.3-1
openais-pve: 1.1.4-2
libqb: 0.10.1-2
redhat-cluster-pve: 3.1.8-3
resource-agents-pve: 3.9.2-3
fence-agents-pve: 3.1.7-2
pve-cluster: 1.0-26
qemu-server: 2.0-39
pve-firmware: 1.0-16
libpve-common-perl: 1.0-27
libpve-access-control: 1.0-21
libpve-storage-perl: 2.0-18
vncterm: 1.0-2
vzctl: 3.0.30-2pve5
vzprocps: 2.0.11-2
vzquota: 3.0.12-3
pve-qemu-kvm: 1.0-9
ksm-control-daemon: 1.1-1

 

[dietmar]

I guess you should update your kernel.

 

[Marvin]

Thank you Dietmar. It is now updated.

pveversion -v
pve-manager: 2.1-14 (pve-manager/2.1/f32f3f46)
running kernel: 2.6.32-12-pve
proxmox-ve-2.6.32: 2.1-74
pve-kernel-2.6.32-11-pve: 2.6.32-66
pve-kernel-2.6.32-14-pve: 2.6.32-74
lvm2: 2.02.95-1pve2
clvm: 2.02.95-1pve2
corosync-pve: 1.4.3-1
openais-pve: 1.1.4-2
libqb: 0.10.1-2
redhat-cluster-pve: 3.1.92-3
resource-agents-pve: 3.9.2-3
fence-agents-pve: 3.1.8-1
pve-cluster: 1.0-27
qemu-server: 2.0-49
pve-firmware: 1.0-18
libpve-common-perl: 1.0-30
libpve-access-control: 1.0-24
libpve-storage-perl: 2.0-31
vncterm: 1.0-3
vzctl: 3.0.30-2pve5
vzprocps: 2.0.11-2
vzquota: 3.0.12-3
pve-qemu-kvm: 1.1-8
ksm-control-daemon: 1.1-1

 

[dietmar]

You need to reboot to activate the new kernel.

 

[Marvin]

Oh right, thank you. It was a late night... %-/

 

[Marvin]

Today i had occasion to try to restore a vm backup as another VMID for use as a "test" vm while my production vm's were running as normal. I used the GUI to do this. A few minutes into the process the previous problem documented in this thread reoccurred. First the GUI display of vm's went all black, all summary graph data went to zero, and the vm's became hung up (would not respond via network or console.) I could temporarily bring the GUI display back by running "service pvestatd restart". But it would soon go black again.

Neither could i shutdown nor stop the vm's. The log showed the exact same errors as my original post at the top of this thread (9/12/2012). I could not shutdown Proxmox, either by GUI or command line as it kept giving errors trying to stop the vm's. I finally had to force off the Proxmox server and restart. Unfortunately this cause several vm's to corrupt and i had to restore them, this time i had all vm's shutdown and those restores finished normally. However those were very small Linux servers (<1Gb).

Previously this issue occurred with v2.1, now with 2.2. I don't know if i'm doing something wrong or what? BTW, i was restoring a different vm backup than i was when i reported the earlier occurrence.

*The pve-data drive is a 75Gb RAID 1 with 68Gb free.
*The image drive is a 2.2Tb RAID 5 LVM with 556Gb free.
*The backup storage is a 750Gb iSCSI with 267Gb free.
*The vm backup i was trying to restore is 25.5Gb compressed, 150.1 Gb uncompressed.
*This Proxmox server has 15 vm's running (a variety of Linux and Windows XP, 2003, 2008 servers), and normally they all run quite well.

Could it be that the problem is cause by the uncompressed size of the target vm is more than twice the size of the pve-data drive (Even though the vm was being restored to the image disk)? Is the pve-data drive being used as a temporary location for the decompression process?

root@proxmox2b:~# pveversion -v
pve-manager: 2.2-32 (pve-manager/2.2/3089a616)
running kernel: 2.6.32-17-pve
proxmox-ve-2.6.32: 2.2-83
pve-kernel-2.6.32-16-pve: 2.6.32-82
pve-kernel-2.6.32-17-pve: 2.6.32-83
lvm2: 2.02.95-1pve2
clvm: 2.02.95-1pve2
corosync-pve: 1.4.4-1
openais-pve: 1.1.4-2
libqb: 0.10.1-2
redhat-cluster-pve: 3.1.93-2
resource-agents-pve: 3.9.2-3
fence-agents-pve: 3.1.9-1
pve-cluster: 1.0-34
qemu-server: 2.0-72
pve-firmware: 1.0-21
libpve-common-perl: 1.0-41
libpve-access-control: 1.0-25
libpve-storage-perl: 2.0-36
vncterm: 1.0-3
vzctl: 4.0-1pve2
vzprocps: 2.0.11-2
vzquota: 3.1-1
pve-qemu-kvm: 1.3-10
ksm-control-daemon: 1.1-1

root@proxmox2b:~# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/pve-root 37G 1.4G 34G 5% /
tmpfs 18G 0 18G 0% /lib/init/rw
udev 18G 336K 18G 1% /dev
tmpfs 18G 16M 18G 1% /dev/shm
/dev/mapper/pve-data 75G 7.8G 68G 11% /var/lib/vz
/dev/sda1 495M 102M 368M 22% /boot
/dev/sdc 739G 434G 268G 62% /mnt/iSCSI_Backup
/dev/fuse 30M 20K 30M 1% /etc/pve

root@proxmox2b:~# pvscan
PV /dev/sdb1 VG ImageLVM lvm2 [2.27 TiB / 556.46 GiB free]
PV /dev/sda2 VG pve lvm2 [147.58 GiB / 16.00 GiB free]
Total: 2 [2.41 TiB] / in use: 2 [2.41 TiB] / in no VG: 0 [0 ]