Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

0.6.0.93 causing soft-lockups with Ubuntu 12.04 #1227

Closed
wrouesnel opened this issue Jan 21, 2013 · 8 comments
Closed

0.6.0.93 causing soft-lockups with Ubuntu 12.04 #1227

wrouesnel opened this issue Jan 21, 2013 · 8 comments
Milestone

Comments

@wrouesnel
Copy link
Contributor

Just installed the newest ZoL daily package on my server running Ubuntu 12.04 (kernel 3.2) today, and got inundated with soft-lockup bugs. I've attached a 1-second sample from my logs (since I don't quite know what I'm looking at). This same machine was fine with the previous version of ZoL.

I'm trying an update to kernel 3.5 to see if that fixes it (since I have a desktop and laptop with ZoL which show no problems).

Jan 22 06:09:44 xen kernel: [ 2522.328901] BUG: soft lockup - CPU#0 stuck for 23s! [spl_kmem_cache/:595]
Jan 22 06:09:44 xen kernel: [ 2522.328902] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2522.328941] CPU 0 
Jan 22 06:09:44 xen kernel: [ 2522.328942] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2522.328977] 
Jan 22 06:09:44 xen kernel: [ 2522.328978] Pid: 595, comm: spl_kmem_cache/ Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2522.328981] RIP: 0010:[<ffffffff810a30e6>]  [<ffffffff810a30e6>] smp_call_function_many+0x1f6/0x260
Jan 22 06:09:44 xen kernel: [ 2522.328985] RSP: 0018:ffff8801f7e63d60  EFLAGS: 00000202
Jan 22 06:09:44 xen kernel: [ 2522.328986] RAX: 00000000000008fc RBX: ffff880206235c48 RCX: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2522.328987] RDX: 000000000e000000 RSI: ffffffff81806c00 RDI: 0000000000000293
Jan 22 06:09:44 xen kernel: [ 2522.328989] RBP: ffff8801f7e63db0 R08: 0000000000000000 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2522.328990] R10: 0000000000000004 R11: 0000000000000001 R12: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2522.328991] R13: 0000000000000293 R14: ffff8801f7e63d10 R15: ffff880217c13830
Jan 22 06:09:44 xen kernel: [ 2522.328993] FS:  0000000000000000(0000) GS:ffff880217c00000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2522.328994] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 22 06:09:44 xen kernel: [ 2522.328996] CR2: 00007fa646ab5c39 CR3: 0000000001c05000 CR4: 00000000000006f0
Jan 22 06:09:44 xen kernel: [ 2522.328997] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2522.328998] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2522.329000] Process spl_kmem_cache/ (pid: 595, threadinfo ffff8801f7e62000, task ffff880206235c00)
Jan 22 06:09:44 xen kernel: [ 2522.329001] Stack:
Jan 22 06:09:44 xen kernel: [ 2522.329002]  ffff8801f7e63d90 01ffffff810571ca ffff8801f7ef0000 ffffffffa00f5eb0
Jan 22 06:09:44 xen kernel: [ 2522.329004]  ffff88020639f380 ffffffffa00f5eb0 ffff8801f7ef0000 ffff8801fe954d20
Jan 22 06:09:44 xen kernel: [ 2522.329006]  ffff8801fe954d30 ffff880206235c00 ffff8801f7e63dc0 ffffffff810a3172
Jan 22 06:09:44 xen kernel: [ 2522.329008] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2522.329016]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329022]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329024]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2522.329026]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2522.329033]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329040]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329043]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2522.329049]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329052]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.329054]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2522.329056]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.329058]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2522.329059] Code: 4c 89 ff ff 15 04 33 b7 00 80 7d bf 00 0f 84 9b fe ff ff f6 43 20 01 0f 84 91 fe ff ff 0f 1f 84 00 00 00 00 00 f3 90 f6 43 20 01 <75> f8 e9 7c fe ff ff 0f 1f 00 4c 89 ea 4c 89 f6 44 89 e7 e8 a2 
Jan 22 06:09:44 xen kernel: [ 2522.329073] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2522.329079]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329085]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329087]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2522.329089]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2522.329096]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329102]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329105]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2522.329111]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2522.329113]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.329115]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2522.329117]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.329119]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2522.604714] BUG: soft lockup - CPU#3 stuck for 22s! [apt-cacher-ng:11148]
Jan 22 06:09:44 xen kernel: [ 2522.604715] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2522.604752] CPU 3 
Jan 22 06:09:44 xen kernel: [ 2522.604752] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2522.604787] 
Jan 22 06:09:44 xen kernel: [ 2522.604789] Pid: 11148, comm: apt-cacher-ng Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2522.604791] RIP: 0010:[<ffffffff810469e2>]  [<ffffffff810469e2>] flush_tlb_others_ipi+0x122/0x140
Jan 22 06:09:44 xen kernel: [ 2522.604795] RSP: 0018:ffff88019d4cfd78  EFLAGS: 00000246
Jan 22 06:09:44 xen kernel: [ 2522.604796] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2522.604798] RDX: ffffffff81806c60 RSI: 0000000000000100 RDI: ffffffff81e0d918
Jan 22 06:09:44 xen kernel: [ 2522.604799] RBP: ffff88019d4cfdb8 R08: 0000000000000002 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2522.604800] R10: 0000000000000000 R11: ffff8801a8d6b790 R12: ffff88019d4cfd18
Jan 22 06:09:44 xen kernel: [ 2522.604801] R13: ffff88019d4cfdb8 R14: 00000001d116dc00 R15: ffff880100000000
Jan 22 06:09:44 xen kernel: [ 2522.604803] FS:  00007f176e7fc700(0000) GS:ffff880217cc0000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2522.604805] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 22 06:09:44 xen kernel: [ 2522.604806] CR2: 00007f173a7fcd90 CR3: 00000001d3b0e000 CR4: 00000000000006e0
Jan 22 06:09:44 xen kernel: [ 2522.604807] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2522.604808] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2522.604810] Process apt-cacher-ng (pid: 11148, threadinfo ffff88019d4ce000, task ffff8801d116dc00)
Jan 22 06:09:44 xen kernel: [ 2522.604811] Stack:
Jan 22 06:09:44 xen kernel: [ 2522.604812]  ffff88019d4cfe18 ffffffff81143628 ffff88019d4cfd98 ffff88020639d780
Jan 22 06:09:44 xen kernel: [ 2522.604814]  ffff88020639da48 00007f1739ffc000 00007f1739ffd000 00007f1739ffcfff
Jan 22 06:09:44 xen kernel: [ 2522.604816]  ffff88019d4cfdc8 ffffffff81046b7e ffff88019d4cfde8 ffffffff81046c4b
Jan 22 06:09:44 xen kernel: [ 2522.604818] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2522.604821]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2522.604824]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2522.604826]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.604828]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2522.604831]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2522.604833]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2522.604835]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2522.604836] Code: 2e 0f 1f 84 00 00 00 00 00 48 8b 05 f9 7a c9 00 41 8d b6 cf 00 00 00 4c 89 e7 ff 90 d0 00 00 00 eb 09 0f 1f 80 00 00 00 00 f3 90 <be> 00 01 00 00 4c 89 e7 e8 31 59 2d 00 85 c0 74 ed e9 59 ff ff 
Jan 22 06:09:44 xen kernel: [ 2522.604850] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2522.604852]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2522.604854]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2522.604856]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2522.604858]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2522.604860]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2522.604862]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2522.604864]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2542.498598] BUG: soft lockup - CPU#2 stuck for 22s! [z_wr_int/14:751]
Jan 22 06:09:44 xen kernel: [ 2542.498599] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2542.498639] CPU 2 
Jan 22 06:09:44 xen kernel: [ 2542.498639] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2542.498674] 
Jan 22 06:09:44 xen kernel: [ 2542.498675] Pid: 751, comm: z_wr_int/14 Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2542.498678] RIP: 0010:[<ffffffff810a30e6>]  [<ffffffff810a30e6>] smp_call_function_many+0x1f6/0x260
Jan 22 06:09:44 xen kernel: [ 2542.498682] RSP: 0018:ffff8801e49dbc10  EFLAGS: 00000202
Jan 22 06:09:44 xen kernel: [ 2542.498683] RAX: 00000000000008fc RBX: 0000000000000000 RCX: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2542.498684] RDX: 000000000b000000 RSI: ffffffff81806c40 RDI: 0000000000000297
Jan 22 06:09:44 xen kernel: [ 2542.498685] RBP: ffff8801e49dbc60 R08: 0000000000000000 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2542.498687] R10: 0000000000000004 R11: 0000000000000001 R12: ffff8801e49dbbb0
Jan 22 06:09:44 xen kernel: [ 2542.498688] R13: 0000000000000297 R14: ffff8801e49dbbc0 R15: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2542.498690] FS:  0000000000000000(0000) GS:ffff880217c80000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2542.498691] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 22 06:09:44 xen kernel: [ 2542.498692] CR2: 00007fd854bd0810 CR3: 00000001d2584000 CR4: 00000000000006e0
Jan 22 06:09:44 xen kernel: [ 2542.498694] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2542.498695] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2542.498697] Process z_wr_int/14 (pid: 751, threadinfo ffff8801e49da000, task ffff8801e49e0000)
Jan 22 06:09:44 xen kernel: [ 2542.498698] Stack:
Jan 22 06:09:44 xen kernel: [ 2542.498699]  ffff880100000002 010000000623a158 0000000000000000 ffffffff811aab10
Jan 22 06:09:44 xen kernel: [ 2542.498701]  ffff8801e49dbc40 ffffffff811aab10 0000000000000000 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2542.498703]  0000000000000000 ffff8801e49e0000 ffff8801e49dbc70 ffffffff810a3172
Jan 22 06:09:44 xen kernel: [ 2542.498705] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2542.498707]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498709]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498711]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2542.498713]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2542.498715]  [<ffffffff811a9c3c>] invalidate_bh_lrus+0x1c/0x20
Jan 22 06:09:44 xen kernel: [ 2542.498717]  [<ffffffff811aa15d>] invalidate_bdev+0x2d/0x70
Jan 22 06:09:44 xen kernel: [ 2542.498719]  [<ffffffff811b052a>] __invalidate_device+0x5a/0x70
Jan 22 06:09:44 xen kernel: [ 2542.498721]  [<ffffffff811b0655>] flush_disk+0x25/0xc0
Jan 22 06:09:44 xen kernel: [ 2542.498724]  [<ffffffff812fdde7>] ? disk_clear_events+0xb7/0x130
Jan 22 06:09:44 xen kernel: [ 2542.498726]  [<ffffffff811b0750>] check_disk_change+0x60/0x80
Jan 22 06:09:44 xen kernel: [ 2542.498752]  [<ffffffffa02069ad>] vdev_disk_io_done+0x4d/0x80 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498775]  [<ffffffffa0242822>] zio_vdev_io_done+0xd2/0x190 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498797]  [<ffffffffa024325a>] zio_execute+0xba/0x140 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498805]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2542.498808]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2542.498814]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2542.498816]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498819]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2542.498821]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498823]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2542.498824] Code: 4c 89 ff ff 15 04 33 b7 00 80 7d bf 00 0f 84 9b fe ff ff f6 43 20 01 0f 84 91 fe ff ff 0f 1f 84 00 00 00 00 00 f3 90 f6 43 20 01 <75> f8 e9 7c fe ff ff 0f 1f 00 4c 89 ea 4c 89 f6 44 89 e7 e8 a2 
Jan 22 06:09:44 xen kernel: [ 2542.498838] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2542.498840]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498841]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498844]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2542.498845]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2542.498847]  [<ffffffff811a9c3c>] invalidate_bh_lrus+0x1c/0x20
Jan 22 06:09:44 xen kernel: [ 2542.498849]  [<ffffffff811aa15d>] invalidate_bdev+0x2d/0x70
Jan 22 06:09:44 xen kernel: [ 2542.498851]  [<ffffffff811b052a>] __invalidate_device+0x5a/0x70
Jan 22 06:09:44 xen kernel: [ 2542.498853]  [<ffffffff811b0655>] flush_disk+0x25/0xc0
Jan 22 06:09:44 xen kernel: [ 2542.498855]  [<ffffffff812fdde7>] ? disk_clear_events+0xb7/0x130
Jan 22 06:09:44 xen kernel: [ 2542.498857]  [<ffffffff811b0750>] check_disk_change+0x60/0x80
Jan 22 06:09:44 xen kernel: [ 2542.498879]  [<ffffffffa02069ad>] vdev_disk_io_done+0x4d/0x80 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498901]  [<ffffffffa0242822>] zio_vdev_io_done+0xd2/0x190 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498923]  [<ffffffffa024325a>] zio_execute+0xba/0x140 [zfs]
Jan 22 06:09:44 xen kernel: [ 2542.498931]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2542.498933]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2542.498940]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2542.498942]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498944]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2542.498946]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2542.498948]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2550.309053] BUG: soft lockup - CPU#0 stuck for 23s! [spl_kmem_cache/:595]
Jan 22 06:09:44 xen kernel: [ 2550.309054] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2550.309093] CPU 0 
Jan 22 06:09:44 xen kernel: [ 2550.309094] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2550.309129] 
Jan 22 06:09:44 xen kernel: [ 2550.309130] Pid: 595, comm: spl_kmem_cache/ Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2550.309133] RIP: 0010:[<ffffffff810a30e2>]  [<ffffffff810a30e2>] smp_call_function_many+0x1f2/0x260
Jan 22 06:09:44 xen kernel: [ 2550.309136] RSP: 0018:ffff8801f7e63d60  EFLAGS: 00000202
Jan 22 06:09:44 xen kernel: [ 2550.309138] RAX: 00000000000008fc RBX: ffff880206235c48 RCX: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2550.309139] RDX: 000000000e000000 RSI: ffffffff81806c00 RDI: 0000000000000293
Jan 22 06:09:44 xen kernel: [ 2550.309140] RBP: ffff8801f7e63db0 R08: 0000000000000000 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2550.309142] R10: 0000000000000004 R11: 0000000000000001 R12: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2550.309143] R13: 0000000000000293 R14: ffff8801f7e63d10 R15: ffff880217c13830
Jan 22 06:09:44 xen kernel: [ 2550.309145] FS:  0000000000000000(0000) GS:ffff880217c00000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2550.309146] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 22 06:09:44 xen kernel: [ 2550.309147] CR2: 00007fa646ab5c39 CR3: 0000000001c05000 CR4: 00000000000006f0
Jan 22 06:09:44 xen kernel: [ 2550.309149] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2550.309150] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2550.309152] Process spl_kmem_cache/ (pid: 595, threadinfo ffff8801f7e62000, task ffff880206235c00)
Jan 22 06:09:44 xen kernel: [ 2550.309153] Stack:
Jan 22 06:09:44 xen kernel: [ 2550.309154]  ffff8801f7e63d90 01ffffff810571ca ffff8801f7ef0000 ffffffffa00f5eb0
Jan 22 06:09:44 xen kernel: [ 2550.309156]  ffff88020639f380 ffffffffa00f5eb0 ffff8801f7ef0000 ffff8801fe954d20
Jan 22 06:09:44 xen kernel: [ 2550.309158]  ffff8801fe954d30 ffff880206235c00 ffff8801f7e63dc0 ffffffff810a3172
Jan 22 06:09:44 xen kernel: [ 2550.309160] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2550.309167]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309174]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309176]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2550.309178]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2550.309185]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309191]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309194]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2550.309201]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309203]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.309205]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2550.309207]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.309209]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2550.309210] Code: 00 0f ae f0 4c 89 ff ff 15 04 33 b7 00 80 7d bf 00 0f 84 9b fe ff ff f6 43 20 01 0f 84 91 fe ff ff 0f 1f 84 00 00 00 00 00 f3 90 <f6> 43 20 01 75 f8 e9 7c fe ff ff 0f 1f 00 4c 89 ea 4c 89 f6 44 
Jan 22 06:09:44 xen kernel: [ 2550.309224] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2550.309230]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309237]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309239]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2550.309241]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2550.309247]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309254]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309256]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2550.309263]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2550.309264]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.309266]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2550.309269]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.309270]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2550.584849] BUG: soft lockup - CPU#3 stuck for 22s! [apt-cacher-ng:11148]
Jan 22 06:09:44 xen kernel: [ 2550.584850] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2550.584887] CPU 3 
Jan 22 06:09:44 xen kernel: [ 2550.584888] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2550.584923] 
Jan 22 06:09:44 xen kernel: [ 2550.584924] Pid: 11148, comm: apt-cacher-ng Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2550.584927] RIP: 0010:[<ffffffff810469e2>]  [<ffffffff810469e2>] flush_tlb_others_ipi+0x122/0x140
Jan 22 06:09:44 xen kernel: [ 2550.584931] RSP: 0018:ffff88019d4cfd78  EFLAGS: 00000246
Jan 22 06:09:44 xen kernel: [ 2550.584932] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2550.584933] RDX: ffffffff81806c60 RSI: 0000000000000100 RDI: ffffffff81e0d918
Jan 22 06:09:44 xen kernel: [ 2550.584934] RBP: ffff88019d4cfdb8 R08: 0000000000000002 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2550.584936] R10: 0000000000000000 R11: ffff8801a8d6b790 R12: ffff88019d4cfd18
Jan 22 06:09:44 xen kernel: [ 2550.584937] R13: ffff88019d4cfdb8 R14: 00000001d116dc00 R15: ffff880100000000
Jan 22 06:09:44 xen kernel: [ 2550.584939] FS:  00007f176e7fc700(0000) GS:ffff880217cc0000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2550.584940] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 22 06:09:44 xen kernel: [ 2550.584942] CR2: 00007f173a7fcd90 CR3: 00000001d3b0e000 CR4: 00000000000006e0
Jan 22 06:09:44 xen kernel: [ 2550.584943] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2550.584944] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2550.584946] Process apt-cacher-ng (pid: 11148, threadinfo ffff88019d4ce000, task ffff8801d116dc00)
Jan 22 06:09:44 xen kernel: [ 2550.584947] Stack:
Jan 22 06:09:44 xen kernel: [ 2550.584948]  ffff88019d4cfe18 ffffffff81143628 ffff88019d4cfd98 ffff88020639d780
Jan 22 06:09:44 xen kernel: [ 2550.584950]  ffff88020639da48 00007f1739ffc000 00007f1739ffd000 00007f1739ffcfff
Jan 22 06:09:44 xen kernel: [ 2550.584952]  ffff88019d4cfdc8 ffffffff81046b7e ffff88019d4cfde8 ffffffff81046c4b
Jan 22 06:09:44 xen kernel: [ 2550.584954] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2550.584957]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2550.584959]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2550.584961]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.584964]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2550.584966]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2550.584968]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2550.584970]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2550.584971] Code: 2e 0f 1f 84 00 00 00 00 00 48 8b 05 f9 7a c9 00 41 8d b6 cf 00 00 00 4c 89 e7 ff 90 d0 00 00 00 eb 09 0f 1f 80 00 00 00 00 f3 90 <be> 00 01 00 00 4c 89 e7 e8 31 59 2d 00 85 c0 74 ed e9 59 ff ff 
Jan 22 06:09:44 xen kernel: [ 2550.584985] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2550.584987]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2550.584989]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2550.584991]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2550.584993]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2550.584995]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2550.584997]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2550.584999]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2570.478684] BUG: soft lockup - CPU#2 stuck for 22s! [z_wr_int/14:751]
Jan 22 06:09:44 xen kernel: [ 2570.478686] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2570.478723] CPU 2 
Jan 22 06:09:44 xen kernel: [ 2570.478723] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2570.478758] 
Jan 22 06:09:44 xen kernel: [ 2570.478759] Pid: 751, comm: z_wr_int/14 Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2570.478762] RIP: 0010:[<ffffffff810a30e2>]  [<ffffffff810a30e2>] smp_call_function_many+0x1f2/0x260
Jan 22 06:09:44 xen kernel: [ 2570.478765] RSP: 0018:ffff8801e49dbc10  EFLAGS: 00000202
Jan 22 06:09:44 xen kernel: [ 2570.478766] RAX: 00000000000008fc RBX: 0000000000000000 RCX: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2570.478767] RDX: 000000000b000000 RSI: ffffffff81806c40 RDI: 0000000000000297
Jan 22 06:09:44 xen kernel: [ 2570.478769] RBP: ffff8801e49dbc60 R08: 0000000000000000 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2570.478770] R10: 0000000000000004 R11: 0000000000000001 R12: ffff8801e49dbbb0
Jan 22 06:09:44 xen kernel: [ 2570.478771] R13: 0000000000000297 R14: ffff8801e49dbbc0 R15: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2570.478773] FS:  0000000000000000(0000) GS:ffff880217c80000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2570.478774] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 22 06:09:44 xen kernel: [ 2570.478776] CR2: 00007fd854bd0810 CR3: 00000001d2584000 CR4: 00000000000006e0
Jan 22 06:09:44 xen kernel: [ 2570.478777] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2570.478778] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2570.478780] Process z_wr_int/14 (pid: 751, threadinfo ffff8801e49da000, task ffff8801e49e0000)
Jan 22 06:09:44 xen kernel: [ 2570.478781] Stack:
Jan 22 06:09:44 xen kernel: [ 2570.478782]  ffff880100000002 010000000623a158 0000000000000000 ffffffff811aab10
Jan 22 06:09:44 xen kernel: [ 2570.478784]  ffff8801e49dbc40 ffffffff811aab10 0000000000000000 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2570.478786]  0000000000000000 ffff8801e49e0000 ffff8801e49dbc70 ffffffff810a3172
Jan 22 06:09:44 xen kernel: [ 2570.478788] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2570.478790]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478792]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478794]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2570.478796]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2570.478798]  [<ffffffff811a9c3c>] invalidate_bh_lrus+0x1c/0x20
Jan 22 06:09:44 xen kernel: [ 2570.478800]  [<ffffffff811aa15d>] invalidate_bdev+0x2d/0x70
Jan 22 06:09:44 xen kernel: [ 2570.478802]  [<ffffffff811b052a>] __invalidate_device+0x5a/0x70
Jan 22 06:09:44 xen kernel: [ 2570.478804]  [<ffffffff811b0655>] flush_disk+0x25/0xc0
Jan 22 06:09:44 xen kernel: [ 2570.478806]  [<ffffffff812fdde7>] ? disk_clear_events+0xb7/0x130
Jan 22 06:09:44 xen kernel: [ 2570.478808]  [<ffffffff811b0750>] check_disk_change+0x60/0x80
Jan 22 06:09:44 xen kernel: [ 2570.478831]  [<ffffffffa02069ad>] vdev_disk_io_done+0x4d/0x80 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.478854]  [<ffffffffa0242822>] zio_vdev_io_done+0xd2/0x190 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.478875]  [<ffffffffa024325a>] zio_execute+0xba/0x140 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.478883]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2570.478886]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2570.478892]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2570.478895]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478897]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2570.478899]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478901]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2570.478902] Code: 00 0f ae f0 4c 89 ff ff 15 04 33 b7 00 80 7d bf 00 0f 84 9b fe ff ff f6 43 20 01 0f 84 91 fe ff ff 0f 1f 84 00 00 00 00 00 f3 90 <f6> 43 20 01 75 f8 e9 7c fe ff ff 0f 1f 00 4c 89 ea 4c 89 f6 44 
Jan 22 06:09:44 xen kernel: [ 2570.478916] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2570.478918]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478920]  [<ffffffff811aab10>] ? buffer_cpu_notify+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.478922]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2570.478924]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2570.478925]  [<ffffffff811a9c3c>] invalidate_bh_lrus+0x1c/0x20
Jan 22 06:09:44 xen kernel: [ 2570.478927]  [<ffffffff811aa15d>] invalidate_bdev+0x2d/0x70
Jan 22 06:09:44 xen kernel: [ 2570.478929]  [<ffffffff811b052a>] __invalidate_device+0x5a/0x70
Jan 22 06:09:44 xen kernel: [ 2570.478931]  [<ffffffff811b0655>] flush_disk+0x25/0xc0
Jan 22 06:09:44 xen kernel: [ 2570.478933]  [<ffffffff812fdde7>] ? disk_clear_events+0xb7/0x130
Jan 22 06:09:44 xen kernel: [ 2570.478935]  [<ffffffff811b0750>] check_disk_change+0x60/0x80
Jan 22 06:09:44 xen kernel: [ 2570.478957]  [<ffffffffa02069ad>] vdev_disk_io_done+0x4d/0x80 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.478980]  [<ffffffffa0242822>] zio_vdev_io_done+0xd2/0x190 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.479001]  [<ffffffffa024325a>] zio_execute+0xba/0x140 [zfs]
Jan 22 06:09:44 xen kernel: [ 2570.479009]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2570.479011]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2570.479018]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2570.479020]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.479022]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2570.479024]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2570.479026]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2578.289187] BUG: soft lockup - CPU#0 stuck for 23s! [spl_kmem_cache/:595]
Jan 22 06:09:44 xen kernel: [ 2578.289188] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2578.289226] CPU 0 
Jan 22 06:09:44 xen kernel: [ 2578.289227] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2578.289262] 
Jan 22 06:09:44 xen kernel: [ 2578.289263] Pid: 595, comm: spl_kmem_cache/ Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2578.289266] RIP: 0010:[<ffffffff810a30e2>]  [<ffffffff810a30e2>] smp_call_function_many+0x1f2/0x260
Jan 22 06:09:44 xen kernel: [ 2578.289269] RSP: 0018:ffff8801f7e63d60  EFLAGS: 00000202
Jan 22 06:09:44 xen kernel: [ 2578.289270] RAX: 00000000000008fc RBX: ffff880206235c48 RCX: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2578.289272] RDX: 000000000e000000 RSI: ffffffff81806c00 RDI: 0000000000000293
Jan 22 06:09:44 xen kernel: [ 2578.289273] RBP: ffff8801f7e63db0 R08: 0000000000000000 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2578.289274] R10: 0000000000000004 R11: 0000000000000001 R12: 0000000000000001
Jan 22 06:09:44 xen kernel: [ 2578.289276] R13: 0000000000000293 R14: ffff8801f7e63d10 R15: ffff880217c13830
Jan 22 06:09:44 xen kernel: [ 2578.289277] FS:  0000000000000000(0000) GS:ffff880217c00000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2578.289279] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 22 06:09:44 xen kernel: [ 2578.289280] CR2: 00007fa646ab5c39 CR3: 0000000001c05000 CR4: 00000000000006f0
Jan 22 06:09:44 xen kernel: [ 2578.289281] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2578.289283] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2578.289284] Process spl_kmem_cache/ (pid: 595, threadinfo ffff8801f7e62000, task ffff880206235c00)
Jan 22 06:09:44 xen kernel: [ 2578.289285] Stack:
Jan 22 06:09:44 xen kernel: [ 2578.289286]  ffff8801f7e63d90 01ffffff810571ca ffff8801f7ef0000 ffffffffa00f5eb0
Jan 22 06:09:44 xen kernel: [ 2578.289289]  ffff88020639f380 ffffffffa00f5eb0 ffff8801f7ef0000 ffff8801fe954d20
Jan 22 06:09:44 xen kernel: [ 2578.289291]  ffff8801fe954d30 ffff880206235c00 ffff8801f7e63dc0 ffffffff810a3172
Jan 22 06:09:44 xen kernel: [ 2578.289293] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2578.289300]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289306]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289308]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2578.289310]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2578.289317]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289323]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289326]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2578.289333]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289335]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.289337]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2578.289339]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.289341]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2578.289342] Code: 00 0f ae f0 4c 89 ff ff 15 04 33 b7 00 80 7d bf 00 0f 84 9b fe ff ff f6 43 20 01 0f 84 91 fe ff ff 0f 1f 84 00 00 00 00 00 f3 90 <f6> 43 20 01 75 f8 e9 7c fe ff ff 0f 1f 00 4c 89 ea 4c 89 f6 44 
Jan 22 06:09:44 xen kernel: [ 2578.289356] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2578.289362]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289368]  [<ffffffffa00f5eb0>] ? spl_cache_reclaim_wait+0x20/0x20 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289371]  [<ffffffff810a3172>] smp_call_function+0x22/0x30
Jan 22 06:09:44 xen kernel: [ 2578.289372]  [<ffffffff810a31a8>] on_each_cpu+0x28/0x60
Jan 22 06:09:44 xen kernel: [ 2578.289379]  [<ffffffffa00f8fc0>] spl_cache_age+0x30/0x110 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289385]  [<ffffffffa00fb6f6>] taskq_thread+0x236/0x4b0 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289388]  [<ffffffff810606a0>] ? try_to_wake_up+0x200/0x200
Jan 22 06:09:44 xen kernel: [ 2578.289394]  [<ffffffffa00fb4c0>] ? task_done+0x160/0x160 [spl]
Jan 22 06:09:44 xen kernel: [ 2578.289396]  [<ffffffff8108b27c>] kthread+0x8c/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.289398]  [<ffffffff81667b74>] kernel_thread_helper+0x4/0x10
Jan 22 06:09:44 xen kernel: [ 2578.289400]  [<ffffffff8108b1f0>] ? flush_kthread_worker+0xa0/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.289402]  [<ffffffff81667b70>] ? gs_change+0x13/0x13
Jan 22 06:09:44 xen kernel: [ 2578.564975] BUG: soft lockup - CPU#3 stuck for 22s! [apt-cacher-ng:11148]
Jan 22 06:09:44 xen kernel: [ 2578.564976] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2578.565013] CPU 3 
Jan 22 06:09:44 xen kernel: [ 2578.565014] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2578.565049] 
Jan 22 06:09:44 xen kernel: [ 2578.565050] Pid: 11148, comm: apt-cacher-ng Tainted: P      D W  O 3.2.0-36-generic #57-Ubuntu Gigabyte Technology Co., Ltd. P55A-UD4P/P55A-UD4P
Jan 22 06:09:44 xen kernel: [ 2578.565052] RIP: 0010:[<ffffffff8131c320>]  [<ffffffff8131c320>] kasprintf+0x40/0x40
Jan 22 06:09:44 xen kernel: [ 2578.565055] RSP: 0018:ffff88019d4cfd70  EFLAGS: 00000246
Jan 22 06:09:44 xen kernel: [ 2578.565057] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2578.565058] RDX: ffffffff81806c60 RSI: 0000000000000100 RDI: ffffffff81e0d918
Jan 22 06:09:44 xen kernel: [ 2578.565059] RBP: ffff88019d4cfdb8 R08: 0000000000000002 R09: 0000000000000004
Jan 22 06:09:44 xen kernel: [ 2578.565060] R10: 0000000000000000 R11: ffff8801a8d6b790 R12: ffff88019d4cfd18
Jan 22 06:09:44 xen kernel: [ 2578.565062] R13: ffff88019d4cfd68 R14: 00000001d116dc00 R15: ffff880100000000
Jan 22 06:09:44 xen kernel: [ 2578.565063] FS:  00007f176e7fc700(0000) GS:ffff880217cc0000(0000) knlGS:0000000000000000
Jan 22 06:09:44 xen kernel: [ 2578.565065] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Jan 22 06:09:44 xen kernel: [ 2578.565066] CR2: 00007f173a7fcd90 CR3: 00000001d3b0e000 CR4: 00000000000006e0
Jan 22 06:09:44 xen kernel: [ 2578.565068] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 22 06:09:44 xen kernel: [ 2578.565069] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 22 06:09:44 xen kernel: [ 2578.565070] Process apt-cacher-ng (pid: 11148, threadinfo ffff88019d4ce000, task ffff8801d116dc00)
Jan 22 06:09:44 xen kernel: [ 2578.565072] Stack:
Jan 22 06:09:44 xen kernel: [ 2578.565072]  ffffffff810469ef ffff88019d4cfe18 ffffffff81143628 ffff88019d4cfd98
Jan 22 06:09:44 xen kernel: [ 2578.565074]  ffff88020639d780 ffff88020639da48 00007f1739ffc000 00007f1739ffd000
Jan 22 06:09:44 xen kernel: [ 2578.565076]  00007f1739ffcfff ffff88019d4cfdc8 ffffffff81046b7e ffff88019d4cfde8
Jan 22 06:09:44 xen kernel: [ 2578.565079] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2578.565081]  [<ffffffff810469ef>] ? flush_tlb_others_ipi+0x12f/0x140
Jan 22 06:09:44 xen kernel: [ 2578.565083]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2578.565086]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2578.565088]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.565090]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2578.565092]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2578.565094]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2578.565096]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2578.565098] Code: 89 4d e8 4c 89 45 f0 48 89 45 c0 48 8d 45 d0 4c 89 4d f8 c7 45 b8 10 00 00 00 48 89 45 c8 e8 38 ff ff ff c9 c3 90 90 90 90 90 90 <8d> 4e 3f 85 f6 55 0f 49 ce 48 89 e5 c1 f9 06 85 c9 7e 61 31 c0 
Jan 22 06:09:44 xen kernel: [ 2578.565111] Call Trace:
Jan 22 06:09:44 xen kernel: [ 2578.565113]  [<ffffffff810469ef>] ? flush_tlb_others_ipi+0x12f/0x140
Jan 22 06:09:44 xen kernel: [ 2578.565115]  [<ffffffff81143628>] ? vma_adjust+0x378/0x490
Jan 22 06:09:44 xen kernel: [ 2578.565118]  [<ffffffff81046b7e>] native_flush_tlb_others+0xe/0x10
Jan 22 06:09:44 xen kernel: [ 2578.565120]  [<ffffffff81046c4b>] flush_tlb_mm+0x5b/0xa0
Jan 22 06:09:44 xen kernel: [ 2578.565122]  [<ffffffff811463dc>] change_protection+0x26c/0x2b0
Jan 22 06:09:44 xen kernel: [ 2578.565124]  [<ffffffff81146555>] mprotect_fixup+0x135/0x2b0
Jan 22 06:09:44 xen kernel: [ 2578.565126]  [<ffffffff81146871>] sys_mprotect+0x1a1/0x250
Jan 22 06:09:44 xen kernel: [ 2578.565128]  [<ffffffff81665a02>] system_call_fastpath+0x16/0x1b
Jan 22 06:09:44 xen kernel: [ 2598.458844] BUG: soft lockup - CPU#2 stuck for 23s! [z_wr_int/14:751]
Jan 22 06:09:44 xen kernel: [ 2598.458845] Modules linked in: iscsi_trgt(O) kvm_intel kvm ip6t_LOG nf_conntrack_ipv6 nf_defrag_ipv6 xt_multiport ipt_LOG ipt_MASQUERADE ipt_REDIRECT xt_tcpudp xt_state ip6table_filter ip6_tables iptable_filter ebtable_nat ebtables ebt_snat ebt_dnat nf_nat_ftp nf_nat_proto_sctp libcrc32c nf_nat_tftp nf_nat_h323 nf_nat_proto_dccp nf_nat_sip nf_nat_irc nf_nat_pptp iptable_nat ip_tables nf_nat_proto_gre nf_nat_snmp_basic nf_nat_proto_udplite nf_nat_amanda nf_nat act_nat nf_conntrack_proto_sctp nf_conntrack_netlink nfnetlink nf_conntrack_tftp xt_conntrack x_tables nf_conntrack_irc nf_conntrack_ftp nf_conntrack_sip nf_conntrack_pptp nf_conntrack_snmp nf_conntrack_netbios_ns nf_conntrack_broadcast nf_conntrack_proto_gre nf_conntrack_sane ts_kmp nf_conntrack_amanda nf_conntrack_proto_udplite nf_conntrack_h323 nf_conntrack_proto_dccp nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 pppoe pppox vesafb bridge stp mxm_wmi bonding i7core_edac edac_core serio_raw radeon snd_hda_codec_realtek tt
Jan 22 06:09:44 xen kernel: m drm_kms_helper drm i2c_algo_bit ppdev joydev snd_hda_intel snd_hda_codec snd_hwdep snd_pcm snd_seq_midi rfcomm snd_rawmidi bnep snd_seq_midi_event bluetooth snd_seq snd_timer snd_seq_device snd soundcore snd_page_alloc parport_pc wmi mac_hid lp parport nfsd binfmt_misc nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate usbhid hid e1000e pata_jmicron mpt2sas scsi_transport_sas raid_class r8168(O)
Jan 22 06:09:44 xen kernel: [ 2598.458882] CPU 2 
Jan 22 06:09:44 xen 
@wrouesnel
Copy link
Contributor Author

Ok I can confirm I'm still having problems with it on 0.6.0.93 with kernel 3.5.0-22-generic on Ubuntu 12.10 as well - the symptom is that services like nginx and nfsd deadlock waiting on "lookup_slow" and "vfs_readdir".

This was all working on the previous daily build, so there's been some type of regression since then. I'm rolling back to the ZFS stable PPA to see if it fixes it.

EDIT:

This is all on a system with a 20-disk pool split across two RAID-Z3 volumes. Everything else seems to work properly - but nginx and the nfs-kernel-server both seemed to deadlock. I was having earlier issues with a dataset not being able to be mounted or visible as well (it kept claiming to be mounted in /proc/mounts, but wasn't accessible or unmountable).

@behlendorf
Copy link
Contributor

@wrouesnel Yes, there were some regressions which were missing, we'll get them nailed down.

If you get a change can you please apply openzfs/spl@27d2633 to your spl source and set the new module option spl_kmem_cache_aging=0. This will effectively disable the cache aging in favor of reclaiming the caches where there is memory pressure. I expect it will resolved the issues your seeing with the stack traces but I'd love to verify that.

@tomposmiko
Copy link

I tried.
Module compiled with no error, but after that zfs.ko cannot be loaded:

[ 5016.154628] zfs: Unknown symbol invalidate_inodes_fn (err 0)

@behlendorf
Copy link
Contributor

You'll need to update ZFS to the latest code as well or revert openzfs/spl@769528f

@tomposmiko
Copy link

Revert didn't help with the same error.

I tried ppa:zfs-native/daily, but with the zfs.ko cannot be loaded.
'modprobe zfs' is there, locked, and in dmesg:

[14562.389826] SPL: Loaded module v0.6.0.93-rc13
[14763.672057] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[14763.672060] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[14763.672063] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[14763.672068] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[14763.672074] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[14763.672078] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[14763.672083] Call Trace:
[14763.672091] [] schedule+0x3f/0x60
[14763.672095] [] __mutex_lock_slowpath+0xd7/0x150
[14763.672140] [] ? l2arc_evict+0x310/0x310 [zfs]
[14763.672173] [] ? l2arc_evict+0x310/0x310 [zfs]
[14763.672177] [] mutex_lock+0x2a/0x50
[14763.672210] [] ? l2arc_evict+0x310/0x310 [zfs]
[14763.672242] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[14763.672248] [] ? kfree+0x114/0x140
[14763.672259] [] ? kmem_free_debug+0x4b/0x150 [spl]
[14763.672292] [] ? l2arc_evict+0x310/0x310 [zfs]
[14763.672307] [] thread_generic_wrapper+0x78/0x90 [spl]
[14763.672314] [] ? __thread_create+0x310/0x310 [spl]
[14763.672319] [] kthread+0x8c/0xa0
[14763.672323] [] kernel_thread_helper+0x4/0x10
[14763.672327] [] ? flush_kthread_worker+0xa0/0xa0
[14763.672330] [] ? gs_change+0x13/0x13
[14883.672047] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[14883.672050] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[14883.672052] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[14883.672056] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[14883.672060] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[14883.672064] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[14883.672068] Call Trace:
[14883.672076] [] schedule+0x3f/0x60
[14883.672079] [] __mutex_lock_slowpath+0xd7/0x150
[14883.672117] [] ? l2arc_evict+0x310/0x310 [zfs]
[14883.672144] [] ? l2arc_evict+0x310/0x310 [zfs]
[14883.672147] [] mutex_lock+0x2a/0x50
[14883.672173] [] ? l2arc_evict+0x310/0x310 [zfs]
[14883.672199] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[14883.672203] [] ? kfree+0x114/0x140
[14883.672213] [] ? kmem_free_debug+0x4b/0x150 [spl]
[14883.672239] [] ? l2arc_evict+0x310/0x310 [zfs]
[14883.672245] [] thread_generic_wrapper+0x78/0x90 [spl]
[14883.672251] [] ? __thread_create+0x310/0x310 [spl]
[14883.672255] [] kthread+0x8c/0xa0
[14883.672258] [] kernel_thread_helper+0x4/0x10
[14883.672261] [] ? flush_kthread_worker+0xa0/0xa0
[14883.672263] [] ? gs_change+0x13/0x13
[15003.672061] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15003.672063] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15003.672065] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15003.672070] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15003.672075] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15003.672078] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15003.672082] Call Trace:
[15003.672089] [] schedule+0x3f/0x60
[15003.672093] [] __mutex_lock_slowpath+0xd7/0x150
[15003.672132] [] ? l2arc_evict+0x310/0x310 [zfs]
[15003.672159] [] ? l2arc_evict+0x310/0x310 [zfs]
[15003.672162] [] mutex_lock+0x2a/0x50
[15003.672188] [] ? l2arc_evict+0x310/0x310 [zfs]
[15003.672214] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15003.672218] [] ? kfree+0x114/0x140
[15003.672228] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15003.672254] [] ? l2arc_evict+0x310/0x310 [zfs]
[15003.672260] [] thread_generic_wrapper+0x78/0x90 [spl]
[15003.672266] [] ? __thread_create+0x310/0x310 [spl]
[15003.672270] [] kthread+0x8c/0xa0
[15003.672273] [] kernel_thread_helper+0x4/0x10
[15003.672276] [] ? flush_kthread_worker+0xa0/0xa0
[15003.672279] [] ? gs_change+0x13/0x13
[15123.672063] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15123.672066] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15123.672069] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15123.672074] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15123.672080] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15123.672084] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15123.672089] Call Trace:
[15123.672097] [] schedule+0x3f/0x60
[15123.672101] [] __mutex_lock_slowpath+0xd7/0x150
[15123.672144] [] ? l2arc_evict+0x310/0x310 [zfs]
[15123.672177] [] ? l2arc_evict+0x310/0x310 [zfs]
[15123.672181] [] mutex_lock+0x2a/0x50
[15123.672213] [] ? l2arc_evict+0x310/0x310 [zfs]
[15123.672246] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15123.672251] [] ? kfree+0x114/0x140
[15123.672262] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15123.672295] [] ? l2arc_evict+0x310/0x310 [zfs]
[15123.672302] [] thread_generic_wrapper+0x78/0x90 [spl]
[15123.672309] [] ? __thread_create+0x310/0x310 [spl]
[15123.672314] [] kthread+0x8c/0xa0
[15123.672318] [] kernel_thread_helper+0x4/0x10
[15123.672322] [] ? flush_kthread_worker+0xa0/0xa0
[15123.672325] [] ? gs_change+0x13/0x13
[15243.672048] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15243.672051] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15243.672053] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15243.672058] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15243.672062] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15243.672066] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15243.672070] Call Trace:
[15243.672077] [] schedule+0x3f/0x60
[15243.672081] [] __mutex_lock_slowpath+0xd7/0x150
[15243.672119] [] ? l2arc_evict+0x310/0x310 [zfs]
[15243.672146] [] ? l2arc_evict+0x310/0x310 [zfs]
[15243.672148] [] mutex_lock+0x2a/0x50
[15243.672174] [] ? l2arc_evict+0x310/0x310 [zfs]
[15243.672201] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15243.672205] [] ? kfree+0x114/0x140
[15243.672214] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15243.672241] [] ? l2arc_evict+0x310/0x310 [zfs]
[15243.672247] [] thread_generic_wrapper+0x78/0x90 [spl]
[15243.672252] [] ? __thread_create+0x310/0x310 [spl]
[15243.672256] [] kthread+0x8c/0xa0
[15243.672259] [] kernel_thread_helper+0x4/0x10
[15243.672262] [] ? flush_kthread_worker+0xa0/0xa0
[15243.672265] [] ? gs_change+0x13/0x13
[15363.672121] INFO: task modprobe:22025 blocked for more than 120 seconds.
[15363.672124] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15363.672126] modprobe D ffffffff81806240 0 22025 1 0x00000004
[15363.672130] ffff880130a93468 0000000000000082 0000000000000001 ffff880080a61ae8
[15363.672135] ffff880130a93fd8 ffff880130a93fd8 ffff880130a93fd8 00000000000137c0
[15363.672139] ffff88022e181700 ffff880225cf8000 ffff880130a93478 ffff880080a61b20
[15363.672142] Call Trace:
[15363.672149] [] schedule+0x3f/0x60
[15363.672161] [] cv_wait_common+0xfd/0x1b0 [spl]
[15363.672166] [] ? add_wait_queue+0x60/0x60
[15363.672172] [] __cv_wait+0x15/0x20 [spl]
[15363.672217] [] txg_wait_open+0x8b/0x110 [zfs]
[15363.672247] [] dmu_tx_wait+0xed/0xf0 [zfs]
[15363.672277] [] dmu_tx_assign+0x86/0x460 [zfs]
[15363.672305] [] dmu_free_object+0xac/0x100 [zfs]
[15363.672334] [] ? dmu_object_next+0x43/0x60 [zfs]
[15363.672364] [] ? dsl_dataset_destroy+0x191/0x4d0 [zfs]
[15363.672394] [] dsl_dataset_destroy+0x18d/0x4d0 [zfs]
[15363.672424] [] dsl_destroy_inconsistent+0x56/0x60 [zfs]
[15363.672453] [] findfunc+0x12/0x20 [zfs]
[15363.672482] [] dmu_objset_find_spa+0x104/0x4b0 [zfs]
[15363.672486] [] ? kvasprintf+0x70/0x90
[15363.672514] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15363.672544] [] dmu_objset_find_spa+0x1ab/0x4b0 [zfs]
[15363.672572] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15363.672601] [] dmu_objset_find_spa+0x1ab/0x4b0 [zfs]
[15363.672604] [] ? mutex_lock+0x1d/0x50
[15363.672633] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15363.672665] [] ? vdev_resilver_needed+0x59/0x160 [zfs]
[15363.672694] [] dmu_objset_find+0x2d/0x30 [zfs]
[15363.672724] [] ? dsl_dataset_destroy+0x4d0/0x4d0 [zfs]
[15363.672756] [] spa_load+0x16e8/0x19f0 [zfs]
[15363.672759] [] ? snprintf+0x34/0x40
[15363.672791] [] spa_load+0x9fb/0x19f0 [zfs]
[15363.672823] [] ? txg_list_create+0x2e/0x60 [zfs]
[15363.672854] [] spa_load_best+0x4e/0x250 [zfs]
[15363.672886] [] spa_open_common+0x13f/0x340 [zfs]
[15363.672917] [] spa_open+0x13/0x20 [zfs]
[15363.672948] [] dsl_dir_open_spa+0x4d3/0x610 [zfs]
[15363.672953] [] ? __switch_to+0x288/0x360
[15363.672956] [] ? __schedule+0x3cc/0x6f0
[15363.672988] [] ? _fini+0x100/0x100 [zfs]
[15363.673017] [] dmu_objset_find_spa+0x56/0x4b0 [zfs]
[15363.673021] [] ? __kmalloc+0x13d/0x190
[15363.673025] [] ? kobj_map+0x80/0x1b0
[15363.673056] [] ? __zvol_create_minor+0x570/0x570 [zfs]
[15363.673058] [] ? mutex_lock+0x1d/0x50
[15363.673061] [] ? kobj_map+0x181/0x1b0
[15363.673090] [] ? zvol_replay_write+0xe0/0xe0 [zfs]
[15363.673121] [] ? _fini+0x100/0x100 [zfs]
[15363.673150] [] zvol_create_minors+0xb1/0xe0 [zfs]
[15363.673154] [] ? blk_register_region+0x2b/0x30
[15363.673184] [] zvol_init+0xd3/0x110 [zfs]
[15363.673214] [] _init+0x22/0x130 [zfs]
[15363.673244] [] spl__init+0x13/0x20 [zfs]
[15363.673248] [] do_one_initcall+0x40/0x180
[15363.673252] [] sys_init_module+0xbe/0x230
[15363.673255] [] system_call_fastpath+0x16/0x1b
[15363.673258] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15363.673260] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15363.673262] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15363.673265] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15363.673269] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15363.673272] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15363.673276] Call Trace:
[15363.673278] [] schedule+0x3f/0x60
[15363.673281] [] __mutex_lock_slowpath+0xd7/0x150
[15363.673307] [] ? l2arc_evict+0x310/0x310 [zfs]
[15363.673334] [] ? l2arc_evict+0x310/0x310 [zfs]
[15363.673336] [] mutex_lock+0x2a/0x50
[15363.673362] [] ? l2arc_evict+0x310/0x310 [zfs]
[15363.673389] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15363.673392] [] ? kfree+0x114/0x140
[15363.673398] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15363.673424] [] ? l2arc_evict+0x310/0x310 [zfs]
[15363.673430] [] thread_generic_wrapper+0x78/0x90 [spl]
[15363.673436] [] ? __thread_create+0x310/0x310 [spl]
[15363.673439] [] kthread+0x8c/0xa0
[15363.673442] [] kernel_thread_helper+0x4/0x10
[15363.673444] [] ? flush_kthread_worker+0xa0/0xa0
[15363.673447] [] ? gs_change+0x13/0x13
[15483.672125] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15483.672128] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15483.672131] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15483.672136] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15483.672141] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15483.672146] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15483.672150] Call Trace:
[15483.672158] [] schedule+0x3f/0x60
[15483.672162] [] __mutex_lock_slowpath+0xd7/0x150
[15483.672206] [] ? l2arc_evict+0x310/0x310 [zfs]
[15483.672239] [] ? l2arc_evict+0x310/0x310 [zfs]
[15483.672243] [] mutex_lock+0x2a/0x50
[15483.672275] [] ? l2arc_evict+0x310/0x310 [zfs]
[15483.672308] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15483.672314] [] ? kfree+0x114/0x140
[15483.672324] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15483.672357] [] ? l2arc_evict+0x310/0x310 [zfs]
[15483.672364] [] thread_generic_wrapper+0x78/0x90 [spl]
[15483.672372] [] ? __thread_create+0x310/0x310 [spl]
[15483.672376] [] kthread+0x8c/0xa0
[15483.672380] [] kernel_thread_helper+0x4/0x10
[15483.672384] [] ? flush_kthread_worker+0xa0/0xa0
[15483.672387] [] ? gs_change+0x13/0x13
[15603.672121] INFO: task modprobe:22025 blocked for more than 120 seconds.
[15603.672124] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15603.672127] modprobe D ffffffff81806240 0 22025 1 0x00000004
[15603.672132] ffff880130a93468 0000000000000082 0000000000000001 ffff880080a61ae8
[15603.672137] ffff880130a93fd8 ffff880130a93fd8 ffff880130a93fd8 00000000000137c0
[15603.672142] ffff88022e169700 ffff880225cf8000 ffff880130a93478 ffff880080a61b20
[15603.672147] Call Trace:
[15603.672155] [] schedule+0x3f/0x60
[15603.672168] [] cv_wait_common+0xfd/0x1b0 [spl]
[15603.672173] [] ? add_wait_queue+0x60/0x60
[15603.672181] [] __cv_wait+0x15/0x20 [spl]
[15603.672234] [] txg_wait_open+0x8b/0x110 [zfs]
[15603.672271] [] dmu_tx_wait+0xed/0xf0 [zfs]
[15603.672308] [] dmu_tx_assign+0x86/0x460 [zfs]
[15603.672343] [] dmu_free_object+0xac/0x100 [zfs]
[15603.672379] [] ? dmu_object_next+0x43/0x60 [zfs]
[15603.672417] [] dsl_dataset_destroy+0x18d/0x4d0 [zfs]
[15603.672455] [] dsl_destroy_inconsistent+0x56/0x60 [zfs]
[15603.672491] [] findfunc+0x12/0x20 [zfs]
[15603.672527] [] dmu_objset_find_spa+0x104/0x4b0 [zfs]
[15603.672531] [] ? kvasprintf+0x70/0x90
[15603.672567] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15603.672603] [] dmu_objset_find_spa+0x1ab/0x4b0 [zfs]
[15603.672639] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15603.672675] [] dmu_objset_find_spa+0x1ab/0x4b0 [zfs]
[15603.672679] [] ? mutex_lock+0x1d/0x50
[15603.672715] [] ? dmu_objset_userspace_present+0x20/0x20 [zfs]
[15603.672754] [] ? vdev_resilver_needed+0x59/0x160 [zfs]
[15603.672791] [] dmu_objset_find+0x2d/0x30 [zfs]
[15603.672828] [] ? dsl_dataset_destroy+0x4d0/0x4d0 [zfs]
[15603.672867] [] spa_load+0x16e8/0x19f0 [zfs]
[15603.672872] [] ? snprintf+0x34/0x40
[15603.672911] [] spa_load+0x9fb/0x19f0 [zfs]
[15603.672951] [] ? txg_list_create+0x2e/0x60 [zfs]
[15603.672990] [] spa_load_best+0x4e/0x250 [zfs]
[15603.673030] [] spa_open_common+0x13f/0x340 [zfs]
[15603.673069] [] spa_open+0x13/0x20 [zfs]
[15603.673108] [] dsl_dir_open_spa+0x4d3/0x610 [zfs]
[15603.673112] [] ? __switch_to+0x288/0x360
[15603.673117] [] ? __schedule+0x3cc/0x6f0
[15603.673157] [] ? _fini+0x100/0x100 [zfs]
[15603.673193] [] dmu_objset_find_spa+0x56/0x4b0 [zfs]
[15603.673197] [] ? __kmalloc+0x13d/0x190
[15603.673202] [] ? kobj_map+0x80/0x1b0
[15603.673240] [] ? __zvol_create_minor+0x570/0x570 [zfs]
[15603.673243] [] ? mutex_lock+0x1d/0x50
[15603.673246] [] ? kobj_map+0x181/0x1b0
[15603.673283] [] ? zvol_replay_write+0xe0/0xe0 [zfs]
[15603.673321] [] ? _fini+0x100/0x100 [zfs]
[15603.673359] [] zvol_create_minors+0xb1/0xe0 [zfs]
[15603.673363] [] ? blk_register_region+0x2b/0x30
[15603.673400] [] zvol_init+0xd3/0x110 [zfs]
[15603.673438] [] _init+0x22/0x130 [zfs]
[15603.673476] [] spl__init+0x13/0x20 [zfs]
[15603.673480] [] do_one_initcall+0x40/0x180
[15603.673484] [] sys_init_module+0xbe/0x230
[15603.673488] [] system_call_fastpath+0x16/0x1b
[15603.673492] INFO: task l2arc_feed:22032 blocked for more than 120 seconds.
[15603.673494] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[15603.673496] l2arc_feed D ffffffff81806240 0 22032 2 0x00000000
[15603.673501] ffff880046863d10 0000000000000046 ffff880046863cb0 ffffffffa058eb80
[15603.673505] ffff880046863fd8 ffff880046863fd8 ffff880046863fd8 00000000000137c0
[15603.673510] ffff88022e169700 ffff88009cf4c500 ffff880046863d10 ffffffffa0590e80
[15603.673514] Call Trace:
[15603.673517] [] schedule+0x3f/0x60
[15603.673520] [] __mutex_lock_slowpath+0xd7/0x150
[15603.673554] [] ? l2arc_evict+0x310/0x310 [zfs]
[15603.673586] [] ? l2arc_evict+0x310/0x310 [zfs]
[15603.673590] [] mutex_lock+0x2a/0x50
[15603.673622] [] ? l2arc_evict+0x310/0x310 [zfs]
[15603.673655] [] l2arc_feed_thread+0xaa/0x850 [zfs]
[15603.673659] [] ? kfree+0x114/0x140
[15603.673667] [] ? kmem_free_debug+0x4b/0x150 [spl]
[15603.673699] [] ? l2arc_evict+0x310/0x310 [zfs]
[15603.673707] [] thread_generic_wrapper+0x78/0x90 [spl]
[15603.673714] [] ? __thread_create+0x310/0x310 [spl]
[15603.673717] [] kthread+0x8c/0xa0
[15603.673721] [] kernel_thread_helper+0x4/0x10
[15603.673724] [] ? flush_kthread_worker+0xa0/0xa0
[15603.673728] [] ? gs_change+0x13/0x13

behlendorf added a commit to openzfs/spl that referenced this issue Jan 29, 2013
Cache aging was implemented because it was part of the default Solaris
kmem_cache behavior.  The idea is that per-cpu objects which haven't been
accessed in several seconds should be returned to the cache.  On the other
hand Linux slabs never move objects back to the slabs unless there is
memory pressure on the system.

This behavior is now configurable through the 'spl_kmem_cache_expire'
module option.  The value is a bit mask with the following meaning.

  0x1 - Solaris style cache aging eviction is enabled.
  0x2 - Linux style low memory eviction is enabled.

Both methods may be safely enabled simultaneously, but by default
both are disabled.  It has never been clear if the kmem cache aging
(which has been around from day one) actually does any good.  It has
however been the source of numerous bugs so I wouldn't mind retiring
it entirely.

Signed-off-by: Brian Behlendorf <behlendorf1@llnl.gov>
Closes openzfs/zfs#1227
Closes #210
@behlendorf
Copy link
Contributor

@wrouesnel OK, the expected fixes have been merged in to master. If you want to give it a try you'll need to update both the spl and zfs to the latest master source.

@gwlcinphilly
Copy link

Hello,

I am new to here. have similar issue on my machine. Can you check if it is same issue?

NSF not response in random time (max healthy time is 1 day), Basically no io activity when zpool stop response. I have to reset machine to bring everything up.

Thanks

setup info:
memory is 16G
AMD 6core
Linux mirror 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
ZFS: Loaded module v0.6.1-rc14, ZFS pool version 5000, ZFS filesystem version 5

Apr 7 05:50:43 mirror kernel: [83348.432001] CPU 4
Apr 7 05:50:43 mirror kernel: [83348.432001] Modules linked in: nfs fscache ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables kvm_amd kvm nfsd lockd nfs_acl auth_rpcgss sunrpc snd_hda_codec_hdmi bridge stp sp5100_tco snd_hda_codec_realtek serio_raw k10temp edac_core edac_mce_amd dm_multipath i2c_piix4 snd_hda_intel snd_hda_codec mac_hid snd_hwdep snd_pcm snd_timer radeon snd soundcore snd_page_alloc asus_atk0110 ttm drm_kms_helper drm i2c_algo_bit wmi shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate firewire_ohci firewire_core crc_itu_t sata_sil sata_sil24 r8169 pata_jmicron pata_atiixp usb_storage
Apr 7 05:50:43 mirror kernel: [83348.432001]
Apr 7 05:50:43 mirror kernel: [83348.432001] Pid: 2390, comm: z_wr_iss/4 Tainted: P O 3.2.0-23-generic #36-Ubuntu System manufacturer System Product Name/M4A89GTD-PRO/USB3
Apr 7 05:50:43 mirror kernel: [83348.432001] RIP: 0010:[] [] zap_leaf_lookup+0xbf/0x150 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] RSP: 0018:ffff8803eaae3980 EFLAGS: 00000283
Apr 7 05:50:43 mirror kernel: [83348.432001] RAX: 0000000000000012 RBX: ffff8803eaae3920 RCX: 0000000000000007
Apr 7 05:50:43 mirror kernel: [83348.432001] RDX: 0000000000000080 RSI: 1d983caef74c0000 RDI: 00000000ecc1e577
Apr 7 05:50:43 mirror kernel: [83348.432001] RBP: ffff8803eaae39d0 R08: 0000000000000001 R09: ffffc90298789162
Apr 7 05:50:43 mirror kernel: [83348.432001] R10: 0000000000000000 R11: 0000000000000001 R12: ffff8803eaae3900
Apr 7 05:50:43 mirror kernel: [83348.432001] R13: 0000000000000000 R14: 0000000000000000 R15: ffff8801ae915358
Apr 7 05:50:43 mirror kernel: [83348.432001] FS: 00007f42a57fa700(0000) GS:ffff88041fd00000(0000) knlGS:0000000000000000
Apr 7 05:50:43 mirror kernel: [83348.432001] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Apr 7 05:50:43 mirror kernel: [83348.432001] CR2: 00000000b77f0000 CR3: 0000000001c05000 CR4: 00000000000006e0
Apr 7 05:50:43 mirror kernel: [83348.432001] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Apr 7 05:50:43 mirror kernel: [83348.432001] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Apr 7 05:50:43 mirror kernel: [83348.432001] Process z_wr_iss/4 (pid: 2390, threadinfo ffff8803eaae2000, task ffff8803f170c4d0)
Apr 7 05:50:43 mirror kernel: [83348.432001] Stack:
Apr 7 05:50:43 mirror kernel: [83348.432001] ffff8803eaae3a18 ffffffffa013b100 ffff8803eaae39d0 ffff8803eaae39f0
Apr 7 05:50:43 mirror kernel: [83348.432001] ffff8803eaae3a00 ffff88011c2d3800 ffff8803eaae3ac0 ffff8803eaae3ac8
Apr 7 05:50:43 mirror kernel: [83348.432001] ffff8803eaae3ac0 ffffffffa013b100 ffff8803eaae3a40 ffffffffa0197bd0
Apr 7 05:50:43 mirror kernel: [83348.432001] Call Trace:
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] fzap_length+0x60/0xa0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zap_length_uint64+0x84/0xb0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ddt_zap_lookup+0x69/0xe0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ddt_lookup+0xec/0x1b0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? SHA256Transform+0x16a/0x220 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? zio_checksum_SHA256+0x178/0x210 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zio_ddt_write+0x67/0x490 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? mutex_lock+0x1d/0x50
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zio_execute+0xba/0x140 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] taskq_thread+0x236/0x4b0 [spl]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? try_to_wake_up+0x200/0x200
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? task_done+0x160/0x160 [spl]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] kthread+0x8c/0xa0
Apr 7 05:50:43 mirror kernel: [83348.432001] [] kernel_thread_helper+0x4/0x10
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? flush_kthread_worker+0xa0/0xa0
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? gs_change+0x13/0x13
Apr 7 05:50:43 mirror kernel: [83348.432001] Code: 41 8b 56 30 4c 8d 4b 02 49 8b 77 30 8d 4a fb 0f b7 c0 44 89 c2 48 8d 04 40 d3 e2 48 63 d2 4c 8d 6c 82 18 4b 8d 1c 6c 48 39 73 10 <75> bf 0f b7 4b 06 0f b7 53 04 4c 89 fe 4c 89 f7 44 89 45 b8 4c
Apr 7 05:50:43 mirror kernel: [83348.432001] Call Trace:
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] fzap_length+0x60/0xa0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zap_length_uint64+0x84/0xb0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ddt_zap_lookup+0x69/0xe0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? ddt_zap_prefetch+0x20/0x20 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ddt_lookup+0xec/0x1b0 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? SHA256Transform+0x16a/0x220 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? zio_checksum_SHA256+0x178/0x210 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zio_ddt_write+0x67/0x490 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? mutex_lock+0x1d/0x50
Apr 7 05:50:43 mirror kernel: [83348.432001] [] zio_execute+0xba/0x140 [zfs]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] taskq_thread+0x236/0x4b0 [spl]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? try_to_wake_up+0x200/0x200
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? task_done+0x160/0x160 [spl]
Apr 7 05:50:43 mirror kernel: [83348.432001] [] kthread+0x8c/0xa0
Apr 7 05:50:43 mirror kernel: [83348.432001] [] kernel_thread_helper+0x4/0x10
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? flush_kthread_worker+0xa0/0xa0
Apr 7 05:50:43 mirror kernel: [83348.432001] [] ? gs_change+0x13/0x13
Apr 7 05:51:11 mirror kernel: [83376.428030] BUG: soft lockup - CPU#4 stuck for 23s! [z_wr_iss/4:2390]
Apr 7 05:51:11 mirror kernel: [83376.432001] Modules linked in: nfs fscache ip6table_filter ip6_tables ebtable_nat ebtables ipt_MASQUERADE iptable_nat nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack ipt_REJECT xt_CHECKSUM iptable_mangle xt_tcpudp iptable_filter ip_tables x_tables kvm_amd kvm nfsd lockd nfs_acl auth_rpcgss sunrpc snd_hda_codec_hdmi bridge stp sp5100_tco snd_hda_codec_realtek serio_raw k10temp edac_core edac_mce_amd dm_multipath i2c_piix4 snd_hda_intel snd_hda_codec mac_hid snd_hwdep snd_pcm snd_timer radeon snd soundcore snd_page_alloc asus_atk0110 ttm drm_kms_helper drm i2c_algo_bit wmi shpchp lp parport zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate firewire_ohci firewire_core crc_itu_t sata_sil sata_sil24 r8169 pata_jmicron pata_atiixp usb_storage

@behlendorf
Copy link
Contributor

The original cause of these issues was resolved in the master source. This issue has also been muddled by a few different problem reports so I'm closing this issue. If there are still issues in this area let's open a new issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants