openzfs / spl

A shim layer which adds the core interfaces required for OpenZFS.
https://zfsonlinux.org/
GNU General Public License v2.0
282 stars 181 forks source link

Kernel hang spl_kmem_cache/:308 on Ubuntu 13.10 kernel 3.11.0-12-generic #305

Closed mattaw closed 8 years ago

mattaw commented 10 years ago

I have had two hardlocks with my Ubuntu system running the zfsonlinux 0.6.2 PPA.

The stack trace of the one that was captured in the log was:

Nov  2 19:34:58 mythmaster kernel: [172234.071910] WARNING: CPU: 0 PID: 308 at /build/buildd/linux-3.11.0/mm/vmalloc.c:126 vmap_page_range_noflush+0x2d1/0x370()
Nov  2 19:34:58 mythmaster kernel: [172234.071915] Modules linked in: nls_utf8 udf(F) usb_storage(F) ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi ir_lirc_codec ir_mce_kbd_decoder ir_jvc_decoder ir_rc5_decoder ir_nec_decoder lirc_dev ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder rc_rc6_mce hp_wmi sparse_keymap snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) snd_page_alloc(F) joydev(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) snd(F) soundcore(F) microcode(F) psmouse(F) nv_tco drm amd64_edac_mod shpchp k10temp edac_core i2c_nforce2 ohci_pci serio_raw(F) wmi edac_mce_amd mac_hid 
Nov  2 19:34:58 mythmaster kernel: bonding(F) lp(F) parport(F) zfs(POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid tg3 bnx2 firewire_ohci mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_core ptp(F) pps_core(F) pata_acpi crc_itu_t(F) forcedeth sata_nv pata_amd
Nov  2 19:34:58 mythmaster kernel: [172234.072091] CPU: 0 PID: 308 Comm: spl_kmem_cache/ Tainted: PF          O 3.11.0-12-generic #19-Ubuntu
Nov  2 19:34:58 mythmaster kernel: [172234.072096] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov  2 19:34:58 mythmaster kernel: [172234.072102]  0000000000000009 ffff8804050e9b88 ffffffff816e547a 0000000000000000
Nov  2 19:34:58 mythmaster kernel: [172234.072113]  ffff8804050e9bc0 ffffffff81061dbd ffff88033e019b20 0000000000000001
Nov  2 19:34:58 mythmaster kernel: [172234.072121]  ffff88034e507440 ffffc90077764000 0000000000000000 ffff8804050e9bd0
Nov  2 19:34:58 mythmaster kernel: [172234.072129] Call Trace:
Nov  2 19:34:58 mythmaster kernel: [172234.072145]  [<ffffffff816e547a>] dump_stack+0x45/0x56
Nov  2 19:34:58 mythmaster kernel: [172234.072156]  [<ffffffff81061dbd>] warn_slowpath_common+0x7d/0xa0
Nov  2 19:34:58 mythmaster kernel: [172234.072165]  [<ffffffff81061e9a>] warn_slowpath_null+0x1a/0x20
Nov  2 19:34:58 mythmaster kernel: [172234.072172]  [<ffffffff81174291>] vmap_page_range_noflush+0x2d1/0x370
Nov  2 19:34:58 mythmaster kernel: [172234.072180]  [<ffffffff8117435e>] map_vm_area+0x2e/0x40
Nov  2 19:34:58 mythmaster kernel: [172234.072187]  [<ffffffff811766b0>] __vmalloc_node_range+0x170/0x250
Nov  2 19:34:58 mythmaster kernel: [172234.072224]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072248]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072256]  [<ffffffff8117675f>] __vmalloc_node_range+0x21f/0x250
Nov  2 19:34:58 mythmaster kernel: [172234.072279]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072287]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov  2 19:34:58 mythmaster kernel: [172234.072309]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072331]  [<ffffffffa0165639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072355]  [<ffffffffa01657b0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072362]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov  2 19:34:58 mythmaster kernel: [172234.072372]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov  2 19:34:58 mythmaster kernel: [172234.072397]  [<ffffffffa016a6e7>] taskq_thread+0x237/0x4b0 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072406]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov  2 19:34:58 mythmaster kernel: [172234.072416]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov  2 19:34:58 mythmaster kernel: [172234.072439]  [<ffffffffa016a4b0>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov  2 19:34:58 mythmaster kernel: [172234.072450]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov  2 19:34:58 mythmaster kernel: [172234.072459]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov  2 19:34:58 mythmaster kernel: [172234.072468]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov  2 19:34:58 mythmaster kernel: [172234.072476]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov  2 19:34:58 mythmaster kernel: [172234.072481] ---[ end trace 5caf3addc5507e38 ]---
Nov  2 19:35:25 mythmaster kernel: [172261.665607] BUG: soft lockup - CPU#0 stuck for 23s! [spl_kmem_cache/:308]
Nov  2 19:35:25 mythmaster kernel: [172261.665617] Modules linked in: nls_utf8 udf(F) usb_storage(F) ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi ir_lirc_codec ir_mce_kbd_decoder ir_jvc_decoder ir_rc5_decoder ir_nec_decoder lirc_dev ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder rc_rc6_mce hp_wmi sparse_keymap snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) snd_page_alloc(F) joydev(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) snd(F) soundcore(F) microcode(F) psmouse(F) nv_tco drm amd64_edac_mod shpchp k10temp edac_core i2c_nforce2 ohci_pci serio_raw(F) wmi edac_mce_amd mac_hid 
Nov  2 19:35:25 mythmaster kernel: bonding(F) lp(F) parport(F) zfs(POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid tg3 bnx2 firewire_ohci mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_core ptp(F) pps_core(F) pata_acpi crc_itu_t(F) forcedeth sata_nv pata_amd
Nov  2 19:35:25 mythmaster kernel: [172261.665786] CPU: 0 PID: 308 Comm: spl_kmem_cache/ Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov  2 19:35:25 mythmaster kernel: [172261.665792] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov  2 19:35:25 mythmaster kernel: [172261.665798] task: ffff880405ba5dc0 ti: ffff8804050e8000 task.ti: ffff8804050e8000
Nov  2 19:35:25 mythmaster kernel: [172261.665803] RIP: 0010:[<ffffffff81173872>]  [<ffffffff81173872>] find_vmap_area+0x32/0x70
Nov  2 19:35:25 mythmaster kernel: [172261.665817] RSP: 0018:ffff8804050e9c18  EFLAGS: 00000282
Nov  2 19:35:25 mythmaster kernel: [172261.665822] RAX: ffff8803faa9ba98 RBX: ffffffff81061dcf RCX: 00000000000016db
Nov  2 19:35:25 mythmaster kernel: [172261.665826] RDX: 00000000000016db RSI: 0000000000000001 RDI: ffffffff81f93578
Nov  2 19:35:25 mythmaster kernel: [172261.665831] RBP: ffff8804050e9c20 R08: 0000000000003000 R09: 0000000000001d90
Nov  2 19:35:25 mythmaster kernel: [172261.665835] R10: 0000000000000000 R11: ffff8804050e98ae R12: 0000000000000000
Nov  2 19:35:25 mythmaster kernel: [172261.665839] R13: ffff8804050e9b88 R14: 0000000000001d8f R15: 000000000000000a
Nov  2 19:35:25 mythmaster kernel: [172261.665846] FS:  00007f71dc0d3740(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
Nov  2 19:35:25 mythmaster kernel: [172261.665850] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov  2 19:35:25 mythmaster kernel: [172261.665855] CR2: 00007f9704916000 CR3: 00000003a1430000 CR4: 00000000000007f0
Nov  2 19:35:25 mythmaster kernel: [172261.665859] Stack:
Nov  2 19:35:25 mythmaster kernel: [172261.665862]  ffffc90077764000 ffff8804050e9c40 ffffffff81176131 ffffc90077764000
Nov  2 19:35:25 mythmaster kernel: [172261.665873]  0000000000000000 ffff8804050e9c68 ffffffff811761ca 00000000ffffffff
Nov  2 19:35:25 mythmaster kernel: [172261.665881]  0000000000000000 0000000000009232 ffff8804050e9c80 ffffffff81176316
Nov  2 19:35:25 mythmaster kernel: [172261.665889] Call Trace:
Nov  2 19:35:25 mythmaster kernel: [172261.665901]  [<ffffffff81176131>] remove_vm_area+0x11/0x80
Nov  2 19:35:25 mythmaster kernel: [172261.665908]  [<ffffffff811761ca>] __vunmap+0x2a/0x100
Nov  2 19:35:25 mythmaster kernel: [172261.665915]  [<ffffffff81176316>] vfree+0x36/0x80
Nov  2 19:35:25 mythmaster kernel: [172261.665923]  [<ffffffff811766f9>] __vmalloc_node_range+0x1b9/0x250
Nov  2 19:35:25 mythmaster kernel: [172261.665959]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.665982]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.665990]  [<ffffffff8117675f>] __vmalloc_node_range+0x21f/0x250
Nov  2 19:35:25 mythmaster kernel: [172261.666013]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666021]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov  2 19:35:25 mythmaster kernel: [172261.666043]  [<ffffffffa0165639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666065]  [<ffffffffa0165639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666088]  [<ffffffffa01657b0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666096]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov  2 19:35:25 mythmaster kernel: [172261.666106]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov  2 19:35:25 mythmaster kernel: [172261.666131]  [<ffffffffa016a6e7>] taskq_thread+0x237/0x4b0 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666141]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov  2 19:35:25 mythmaster kernel: [172261.666150]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov  2 19:35:25 mythmaster kernel: [172261.666174]  [<ffffffffa016a4b0>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov  2 19:35:25 mythmaster kernel: [172261.666184]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov  2 19:35:25 mythmaster kernel: [172261.666193]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov  2 19:35:25 mythmaster kernel: [172261.666201]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov  2 19:35:25 mythmaster kernel: [172261.666210]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov  2 19:35:25 mythmaster kernel: [172261.666214] Code: 89 e5 53 48 89 fb 48 c7 c7 78 35 f9 81 e8 17 8d 57 00 48 8b 05 10 fd e1 00 48 85 c0 74 0f 48 3b 58 e8 73 25 48 8b 40 10 48 85 c0 <75> f1 31 db 48 c7 c7 78 35 f9 81 e8 0e a6 ed ff 66 90 48 89 d8 
mattaw commented 10 years ago

I updated to git master for both zfs and spl. It identified the kernel as having the new shrinker in it and activated the new code which is probably the cause of the issues I was seeing. So far performing flawlessly, great work guys. NB performance has also improved about 10MB/s with two mirrored vdevs made from two 2gb Western Digital Greens (i.e. 4x 2TB).

Matthew

behlendorf commented 10 years ago

Excellent, then I'm going to close this one out.

mattaw commented 10 years ago

Bad news I spoke too soon. I don't think this is solved with the new SPL shrinker code. Hardlocks still occurring (clearly it is based on what I am doing). I have a failing disk generating errors but that shouldn't take down the computer?

root@mythmaster:/var/log# zpool status 
  pool: tank
 state: ONLINE
status: One or more devices has experienced an unrecoverable error.  An
    attempt was made to correct the error.  Applications are unaffected.
action: Determine if the device needs to be replaced, and clear the errors
    using 'zpool clear' or replace the device with 'zpool replace'.
   see: http://zfsonlinux.org/msg/ZFS-8000-9P
  scan: scrub repaired 11.1M in 2h51m with 0 errors on Sat Nov 16 23:57:25 2013
config:

    NAME                                          STATE     READ WRITE CKSUM
    tank                                          ONLINE       0     0     0
      mirror-0                                    ONLINE       0     0     0
        ata-WDC_WD20EARS-00MVWB0_WD-WCAZA2585130  ONLINE       0     0     0
        scsi-350014ee25aa3f34f                    ONLINE       0     0     0
      mirror-1                                    ONLINE       0     0     0
        ata-WDC_WD20EARS-00MVWB0_WD-WCAZA2585499  ONLINE       0     0 1.26K
        scsi-350014ee2aff99e83                    ONLINE       0     0     0
    logs
      ata-GIGABYTE_i-RAM_E79C3EC206634BC14E15     ONLINE       0     0     0

errors: No known data errors

Kernel: Linux mythmaster 3.11.0-12-generic #19-Ubuntu SMP Wed Oct 9 16:20:46 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

OS: DISTRIB_ID=Ubuntu DISTRIB_RELEASE=13.10 DISTRIB_CODENAME=saucy DISTRIB_DESCRIPTION="Ubuntu 13.10"

Last entries from kern.log

Nov 16 20:55:39 mythmaster kernel: [865462.232667] ------------[ cut here ]------------
Nov 16 20:55:39 mythmaster kernel: [865462.232693] WARNING: CPU: 0 PID: 278 at /build/buildd/linux-3.11.0/mm/vmalloc.c:126 vmap_page_range_noflush+0x2d1/0x370()
Nov 16 20:55:39 mythmaster kernel: [865462.232698] Modules linked in: ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi hp_wmi sparse_keymap ir_lirc_codec ir_jvc_decoder lirc_dev ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) joydev(F) microcode(F) snd_page_alloc(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) i2c_nforce2 psmouse(F) snd(F) serio_raw(F) drm soundcore(F) shpchp ohci_pci wmi nv_tco k10temp amd64_edac_mod edac_mce_amd edac_core mac_hid bonding(F) lp(F) parport(F) zfs
Nov 16 20:55:39 mythmaster kernel: (POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid bnx2 mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_ohci tg3 firewire_core pata_acpi crc_itu_t(F) ptp(F) forcedeth pps_core(F) sata_nv pata_amd
Nov 16 20:55:39 mythmaster kernel: [865462.232872] CPU: 0 PID: 278 Comm: spl_kmem_cache/ Tainted: PF          O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:55:39 mythmaster kernel: [865462.232878] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:55:39 mythmaster kernel: [865462.232883]  0000000000000009 ffff880405097bf8 ffffffff816e547a 0000000000000000
Nov 16 20:55:39 mythmaster kernel: [865462.232895]  ffff880405097c30 ffffffff81061dbd ffff880304c940e8 0000000000000001
Nov 16 20:55:39 mythmaster kernel: [865462.232903]  ffff88015566a000 ffffc900d1c1d000 0000000000000000 ffff880405097c40
Nov 16 20:55:39 mythmaster kernel: [865462.232911] Call Trace:
Nov 16 20:55:39 mythmaster kernel: [865462.232926]  [<ffffffff816e547a>] dump_stack+0x45/0x56
Nov 16 20:55:39 mythmaster kernel: [865462.232938]  [<ffffffff81061dbd>] warn_slowpath_common+0x7d/0xa0
Nov 16 20:55:39 mythmaster kernel: [865462.232946]  [<ffffffff81061e9a>] warn_slowpath_null+0x1a/0x20
Nov 16 20:55:39 mythmaster kernel: [865462.232954]  [<ffffffff81174291>] vmap_page_range_noflush+0x2d1/0x370
Nov 16 20:55:39 mythmaster kernel: [865462.232961]  [<ffffffff8117435e>] map_vm_area+0x2e/0x40
Nov 16 20:55:39 mythmaster kernel: [865462.232969]  [<ffffffff811766b0>] __vmalloc_node_range+0x170/0x250
Nov 16 20:55:39 mythmaster kernel: [865462.233007]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233015]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov 16 20:55:39 mythmaster kernel: [865462.233039]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233062]  [<ffffffffa0161639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233085]  [<ffffffffa01628d0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233092]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov 16 20:55:39 mythmaster kernel: [865462.233103]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov 16 20:55:39 mythmaster kernel: [865462.233128]  [<ffffffffa01666c7>] taskq_thread+0x237/0x4b0 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233137]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov 16 20:55:39 mythmaster kernel: [865462.233147]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov 16 20:55:39 mythmaster kernel: [865462.233171]  [<ffffffffa0166490>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov 16 20:55:39 mythmaster kernel: [865462.233181]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov 16 20:55:39 mythmaster kernel: [865462.233190]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:55:39 mythmaster kernel: [865462.233199]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov 16 20:55:39 mythmaster kernel: [865462.233207]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:55:39 mythmaster kernel: [865462.233213] ---[ end trace d2ec9634466462df ]---
Nov 16 20:56:03 mythmaster kernel: [865486.251189] BUG: soft lockup - CPU#0 stuck for 22s! [spl_kmem_cache/:278]
Nov 16 20:56:03 mythmaster kernel: [865486.251206] Modules linked in: ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi hp_wmi sparse_keymap ir_lirc_codec ir_jvc_decoder lirc_dev ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) joydev(F) microcode(F) snd_page_alloc(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) i2c_nforce2 psmouse(F) snd(F) serio_raw(F) drm soundcore(F) shpchp ohci_pci wmi nv_tco k10temp amd64_edac_mod edac_mce_amd edac_core mac_hid bonding(F) lp(F) parport(F) zfs
Nov 16 20:56:03 mythmaster kernel: (POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid bnx2 mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_ohci tg3 firewire_core pata_acpi crc_itu_t(F) ptp(F) forcedeth pps_core(F) sata_nv pata_amd
Nov 16 20:56:03 mythmaster kernel: [865486.251377] CPU: 0 PID: 278 Comm: spl_kmem_cache/ Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:03 mythmaster kernel: [865486.251383] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:03 mythmaster kernel: [865486.251390] task: ffff8804044a0000 ti: ffff880405096000 task.ti: ffff880405096000
Nov 16 20:56:03 mythmaster kernel: [865486.251395] RIP: 0010:[<ffffffff81173869>]  [<ffffffff81173869>] find_vmap_area+0x29/0x70
Nov 16 20:56:03 mythmaster kernel: [865486.251410] RSP: 0018:ffff880405097c88  EFLAGS: 00000287
Nov 16 20:56:03 mythmaster kernel: [865486.251415] RAX: ffff880409361498 RBX: ffffffff81061dcf RCX: 0000000000008a15
Nov 16 20:56:03 mythmaster kernel: [865486.251420] RDX: 0000000000008a15 RSI: 0000000000000001 RDI: ffffffff81f93578
Nov 16 20:56:03 mythmaster kernel: [865486.251424] RBP: ffff880405097c90 R08: 0000000000041000 R09: 0000000000002870
Nov 16 20:56:03 mythmaster kernel: [865486.251429] R10: 0000000000000000 R11: ffff88040509791e R12: 0000000000000000
Nov 16 20:56:03 mythmaster kernel: [865486.251433] R13: ffff880405097bf8 R14: 000000000000286f R15: 000000000000000a
Nov 16 20:56:03 mythmaster kernel: [865486.251439] FS:  00007f3568921700(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
Nov 16 20:56:03 mythmaster kernel: [865486.251443] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:03 mythmaster kernel: [865486.251448] CR2: 00007f35c4fae000 CR3: 0000000001c0e000 CR4: 00000000000007f0
Nov 16 20:56:03 mythmaster kernel: [865486.251452] Stack:
Nov 16 20:56:03 mythmaster kernel: [865486.251456]  ffffc900d1c1d000 ffff880405097cb0 ffffffff81176131 ffffc900d1c1d000
Nov 16 20:56:03 mythmaster kernel: [865486.251466]  0000000000000000 ffff880405097cd8 ffffffff811761ca 00000000ffffffff
Nov 16 20:56:03 mythmaster kernel: [865486.251475]  0000000000000000 0000000000001232 ffff880405097cf0 ffffffff81176316
Nov 16 20:56:03 mythmaster kernel: [865486.251483] Call Trace:
Nov 16 20:56:03 mythmaster kernel: [865486.251495]  [<ffffffff81176131>] remove_vm_area+0x11/0x80
Nov 16 20:56:03 mythmaster kernel: [865486.251503]  [<ffffffff811761ca>] __vunmap+0x2a/0x100
Nov 16 20:56:03 mythmaster kernel: [865486.251510]  [<ffffffff81176316>] vfree+0x36/0x80
Nov 16 20:56:03 mythmaster kernel: [865486.251518]  [<ffffffff811766f9>] __vmalloc_node_range+0x1b9/0x250
Nov 16 20:56:03 mythmaster kernel: [865486.251559]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251567]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov 16 20:56:03 mythmaster kernel: [865486.251591]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251613]  [<ffffffffa0161639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251636]  [<ffffffffa01628d0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251646]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov 16 20:56:03 mythmaster kernel: [865486.251656]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov 16 20:56:03 mythmaster kernel: [865486.251682]  [<ffffffffa01666c7>] taskq_thread+0x237/0x4b0 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251691]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov 16 20:56:03 mythmaster kernel: [865486.251701]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov 16 20:56:03 mythmaster kernel: [865486.251725]  [<ffffffffa0166490>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov 16 20:56:03 mythmaster kernel: [865486.251735]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov 16 20:56:03 mythmaster kernel: [865486.251744]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:03 mythmaster kernel: [865486.251753]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov 16 20:56:03 mythmaster kernel: [865486.251762]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:03 mythmaster kernel: [865486.251766] Code: 00 00 66 66 66 66 90 55 48 89 e5 53 48 89 fb 48 c7 c7 78 35 f9 81 e8 17 8d 57 00 48 8b 05 10 fd e1 00 48 85 c0 74 0f 48 3b 58 e8 <73> 25 48 8b 40 10 48 85 c0 75 f1 31 db 48 c7 c7 78 35 f9 81 e8 
Nov 16 20:56:31 mythmaster kernel: [865514.242968] BUG: soft lockup - CPU#0 stuck for 22s! [spl_kmem_cache/:278]
Nov 16 20:56:31 mythmaster kernel: [865514.242975] Modules linked in: ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi hp_wmi sparse_keymap ir_lirc_codec ir_jvc_decoder lirc_dev ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) joydev(F) microcode(F) snd_page_alloc(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) i2c_nforce2 psmouse(F) snd(F) serio_raw(F) drm soundcore(F) shpchp ohci_pci wmi nv_tco k10temp amd64_edac_mod edac_mce_amd edac_core mac_hid bonding(F) lp(F) parport(F) zfs
Nov 16 20:56:31 mythmaster kernel: (POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid bnx2 mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_ohci tg3 firewire_core pata_acpi crc_itu_t(F) ptp(F) forcedeth pps_core(F) sata_nv pata_amd
Nov 16 20:56:31 mythmaster kernel: [865514.243141] CPU: 0 PID: 278 Comm: spl_kmem_cache/ Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:31 mythmaster kernel: [865514.243146] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:31 mythmaster kernel: [865514.243152] task: ffff8804044a0000 ti: ffff880405096000 task.ti: ffff880405096000
Nov 16 20:56:31 mythmaster kernel: [865514.243156] RIP: 0010:[<ffffffff81173869>]  [<ffffffff81173869>] find_vmap_area+0x29/0x70
Nov 16 20:56:31 mythmaster kernel: [865514.243168] RSP: 0018:ffff880405097c88  EFLAGS: 00000287
Nov 16 20:56:31 mythmaster kernel: [865514.243172] RAX: ffff880409361498 RBX: ffffffff81061dcf RCX: 0000000000008a15
Nov 16 20:56:31 mythmaster kernel: [865514.243177] RDX: 0000000000008a15 RSI: 0000000000000001 RDI: ffffffff81f93578
Nov 16 20:56:31 mythmaster kernel: [865514.243182] RBP: ffff880405097c90 R08: 0000000000041000 R09: 0000000000002870
Nov 16 20:56:31 mythmaster kernel: [865514.243187] R10: 0000000000000000 R11: ffff88040509791e R12: 0000000000000000
Nov 16 20:56:31 mythmaster kernel: [865514.243191] R13: ffff880405097bf8 R14: 000000000000286f R15: 000000000000000a
Nov 16 20:56:31 mythmaster kernel: [865514.243197] FS:  00007f3568921700(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
Nov 16 20:56:31 mythmaster kernel: [865514.243202] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:31 mythmaster kernel: [865514.243207] CR2: 00007f35c4fae000 CR3: 0000000001c0e000 CR4: 00000000000007f0
Nov 16 20:56:31 mythmaster kernel: [865514.243210] Stack:
Nov 16 20:56:31 mythmaster kernel: [865514.243213]  ffffc900d1c1d000 ffff880405097cb0 ffffffff81176131 ffffc900d1c1d000
Nov 16 20:56:31 mythmaster kernel: [865514.243224]  0000000000000000 ffff880405097cd8 ffffffff811761ca 00000000ffffffff
Nov 16 20:56:31 mythmaster kernel: [865514.243232]  0000000000000000 0000000000001232 ffff880405097cf0 ffffffff81176316
Nov 16 20:56:31 mythmaster kernel: [865514.243241] Call Trace:
Nov 16 20:56:31 mythmaster kernel: [865514.243251]  [<ffffffff81176131>] remove_vm_area+0x11/0x80
Nov 16 20:56:31 mythmaster kernel: [865514.243259]  [<ffffffff811761ca>] __vunmap+0x2a/0x100
Nov 16 20:56:31 mythmaster kernel: [865514.243267]  [<ffffffff81176316>] vfree+0x36/0x80
Nov 16 20:56:31 mythmaster kernel: [865514.243275]  [<ffffffff811766f9>] __vmalloc_node_range+0x1b9/0x250
Nov 16 20:56:31 mythmaster kernel: [865514.243307]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243315]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov 16 20:56:31 mythmaster kernel: [865514.243338]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243360]  [<ffffffffa0161639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243383]  [<ffffffffa01628d0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243391]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov 16 20:56:31 mythmaster kernel: [865514.243401]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov 16 20:56:31 mythmaster kernel: [865514.243425]  [<ffffffffa01666c7>] taskq_thread+0x237/0x4b0 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243434]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov 16 20:56:31 mythmaster kernel: [865514.243443]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov 16 20:56:31 mythmaster kernel: [865514.243467]  [<ffffffffa0166490>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov 16 20:56:31 mythmaster kernel: [865514.243477]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov 16 20:56:31 mythmaster kernel: [865514.243486]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:31 mythmaster kernel: [865514.243495]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov 16 20:56:31 mythmaster kernel: [865514.243503]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:31 mythmaster kernel: [865514.243507] Code: 00 00 66 66 66 66 90 55 48 89 e5 53 48 89 fb 48 c7 c7 78 35 f9 81 e8 17 8d 57 00 48 8b 05 10 fd e1 00 48 85 c0 74 0f 48 3b 58 e8 <73> 25 48 8b 40 10 48 85 c0 75 f1 31 db 48 c7 c7 78 35 f9 81 e8 
Nov 16 20:56:39 mythmaster kernel: [865522.280607] INFO: rcu_sched self-detected stall on CPU { 0}  (t=15000 jiffies g=4888623 c=4888622 q=0)
Nov 16 20:56:39 mythmaster kernel: [865522.280621] sending NMI to all CPUs:
Nov 16 20:56:39 mythmaster kernel: [865522.280631] NMI backtrace for cpu 0
Nov 16 20:56:39 mythmaster kernel: [865522.280639] CPU: 0 PID: 278 Comm: spl_kmem_cache/ Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.280643] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.280648] task: ffff8804044a0000 ti: ffff880405096000 task.ti: ffff880405096000
Nov 16 20:56:39 mythmaster kernel: [865522.280652] RIP: 0010:[<ffffffff810426e1>]  [<ffffffff810426e1>] default_send_IPI_mask_sequence_phys+0xe1/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.280665] RSP: 0018:ffff88041fc03da0  EFLAGS: 00000046
Nov 16 20:56:39 mythmaster kernel: [865522.280669] RAX: ffffffff81c26620 RBX: 000000000000b06a RCX: 0000000000000002
Nov 16 20:56:39 mythmaster kernel: [865522.280674] RDX: 0000000000000002 RSI: 0000000000000001 RDI: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.280678] RBP: ffff88041fc03dd8 R08: ffffffff81d04880 R09: 00000000000028c4
Nov 16 20:56:39 mythmaster kernel: [865522.280682] R10: 0000000000000000 R11: ffff88041fc03b1e R12: ffffffff81d04880
Nov 16 20:56:39 mythmaster kernel: [865522.280687] R13: 0000000000000400 R14: 0000000000000086 R15: 0000000000000002
Nov 16 20:56:39 mythmaster kernel: [865522.280693] FS:  00007f3568921700(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.280697] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.280702] CR2: 00007f35c4fae000 CR3: 0000000001c0e000 CR4: 00000000000007f0
Nov 16 20:56:39 mythmaster kernel: [865522.280705] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.280708]  0000000100000008 0000000000000001 0000000000002710 ffffffff81c53940
Nov 16 20:56:39 mythmaster kernel: [865522.280718]  ffffffff81c53940 ffff88041fc0ed40 0000000000000000 ffff88041fc03de8
Nov 16 20:56:39 mythmaster kernel: [865522.280726]  ffffffff81046db7 ffff88041fc03e00 ffffffff81042877 ffffffff81d048a0
Nov 16 20:56:39 mythmaster kernel: [865522.280735] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.280738]  <IRQ> 
Nov 16 20:56:39 mythmaster kernel: [865522.280742]  [<ffffffff81046db7>] physflat_send_IPI_all+0x17/0x20
Nov 16 20:56:39 mythmaster kernel: [865522.280759]  [<ffffffff81042877>] arch_trigger_all_cpu_backtrace+0x57/0x90
Nov 16 20:56:39 mythmaster kernel: [865522.280770]  [<ffffffff8110051d>] rcu_check_callbacks+0x30d/0x5f0
Nov 16 20:56:39 mythmaster kernel: [865522.280780]  [<ffffffff810706a7>] update_process_times+0x47/0x80
Nov 16 20:56:39 mythmaster kernel: [865522.280789]  [<ffffffff810bfd85>] tick_sched_handle.isra.14+0x25/0x60
Nov 16 20:56:39 mythmaster kernel: [865522.280797]  [<ffffffff810c03e1>] tick_sched_timer+0x41/0x60
Nov 16 20:56:39 mythmaster kernel: [865522.280805]  [<ffffffff81087ee9>] __run_hrtimer+0x79/0x1d0
Nov 16 20:56:39 mythmaster kernel: [865522.280813]  [<ffffffff810c03a0>] ? tick_sched_do_timer+0x40/0x40
Nov 16 20:56:39 mythmaster kernel: [865522.280821]  [<ffffffff810886f7>] hrtimer_interrupt+0xf7/0x240
Nov 16 20:56:39 mythmaster kernel: [865522.280830]  [<ffffffff81040ca7>] local_apic_timer_interrupt+0x37/0x60
Nov 16 20:56:39 mythmaster kernel: [865522.280839]  [<ffffffff816f75bf>] smp_apic_timer_interrupt+0x3f/0x60
Nov 16 20:56:39 mythmaster kernel: [865522.280847]  [<ffffffff816f5f5d>] apic_timer_interrupt+0x6d/0x80
Nov 16 20:56:39 mythmaster kernel: [865522.280850]  <EOI> 
Nov 16 20:56:39 mythmaster kernel: [865522.280853]  [<ffffffff81061dcf>] ? warn_slowpath_common+0x8f/0xa0
Nov 16 20:56:39 mythmaster kernel: [865522.280868]  [<ffffffff81173869>] ? find_vmap_area+0x29/0x70
Nov 16 20:56:39 mythmaster kernel: [865522.280875]  [<ffffffff81173859>] ? find_vmap_area+0x19/0x70
Nov 16 20:56:39 mythmaster kernel: [865522.280882]  [<ffffffff81176131>] remove_vm_area+0x11/0x80
Nov 16 20:56:39 mythmaster kernel: [865522.280889]  [<ffffffff811761ca>] __vunmap+0x2a/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.280897]  [<ffffffff81176316>] vfree+0x36/0x80
Nov 16 20:56:39 mythmaster kernel: [865522.280904]  [<ffffffff811766f9>] __vmalloc_node_range+0x1b9/0x250
Nov 16 20:56:39 mythmaster kernel: [865522.280931]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.280939]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov 16 20:56:39 mythmaster kernel: [865522.280962]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.280984]  [<ffffffffa0161639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.281006]  [<ffffffffa01628d0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.281013]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov 16 20:56:39 mythmaster kernel: [865522.281021]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.281045]  [<ffffffffa01666c7>] taskq_thread+0x237/0x4b0 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.281053]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov 16 20:56:39 mythmaster kernel: [865522.281062]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov 16 20:56:39 mythmaster kernel: [865522.281085]  [<ffffffffa0166490>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov 16 20:56:39 mythmaster kernel: [865522.281094]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov 16 20:56:39 mythmaster kernel: [865522.281103]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:39 mythmaster kernel: [865522.281110]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov 16 20:56:39 mythmaster kernel: [865522.281118]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:56:39 mythmaster kernel: [865522.281122] Code: 04 25 00 73 5f ff eb 8a 4c 89 f7 57 9d 66 66 90 66 90 48 83 c4 10 5b 41 5c 41 5d 41 5e 41 5f 5d c3 48 8b 05 0a 1e cc 00 89 75 cc <48> 89 55 d0 ff 90 50 01 00 00 48 8b 55 d0 8b 75 cc eb aa 66 66 
Nov 16 20:56:39 mythmaster kernel: [865522.281210] NMI backtrace for cpu 1
Nov 16 20:56:39 mythmaster kernel: [865522.281231] CPU: 1 PID: 0 Comm: swapper/1 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.281237] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.281244] task: ffff88040960aee0 ti: ffff880409614000 task.ti: ffff880409614000
Nov 16 20:56:39 mythmaster kernel: [865522.281249] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.281268] RSP: 0018:ffff880409615e88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.281273] RAX: 000000000200f92e RBX: ffff880409615ebc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281278] RDX: 000000000200f92e RSI: ffff880409615ebc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.281282] RBP: ffff880409615e88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281286] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000001
Nov 16 20:56:39 mythmaster kernel: [865522.281291] R13: ffff880409615fd8 R14: ffff880409615fd8 R15: ffff880409615fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281297] FS:  00007f35ae845700(0000) GS:ffff88041fc20000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281301] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.281306] CR2: 00007f35c4fae000 CR3: 00000003e8615000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.281310] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.281313]  ffff880409615ea8 ffffffff8101b22f ffff880409615ebc ffff880409615fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281324]  ffff880409615ec8 ffffffff8101b30f 0000000009615fd8 ffff880409615fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281333]  ffff880409615ed8 ffffffff8101baf6 ffff880409615f28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.281341] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.281356]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.281365]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.281373]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.281383]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.281392]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.281402]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.281406] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.281478] NMI backtrace for cpu 3
Nov 16 20:56:39 mythmaster kernel: [865522.281497] CPU: 3 PID: 0 Comm: swapper/3 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.281503] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.281510] task: ffff88040960ddc0 ti: ffff880409618000 task.ti: ffff880409618000
Nov 16 20:56:39 mythmaster kernel: [865522.281516] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.281534] RSP: 0018:ffff880409619e88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.281540] RAX: 000000000200f92e RBX: ffff880409619ebc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281545] RDX: 000000000200f92e RSI: ffff880409619ebc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.281549] RBP: ffff880409619e88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281553] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000003
Nov 16 20:56:39 mythmaster kernel: [865522.281557] R13: ffff880409619fd8 R14: ffff880409619fd8 R15: ffff880409619fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281563] FS:  00007ffc6a952980(0000) GS:ffff88041fc60000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281567] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.281572] CR2: 00007f35c4fae000 CR3: 00000003ff57d000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.281576] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.281580]  ffff880409619ea8 ffffffff8101b22f ffff880409619ebc ffff880409619fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281590]  ffff880409619ec8 ffffffff8101b30f 0000000009619fd8 ffff880409619fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281599]  ffff880409619ed8 ffffffff8101baf6 ffff880409619f28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.281607] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.281622]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.281631]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.281639]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.281649]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.281659]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.281668]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.281672] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.281745] NMI backtrace for cpu 7
Nov 16 20:56:39 mythmaster kernel: [865522.281761] CPU: 7 PID: 0 Comm: swapper/7 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.281767] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.281774] task: ffff880409624650 ti: ffff880409630000 task.ti: ffff880409630000
Nov 16 20:56:39 mythmaster kernel: [865522.281780] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.281798] RSP: 0018:ffff880409631e88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.281803] RAX: 000000000200f92e RBX: ffff880409631ebc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281808] RDX: 000000000200f92e RSI: ffff880409631ebc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.281812] RBP: ffff880409631e88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281816] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000007
Nov 16 20:56:39 mythmaster kernel: [865522.281821] R13: ffff880409631fd8 R14: ffff880409631fd8 R15: ffff880409631fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281827] FS:  00007ffc6a952980(0000) GS:ffff88041fce0000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.281832] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.281836] CR2: 00007f7c757be000 CR3: 00000003ff57d000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.281841] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.281844]  ffff880409631ea8 ffffffff8101b22f ffff880409631ebc ffff880409631fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281855]  ffff880409631ec8 ffffffff8101b30f 0000000009631fd8 ffff880409631fd8
Nov 16 20:56:39 mythmaster kernel: [865522.281863]  ffff880409631ed8 ffffffff8101baf6 ffff880409631f28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.281872] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.281886]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.281895]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.281903]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.281913]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.281922]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.281931]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.281936] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.282008] NMI backtrace for cpu 2
Nov 16 20:56:39 mythmaster kernel: [865522.282030] CPU: 2 PID: 0 Comm: swapper/2 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.282051] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.282072] task: ffff88040960c650 ti: ffff880409616000 task.ti: ffff880409616000
Nov 16 20:56:39 mythmaster kernel: [865522.282093] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.282135] RSP: 0018:ffff880409617e88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.282155] RAX: 000000000200f92e RBX: ffff880409617ebc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282175] RDX: 000000000200f92e RSI: ffff880409617ebc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.282192] RBP: ffff880409617e88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282211] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000002
Nov 16 20:56:39 mythmaster kernel: [865522.282230] R13: ffff880409617fd8 R14: ffff880409617fd8 R15: ffff880409617fd8
Nov 16 20:56:39 mythmaster kernel: [865522.282249] FS:  00007f35b1875700(0000) GS:ffff88041fc40000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282268] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.282273] CR2: 00007fcbbbf47000 CR3: 00000003e8615000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.282278] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.282281]  ffff880409617ea8 ffffffff8101b22f ffff880409617ebc ffff880409617fd8
Nov 16 20:56:39 mythmaster kernel: [865522.282293]  ffff880409617ec8 ffffffff8101b30f 0000000009617fd8 ffff880409617fd8
Nov 16 20:56:39 mythmaster kernel: [865522.282302]  ffff880409617ed8 ffffffff8101baf6 ffff880409617f28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.282310] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.282325]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.282334]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.282342]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.282352]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.282361]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.282371]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.282375] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.282449] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1.225 msecs
Nov 16 20:56:39 mythmaster kernel: [865522.282454] NMI backtrace for cpu 5
Nov 16 20:56:39 mythmaster kernel: [865522.282464] CPU: 5 PID: 0 Comm: swapper/5 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.282471] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.282477] task: ffff880409621770 ti: ffff88040961c000 task.ti: ffff88040961c000
Nov 16 20:56:39 mythmaster kernel: [865522.282494] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.282500] RSP: 0018:ffff88040961de88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.282506] RAX: 000000000200f92e RBX: ffff88040961debc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282512] RDX: 000000000200f92e RSI: ffff88040961debc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.282523] RBP: ffff88040961de88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282528] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000005
Nov 16 20:56:39 mythmaster kernel: [865522.282534] R13: ffff88040961dfd8 R14: ffff88040961dfd8 R15: ffff88040961dfd8
Nov 16 20:56:39 mythmaster kernel: [865522.282541] FS:  00007f35c50047c0(0000) GS:ffff88041fca0000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282547] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.282552] CR2: 00007f0f82b73000 CR3: 00000003e8615000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.282557] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.282561]  ffff88040961dea8 ffffffff8101b22f ffff88040961debc ffff88040961dfd8
Nov 16 20:56:39 mythmaster kernel: [865522.282573]  ffff88040961dec8 ffffffff8101b30f 000000000961dfd8 ffff88040961dfd8
Nov 16 20:56:39 mythmaster kernel: [865522.282582]  ffff88040961ded8 ffffffff8101baf6 ffff88040961df28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.282591] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.282604]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.282614]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.282622]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.282630]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.282638]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.282647]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.282651] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.282873] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1.647 msecs
Nov 16 20:56:39 mythmaster kernel: [865522.282879] NMI backtrace for cpu 4
Nov 16 20:56:39 mythmaster kernel: [865522.282890] CPU: 4 PID: 0 Comm: swapper/4 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.282896] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.282903] task: ffff880409620000 ti: ffff88040961a000 task.ti: ffff88040961a000
Nov 16 20:56:39 mythmaster kernel: [865522.282926] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.282932] RSP: 0018:ffff88040961be88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.282938] RAX: 000000000200f92e RBX: ffff88040961bebc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282943] RDX: 000000000200f92e RSI: ffff88040961bebc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.282949] RBP: ffff88040961be88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282954] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000004
Nov 16 20:56:39 mythmaster kernel: [865522.282960] R13: ffff88040961bfd8 R14: ffff88040961bfd8 R15: ffff88040961bfd8
Nov 16 20:56:39 mythmaster kernel: [865522.282966] FS:  00007f35a0f89700(0000) GS:ffff88041fc80000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.282972] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.282977] CR2: 00007fba40017000 CR3: 00000003e8615000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.282982] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.282986]  ffff88040961bea8 ffffffff8101b22f ffff88040961bebc ffff88040961bfd8
Nov 16 20:56:39 mythmaster kernel: [865522.283002]  ffff88040961bec8 ffffffff8101b30f 000000000961bfd8 ffff88040961bfd8
Nov 16 20:56:39 mythmaster kernel: [865522.283011]  ffff88040961bed8 ffffffff8101baf6 ffff88040961bf28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.283020] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.283035]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.283044]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.283053]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.283061]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.283069]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.283078]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.283082] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.283304] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 2.080 msecs
Nov 16 20:56:39 mythmaster kernel: [865522.283309] NMI backtrace for cpu 6
Nov 16 20:56:39 mythmaster kernel: [865522.283319] CPU: 6 PID: 0 Comm: swapper/6 Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:56:39 mythmaster kernel: [865522.283325] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:56:39 mythmaster kernel: [865522.283332] task: ffff880409622ee0 ti: ffff88040961e000 task.ti: ffff88040961e000
Nov 16 20:56:39 mythmaster kernel: [865522.283350] RIP: 0010:[<ffffffff8104d386>]  [<ffffffff8104d386>] native_safe_halt+0x6/0x10
Nov 16 20:56:39 mythmaster kernel: [865522.283355] RSP: 0018:ffff88040961fe88  EFLAGS: 00000246
Nov 16 20:56:39 mythmaster kernel: [865522.283361] RAX: 000000000200f92e RBX: ffff88040961febc RCX: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.283366] RDX: 000000000200f92e RSI: ffff88040961febc RDI: 00000000c0010055
Nov 16 20:56:39 mythmaster kernel: [865522.283371] RBP: ffff88040961fe88 R08: 0000000000000000 R09: 0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.283376] R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000006
Nov 16 20:56:39 mythmaster kernel: [865522.283382] R13: ffff88040961ffd8 R14: ffff88040961ffd8 R15: ffff88040961ffd8
Nov 16 20:56:39 mythmaster kernel: [865522.283388] FS:  00007f3568921700(0000) GS:ffff88041fcc0000(0000) knlGS:0000000000000000
Nov 16 20:56:39 mythmaster kernel: [865522.283394] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:56:39 mythmaster kernel: [865522.283399] CR2: 00007fcbbbf47000 CR3: 00000003e8615000 CR4: 00000000000007e0
Nov 16 20:56:39 mythmaster kernel: [865522.283403] Stack:
Nov 16 20:56:39 mythmaster kernel: [865522.283407]  ffff88040961fea8 ffffffff8101b22f ffff88040961febc ffff88040961ffd8
Nov 16 20:56:39 mythmaster kernel: [865522.283421]  ffff88040961fec8 ffffffff8101b30f 000000000961ffd8 ffff88040961ffd8
Nov 16 20:56:39 mythmaster kernel: [865522.283430]  ffff88040961fed8 ffffffff8101baf6 ffff88040961ff28 ffffffff810b54ee
Nov 16 20:56:39 mythmaster kernel: [865522.283438] Call Trace:
Nov 16 20:56:39 mythmaster kernel: [865522.283454]  [<ffffffff8101b22f>] default_idle+0x1f/0xc0
Nov 16 20:56:39 mythmaster kernel: [865522.283463]  [<ffffffff8101b30f>] amd_e400_idle+0x3f/0x100
Nov 16 20:56:39 mythmaster kernel: [865522.283471]  [<ffffffff8101baf6>] arch_cpu_idle+0x26/0x30
Nov 16 20:56:39 mythmaster kernel: [865522.283480]  [<ffffffff810b54ee>] cpu_startup_entry+0xce/0x280
Nov 16 20:56:39 mythmaster kernel: [865522.283488]  [<ffffffff810bdd53>] ? clockevents_register_device+0xe3/0x150
Nov 16 20:56:39 mythmaster kernel: [865522.283496]  [<ffffffff8103eef7>] start_secondary+0x217/0x2c0
Nov 16 20:56:39 mythmaster kernel: [865522.283500] Code: 00 00 00 00 00 55 48 89 e5 fa 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb 5d c3 66 0f 1f 84 00 00 00 00 00 55 48 89 e5 fb f4 <5d> c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 f4 5d c3 66 0f 1f 84 
Nov 16 20:56:39 mythmaster kernel: [865522.283617] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 2.393 msecs
Nov 16 20:57:07 mythmaster kernel: [865550.232407] BUG: soft lockup - CPU#0 stuck for 22s! [spl_kmem_cache/:278]
Nov 16 20:57:07 mythmaster kernel: [865550.232413] Modules linked in: ib_srpt tcm_qla2xxx qla2xxx tcm_loop tcm_fc libfc scsi_transport_fc(F) scsi_tgt(F) iscsi_target_mod target_core_pscsi target_core_file target_core_iblock target_core_mod configfs(F) ib_iser rdma_cm(F) ib_addr(F) iw_cm(F) ib_cm(F) ib_sa(F) ib_mad(F) ib_core(F) iscsi_tcp(F) libiscsi_tcp(F) libiscsi(F) scsi_transport_iscsi(F) parport_pc(F) ppdev(F) bnep rfcomm bluetooth nvidia(POF) snd_hda_codec_hdmi hp_wmi sparse_keymap ir_lirc_codec ir_jvc_decoder lirc_dev ir_mce_kbd_decoder ir_sanyo_decoder ir_sony_decoder ir_rc6_decoder ir_rc5_decoder ir_nec_decoder rc_rc6_mce snd_hda_intel mceusb snd_hda_codec rc_core snd_hwdep(F) snd_pcm(F) joydev(F) microcode(F) snd_page_alloc(F) snd_seq_midi(F) snd_seq_midi_event(F) kvm_amd(F) snd_rawmidi(F) kvm(F) snd_seq(F) snd_seq_device(F) snd_timer(F) i2c_nforce2 psmouse(F) snd(F) serio_raw(F) drm soundcore(F) shpchp ohci_pci wmi nv_tco k10temp amd64_edac_mod edac_mce_amd edac_core mac_hid bonding(F) lp(F) parport(F) zfs
Nov 16 20:57:07 mythmaster kernel: (POF) zunicode(POF) zavl(POF) zcommon(POF) znvpair(POF) spl(OF) zlib_deflate(F) hid_generic usbhid hid bnx2 mptsas(F) mptscsih(F) mptbase(F) scsi_transport_sas(F) firewire_ohci tg3 firewire_core pata_acpi crc_itu_t(F) ptp(F) forcedeth pps_core(F) sata_nv pata_amd
Nov 16 20:57:07 mythmaster kernel: [865550.232576] CPU: 0 PID: 278 Comm: spl_kmem_cache/ Tainted: PF       W  O 3.11.0-12-generic #19-Ubuntu
Nov 16 20:57:07 mythmaster kernel: [865550.232581] Hardware name: Hewlett-Packard HP xw9400 Workstation/0A1Ch, BIOS 786D6 v04.03 12/10/2009
Nov 16 20:57:07 mythmaster kernel: [865550.232586] task: ffff8804044a0000 ti: ffff880405096000 task.ti: ffff880405096000
Nov 16 20:57:07 mythmaster kernel: [865550.232590] RIP: 0010:[<ffffffff81173869>]  [<ffffffff81173869>] find_vmap_area+0x29/0x70
Nov 16 20:57:07 mythmaster kernel: [865550.232601] RSP: 0018:ffff880405097c88  EFLAGS: 00000287
Nov 16 20:57:07 mythmaster kernel: [865550.232606] RAX: ffff880409361498 RBX: ffffffff81061dcf RCX: 0000000000008a15
Nov 16 20:57:07 mythmaster kernel: [865550.232611] RDX: 0000000000008a15 RSI: 0000000000000001 RDI: ffffffff81f93578
Nov 16 20:57:07 mythmaster kernel: [865550.232615] RBP: ffff880405097c90 R08: 0000000000041000 R09: 0000000000002870
Nov 16 20:57:07 mythmaster kernel: [865550.232619] R10: 0000000000000000 R11: ffff88040509791e R12: 0000000000000000
Nov 16 20:57:07 mythmaster kernel: [865550.232624] R13: ffff880405097bf8 R14: 000000000000286f R15: 000000000000000a
Nov 16 20:57:07 mythmaster kernel: [865550.232629] FS:  00007f3568921700(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
Nov 16 20:57:07 mythmaster kernel: [865550.232634] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Nov 16 20:57:07 mythmaster kernel: [865550.232638] CR2: 00007f35c4fae000 CR3: 0000000001c0e000 CR4: 00000000000007f0
Nov 16 20:57:07 mythmaster kernel: [865550.232642] Stack:
Nov 16 20:57:07 mythmaster kernel: [865550.232645]  ffffc900d1c1d000 ffff880405097cb0 ffffffff81176131 ffffc900d1c1d000
Nov 16 20:57:07 mythmaster kernel: [865550.232655]  0000000000000000 ffff880405097cd8 ffffffff811761ca 00000000ffffffff
Nov 16 20:57:07 mythmaster kernel: [865550.232664]  0000000000000000 0000000000001232 ffff880405097cf0 ffffffff81176316
Nov 16 20:57:07 mythmaster kernel: [865550.232672] Call Trace:
Nov 16 20:57:07 mythmaster kernel: [865550.232682]  [<ffffffff81176131>] remove_vm_area+0x11/0x80
Nov 16 20:57:07 mythmaster kernel: [865550.232689]  [<ffffffff811761ca>] __vunmap+0x2a/0x100
Nov 16 20:57:07 mythmaster kernel: [865550.232696]  [<ffffffff81176316>] vfree+0x36/0x80
Nov 16 20:57:07 mythmaster kernel: [865550.232704]  [<ffffffff811766f9>] __vmalloc_node_range+0x1b9/0x250
Nov 16 20:57:07 mythmaster kernel: [865550.232736]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232744]  [<ffffffff811767d1>] __vmalloc+0x41/0x50
Nov 16 20:57:07 mythmaster kernel: [865550.232766]  [<ffffffffa0161639>] ? kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232789]  [<ffffffffa0161639>] kv_alloc.isra.9+0x49/0x50 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232811]  [<ffffffffa01628d0>] spl_cache_grow_work+0x40/0x460 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232819]  [<ffffffff816ea120>] ? __schedule+0x3b0/0x7e0
Nov 16 20:57:07 mythmaster kernel: [865550.232828]  [<ffffffff8104dee9>] ? default_spin_lock_flags+0x9/0x10
Nov 16 20:57:07 mythmaster kernel: [865550.232852]  [<ffffffffa01666c7>] taskq_thread+0x237/0x4b0 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232861]  [<ffffffff81091420>] ? finish_task_switch+0x50/0xf0
Nov 16 20:57:07 mythmaster kernel: [865550.232870]  [<ffffffff81094950>] ? wake_up_state+0x20/0x20
Nov 16 20:57:07 mythmaster kernel: [865550.232894]  [<ffffffffa0166490>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
Nov 16 20:57:07 mythmaster kernel: [865550.232903]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Nov 16 20:57:07 mythmaster kernel: [865550.232912]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:57:07 mythmaster kernel: [865550.232920]  [<ffffffff816f516c>] ret_from_fork+0x7c/0xb0
Nov 16 20:57:07 mythmaster kernel: [865550.232928]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Nov 16 20:57:07 mythmaster kernel: [865550.232932] Code: 00 00 66 66 66 66 90 55 48 89 e5 53 48 89 fb 48 c7 c7 78 35 f9 81 e8 17 8d 57 00 48 8b 05 10 fd e1 00 48 85 c0 74 0f 48 3b 58 e8 <73> 25 48 8b 40 10 48 85 c0 75 f1 31 db 48 c7 c7 78 35 f9 81 e8 

dmesg snip showing the dieing disk:

[Sat Nov 16 22:27:01 2013] ata3: EH complete
[Sat Nov 16 22:27:48 2013] ata3: EH in SWNCQ mode,QC:qc_active 0x3F sactive 0x3F
[Sat Nov 16 22:27:48 2013] ata3: SWNCQ:qc_active 0x1E defer_bits 0x21 last_issue_tag 0x4
[Sat Nov 16 22:27:48 2013]   dhfis 0x1E dmafis 0x4 sdbfis 0x0
[Sat Nov 16 22:27:48 2013] ata3: ATA_REG 0x41 ERR_REG 0x40
[Sat Nov 16 22:27:48 2013] ata3: tag : dhfis dmafis sdbfis sactive
[Sat Nov 16 22:27:48 2013] ata3: tag 0x1: 1 0 0 1  
[Sat Nov 16 22:27:48 2013] ata3: tag 0x2: 1 1 0 1  
[Sat Nov 16 22:27:48 2013] ata3: tag 0x3: 1 0 0 1  
[Sat Nov 16 22:27:48 2013] ata3: tag 0x4: 1 0 0 1  
[Sat Nov 16 22:27:48 2013] ata3.00: exception Emask 0x1 SAct 0x3f SErr 0x0 action 0x6 frozen
[Sat Nov 16 22:27:48 2013] ata3.00: Ata error. fis:0x21
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/00:00:70:b3:c4/01:00:14:00:00/40 tag 0 ncq 131072 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/60:08:70:b2:c4/00:00:14:00:00/40 tag 1 ncq 49152 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/00:10:70:b1:c4/01:00:14:00:00/40 tag 2 ncq 131072 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/90:18:d0:b2:c4/00:00:14:00:00/40 tag 3 ncq 73728 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/10:20:60:b3:c4/00:00:14:00:00/40 tag 4 ncq 8192 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3.00: failed command: READ FPDMA QUEUED
[Sat Nov 16 22:27:48 2013] ata3.00: cmd 60/00:28:70:b4:c4/01:00:14:00:00/40 tag 5 ncq 131072 in
[Sat Nov 16 22:27:48 2013]          res 41/40:24:60:b3:c4/40:00:14:00:00/40 Emask 0x9 (media error)
[Sat Nov 16 22:27:48 2013] ata3.00: status: { DRDY ERR }
[Sat Nov 16 22:27:48 2013] ata3.00: error: { UNC }
[Sat Nov 16 22:27:48 2013] ata3: hard resetting link
[Sat Nov 16 22:27:48 2013] ata3: nv: skipping hardreset on occupied port
[Sat Nov 16 22:27:48 2013] ata3: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[Sat Nov 16 22:27:48 2013] ata3.00: configured for UDMA/133
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda] Unhandled sense code
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda]  
[Sat Nov 16 22:27:48 2013] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda]  
[Sat Nov 16 22:27:48 2013] Sense Key : Medium Error [current] [descriptor]
[Sat Nov 16 22:27:48 2013] Descriptor sense data with sense descriptors (in hex):
[Sat Nov 16 22:27:48 2013]         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 
[Sat Nov 16 22:27:48 2013]         14 c4 b3 60 
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda]  
[Sat Nov 16 22:27:48 2013] Add. Sense: Unrecovered read error - auto reallocate failed
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda] CDB: 
[Sat Nov 16 22:27:48 2013] Read(10): 28 00 14 c4 b3 70 00 01 00 00
[Sat Nov 16 22:27:48 2013] end_request: I/O error, dev sda, sector 348435312
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda] Unhandled sense code
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda]  
[Sat Nov 16 22:27:48 2013] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
[Sat Nov 16 22:27:48 2013] sd 2:0:0:0: [sda]  
[Sat Nov 16 22:27:48 2013] Sense Key : Medium Error [current] [descriptor]
[Sat Nov 16 22:27:48 2013] Descriptor sense data with sense descriptors (in hex):
[Sat Nov 16 22:27:48 2013]         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 
[Sat Nov 16 22:27:48 2013]         14 c4 b3 60 
behlendorf commented 10 years ago

This really looks like vmalloc() contention which is a known issue. I'll reopen the issue, we can verify it's fixed one that memory management work is done. Thanks for the feedback.

ecoop3r commented 10 years ago

We're having the same issue. We were running Ubuntu, with Linux 3.11.0-12. We rolled back to Ubuntu, with Linux 3.8.0 and the issue has stopped. I know that's not much info but it does present to possibility that it is kernel related.

behlendorf commented 8 years ago

Closing, this issue was resolved.