[ 1207.472558][ T5961] br: port 1(veth1) entered blocking state [ 1207.473238][ T5961] br: port 1(veth1) entered disabled state [ 1207.473528][ T5961] veth1: entered allmulticast mode [ 1207.475932][ T5961] veth1: entered promiscuous mode [ 1207.488270][ T2698] br: port 1(veth1) entered blocking state [ 1207.488535][ T2698] br: port 1(veth1) entered forwarding state [ 1207.565450][ T5966] br: port 2(veth3) entered blocking state [ 1207.565738][ T5966] br: port 2(veth3) entered disabled state [ 1207.566009][ T5966] veth3: entered allmulticast mode [ 1207.568185][ T5966] veth3: entered promiscuous mode [ 1207.570121][ T4076] br: port 2(veth3) entered blocking state [ 1207.570323][ T4076] br: port 2(veth3) entered forwarding state [ 1207.632851][ T5971] br: port 3(veth4) entered blocking state [ 1207.633127][ T5971] br: port 3(veth4) entered disabled state [ 1207.633399][ T5971] veth4: entered allmulticast mode [ 1207.645160][ T5971] veth4: entered promiscuous mode [ 1207.647166][ T2698] br: port 3(veth4) entered blocking state [ 1207.647424][ T2698] br: port 3(veth4) entered forwarding state [ 1287.888016][ T6402] Mirror/redirect action on [ 1301.177180][ C0] [ 1301.177276][ C0] ================================ [ 1301.177392][ C0] WARNING: inconsistent lock state [ 1301.177495][ C0] 7.1.0-rc5-virtme #1 Not tainted [ 1301.177599][ C0] -------------------------------- [ 1301.177709][ C0] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. [ 1301.177840][ C0] jq/6474 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 1301.177952][ C0] ffffffffc056c7b8 (mirred_list_lock){+.?.}-{3:3}, at: tcf_mirred_release+0x1d/0x2e0 [act_mirred] [ 1301.178167][ C0] {SOFTIRQ-ON-W} state was registered at: [ 1301.178274][ C0] __lock_acquire+0x378/0xc10 [ 1301.178388][ C0] lock_acquire.part.0+0xbc/0x260 [ 1301.178497][ C0] _raw_spin_lock+0x33/0x40 [ 1301.178600][ C0] tcf_mirred_init+0x844/0xd70 [act_mirred] [ 1301.178732][ C0] tcf_action_init_1+0x428/0x6b0 [ 1301.178836][ C0] tcf_action_init+0x3cf/0x890 [ 1301.178976][ C0] tcf_exts_validate_ex+0x411/0x670 [ 1301.179087][ C0] mall_change+0x3cd/0xe9b [cls_matchall] [ 1301.179215][ C0] tc_new_tfilter+0x875/0x21e0 [ 1301.179318][ C0] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 1301.179424][ C0] netlink_rcv_skb+0x14e/0x3a0 [ 1301.179525][ C0] netlink_unicast+0x486/0x750 [ 1301.179625][ C0] netlink_sendmsg+0x735/0xc60 [ 1301.179729][ C0] ____sys_sendmsg+0x419/0x850 [ 1301.179840][ C0] ___sys_sendmsg+0x14e/0x1d0 [ 1301.179950][ C0] __sys_sendmsg+0x145/0x1f0 [ 1301.180052][ C0] do_syscall_64+0x117/0x590 [ 1301.180158][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 1301.180292][ C0] irq event stamp: 6270 [ 1301.180375][ C0] hardirqs last enabled at (6270): [] _raw_spin_unlock_irqrestore+0x53/0x80 [ 1301.180589][ C0] hardirqs last disabled at (6269): [] _raw_spin_lock_irqsave+0x50/0x60 [ 1301.180771][ C0] softirqs last enabled at (4920): [] handle_softirqs+0x611/0x940 [ 1301.180953][ C0] softirqs last disabled at (5391): [] __irq_exit_rcu+0x103/0x1c0 [ 1301.181128][ C0] [ 1301.181128][ C0] other info that might help us debug this: [ 1301.181276][ C0] Possible unsafe locking scenario: [ 1301.181276][ C0] [ 1301.181427][ C0] CPU0 [ 1301.181505][ C0] ---- [ 1301.181581][ C0] lock(mirred_list_lock); [ 1301.181683][ C0] [ 1301.181759][ C0] lock(mirred_list_lock); [ 1301.181863][ C0] [ 1301.181863][ C0] *** DEADLOCK *** [ 1301.181863][ C0] [ 1301.182019][ C0] 3 locks held by jq/6474: [ 1301.182124][ C0] #0: ff11000005db85d8 (&fsvq->lock){+.+.}-{3:3}, at: virtio_fs_enqueue_req+0x5a2/0xfa0 [ 1301.182307][ C0] #1: ffffffff8eb77d20 (rcu_read_lock){....}-{1:3}, at: unwind_next_frame+0x17e/0x1ea0 [ 1301.182489][ C0] #2: ffffffff8eb77c00 (rcu_callback){....}-{0:0}, at: rcu_do_batch+0x389/0x1020 [ 1301.182734][ C0] [ 1301.182734][ C0] stack backtrace: [ 1301.182860][ C0] CPU: 0 UID: 0 PID: 6474 Comm: jq Not tainted 7.1.0-rc5-virtme #1 PREEMPT(full) [ 1301.182864][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 1301.182866][ C0] Call Trace: [ 1301.182867][ C0] [ 1301.182869][ C0] dump_stack_lvl+0x6f/0xa0 [ 1301.182873][ C0] print_usage_bug.part.0.cold+0xa9/0xb7 [ 1301.182876][ C0] ? filter_irq_stacks+0xd0/0xd0 [ 1301.182880][ C0] mark_lock_irq+0x4e3/0x9c0 [ 1301.182882][ C0] ? sysvec_apic_timer_interrupt+0x9d/0xe0 [ 1301.182884][ C0] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 1301.182886][ C0] ? save_trace+0x68/0x280 [ 1301.182887][ C0] ? virtqueue_add_packed_in_order+0x7f0/0x1400 [ 1301.182894][ C0] mark_lock+0x1d7/0xa00 [ 1301.182896][ C0] mark_usage+0x42/0x170 [ 1301.182897][ C0] __lock_acquire+0x378/0xc10 [ 1301.182899][ C0] ? mark_held_locks+0x40/0x70 [ 1301.182900][ C0] ? rcu_do_batch+0x2b4/0x1020 [ 1301.182903][ C0] lock_acquire.part.0+0xbc/0x260 [ 1301.182905][ C0] ? tcf_mirred_release+0x1d/0x2e0 [act_mirred] [ 1301.182907][ C0] ? rcu_is_watching+0x15/0xd0 [ 1301.182909][ C0] ? lock_acquire+0x134/0x160 [ 1301.182911][ C0] _raw_spin_lock+0x33/0x40 [ 1301.182912][ C0] ? tcf_mirred_release+0x1d/0x2e0 [act_mirred] [ 1301.182914][ C0] tcf_mirred_release+0x1d/0x2e0 [act_mirred] [ 1301.182916][ C0] tcf_action_rcu_free+0x74/0x1a0 [ 1301.182917][ C0] ? rcu_do_batch+0x2b4/0x1020 [ 1301.182919][ C0] rcu_do_batch+0x2b6/0x1020 [ 1301.182921][ C0] ? mark_held_locks+0x40/0x70 [ 1301.182923][ C0] ? sched_balance_softirq+0x260/0x320 [ 1301.182926][ C0] ? trace_rcu_batch_end+0x330/0x330 [ 1301.182933][ C0] ? sched_balance_domains+0xcd0/0xcd0 [ 1301.182935][ C0] ? mark_held_locks+0x40/0x70 [ 1301.182937][ C0] ? lockdep_hardirqs_on_prepare.part.0+0x9a/0x160 [ 1301.182938][ C0] ? lockdep_hardirqs_on+0x8c/0x130 [ 1301.182940][ C0] rcu_core+0x2bf/0x640 [ 1301.182942][ C0] handle_softirqs+0x1d8/0x940 [ 1301.182944][ C0] ? find_held_lock+0x2b/0x80 [ 1301.182947][ C0] ? __lock_release.isra.0+0x6b/0x1a0 [ 1301.182948][ C0] ? _local_bh_enable+0xd0/0xd0 [ 1301.182951][ C0] __irq_exit_rcu+0x103/0x1c0 [ 1301.182952][ C0] irq_exit_rcu+0xe/0x30 [ 1301.182954][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 1301.182956][ C0] [ 1301.182956][ C0] [ 1301.182957][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 1301.182959][ C0] RIP: 0010:lock_acquire.part.0+0xfa/0x260 [ 1301.182961][ C0] Code: ff 65 0f c1 05 37 d9 33 04 83 f8 01 4c 8b 14 24 0f 85 30 01 00 00 9c 58 f6 c4 02 0f 85 4d 01 00 00 4d 85 d2 0f 85 16 01 00 00 <48> 8b 44 24 30 65 48 2b 05 a9 92 33 04 0f 85 43 01 00 00 48 83 c4 [ 1301.182963][ C0] RSP: 0018:ffa00000006c6d00 EFLAGS: 00000206 [ 1301.182965][ C0] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 4a8286ea93efaeeb [ 1301.182967][ C0] RDX: 0000000000000001 RSI: ffffffff8e5ebde8 RDI: ffffffff8e06f6c0 [ 1301.182968][ C0] RBP: 0000000000000000 R08: 0000000000000001 R09: ff1100000d608b58 [ 1301.182968][ C0] R10: 0000000000000200 R11: 0000000000000001 R12: ffffffff8eb77d20 [ 1301.182969][ C0] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000002 [ 1301.182972][ C0] ? rcu_is_watching+0x15/0xd0 [ 1301.182973][ C0] ? lock_acquire+0x134/0x160 [ 1301.182975][ C0] unwind_next_frame+0x192/0x1ea0 [ 1301.182977][ C0] ? unwind_next_frame+0x17e/0x1ea0 [ 1301.182978][ C0] ? virtio_fs_send_req+0xf6/0x480 [ 1301.182980][ C0] ? mark_usage+0x61/0x170 [ 1301.182981][ C0] ? stack_access_ok+0x1e0/0x1e0 [ 1301.182983][ C0] ? __unwind_start+0x432/0x910 [ 1301.182985][ C0] ? write_profile+0xf0/0xf0 [ 1301.182987][ C0] arch_stack_walk+0xd7/0x130 [ 1301.182991][ C0] ? virtio_fs_send_req+0xf6/0x480 [ 1301.182993][ C0] ? virtqueue_add_split+0xca9/0x1df0 [ 1301.182995][ C0] stack_trace_save+0x93/0xc0 [ 1301.182997][ C0] ? filter_irq_stacks+0xd0/0xd0 [ 1301.182999][ C0] ? virtqueue_add_split+0xca9/0x1df0 [ 1301.183001][ C0] ? __unwind_start+0x432/0x910 [ 1301.183002][ C0] kasan_save_stack+0x2f/0x50 [ 1301.183006][ C0] ? kasan_save_stack+0x2f/0x50 [ 1301.183008][ C0] ? kasan_save_track+0x14/0x30 [ 1301.183009][ C0] ? __kasan_kmalloc+0x7b/0x90 [ 1301.183011][ C0] ? __kmalloc_noprof+0x2ba/0x760 [ 1301.183014][ C0] ? virtqueue_add_split+0xca9/0x1df0 [ 1301.183015][ C0] ? virtqueue_add_sgs+0x136/0x280 [ 1301.183017][ C0] ? virtio_fs_enqueue_req+0x639/0xfa0 [ 1301.183018][ C0] ? virtio_fs_send_req+0xf6/0x480 [ 1301.183024][ C0] kasan_save_track+0x14/0x30 [ 1301.183026][ C0] __kasan_kmalloc+0x7b/0x90 [ 1301.183028][ C0] __kmalloc_noprof+0x2ba/0x760 [ 1301.183030][ C0] ? do_syscall_64+0x117/0x590 [ 1301.183032][ C0] virtqueue_add_split+0xca9/0x1df0 [ 1301.183034][ C0] ? fuse_request_alloc+0x27/0x210 [ 1301.183036][ C0] ? entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 1301.183038][ C0] ? write_profile+0xf0/0xf0 [ 1301.183039][ C0] ? __kernel_text_address+0x12/0x30 [ 1301.183042][ C0] ? virtqueue_add_packed+0x16e0/0x16e0 [ 1301.183044][ C0] ? __lock_acquire+0x508/0xc10 [ 1301.183046][ C0] virtqueue_add_sgs+0x136/0x280 [ 1301.183049][ C0] virtio_fs_enqueue_req+0x639/0xfa0 [ 1301.183051][ C0] ? __lock_release.isra.0+0x6b/0x1a0 [ 1301.183052][ C0] ? ovl_get_link+0x6d/0xf0 [ 1301.183055][ C0] ? virtio_fs_probe+0x310/0x310 [ 1301.183056][ C0] ? rcu_lockdep_current_cpu_online+0x39/0x1b0 [ 1301.183059][ C0] ? rcu_is_watching+0x15/0xd0 [ 1301.183061][ C0] ? __create_object+0x78/0x110 [ 1301.183063][ C0] ? trace_kmem_cache_alloc+0xde/0x120 [ 1301.183067][ C0] ? __rwlock_init+0x150/0x150 [ 1301.183069][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 1301.183071][ C0] virtio_fs_send_req+0xf6/0x480 [ 1301.183073][ C0] __fuse_simple_request+0x227/0xbb0 [ 1301.183075][ C0] fuse_readlink_folio+0x242/0x450 [ 1301.183077][ C0] ? fuse_invalidate_attr_mask+0x100/0x100 [ 1301.183079][ C0] ? __lock_acquire+0x508/0xc10 [ 1301.183082][ C0] ? find_held_lock+0x2b/0x80 [ 1301.183084][ C0] ? find_held_lock+0x2b/0x80 [ 1301.183087][ C0] fuse_get_link+0x131/0x350 [ 1301.183088][ C0] ovl_get_link+0x6d/0xf0 [ 1301.183090][ C0] pick_link+0xf6e/0x1920 [ 1301.183093][ C0] ? ovl_check_rename_whiteout+0x5d0/0x5d0 [ 1301.183095][ C0] step_into_slowpath+0x4c8/0x1240 [ 1301.183097][ C0] ? __lock_release.isra.0+0x6b/0x1a0 [ 1301.183099][ C0] ? pick_link+0x1920/0x1920 [ 1301.183101][ C0] ? ovl_dentry_revalidate_common+0x199/0x240 [ 1301.183103][ C0] ? lookup_fast+0x208/0x630 [ 1301.183105][ C0] open_last_lookups+0x81f/0x1d10 [ 1301.183108][ C0] ? lookup_open.isra.0+0xea0/0xea0 [ 1301.183110][ C0] ? __asan_memset+0x27/0x50 [ 1301.183112][ C0] ? init_file.isra.0+0x30a/0x3e0 [ 1301.183114][ C0] path_openat+0x136/0x3b0 [ 1301.183116][ C0] ? rcu_lockdep_current_cpu_online+0x39/0x1b0 [ 1301.183118][ C0] ? kernel_tmpfile_open+0x70/0x70 [ 1301.183120][ C0] ? validate_chain+0x38b/0xc20 [ 1301.183121][ C0] ? rcu_lockdep_current_cpu_online+0x39/0x1b0 [ 1301.183123][ C0] do_file_open+0x209/0x480 [ 1301.183125][ C0] ? path_openat+0x3b0/0x3b0 [ 1301.183129][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 1301.183131][ C0] ? _raw_spin_unlock+0x2d/0x50 [ 1301.183132][ C0] ? alloc_fd+0x24a/0x450 [ 1301.183135][ C0] do_sys_openat2+0xde/0x170 [ 1301.183138][ C0] ? build_open_flags+0x620/0x620 [ 1301.183141][ C0] __x64_sys_openat+0x10e/0x210 [ 1301.183143][ C0] ? __ia32_sys_open+0x1b0/0x1b0 [ 1301.183145][ C0] ? fpregs_restore_userregs+0x14b/0x310 [ 1301.183147][ C0] ? rcu_is_watching+0x15/0xd0 [ 1301.183149][ C0] ? trace_irq_enable.constprop.0+0x9b/0x180 [ 1301.183152][ C0] do_syscall_64+0x117/0x590 [ 1301.183153][ C0] ? trace_hardirqs_off+0xd/0x30 [ 1301.183155][ C0] ? exc_page_fault+0xee/0x100 [ 1301.183156][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 1301.183158][ C0] RIP: 0033:0x7f519c00b625 [ 1301.183160][ C0] Code: 48 89 e5 48 89 55 e0 41 83 e2 40 75 28 89 f2 f7 d2 81 e2 00 00 41 00 74 1c 89 f2 bf 9c ff ff ff 48 89 c6 b8 01 01 00 00 0f 05 <48> 3d 00 f0 ff ff 77 23 5d c3 90 48 8d 4d 10 c7 45 b8 10 00 00 00 [ 1301.183161][ C0] RSP: 002b:00007ffcb1994ed0 EFLAGS: 00000206 ORIG_RAX: 0000000000000101 [ 1301.183163][ C0] RAX: ffffffffffffffda RBX: 00007ffcb1995160 RCX: 00007f519c00b625 [ 1301.183164][ C0] RDX: 0000000000080000 RSI: 00007ffcb1994f50 RDI: 00000000ffffff9c [ 1301.183164][ C0] RBP: 00007ffcb1994ed0 R08: 00007ffcb1995147 R09: 0000000000000000 [ 1301.183165][ C0] R10: 0000000000000000 R11: 0000000000000206 R12: 00007ffcb1994f50 [ 1301.183166][ C0] R13: 00007ffcb1994f50 R14: 00007f519bfdd000 R15: 0000000000000000 [ 1301.183168][ C0] [ 1317.023458][ T6579] br: port 3(veth4) entered disabled state [ 1317.023816][ T6579] veth4: left allmulticast mode [ 1317.023945][ T6579] veth4: left promiscuous mode [ 1317.024141][ T6579] br: port 3(veth4) entered disabled state [ 1317.043903][ T6581] br: port 2(veth3) entered disabled state [ 1317.044171][ T6581] veth3: left allmulticast mode [ 1317.044263][ T6581] veth3: left promiscuous mode [ 1317.044403][ T6581] br: port 2(veth3) entered disabled state [ 1317.059585][ T6583] br: port 1(veth1) entered disabled state [ 1317.060290][ T6583] veth1: left allmulticast mode [ 1317.060427][ T6583] veth1: left promiscuous mode [ 1317.060614][ T6583] br: port 1(veth1) entered disabled state