[ 30.158408][ T293] br1: port 1(veth1) entered blocking state [ 30.158847][ T293] br1: port 1(veth1) entered disabled state [ 30.159193][ T293] veth1: entered allmulticast mode [ 30.166963][ T293] veth1: entered promiscuous mode [ 30.298713][ T50] br1: port 1(veth1) entered blocking state [ 30.299104][ T50] br1: port 1(veth1) entered forwarding state [ 30.420666][ T296] br1: port 2(veth2) entered blocking state [ 30.420937][ T296] br1: port 2(veth2) entered disabled state [ 30.421201][ T296] veth2: entered allmulticast mode [ 30.423184][ T296] veth2: entered promiscuous mode [ 30.533812][ T51] br1: port 2(veth2) entered blocking state [ 30.534137][ T51] br1: port 2(veth2) entered forwarding state [ 39.791827][ T323] tc (323) used greatest stack depth: 24608 bytes left [ 40.006865][ T328] GACT probability NOT on [ 45.381431][ C2] [ 45.381544][ C2] ======================================================== [ 45.381798][ C2] WARNING: possible irq lock inversion dependency detected [ 45.382027][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 45.382172][ C2] -------------------------------------------------------- [ 45.382491][ C2] swapper/2/0 just changed the state of lock: [ 45.382669][ C2] ffff888008a92c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.383059][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 45.383259][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 45.383263][ C2] [ 45.383263][ C2] [ 45.383263][ C2] and interrupts could create inverse lock ordering between them. [ 45.383263][ C2] [ 45.383741][ C2] [ 45.383741][ C2] other info that might help us debug this: [ 45.383942][ C2] Chain exists of: [ 45.383942][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 45.383942][ C2] [ 45.384270][ C2] Possible interrupt unsafe locking scenario: [ 45.384270][ C2] [ 45.384529][ C2] CPU0 CPU1 [ 45.384671][ C2] ---- ---- [ 45.384838][ C2] lock(&p->alloc_lock); [ 45.384948][ C2] local_irq_disable(); [ 45.385125][ C2] lock(&br->lock); [ 45.385323][ C2] lock(lweventlist_lock); [ 45.385501][ C2] [ 45.385606][ C2] lock(&br->lock); [ 45.385729][ C2] [ 45.385729][ C2] *** DEADLOCK *** [ 45.385729][ C2] [ 45.385944][ C2] 1 lock held by swapper/2/0: [ 45.386088][ C2] #0: ffffc90000230d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 45.386405][ C2] [ 45.386405][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 45.386664][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 45.386827][ C2] HARDIRQ-ON-W at: [ 45.386949][ C2] __lock_acquire+0x797/0x1570 [ 45.387139][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.387350][ C2] _raw_spin_lock+0x30/0x40 [ 45.387542][ C2] set_mems_allowed+0x1d/0x210 [ 45.387735][ C2] kernel_init_freeable+0x72/0x310 [ 45.387938][ C2] kernel_init+0x20/0x200 [ 45.388124][ C2] ret_from_fork+0x31/0x70 [ 45.388312][ C2] ret_from_fork_asm+0x1a/0x30 [ 45.388516][ C2] SOFTIRQ-ON-W at: [ 45.388629][ C2] __lock_acquire+0x797/0x1570 [ 45.388832][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.389012][ C2] _raw_spin_lock+0x30/0x40 [ 45.389226][ C2] set_mems_allowed+0x1d/0x210 [ 45.389405][ C2] kernel_init_freeable+0x72/0x310 [ 45.389599][ C2] kernel_init+0x20/0x200 [ 45.389802][ C2] ret_from_fork+0x31/0x70 [ 45.389985][ C2] ret_from_fork_asm+0x1a/0x30 [ 45.390185][ C2] INITIAL USE at: [ 45.390294][ C2] __lock_acquire+0x797/0x1570 [ 45.390483][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.390681][ C2] _raw_spin_lock+0x30/0x40 [ 45.390870][ C2] set_mems_allowed+0x1d/0x210 [ 45.391064][ C2] kernel_init_freeable+0x72/0x310 [ 45.391246][ C2] kernel_init+0x20/0x200 [ 45.391436][ C2] ret_from_fork+0x31/0x70 [ 45.391636][ C2] ret_from_fork_asm+0x1a/0x30 [ 45.391817][ C2] } [ 45.391892][ C2] ... key at: [] __key.387+0x0/0x40 [ 45.392133][ C2] ... acquired at: [ 45.392253][ C2] __lock_acquire+0xaf0/0x1570 [ 45.392414][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.392569][ C2] _raw_spin_lock+0x30/0x40 [ 45.392734][ C2] __get_task_comm+0x27/0x70 [ 45.392879][ C2] ref_tracker_alloc+0x2ee/0x490 [ 45.393023][ C2] linkwatch_fire_event+0x196/0x200 [ 45.393185][ C2] veth_newlink+0x367/0x830 [veth] [ 45.393345][ C2] rtnl_newlink_create+0x341/0x850 [ 45.393496][ C2] __rtnl_newlink+0xac9/0xd80 [ 45.393641][ C2] rtnl_newlink+0x63/0xa0 [ 45.393808][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.393952][ C2] netlink_rcv_skb+0x130/0x360 [ 45.394112][ C2] netlink_unicast+0x449/0x710 [ 45.394287][ C2] netlink_sendmsg+0x723/0xbe0 [ 45.394430][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 45.394580][ C2] ___sys_sendmsg+0xee/0x170 [ 45.394725][ C2] __sys_sendmsg+0xcd/0x170 [ 45.394868][ C2] do_syscall_64+0xc6/0x1e0 [ 45.395014][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.395208][ C2] [ 45.395313][ C2] -> (lweventlist_lock){....}-{2:2} { [ 45.395465][ C2] INITIAL USE at: [ 45.395573][ C2] __lock_acquire+0x797/0x1570 [ 45.395773][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.395970][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.396168][ C2] linkwatch_sync_dev+0x29/0x1f0 [ 45.396354][ C2] rtnl_getlink+0x4c9/0x970 [ 45.396542][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.396738][ C2] netlink_rcv_skb+0x130/0x360 [ 45.396939][ C2] netlink_unicast+0x449/0x710 [ 45.397121][ C2] netlink_sendmsg+0x723/0xbe0 [ 45.397317][ C2] __sys_sendto+0x37d/0x410 [ 45.397518][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 45.397699][ C2] do_syscall_64+0xc6/0x1e0 [ 45.397914][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.398154][ C2] } [ 45.398228][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 45.398474][ C2] ... acquired at: [ 45.398580][ C2] __lock_acquire+0xaf0/0x1570 [ 45.398761][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.398907][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.399064][ C2] linkwatch_fire_event+0x74/0x200 [ 45.399215][ C2] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 45.399462][ C2] br_set_mac_address+0x1f3/0x260 [bridge] [ 45.399685][ C2] dev_set_mac_address+0x28a/0x410 [ 45.399835][ C2] dev_set_mac_address_user+0x31/0x50 [ 45.399986][ C2] do_setlink+0x17b4/0x21e0 [ 45.400149][ C2] rtnl_setlink+0x1f7/0x310 [ 45.400292][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.400452][ C2] netlink_rcv_skb+0x130/0x360 [ 45.400610][ C2] netlink_unicast+0x449/0x710 [ 45.400769][ C2] netlink_sendmsg+0x723/0xbe0 [ 45.400927][ C2] __sys_sendto+0x37d/0x410 [ 45.401097][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 45.401242][ C2] do_syscall_64+0xc6/0x1e0 [ 45.401413][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.401606][ C2] [ 45.401679][ C2] -> (&br->lock){+.-.}-{2:2} { [ 45.401846][ C2] HARDIRQ-ON-W at: [ 45.401954][ C2] __lock_acquire+0x797/0x1570 [ 45.402172][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.402379][ C2] _raw_spin_lock_bh+0x38/0x50 [ 45.402572][ C2] recalculate_group_addr+0x55/0x130 [bridge] [ 45.402834][ C2] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 45.403096][ C2] br_changelink+0x36c/0x1360 [bridge] [ 45.403333][ C2] br_dev_newlink+0xa5/0x100 [bridge] [ 45.403562][ C2] rtnl_newlink_create+0x341/0x850 [ 45.403789][ C2] __rtnl_newlink+0xac9/0xd80 [ 45.403980][ C2] rtnl_newlink+0x63/0xa0 [ 45.404178][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.404362][ C2] netlink_rcv_skb+0x130/0x360 [ 45.404611][ C2] netlink_unicast+0x449/0x710 [ 45.404894][ C2] netlink_sendmsg+0x723/0xbe0 [ 45.405157][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 45.405477][ C2] ___sys_sendmsg+0xee/0x170 [ 45.405746][ C2] __sys_sendmsg+0xcd/0x170 [ 45.405998][ C2] do_syscall_64+0xc6/0x1e0 [ 45.406263][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.406577][ C2] IN-SOFTIRQ-W at: [ 45.406742][ C2] __lock_acquire+0x797/0x1570 [ 45.407015][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.407283][ C2] _raw_spin_lock+0x30/0x40 [ 45.407543][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.407932][ C2] call_timer_fn+0x13b/0x230 [ 45.408351][ C2] __run_timers+0x545/0x810 [ 45.408625][ C2] run_timer_softirq+0xe8/0x1b0 [ 45.408888][ C2] __do_softirq+0x1f8/0x5df [ 45.409296][ C2] irq_exit_rcu+0x97/0xc0 [ 45.409565][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.409886][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.410344][ C2] default_idle+0xf/0x20 [ 45.410605][ C2] default_idle_call+0x6d/0xb0 [ 45.410874][ C2] cpuidle_idle_call+0x1f4/0x280 [ 45.411283][ C2] do_idle+0xf9/0x160 [ 45.411492][ C2] cpu_startup_entry+0x54/0x60 [ 45.411756][ C2] start_secondary+0x21c/0x2b0 [ 45.412025][ C2] common_startup_64+0x12c/0x138 [ 45.412447][ C2] INITIAL USE at: [ 45.412613][ C2] __lock_acquire+0x797/0x1570 [ 45.412882][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.413173][ C2] _raw_spin_lock_bh+0x38/0x50 [ 45.413439][ C2] recalculate_group_addr+0x55/0x130 [bridge] [ 45.413835][ C2] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 45.414221][ C2] br_changelink+0x36c/0x1360 [bridge] [ 45.414554][ C2] br_dev_newlink+0xa5/0x100 [bridge] [ 45.414884][ C2] rtnl_newlink_create+0x341/0x850 [ 45.415145][ C2] __rtnl_newlink+0xac9/0xd80 [ 45.415569][ C2] rtnl_newlink+0x63/0xa0 [ 45.415834][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.416105][ C2] netlink_rcv_skb+0x130/0x360 [ 45.416374][ C2] netlink_unicast+0x449/0x710 [ 45.416564][ C2] netlink_sendmsg+0x723/0xbe0 [ 45.416736][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 45.416906][ C2] ___sys_sendmsg+0xee/0x170 [ 45.417072][ C2] __sys_sendmsg+0xcd/0x170 [ 45.417240][ C2] do_syscall_64+0xc6/0x1e0 [ 45.417408][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.417688][ C2] } [ 45.417756][ C2] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 45.418024][ C2] ... acquired at: [ 45.418125][ C2] mark_lock+0x28d/0x3e0 [ 45.418341][ C2] mark_usage+0xd9/0x2a0 [ 45.418478][ C2] __lock_acquire+0x797/0x1570 [ 45.418610][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.418744][ C2] _raw_spin_lock+0x30/0x40 [ 45.418879][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.419083][ C2] call_timer_fn+0x13b/0x230 [ 45.419216][ C2] __run_timers+0x545/0x810 [ 45.419350][ C2] run_timer_softirq+0xe8/0x1b0 [ 45.419485][ C2] __do_softirq+0x1f8/0x5df [ 45.419615][ C2] irq_exit_rcu+0x97/0xc0 [ 45.419747][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.419912][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.420152][ C2] default_idle+0xf/0x20 [ 45.420288][ C2] default_idle_call+0x6d/0xb0 [ 45.420420][ C2] cpuidle_idle_call+0x1f4/0x280 [ 45.420552][ C2] do_idle+0xf9/0x160 [ 45.420651][ C2] cpu_startup_entry+0x54/0x60 [ 45.420934][ C2] start_secondary+0x21c/0x2b0 [ 45.421066][ C2] common_startup_64+0x12c/0x138 [ 45.421197][ C2] [ 45.421263][ C2] [ 45.421263][ C2] stack backtrace: [ 45.421499][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 45.421698][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 45.421994][ C2] Call Trace: [ 45.422172][ C2] [ 45.422253][ C2] dump_stack_lvl+0x82/0xd0 [ 45.422391][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 45.422554][ C2] ? common_startup_64+0x12c/0x138 [ 45.422699][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 45.422938][ C2] ? __pfx_usage_skip+0x10/0x10 [ 45.423071][ C2] ? __pfx_usage_match+0x10/0x10 [ 45.423202][ C2] ? arch_stack_walk+0x8c/0xf0 [ 45.423339][ C2] mark_lock_irq+0x4cd/0xa10 [ 45.423547][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 45.423681][ C2] ? stack_trace_save+0x94/0xd0 [ 45.423814][ C2] ? add_chain_cache+0x248/0x8b0 [ 45.423949][ C2] ? save_trace+0x8f/0x5b0 [ 45.424158][ C2] mark_lock+0x28d/0x3e0 [ 45.424258][ C2] mark_usage+0xd9/0x2a0 [ 45.424359][ C2] __lock_acquire+0x797/0x1570 [ 45.424493][ C2] ? __lock_acquire+0xaf0/0x1570 [ 45.424625][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.424933][ C2] lock_acquire.part.0+0xeb/0x330 [ 45.425065][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.425270][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 45.425479][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 45.425612][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.425811][ C2] ? lock_acquire+0x32/0xc0 [ 45.425942][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.426219][ C2] _raw_spin_lock+0x30/0x40 [ 45.426352][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.426554][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.426756][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.427061][ C2] call_timer_fn+0x13b/0x230 [ 45.427193][ C2] ? call_timer_fn+0xe8/0x230 [ 45.427324][ C2] ? call_timer_fn+0xe8/0x230 [ 45.427538][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 45.427683][ C2] ? mark_lock+0x38/0x3e0 [ 45.427805][ C2] __run_timers+0x545/0x810 [ 45.427941][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.428255][ C2] ? __pfx___run_timers+0x10/0x10 [ 45.428388][ C2] ? do_raw_spin_lock+0x131/0x270 [ 45.428518][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 45.428649][ C2] ? lock_acquire+0x32/0xc0 [ 45.428780][ C2] ? run_timer_softirq+0xe0/0x1b0 [ 45.428988][ C2] run_timer_softirq+0xe8/0x1b0 [ 45.429120][ C2] __do_softirq+0x1f8/0x5df [ 45.429255][ C2] irq_exit_rcu+0x97/0xc0 [ 45.429361][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.429570][ C2] [ 45.429638][ C2] [ 45.429707][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.429871][ C2] RIP: 0010:default_idle+0xf/0x20 [ 45.430014][ C2] Code: 4c 01 c7 4c 29 c2 e9 72 ff ff ff 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 f3 0f 1e fa 66 90 0f 00 2d a3 30 35 00 fb f4 c3 cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 [ 45.430570][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000246 [ 45.430738][ C2] RAX: 0000000000103139 RBX: 1ffff9200002bfc1 RCX: ffffffff9590e9d5 [ 45.431014][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff932aa4a4 [ 45.431215][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 45.431566][ C2] R10: ffff8880361384e3 R11: ffff88803613dc80 R12: 0000000000000000 [ 45.431772][ C2] R13: ffff888001b7c5c0 R14: dffffc0000000000 R15: 0000000000000000 [ 45.431974][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 45.432106][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 45.432332][ C2] default_idle_call+0x6d/0xb0 [ 45.432470][ C2] cpuidle_idle_call+0x1f4/0x280 [ 45.432600][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 45.432734][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 45.432945][ C2] do_idle+0xf9/0x160 [ 45.433047][ C2] cpu_startup_entry+0x54/0x60 [ 45.433181][ C2] start_secondary+0x21c/0x2b0 [ 45.433311][ C2] ? __pfx_start_secondary+0x10/0x10 [ 45.433519][ C2] common_startup_64+0x12c/0x138 [ 45.433653][ C2] [ 49.862831][ T449] br1: port 2(veth2) entered disabled state [ 49.964520][ T450] veth2: left allmulticast mode [ 49.964701][ T450] veth2: left promiscuous mode [ 49.964958][ T450] br1: port 2(veth2) entered disabled state [ 50.068128][ T451] br1: port 1(veth1) entered disabled state [ 50.157912][ T452] veth1: left allmulticast mode [ 50.158088][ T452] veth1: left promiscuous mode [ 50.159013][ T452] br1: port 1(veth1) entered disabled state [ 52.452850][ T198] sh (198) used greatest stack depth: 24480 bytes left