Kernel OOPS bei Move Disk

P

pixelpeter

Renowned Member
Proxmox Subscriber
Aug 5, 2015
174
4
83
57
Chemnitz
Hallo,

Ich habe dieses Problem jetzt schon das zweite mal bekommen.
Ich will ein Image von einem NFS Storage auf einen zweiten verschieben.
Dabei kommt es nach wenigen Sekunden zu diesem Fehler:
May 15 08:55:16 sv-c-vdz1 pvedaemon[15193]: <nawroth_p@pve> move disk VM 108: move --disk virtio0 --storage nfs_fast
May 15 08:55:16 sv-c-vdz1 pvedaemon[15193]: <nawroth_p@pve> starting task UPID:sv-c-vdz1:0000692B:0383C5BD:5AFA8454:qmmove:108:nawroth_p@pve:
May 15 08:58:08 sv-c-vdz1 pvedaemon[27358]: <nawroth_p@pve> starting task UPID:sv-c-vdz1:00006B4D:03840901:5AFA8500:qmigrate:105:nawroth_p@pve:
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273497] kvm D 0 5297 1 0x00000000
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273500] Call Trace:
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273506] __schedule+0x3e0/0x870
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273509] ? hrtimer_try_to_cancel+0xc8/0x120
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273510] schedule+0x36/0x80
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273513] rwsem_down_write_failed+0x230/0x3a0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273516] call_rwsem_down_write_failed+0x17/0x30
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273517] ? call_rwsem_down_write_failed+0x17/0x30
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273518] down_write+0x2d/0x40
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273538] nfs_start_io_write+0x19/0x40 [nfs]
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273544] nfs_file_write+0x7c/0x250 [nfs]
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273547] new_sync_write+0xe7/0x140
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273549] __vfs_write+0x29/0x40
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273551] vfs_write+0xb5/0x1a0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273553] SyS_pwrite64+0x95/0xb0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273556] entry_SYSCALL_64_fastpath+0x24/0xab
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273557] RIP: 0033:0x7f94a1a6e963
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273558] RSP: 002b:00007f93877fc5d0 EFLAGS: 00000293 ORIG_RAX: 0000000000000012
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273560] RAX: ffffffffffffffda RBX: 0000000000000189 RCX: 00007f94a1a6e963
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273561] RDX: 0000000000001000 RSI: 00007f9495016000 RDI: 0000000000000019
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273562] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000ffffffff
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273563] R10: 000000027f919e00 R11: 0000000000000293 R12: 00007f93877fc620
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273563] R13: 00007f94960bcf88 R14: 00007f93877ff700 R15: 00007f938e79ae00
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273634] kvm D 0 12788 1 0x00000000
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273635] Call Trace:
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273637] __schedule+0x3e0/0x870
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273638] schedule+0x36/0x80
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273641] io_schedule+0x16/0x40
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273645] wait_on_page_bit_common+0xf3/0x180
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273647] ? page_cache_tree_insert+0xc0/0xc0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273649] __filemap_fdatawait_range+0x114/0x180
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273651] ? __filemap_fdatawrite_range+0xd4/0x100
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273652] filemap_write_and_wait_range+0x57/0xa0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273658] nfs_file_fsync+0x34/0x1e0 [nfs]
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273661] vfs_fsync_range+0x4e/0xb0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273662] do_fsync+0x3d/0x70
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273664] SyS_fdatasync+0x13/0x20
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273665] entry_SYSCALL_64_fastpath+0x24/0xab
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273666] RIP: 0033:0x7f94a17a063d
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273667] RSP: 002b:00007f93837fc5f0 EFLAGS: 00000293 ORIG_RAX: 000000000000004b
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273668] RAX: ffffffffffffffda RBX: 0000000000000189 RCX: 00007f94a17a063d
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273669] RDX: 00007f94960bcf30 RSI: 000055e06b379788 RDI: 0000000000000019
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273669] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000ffffffff
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273670] R10: 00007f93837fc620 R11: 0000000000000293 R12: 00007f93837fc620
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273671] R13: 00007f94960bcf88 R14: 00007f93837ff700 R15: 00007f938f612400
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273740] kvm D 0 27228 1 0x00000000
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273741] Call Trace:
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273743] __schedule+0x3e0/0x870
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273744] schedule+0x36/0x80
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273745] rwsem_down_write_failed+0x230/0x3a0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273747] ? update_curr+0x78/0x1c0
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273748] call_rwsem_down_write_failed+0x17/0x30
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273752] ? dentry_free+0x38/0x70
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273754] ? call_rwsem_down_write_failed+0x17/0x30
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273755] down_write+0x2d/0x40
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273761] nfs_start_io_write+0x19/0x40 [nfs]
May 15 08:59:04 sv-c-vdz1 kernel: [589895.273766] nfs_file_write+0x7c/0x250 [nfs]

Beim Storage handelt es sich um eine NetApp mit 10GB Anbindung.
Alle NFS Mounts sind in dem Zustand nicht mehr verfügbar. Laufende VM's sind nicht mehr steuerbar.
Es hilft dann nur das Blade neu durchzustarten.


Version ist:
proxmox-ve: 5.1-41 (running kernel: 4.13.13-6-pve)
pve-manager: 5.1-46 (running version: 5.1-46/ae8241d4)
pve-kernel-4.13.13-6-pve: 4.13.13-41
corosync: 2.4.2-pve3
criu: 2.11.1-1~bpo90
glusterfs-client: 3.8.8-1
ksm-control-daemon: 1.2-2
libjs-extjs: 6.0.1-2
libpve-access-control: 5.0-8
libpve-common-perl: 5.0-28
libpve-guest-common-perl: 2.0-14
libpve-http-server-perl: 2.0-8
libpve-storage-perl: 5.0-17
libqb0: 1.0.1-1
lvm2: 2.02.168-pve6
lxc-pve: 2.1.1-3
lxcfs: 2.0.8-2
novnc-pve: 0.6-4
openvswitch-switch: 2.7.0-2
proxmox-widget-toolkit: 1.0-11
pve-cluster: 5.0-20
pve-container: 2.0-19
pve-docs: 5.1-16
pve-firewall: 3.0-5
pve-firmware: 2.0-3
pve-ha-manager: 2.0-5
pve-i18n: 1.0-4
pve-libspice-server1: 0.12.8-3
pve-qemu-kvm: 2.9.1-9
pve-xtermjs: 1.0-2
qemu-server: 5.0-22
smartmontools: 6.5+svn4324-1
spiceterm: 3.0-5
vncterm: 1.5-3

Solche verschiebereien haben in der Vergangenheit niemals zu Problemen geführt.
Seit ca. drei Monaten läuft bei uns die Version 5.

Peter
 
handelt es sich tatsächlich um eine kernel panic, oder um einen hung task? bitte den vollständigen log posten (und auf die aktuellen pakete upgraden!)
 
Hallo Fabian,

Es ist ein hang Task.


Hier der log mit Version 5.1 und Kernel 4.13.13.6.

[ 561.622804] device tap119i0 entered promiscuous mode
[ 564.526224] device tap123i0 entered promiscuous mode
[ 687.035858] device tap122i0 entered promiscuous mode
[ 689.673778] device tap125i0 entered promiscuous mode
[ 4524.316661] perf: interrupt took too long (2506 > 2500), lowering kernel.perf_event_max_sample_rate to 79750
[ 6294.240143] perf: interrupt took too long (3142 > 3132), lowering kernel.perf_event_max_sample_rate to 63500
[14596.443094] perf: interrupt took too long (3929 > 3927), lowering kernel.perf_event_max_sample_rate to 50750
[52770.345721] perf: interrupt took too long (4940 > 4911), lowering kernel.perf_event_max_sample_rate to 40250
[68977.656470] perf: interrupt took too long (6485 > 6175), lowering kernel.perf_event_max_sample_rate to 30750
[243473.766262] INFO: task kvm:34673 blocked for more than 120 seconds.
[243473.766290] Not tainted 4.13.13-6-pve #1
[243473.766303] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[243473.766325] kvm D 0 34673 1 0x00000000
[243473.766327] Call Trace:
[243473.766335] __schedule+0x3e0/0x870
[243473.766336] schedule+0x36/0x80
[243473.766340] io_schedule+0x16/0x40
[243473.766343] wait_on_page_bit_common+0xf3/0x180
[243473.766346] ? page_cache_tree_insert+0xc0/0xc0
[243473.766348] __filemap_fdatawait_range+0x114/0x180
[243473.766349] filemap_write_and_wait_range+0x57/0xa0
[243473.766362] nfs_file_fsync+0x34/0x1e0 [nfs]
[243473.766366] vfs_fsync_range+0x4e/0xb0
[243473.766368] do_fsync+0x3d/0x70
[243473.766369] SyS_fdatasync+0x13/0x20
[243473.766373] entry_SYSCALL_64_fastpath+0x24/0xab
[243473.766374] RIP: 0033:0x7faa1ae7a63d
[243473.766375] RSP: 002b:00007fa7e03fc5f0 EFLAGS: 00000293 ORIG_RAX: 000000000000004b
[243473.766377] RAX: ffffffffffffffda RBX: 0000000000000189 RCX: 00007faa1ae7a63d
[243473.766378] RDX: 00007faa0f4bcf30 RSI: 000055901aeee788 RDI: 0000000000000018
[243473.766378] RBP: 0000000000000000 R08: 0000000000000000 R09: 00000000ffffffff
[243473.766379] R10: 00007fa7e03fc620 R11: 0000000000000293 R12: 00007fa7e03fc620
[243473.766380] R13: 00007faa0f4bcf88 R14: 0000000000000000 R15: 00007faa33395040
[243473.766382] INFO: task kvm:30751 blocked for more than 120 seconds.
[243473.766400] Not tainted 4.13.13-6-pve #1
[243473.766413] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[243473.766434] kvm D 0 30751 1 0x00000000
[243473.766435] Call Trace:
[243473.766437] __schedule+0x3e0/0x870
[243473.766439] ? hrtimer_try_to_cancel+0xc8/0x120

Wir haben heute ein Update auf 5.2 gemacht.
Allerdings ist hier das selbe Problem.
Ich verschiebe ein Image und nach ca 50% steht der Prozess.
Alle VM's im Knoten bekommen ein graues Fragezeichen.
Die NFS Mounpoints sind nicht mehr verfügbar.
Allerdings kommt bei der aktuellen Version keine Kernelmeldung mehr! Auch nicht nach mehreren Minuten.
Manuelles Kopieren auf der Konsole geht dagegen sehr fix und ohne Probleme.

Bei der version 5.2 bekommen wir beim starten von den VM's diese Warnung:
[ 190.371505] device tap154i0 entered promiscuous mode
[ 190.389431] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
[ 246.258067] device tap100i0 entered promiscuous mode
[ 246.275223] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
[ 251.293821] device tap103i0 entered promiscuous mode
[ 251.308757] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
[ 256.281602] device tap113i0 entered promiscuous mode
[ 256.296616] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.
[ 256.688711] device tap113i1 entered promiscuous mode
[ 256.704641] netlink: 'ovs-vswitchd': attribute type 5 has an invalid length.


Hier noch unsere aktuellen die Mountoptionen:
10.3.9.100:/vol_dzfs_fast on /mnt/pve/nfs_fast type nfs (rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,mountaddr=10.3.9.100,mountvers=3,mountport=635,mountproto=udp,local_lock=none,addr=10.3.9.100)


Peter
 
guessing by the export name, the NFS share is backed by ZFS? what does monitoring on the server side show?

I cannot reproduce this here (to regular NFS or NFS backed by ZFS), and the symptoms point to the NFS server starting to hang/crawl to an almost stop?
 
Hallo Fabian,

Unser Storage ist eine Netapp. Ziemlich dickes Teil. Die netapp Admins schauen noch nach ob irgendetwas auffälliges zu finden ist.
Aktuell haben wir zwei Mounts auf diesem Storage.
Das Problem tritt auf wenn ich ein Image von einem zum anderen verschiebe. qemu-img geht auf 100% Last.
Ich habe das heute früh mit dem aktuellen Proxmox 5.2 getestet ohne das VM's auf dem Host laufen.
Nach ca 50% bleibt der Output stehen und der Knoten bekommt die grauen Fragezeichen.
Die Netapp ist noch anpingbar! Zugriff auf die Mounts sind allerdings nicht mehr möglich.
pvecm status zeigt in diesem Zustand keine Fehler an.
Das Storage ist über ein Bond mit 2x10GB angebunden.
Cluster Kommunikation laufen über ein weiteres separates Bond.
VM Traffic über ein weiteres.
Was kann ich hier noch weiter testen?

Peter
 
möglichst viel auf beiden seiten monitoren und nach auffälligkeiten suchen bleibt im moment vermutlich als einziger nächster schritt...
 
pixelpeter said:
Hallo Fabian,

Unser Storage ist eine Netapp. Ziemlich dickes Teil. Die netapp Admins schauen noch nach ob irgendetwas auffälliges zu finden ist.
Aktuell haben wir zwei Mounts auf diesem Storage.
Das Problem tritt auf wenn ich ein Image von einem zum anderen verschiebe. qemu-img geht auf 100% Last.
Ich habe das heute früh mit dem aktuellen Proxmox 5.2 getestet ohne das VM's auf dem Host laufen.
Nach ca 50% bleibt der Output stehen und der Knoten bekommt die grauen Fragezeichen.
Die Netapp ist noch anpingbar! Zugriff auf die Mounts sind allerdings nicht mehr möglich.
pvecm status zeigt in diesem Zustand keine Fehler an.
Das Storage ist über ein Bond mit 2x10GB angebunden.
Cluster Kommunikation laufen über ein weiteres separates Bond.
VM Traffic über ein weiteres.
Was kann ich hier noch weiter testen?

Peter
Click to expand...
Hi Peter,
das heisst ein Verschieben von share1 -> local und local -> share2 geht?
Geht's auch gleichzeitig?

Anpingbar sagt nicht allzu viel...

Wenn's bei 50% abbricht - wie gross ist das VM-Image und wie gross der Ram des Servers (insgesamt und frei)? Wie gross ist der Cache der Netapp?
Was für eine Übertragungsrate hast Du bis es abbricht?
Ist der Effekt der gleiche, wenn du ein Interface vom Bond deaktivierst?

Udo
 
Hallo,

Gestern kam ich wieder zum Testen.
Leider ohne wirklichen Erfolg.
Ich teste auf dieser Hardware:
BL460c gen9 128GB RAM
Storage NetApp via NFS. Cache 512 GB.

Systeme neu aufgesetzt.
Gleiches Problem. Beim verschieben einer HD kommt es zu einem hängenden Task der den ganzen Server lahm legt.
Das passiert mal bei 4% dann geht es auch mehrere Male, dann hängt er bei 80%.
Kein System erkennbar. Auf Storageseite nichts erkennbar. Auf dem Host sieht man auch nicht viel. Im Kernellog nichts bis zu dem Hängenden Task.
Ich hatte die Vermutung das es eventuell an den Bond liegt, aber auch ohne Bond hängt es.

Sehr seltsam ist das ich die Images auf der Konsole verschieben kann in alle Richtungen. NFS->NFS, NFS->local, local->NFS.
Dabei gibt es keinerlei Hänger.
Ich installiere jetzt noch einmal die Version 4.4 und teste damit.

hang.png journal.png

Peter
 
Last edited:
Hallo,

Neue Stand!
Mit dem Repository "pvetest" tritt das Problem nicht auf!
Auch nicht auf einer frischen Installation vom iso.
So wie es aussieht nur mit dem Enterprise Repository.
Ich habe jetzt mit "pvetest" gefühlt 50 Mal HD's verschoben-> Kein Problem.

Peter
 
Hallo Udo,

Ich bekomme das Testsystem nicht von pvetest auf entrerprise da jetzt der Key ungültig geworden ist.
Haben die Lizenzen über einen Proxmoxpartner bezogen. Der muss diese erst einmal zurücksetzen.

Peter
 
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