Kernel OOPS bei Move Disk

Discussion in 'Proxmox VE (Deutsch)' started by pixelpeter, May 15, 2018.

  1. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
  2. fabian

    fabian Proxmox Staff Member
    Staff Member

    Joined:
    Jan 7, 2016
    Messages:
    3,045
    Likes Received:
    459
    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!)
     
  3. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
  4. fabian

    fabian Proxmox Staff Member
    Staff Member

    Joined:
    Jan 7, 2016
    Messages:
    3,045
    Likes Received:
    459
    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?
     
  5. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
  6. fabian

    fabian Proxmox Staff Member
    Staff Member

    Joined:
    Jan 7, 2016
    Messages:
    3,045
    Likes Received:
    459
    möglichst viel auf beiden seiten monitoren und nach auffälligkeiten suchen bleibt im moment vermutlich als einziger nächster schritt...
     
  7. udo

    udo Well-Known Member
    Proxmox VE Subscriber

    Joined:
    Apr 22, 2009
    Messages:
    5,605
    Likes Received:
    136
    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
     
  8. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
    #8 pixelpeter, Jul 12, 2018
    Last edited: Jul 16, 2018 at 09:09
  9. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    Hallo,

    Habe es fast schon erwartet. Version 4.4 läuft ohne Probleme. Zig Mal verschoben.
    Bin ich wirklich der einzige mit dem Problem?

    Peter
     
  10. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
  11. udo

    udo Well-Known Member
    Proxmox VE Subscriber

    Joined:
    Apr 22, 2009
    Messages:
    5,605
    Likes Received:
    136
    Hi,
    es gibt gerade frisch ein neuen Kernel im Enterprise-repo - kannst ja mal den testen. Würd' mich interessieren.

    Udo
     
  12. pixelpeter

    pixelpeter Member
    Proxmox VE Subscriber

    Joined:
    Aug 5, 2015
    Messages:
    83
    Likes Received:
    0
    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
     
  1. This site uses cookies to help personalise content, tailor your experience and to keep you logged in if you register.
    By continuing to use this site, you are consenting to our use of cookies.
    Dismiss Notice