On 12/20/2016 1:47 PM, Daniel Borkmann wrote:
Hi Shahar,

On 12/20/2016 07:22 AM, Shahar Klein wrote:
On 12/19/2016 7:58 PM, Cong Wang wrote:
On Mon, Dec 19, 2016 at 8:39 AM, Shahar Klein <shah...@mellanox.com>
wrote:
On 12/13/2016 12:51 AM, Cong Wang wrote:

On Mon, Dec 12, 2016 at 1:18 PM, Or Gerlitz <gerlitz...@gmail.com>
wrote:

On Mon, Dec 12, 2016 at 3:28 PM, Daniel Borkmann
<dan...@iogearbox.net>
wrote:

Note that there's still the RCU fix missing for the deletion race
that
Cong will still send out, but you say that the only thing you do
is to
add a single rule, but no other operation in involved during that
test?

What's missing to have the deletion race fixed? making a patch or
testing to a patch which was sent?

If you think it would help for this problem, here is my patch rebased
on the latest net-next.

Again, I don't see how it could help this case yet, especially I don't
see how we could have a loop in this singly linked list.

I've applied cong's patch and hit a different lockup(full log
attached):

Are you sure this is really different? For me, it is still inside the
loop
in tc_classify(), with only a slightly different offset.


Daniel suggested I'll add a print:
                case RTM_DELTFILTER:
-                   err = tp->ops->delete(tp, fh);
+                 printk(KERN_ERR "DEBUGG:SK %s:%d\n", __func__,
__LINE__);
+                 err = tp->ops->delete(tp, fh, &last);
                        if (err == 0) {

and I couldn't see this print in the output.....

Hmm, that is odd, if this never prints, then my patch should not make
any
difference.

There are still two other cases where we could change tp->next, so do
you
mind to add two more printk's for debugging?

Attached is the delta patch.

Thanks!

I've added a slightly different debug print:
@@ -368,11 +375,12 @@ static int tc_ctl_tfilter(struct sk_buff *skb,
struct nlmsghdr *n)
                 if (tp_created) {
                         RCU_INIT_POINTER(tp->next,
rtnl_dereference(*back));
                         rcu_assign_pointer(*back, tp);
+                 printk(KERN_ERR "DEBUGG:SK add/change filter by: %pf
tp=%p tp->next=%p\n", tp->ops->get, tp, tp->next);
                 }
                 tfilter_notify(net, skb, n, tp, fh, RTM_NEWTFILTER,
false);

I'm curious, could you be a bit more verbose why you didn't go with Cong's
debug patch?

In particular, why you removed the hunk from the condition
'n->nlmsg_type ==
RTM_DELTFILTER && t->tcm_handle == 0' where we delete the whole tp
instance?

I didn't remove this hunk, just added more. anyway I'm attaching the diff to make sure I didn't miss anything.
I've added some more prints in the destroy and added some current info
run log attached also


Is it because if you have that printk() there, then the issue doesn't
trigger
for you anymore? Or any other reason?

How many CPUs does your test machine have, I suspect more than 1, right?

So iff RTM_DELTFILTER with tcm_handle of 0 really played a role in this,
I'm
wondering whether there was a subtle deletion + add race where the newly
added
filter on the other CPU still saw a stale pointer in the list. But just
a wild
guess at this point.

Hmm, could you try this below to see whether the issue still appears?

Thanks,
Daniel

diff --git a/net/sched/cls_api.c b/net/sched/cls_api.c
index 3fbba79..4eee1cb 100644
--- a/net/sched/cls_api.c
+++ b/net/sched/cls_api.c
@@ -317,7 +317,7 @@ static int tc_ctl_tfilter(struct sk_buff *skb,
struct nlmsghdr *n)
         if (n->nlmsg_type == RTM_DELTFILTER && t->tcm_handle == 0) {
             struct tcf_proto *next = rtnl_dereference(tp->next);

-            RCU_INIT_POINTER(*back, next);
+            rcu_assign_pointer(*back, next);

             tfilter_notify(net, skb, n, tp, fh,
                        RTM_DELTFILTER, false);



Tried it with same results

full output attached:

[  283.290271] Mirror/redirect action on
[  283.305031] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9432d704df60 tp->next=          (null)
[  283.322563] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d240 tp->next=          (null)
[  283.359997] GACT probability on
[  283.365923] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d3c0 tp->next=ffff9436e718d240
[  283.378725] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d3c0 tp->next=ffff9436e718d3c0
[  283.391310] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d3c0 tp->next=ffff9436e718d3c0
[  283.403923] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d3c0 tp->next=ffff9436e718d3c0
[  283.416542] DEBUGG:SK add/change filter by: fl_get [cls_flower]
tp=ffff9436e718d3c0 tp->next=ffff9436e718d3c0
[  308.538571] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 23s!
[swapper/0:0]

Thanks
Shahar
diff --git a/net/sched/cls_api.c b/net/sched/cls_api.c
index 3fbba79..1b31fc9 100644
--- a/net/sched/cls_api.c
+++ b/net/sched/cls_api.c
@@ -305,7 +305,7 @@ static int tc_ctl_tfilter(struct sk_buff *skb, struct 
nlmsghdr *n)
                        kfree(tp);
                        goto errout;
                }
-
+               printk(KERN_ERR "DEBUGG:SK thread-%d[cpu-%d] setting tp_created 
to 1 tp=%p back=%p\n", current->pid, current->on_cpu, tp, 
rtnl_dereference(*back));
                tp_created = 1;
 
        } else if (tca[TCA_KIND] && nla_strcmp(tca[TCA_KIND], tp->ops->kind))
@@ -317,11 +317,13 @@ static int tc_ctl_tfilter(struct sk_buff *skb, struct 
nlmsghdr *n)
                if (n->nlmsg_type == RTM_DELTFILTER && t->tcm_handle == 0) {
                        struct tcf_proto *next = rtnl_dereference(tp->next);
 
-                       RCU_INIT_POINTER(*back, next);
+                       printk(KERN_ERR "DEBUGG:SK delete filter by: %pf\n", 
tp->ops->get);
+
+                       rcu_assign_pointer(*back, next);
 
                        tfilter_notify(net, skb, n, tp, fh,
                                       RTM_DELTFILTER, false);
-                       tcf_destroy(tp, true);
+                       tcf_destroy(tp);
                        err = 0;
                        goto errout;
                }
@@ -331,25 +333,30 @@ static int tc_ctl_tfilter(struct sk_buff *skb, struct 
nlmsghdr *n)
                    !(n->nlmsg_flags & NLM_F_CREATE))
                        goto errout;
        } else {
+               bool last;
+
                switch (n->nlmsg_type) {
                case RTM_NEWTFILTER:
                        err = -EEXIST;
                        if (n->nlmsg_flags & NLM_F_EXCL) {
                                if (tp_created)
-                                       tcf_destroy(tp, true);
+                                       tcf_destroy(tp);
                                goto errout;
                        }
                        break;
                case RTM_DELTFILTER:
-                       err = tp->ops->delete(tp, fh);
+                       printk(KERN_ERR "DEBUGG:SK %s:%d\n", __func__, 
__LINE__);
+                       err = tp->ops->delete(tp, fh, &last);
                        if (err == 0) {
-                               struct tcf_proto *next = 
rtnl_dereference(tp->next);
-
                                tfilter_notify(net, skb, n, tp,
                                               t->tcm_handle,
                                               RTM_DELTFILTER, false);
-                               if (tcf_destroy(tp, false))
+                               if (last) {
+                                       struct tcf_proto *next = 
rtnl_dereference(tp->next);
+
                                        RCU_INIT_POINTER(*back, next);
+                                       tcf_destroy(tp);
+                               }
                        }
                        goto errout;
                case RTM_GETTFILTER:
@@ -368,11 +375,12 @@ static int tc_ctl_tfilter(struct sk_buff *skb, struct 
nlmsghdr *n)
                if (tp_created) {
                        RCU_INIT_POINTER(tp->next, rtnl_dereference(*back));
                        rcu_assign_pointer(*back, tp);
+                       printk(KERN_ERR "DEBUGG:SK thread-%d[cpu-%d] add/change 
filter by: %pf tp=%p tp->next=%p\n", current->pid, current->on_cpu, 
tp->ops->get, tp, tp->next);
                }
                tfilter_notify(net, skb, n, tp, fh, RTM_NEWTFILTER, false);
        } else {
                if (tp_created)
-                       tcf_destroy(tp, true);
+                       tcf_destroy(tp);
        }
 
 errout:
[  354.117396] DEBUGG:SK tcf_destroy_chain:1915
[  354.123731] DEBUGG:SK tcf_destroy_chain:1915
[  354.128962] DEBUGG:SK tcf_destroy_chain:1915
[  354.134999] DEBUGG:SK tcf_destroy_chain:1915
[  354.145185] DEBUGG:SK tcf_destroy_chain:1915
[  354.155601] DEBUGG:SK tcf_destroy_chain:1915

[  408.197159] DEBUGG:SK thread-2852[cpu-1] setting tp_created to 1 
tp=ffff94b5b669f8a0 back=          (null)
[  408.246733] Mirror/redirect action on
[  408.251498] DEBUGG:SK destroy ffff94b5b669f8a0 tcf_destroy:1905
[  408.258485] DEBUGG:SK thread-2852[cpu-1] setting tp_created to 1 
tp=ffff94b5b669f900 back=          (null)
[  408.280217] DEBUGG:SK thread-2852[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b669f900 tp->next=          (null)
[  408.294257] DEBUGG:SK thread-2858[cpu-1] setting tp_created to 1 
tp=ffff94b5b5de2060 back=          (null)
[  408.305684] DEBUGG:SK thread-2849[cpu-1] setting tp_created to 1 
tp=ffff94b9df4fd420 back=          (null)
[  408.317103] DEBUGG:SK thread-2856[cpu-1] setting tp_created to 1 
tp=ffff94b9ea932060 back=          (null)
[  408.333832] DEBUGG:SK thread-2856[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b9ea932060 tp->next=          (null)
[  408.347806] GACT probability on
[  408.348815] DEBUGG:SK thread-2851[cpu-1] setting tp_created to 1 
tp=ffff94b5bfaab900 back=ffff94b9ea932060
[  408.348841] DEBUGG:SK thread-2854[cpu-1] setting tp_created to 1 
tp=ffff94b5b669fcc0 back=ffff94b9ea932060
[  408.349841] DEBUGG:SK thread-2846[cpu-1] setting tp_created to 1 
tp=ffff94b5b4ea9720 back=ffff94b9ea932060
[  408.349868] DEBUGG:SK thread-2847[cpu-1] setting tp_created to 1 
tp=ffff94b9ec249ea0 back=ffff94b9ea932060
[  408.350880] DEBUGG:SK thread-2848[cpu-1] setting tp_created to 1 
tp=ffff94b9e9542ea0 back=ffff94b9ea932060
[  408.355302] DEBUGG:SK thread-2855[cpu-1] setting tp_created to 1 
tp=ffff94b5b402ca80 back=ffff94b9ea932060
[  408.358941] DEBUGG:SK thread-2844[cpu-1] setting tp_created to 1 
tp=ffff94b5b0280960 back=ffff94b9ea932060
[  408.358962] DEBUGG:SK thread-2852[cpu-1] setting tp_created to 1 
tp=ffff94b9e8e17840 back=ffff94b9ea932060
[  408.358986] DEBUGG:SK thread-2842[cpu-1] setting tp_created to 1 
tp=ffff94b5b5de2f00 back=ffff94b9ea932060
[  408.360920] DEBUGG:SK thread-2850[cpu-1] setting tp_created to 1 
tp=ffff94b5cfe38ea0 back=ffff94b9ea932060
[  408.360940] DEBUGG:SK thread-2857[cpu-1] setting tp_created to 1 
tp=ffff94b5b0280840 back=ffff94b9ea932060
[  408.361827] DEBUGG:SK thread-2856[cpu-1] setting tp_created to 1 
tp=ffff94b9ea9321e0 back=          (null)
[  408.362812] DEBUGG:SK thread-2856[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b9ea9321e0 tp->next=          (null)
[  408.362850] DEBUGG:SK thread-2853[cpu-1] setting tp_created to 1 
tp=ffff94b5b669fea0 back=ffff94b9ea932060
[  408.362895] DEBUGG:SK thread-2845[cpu-1] setting tp_created to 1 
tp=ffff94b5b0280780 back=ffff94b9ea932060
[  408.362904] DEBUGG:SK thread-2856[cpu-1] setting tp_created to 1 
tp=ffff94b9ea9322a0 back=ffff94b9ea932060
[  408.362942] DEBUGG:SK thread-2843[cpu-1] setting tp_created to 1 
tp=ffff94b5b402c960 back=ffff94b9ea932060
[  408.547689] DEBUGG:SK destroy ffff94b5b669fea0 tcf_destroy:1905
[  408.554689] DEBUGG:SK thread-2853[cpu-1] setting tp_created to 1 
tp=ffff94b5b02805a0 back=ffff94b9ea932060
[  408.574258] DEBUGG:SK thread-2853[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b02805a0 tp->next=ffff94b9ea932060
[  408.587849] DEBUGG:SK destroy ffff94b5b0280780 tcf_destroy:1905
[  408.595862] DEBUGG:SK thread-2845[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b02805a0 tp->next=ffff94b5b02805a0
[  408.609476] DEBUGG:SK destroy ffff94b9ec249ea0 tcf_destroy:1905
[  408.617394] DEBUGG:SK thread-2847[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b02805a0 tp->next=ffff94b5b02805a0
[  408.631068] DEBUGG:SK destroy ffff94b9df4fd420 tcf_destroy:1905
[  408.639090] DEBUGG:SK thread-2849[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b02805a0 tp->next=ffff94b5b02805a0
[  408.652656] DEBUGG:SK destroy ffff94b5b5de2060 tcf_destroy:1905
[  408.660530] DEBUGG:SK thread-2858[cpu-1] add/change filter by: fl_get 
[cls_flower] tp=ffff94b5b02805a0 tp->next=ffff94b5b02805a0
[  432.583406] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [CPU 
0/KVM:2574]
[  432.592457] Modules linked in: act_gact act_mirred openvswitch 
nf_conntrack_ipv6 nf_nat_ipv6 nf_defrag_ipv6 vfio_pci vfio_virqfd 
vfio_iommu_type1 vfio cls_flower mlx5_ib mlx5_core devlink sch_ingress nfsv3 
nfs fscache xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 
iptable_nat nf_nat_ipv4 nf_nat libcrc32c nf_conntrack_ipv4 nf_defrag_ipv4 
xt_conntrack nf_conntrack tun ebtable_filter ebtables ip6table_filter 
ip6_tables netconsole rpcrdma ib_isert iscsi_target_mod ib_iser libiscsi 
scsi_transport_iscsi bridge stp ib_srpt llc ib_srp scsi_transport_srp ib_ipoib 
rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_core intel_rapl 
sb_edac edac_core x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass 
crct10dif_pclmul igb joydev crc32_pclmul ipmi_ssif crc32c_intel iTCO_wdt ptp 
ghash_clmulni_intel pps_core iTCO_vendor_support i2c_algo_bit pcspkr ipmi_si 
wmi ipmi_msghandler ioatdma mei_me lpc_ich tpm_tis dca tpm_tis_core mei shpchp 
i2c_i801 i2c_smbus tpm target_core_mod nfsd auth_rpcgss nfs_acl lockd grace 
sunrpc isci libsas serio_raw scsi_transport_sas [last unloaded: devlink]
[  432.714385] CPU: 0 PID: 2574 Comm: CPU 0/KVM Not tainted 4.9.0+ #40
[  432.721734] Hardware name: Supermicro X9DRW/X9DRW, BIOS 3.0a 08/08/2013
[  432.729469] task: ffff94b5b69d3b00 task.stack: ffffad7948840000
[  432.736428] RIP: 0010:tc_classify+0x5a/0x120
[  432.741526] RSP: 0018:ffff94b5efa03c38 EFLAGS: 00000286 ORIG_RAX: 
ffffffffffffff10
[  432.750677] RAX: 00000000ffffffff RBX: ffff94b5b159a100 RCX: 0000000000000000
[  432.758982] RDX: ffff94b5efa03c98 RSI: ffff94b5b02805a0 RDI: ffff94b5b159a100
[  432.767291] RBP: ffff94b5efa03c70 R08: 000000000000270f R09: 0000000000000000
[  432.775603] R10: 0000000000000000 R11: 0000000000000004 R12: ffff94b5efa03c98
[  432.783907] R13: 0000000000000008 R14: ffff94b5b02805a0 R15: 0000000000000001
[  432.792226] FS:  00007f35c1aec700(0000) GS:ffff94b5efa00000(0000) 
knlGS:0000000000000000
[  432.801861] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  432.808626] CR2: 0000562a2a56b0c8 CR3: 000000042c714000 CR4: 00000000000426f0
[  432.816932] Call Trace:
[  432.819993]  <IRQ>
[  432.822580]  __netif_receive_skb_core+0x623/0xa00
[  432.828173]  ? udp4_gro_receive+0x10b/0x2d0
[  432.833189]  __netif_receive_skb+0x18/0x60
[  432.838095]  netif_receive_skb_internal+0x40/0xb0
[  432.843692]  napi_gro_receive+0xcd/0x120
[  432.848425]  mlx5e_handle_rx_cqe_rep+0x61b/0x890 [mlx5_core]
[  432.855103]  ? kvm_irq_delivery_to_apic+0x2c0/0x2c0 [kvm]
[  432.861482]  mlx5e_poll_rx_cq+0x83/0x840 [mlx5_core]
[  432.867373]  mlx5e_napi_poll+0x89/0x480 [mlx5_core]
[  432.873164]  net_rx_action+0x260/0x3c0
[  432.877693]  __do_softirq+0xc9/0x28c
[  432.882020]  irq_exit+0xd7/0xe0
[  432.885855]  do_IRQ+0x51/0xd0
[  432.889506]  common_interrupt+0x93/0x93
[  432.894140] RIP: 0010:kvm_arch_vcpu_ioctl_run+0xa64/0x1590 [kvm]
[  432.896408] NMI watchdog: BUG: soft lockup - CPU#5 stuck for 23s! 
[handler129:2849]
[  432.896436] Modules linked in: act_gact act_mirred openvswitch 
nf_conntrack_ipv6 nf_nat_ipv6 nf_defrag_ipv6 vfio_pci vfio_virqfd 
vfio_iommu_type1 vfio cls_flower mlx5_ib mlx5_core devlink sch_ingress nfsv3 
nfs fscache xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 
iptable_nat nf_nat_ipv4 nf_nat libcrc32c nf_conntrack_ipv4 nf_defrag_ipv4 
xt_conntrack nf_conntrack tun ebtable_filter ebtables ip6table_filter 
ip6_tables netconsole rpcrdma ib_isert iscsi_target_mod ib_iser libiscsi 
scsi_transport_iscsi bridge stp ib_srpt llc ib_srp scsi_transport_srp ib_ipoib 
rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_core intel_rapl 
sb_edac edac_core x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass 
crct10dif_pclmul igb joydev crc32_pclmul ipmi_ssif crc32c_intel iTCO_wdt ptp 
ghash_clmulni_intel
[  432.896448]  pps_core iTCO_vendor_support i2c_algo_bit pcspkr ipmi_si wmi 
ipmi_msghandler ioatdma mei_me lpc_ich tpm_tis dca tpm_tis_core mei shpchp 
i2c_i801 i2c_smbus tpm target_core_mod nfsd auth_rpcgss nfs_acl lockd grace 
sunrpc isci libsas serio_raw scsi_transport_sas [last unloaded: devlink]
[  432.896450] CPU: 5 PID: 2849 Comm: handler129 Not tainted 4.9.0+ #40
[  432.896451] Hardware name: Supermicro X9DRW/X9DRW, BIOS 3.0a 08/08/2013
[  432.896452] task: ffff94b5c1870000 task.stack: ffffad7944bb4000
[  432.896456] RIP: 0010:tc_ctl_tfilter+0x1cc/0x8c0
[  432.896458] RSP: 0018:ffffad7944bb7a88 EFLAGS: 00000286 ORIG_RAX: 
ffffffffffffff10
[  432.896459] RAX: 0000000000020000 RBX: ffff94b5b02805a0 RCX: 000000000000002c
[  432.896459] RDX: ffff94b9e3729400 RSI: 0000000000000000 RDI: ffff94b5c0663400
[  432.896460] RBP: ffffad7944bb7b88 R08: 0000000000000000 R09: ffffad7944bb7af8
[  432.896461] R10: ffff94b5b02805a0 R11: 00000000ffffffea R12: ffff94b5c0663400
[  432.896462] R13: 00000000ffff0000 R14: ffff94b5e7e9c800 R15: 0000000000030000
[  432.896463] FS:  00007f08c93cb700(0000) GS:ffff94b5efb40000(0000) 
knlGS:0000000000000000
[  432.896464] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  432.896465] CR2: 00007f08b80200a8 CR3: 000000085dfad000 CR4: 00000000000426e0
[  432.896465] Call Trace:
[  432.896470]  ? ns_capable+0x13/0x20
[  432.896475]  rtnetlink_rcv_msg+0xa4/0x230
[  432.896478]  ? __kmalloc_node_track_caller+0x191/0x290
[  432.896481]  ? __alloc_skb+0x8d/0x2b0
[  432.896483]  ? rtnl_newlink+0x870/0x870
[  432.896486]  netlink_rcv_skb+0xa7/0xc0
[  432.896488]  rtnetlink_rcv+0x28/0x30
[  432.896490]  netlink_unicast+0x181/0x240
[  432.896491]  netlink_sendmsg+0x32e/0x3b0
[  432.896495]  sock_sendmsg+0x38/0x50
[  432.896496]  ___sys_sendmsg+0x279/0x290
[  432.896500]  ? task_numa_fault+0x7e5/0xa90
[  432.896502]  ? migrate_misplaced_page+0x169/0x240
[  432.896506]  ? handle_mm_fault+0xa0d/0x1520
[  432.896510]  ? __fget_light+0x25/0x60
[  432.896512]  __sys_sendmsg+0x54/0x90
[  432.896514]  SyS_sendmsg+0x12/0x20
[  432.896516]  entry_SYSCALL_64_fastpath+0x1a/0xa9
[  432.896518] RIP: 0033:0x7f08cd4fc2fd
[  432.896519] RSP: 002b:00007f08c938c110 EFLAGS: 00000293 ORIG_RAX: 
000000000000002e
[  432.896520] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f08cd4fc2fd
[  432.896520] RDX: 0000000000000000 RSI: 00007f08c938c170 RDI: 000000000000000e
[  432.896521] RBP: 00007f08b801e8d0 R08: 0000000000008000 R09: 00007f08b8000158
[  432.896522] R10: 00007f08b8020610 R11: 0000000000000293 R12: 000000000000003f
[  432.896522] R13: 0000564e0421ea18 R14: 00007f08b801e8f8 R15: 00007f08c93ca388
[  432.896538] Code: b5 58 ff ff ff 4c 89 e7 ff d0 48 85 c0 49 89 c2 41 bb ea 
ff ff ff 74 48 41 0f b7 4e 04 48 8b 18 66 83 f9 2d 75 17 e9 64 02 00 00 <8b> 43 
1c 41 39 c7 0f 86 8c 00 00 00 49 89 da 48 8b 1b 48 85 db 
[  432.896540] Kernel panic - not syncing: softlockup: hung tasks
[  432.896541] CPU: 5 PID: 2849 Comm: handler129 Tainted: G             L  
4.9.0+ #40
[  432.896542] Hardware name: Supermicro X9DRW/X9DRW, BIOS 3.0a 08/08/2013
[  432.896542] Call Trace:
[  432.896543]  <IRQ>
[  432.896546]  dump_stack+0x63/0x8c
[  432.896549]  panic+0xeb/0x239
[  432.896552]  watchdog_timer_fn+0x1e5/0x1f0
[  432.896554]  ? watchdog+0x40/0x40
[  432.896557]  __hrtimer_run_queues+0xee/0x270
[  432.896558]  hrtimer_interrupt+0xa8/0x190
[  432.896563]  local_apic_timer_interrupt+0x35/0x60
[  432.896565]  smp_apic_timer_interrupt+0x38/0x50
[  432.896566]  apic_timer_interrupt+0x93/0xa0
[  432.896568] RIP: 0010:tc_ctl_tfilter+0x1cc/0x8c0
[  432.896569] RSP: 0018:ffffad7944bb7a88 EFLAGS: 00000286 ORIG_RAX: 
ffffffffffffff10
[  432.896569] RAX: 0000000000020000 RBX: ffff94b5b02805a0 RCX: 000000000000002c
[  432.896570] RDX: ffff94b9e3729400 RSI: 0000000000000000 RDI: ffff94b5c0663400
[  432.896571] RBP: ffffad7944bb7b88 R08: 0000000000000000 R09: ffffad7944bb7af8
[  432.896572] R10: ffff94b5b02805a0 R11: 00000000ffffffea R12: ffff94b5c0663400
[  432.896573] R13: 00000000ffff0000 R14: ffff94b5e7e9c800 R15: 0000000000030000
[  432.896573]  </IRQ>
[  432.896575]  ? tc_ctl_tfilter+0x1ab/0x8c0
[  432.896577]  ? ns_capable+0x13/0x20
[  432.896579]  rtnetlink_rcv_msg+0xa4/0x230
[  432.896580]  ? __kmalloc_node_track_caller+0x191/0x290
[  432.896581]  ? __alloc_skb+0x8d/0x2b0
[  432.896583]  ? rtnl_newlink+0x870/0x870
[  432.896585]  netlink_rcv_skb+0xa7/0xc0
[  432.896586]  rtnetlink_rcv+0x28/0x30
[  432.896588]  netlink_unicast+0x181/0x240
[  432.896590]  netlink_sendmsg+0x32e/0x3b0
[  432.896592]  sock_sendmsg+0x38/0x50
[  432.896593]  ___sys_sendmsg+0x279/0x290
[  432.896594]  ? task_numa_fault+0x7e5/0xa90
[  432.896596]  ? migrate_misplaced_page+0x169/0x240
[  432.896597]  ? handle_mm_fault+0xa0d/0x1520
[  432.896599]  ? __fget_light+0x25/0x60
[  432.896601]  __sys_sendmsg+0x54/0x90
[  432.896603]  SyS_sendmsg+0x12/0x20
[  432.896605]  entry_SYSCALL_64_fastpath+0x1a/0xa9
[  432.896605] RIP: 0033:0x7f08cd4fc2fd
[  432.896606] RSP: 002b:00007f08c938c110 EFLAGS: 00000293 ORIG_RAX: 
000000000000002e
[  432.896607] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f08cd4fc2fd
[  432.896607] RDX: 0000000000000000 RSI: 00007f08c938c170 RDI: 000000000000000e
[  432.896608] RBP: 00007f08b801e8d0 R08: 0000000000008000 R09: 00007f08b8000158
[  432.896609] R10: 00007f08b8020610 R11: 0000000000000293 R12: 000000000000003f
[  432.896609] R13: 0000564e0421ea18 R14: 00007f08b801e8f8 R15: 00007f08c93ca388
[  432.900868] ------------[ cut here ]------------
[  432.900872] WARNING: CPU: 0 PID: 2574 at arch/x86/kernel/smp.c:127 
native_smp_send_reschedule+0x3f/0x50
[  432.900893] Modules linked in: act_gact act_mirred openvswitch 
nf_conntrack_ipv6 nf_nat_ipv6 nf_defrag_ipv6 vfio_pci vfio_virqfd 
vfio_iommu_type1 vfio cls_flower mlx5_ib mlx5_core devlink sch_ingress nfsv3 
nfs fscache xt_CHECKSUM iptable_mangle ipt_MASQUERADE nf_nat_masquerade_ipv4 
iptable_nat nf_nat_ipv4 nf_nat libcrc32c nf_conntrack_ipv4 nf_defrag_ipv4 
xt_conntrack nf_conntrack tun ebtable_filter ebtables ip6table_filter 
ip6_tables netconsole rpcrdma ib_isert iscsi_target_mod ib_iser libiscsi 
scsi_transport_iscsi bridge stp ib_srpt llc ib_srp scsi_transport_srp ib_ipoib 
rdma_ucm ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_core intel_rapl 
sb_edac edac_core x86_pkg_temp_thermal coretemp kvm_intel kvm irqbypass 
crct10dif_pclmul igb joydev crc32_pclmul ipmi_ssif crc32c_intel iTCO_wdt ptp 
ghash_clmulni_intel
[  432.900902]  pps_core iTCO_vendor_support i2c_algo_bit pcspkr ipmi_si wmi 
ipmi_msghandler ioatdma mei_me lpc_ich tpm_tis dca tpm_tis_core mei shpchp 
i2c_i801 i2c_smbus tpm target_core_mod nfsd auth_rpcgss nfs_acl lockd grace 
sunrpc isci libsas serio_raw scsi_transport_sas [last unloaded: devlink]
[  432.900904] CPU: 0 PID: 2574 Comm: CPU 0/KVM Tainted: G             L  
4.9.0+ #40
[  432.900905] Hardware name: Supermicro X9DRW/X9DRW, BIOS 3.0a 08/08/2013
[  432.900905] Call Trace:
[  432.900906]  <IRQ>
[  432.900909]  dump_stack+0x63/0x8c
[  432.900911]  __warn+0xd1/0xf0
[  432.900913]  warn_slowpath_null+0x1d/0x20
[  432.900914]  native_smp_send_reschedule+0x3f/0x50
[  432.900917]  try_to_wake_up+0x312/0x390
[  432.900919]  default_wake_function+0x12/0x20
[  432.900921]  pollwake+0x73/0x90
[  432.900922]  ? wake_up_q+0x80/0x80
[  432.900926]  __wake_up_common+0x55/0x90
[  432.900928]  __wake_up_sync_key+0x45/0x60
[  432.900929]  sock_def_readable+0x3d/0x70
[  432.900933]  tun_net_xmit+0x1d8/0x360 [tun]
[  432.900936]  netpoll_start_xmit+0x11d/0x1a0
[  432.900937]  netpoll_send_skb_on_dev+0x19b/0x250
[  432.900945]  __br_forward+0x1b2/0x1d0 [bridge]
[  432.900946]  ? skb_clone+0x4c/0xa0
[  432.900948]  ? __skb_clone+0x2e/0x140
[  432.900951]  deliver_clone+0x39/0x60 [bridge]
[  432.900955]  br_flood+0x13b/0x190 [bridge]
[  432.900958]  br_dev_xmit+0x218/0x2c0 [bridge]
[  432.900959]  netpoll_start_xmit+0x11d/0x1a0
[  432.900961]  ? __alloc_skb+0x5d/0x2b0
[  432.900962]  netpoll_send_skb_on_dev+0x19b/0x250
[  432.900963]  netpoll_send_udp+0x2da/0x440
[  432.900967]  write_msg+0xb2/0xf0 [netconsole]
[  432.900970]  call_console_drivers.isra.10.constprop.29+0xef/0x100
[  432.900971]  console_unlock+0x22d/0x540
[  432.900972]  vprintk_emit+0x2eb/0x4b0
[  432.900975]  ? common_interrupt+0x93/0x93
[  432.900976]  vprintk_default+0x29/0x40
[  432.900978]  printk+0x5d/0x74
[  432.900991]  ? kvm_arch_vcpu_ioctl_run+0xa64/0x1590 [kvm]
[  432.900994]  __show_regs+0x37/0x2e0
[  432.900996]  ? update_stack_state+0x63/0x80
[  432.900998]  ? unwind_next_frame+0x83/0x1f0
[  432.901000]  ? common_interrupt+0x93/0x93
[  432.901001]  ? common_interrupt+0x93/0x93
[  432.901004]  show_trace_log_lvl+0x22d/0x380
[  432.901006]  show_regs+0x9f/0x1a0
[  432.901008]  watchdog_timer_fn+0x197/0x1f0
[  432.901009]  ? watchdog+0x40/0x40
[  432.901011]  __hrtimer_run_queues+0xee/0x270
[  432.901013]  hrtimer_interrupt+0xa8/0x190
[  432.901015]  local_apic_timer_interrupt+0x35/0x60
[  432.901016]  smp_apic_timer_interrupt+0x38/0x50
[  432.901017]  apic_timer_interrupt+0x93/0xa0
[  432.901018] RIP: 0010:tc_classify+0x5a/0x120


Reply via email to