Node hangs during restore VM

[cingo_5]

Hi

i've a problem with restoring vm from dump on proxmox ve 6.x
the host is a hp proliant ml110 gen10 with a single sata disk configure in sata ahci mode on board (no raid)
the destination volume of the restore is "local-lvm", the default volume created...

when i start the restore, it reach 100% in a resonable time but it remain there for long.
even a small dump around 1gb takes more than 30 minutes to complete. during this time the node become unresposive with an high load average, and often other vm, on the same storage, swap to read only mode on the file system...

root@pve:~# uptime
10:57:01 up 1:12, 1 user, load average: 6.73, 6.00, 3.41

from dmesg i've got this:

[ 3988.653284] INFO: task kvm:5851 blocked for more than 120 seconds.
[ 3988.653352] Tainted: P OE 5.4.34-1-pve #1
[ 3988.653401] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 3988.653466] kvm D 0 5851 1 0x00000000
[ 3988.653471] Call Trace:
[ 3988.653483] __schedule+0x2e6/0x700
[ 3988.653488] schedule+0x33/0xa0
[ 3988.653493] schedule_timeout+0x205/0x300
[ 3988.653501] ? dm_make_request+0x56/0xb0
[ 3988.653506] io_schedule_timeout+0x1e/0x50
[ 3988.653510] wait_for_completion_io+0xb7/0x140
[ 3988.653517] ? wake_up_q+0x80/0x80
[ 3988.653525] submit_bio_wait+0x61/0x90
[ 3988.653531] blkdev_issue_zeroout+0x140/0x220
[ 3988.653539] blkdev_ioctl+0x5cd/0x9e0
[ 3988.653546] block_ioctl+0x3d/0x50
[ 3988.653550] do_vfs_ioctl+0xa9/0x640
[ 3988.653556] ? _copy_from_user+0x3e/0x60
[ 3988.653561] ksys_ioctl+0x67/0x90
[ 3988.653565] __x64_sys_ioctl+0x1a/0x20
[ 3988.653572] do_syscall_64+0x57/0x190
[ 3988.653578] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 3988.653583] RIP: 0033:0x7f0433fa4427
[ 3988.653591] Code: Bad RIP value.
[ 3988.653594] RSP: 002b:00007f01f5ae04a8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 3988.653598] RAX: ffffffffffffffda RBX: 00007f0204c707e0 RCX: 00007f0433fa4427
[ 3988.653601] RDX: 00007f01f5ae04b0 RSI: 000000000000127f RDI: 000000000000001c
[ 3988.653603] RBP: 00007f0426aea7e0 R08: 0000000000000000 R09: 00000000ffffffff
[ 3988.653605] R10: 00007f01f5ae04b0 R11: 0000000000000246 R12: 00007f01f5ae04b0
[ 3988.653607] R13: 00007f042706ca78 R14: 00007f0426aeaa80 R15: 0000561ac7346302

in the previsious versione of pve (5.x and 4.x) on the same hardware, there isn't problem
what can i do to solve this?

thank for your attention and sorry for my english.

 

[wolfgang]

Hi,

can you send the output of

pveversion -v

 

[cingo_5]

Hi, thanks for your reply:

root@pve:~# pveversion -v
proxmox-ve: 4.3-66 (running kernel: 4.4.19-1-pve)
pve-manager: 4.3-1 (running version: 4.3-1/e7cdc165)
pve-kernel-4.4.19-1-pve: 4.4.19-66
lvm2: 2.02.116-pve3
corosync-pve: 2.4.0-1
libqb0: 1.0-1
pve-cluster: 4.0-46
qemu-server: 4.0-88
pve-firmware: 1.1-9
libpve-common-perl: 4.0-73
libpve-access-control: 4.0-19
libpve-storage-perl: 4.0-61
pve-libspice-server1: 0.12.8-1
vncterm: 1.2-1
pve-qemu-kvm: 2.6.1-6
pve-container: 1.0-75
pve-firewall: 2.0-29
pve-ha-manager: 1.0-35
ksm-control-daemon: 1.2-1
glusterfs-client: 3.5.2-2+deb8u2
lxc-pve: 2.0.4-1
lxcfs: 2.0.3-pve1
criu: 1.6.0-1
novnc-pve: 0.5-8
zfsutils: 0.6.5.7-pve10~bpo80

 

[cingo_5]

hi.
right now i'm restoring the same dump image on a fresh install of proxmox 6.2,but in a different hardware (hp proliant ml 30 gen 10, only 1 sata disk in ahci mode) , the hardware is lower in performance then the previsious but here i've restored the dump in less time

restore vma archive: lzop -d -c /var/lib/vz/dump/vzdump-qemu-103-2017_11_27-02_51_06.vma.lzo | vma extract -v -r /var/tmp/vzdumptmp9954.fifo - /var/tmp/vzdumptmp9954
CFG: size: 352 name: qemu-server.conf
DEV: dev_id=1 size: 8589934592 devname: drive-ide0
CTIME: Mon Nov 27 02:51:07 2017
  Logical volume "vm-101-disk-0" created.
new volume ID is 'local-lvm:vm-101-disk-0'
map 'drive-ide0' to '/dev/pve/vm-101-disk-0' (write zeros = 0)
progress 1% (read 85917696 bytes, duration 0 sec)
progress 2% (read 171835392 bytes, duration 0 sec)
progress 3% (read 257753088 bytes, duration 0 sec)
progress 4% (read 343605248 bytes, duration 2 sec)
progress 5% (read 429522944 bytes, duration 3 sec)
progress 6% (read 515440640 bytes, duration 4 sec)
progress 7% (read 601358336 bytes, duration 6 sec)
progress 8% (read 687210496 bytes, duration 7 sec)
progress 9% (read 773128192 bytes, duration 9 sec)
progress 10% (read 859045888 bytes, duration 10 sec)
progress 11% (read 944898048 bytes, duration 12 sec)
progress 12% (read 1030815744 bytes, duration 14 sec)
progress 13% (read 1116733440 bytes, duration 16 sec)
progress 14% (read 1202651136 bytes, duration 25 sec)
progress 15% (read 1288503296 bytes, duration 168 sec)
progress 16% (read 1374420992 bytes, duration 180 sec)
progress 17% (read 1460338688 bytes, duration 191 sec)
progress 18% (read 1546190848 bytes, duration 206 sec)
progress 19% (read 1632108544 bytes, duration 220 sec)
progress 20% (read 1718026240 bytes, duration 231 sec)
progress 21% (read 1803943936 bytes, duration 241 sec)
progress 22% (read 1889796096 bytes, duration 252 sec)
progress 23% (read 1975713792 bytes, duration 264 sec)
progress 24% (read 2061631488 bytes, duration 286 sec)
progress 25% (read 2147483648 bytes, duration 299 sec)
progress 26% (read 2233401344 bytes, duration 302 sec)
progress 27% (read 2319319040 bytes, duration 308 sec)
progress 28% (read 2405236736 bytes, duration 322 sec)
progress 29% (read 2491088896 bytes, duration 334 sec)
progress 30% (read 2577006592 bytes, duration 348 sec)
progress 31% (read 2662924288 bytes, duration 356 sec)
progress 32% (read 2748841984 bytes, duration 356 sec)
progress 33% (read 2834694144 bytes, duration 356 sec)
progress 34% (read 2920611840 bytes, duration 356 sec)
progress 35% (read 3006529536 bytes, duration 356 sec)
progress 36% (read 3092381696 bytes, duration 356 sec)
progress 37% (read 3178299392 bytes, duration 356 sec)
progress 38% (read 3264217088 bytes, duration 356 sec)
progress 39% (read 3350134784 bytes, duration 356 sec)
progress 40% (read 3435986944 bytes, duration 356 sec)
progress 41% (read 3521904640 bytes, duration 356 sec)
progress 42% (read 3607822336 bytes, duration 356 sec)
progress 43% (read 3693674496 bytes, duration 356 sec)
progress 44% (read 3779592192 bytes, duration 356 sec)
progress 45% (read 3865509888 bytes, duration 356 sec)
progress 46% (read 3951427584 bytes, duration 356 sec)
progress 47% (read 4037279744 bytes, duration 356 sec)
progress 48% (read 4123197440 bytes, duration 356 sec)
progress 49% (read 4209115136 bytes, duration 356 sec)
progress 50% (read 4294967296 bytes, duration 356 sec)
progress 51% (read 4380884992 bytes, duration 357 sec)
progress 52% (read 4466802688 bytes, duration 363 sec)
progress 53% (read 4552720384 bytes, duration 384 sec)
progress 54% (read 4638572544 bytes, duration 404 sec)
progress 55% (read 4724490240 bytes, duration 423 sec)
progress 56% (read 4810407936 bytes, duration 444 sec)
progress 57% (read 4896325632 bytes, duration 454 sec)
progress 58% (read 4982177792 bytes, duration 464 sec)
progress 59% (read 5068095488 bytes, duration 475 sec)
progress 60% (read 5154013184 bytes, duration 483 sec)
progress 61% (read 5239865344 bytes, duration 486 sec)
progress 62% (read 5325783040 bytes, duration 494 sec)
progress 63% (read 5411700736 bytes, duration 501 sec)
progress 64% (read 5497618432 bytes, duration 521 sec)
progress 65% (read 5583470592 bytes, duration 524 sec)
progress 66% (read 5669388288 bytes, duration 524 sec)
progress 67% (read 5755305984 bytes, duration 524 sec)
progress 68% (read 5841158144 bytes, duration 524 sec)
progress 69% (read 5927075840 bytes, duration 524 sec)
progress 70% (read 6012993536 bytes, duration 524 sec)
progress 71% (read 6098911232 bytes, duration 524 sec)
progress 72% (read 6184763392 bytes, duration 524 sec)
progress 73% (read 6270681088 bytes, duration 524 sec)
progress 74% (read 6356598784 bytes, duration 524 sec)
progress 75% (read 6442450944 bytes, duration 524 sec)
progress 76% (read 6528368640 bytes, duration 524 sec)
progress 77% (read 6614286336 bytes, duration 527 sec)
progress 78% (read 6700204032 bytes, duration 529 sec)
progress 79% (read 6786056192 bytes, duration 529 sec)
progress 80% (read 6871973888 bytes, duration 529 sec)
progress 81% (read 6957891584 bytes, duration 529 sec)
progress 82% (read 7043809280 bytes, duration 529 sec)
progress 83% (read 7129661440 bytes, duration 529 sec)
progress 84% (read 7215579136 bytes, duration 529 sec)
progress 85% (read 7301496832 bytes, duration 529 sec)
progress 86% (read 7387348992 bytes, duration 529 sec)
progress 87% (read 7473266688 bytes, duration 529 sec)
progress 88% (read 7559184384 bytes, duration 529 sec)
progress 89% (read 7645102080 bytes, duration 529 sec)
progress 90% (read 7730954240 bytes, duration 529 sec)
progress 91% (read 7816871936 bytes, duration 529 sec)
progress 92% (read 7902789632 bytes, duration 529 sec)
progress 93% (read 7988641792 bytes, duration 529 sec)
progress 94% (read 8074559488 bytes, duration 529 sec)
progress 95% (read 8160477184 bytes, duration 529 sec)
progress 96% (read 8246394880 bytes, duration 529 sec)
progress 97% (read 8332247040 bytes, duration 529 sec)
progress 98% (read 8418164736 bytes, duration 529 sec)
progress 99% (read 8504082432 bytes, duration 529 sec)
progress 100% (read 8589934592 bytes, duration 529 sec)
total bytes read 8589934592, sparse bytes 5535399936 (64.4%)
space reduction due to 4K zero blocks 0.6%
rescan volumes...
TASK OK

just last week i've restored several vm on a fujitsu primergy server, with sas disk and raid controller, and it works well... I'm starting to think of an incompatibility with the hp proliant ml110.

 

[wolfgang]

I'm starting to think of an incompatibility with the hp proliant ml110.

Have you checked the bios firmware?
Maybe there is a new one witch solves the problem?