[ 23.609168][ T236] ip (236) used greatest stack depth: 23520 bytes left [ 29.805333][ T303] br1: port 1(veth1) entered blocking state [ 29.806474][ T303] br1: port 1(veth1) entered disabled state [ 29.807060][ T303] veth1: entered allmulticast mode [ 29.810734][ T303] veth1: entered promiscuous mode [ 29.934110][ T61] br1: port 1(veth1) entered blocking state [ 29.934596][ T61] br1: port 1(veth1) entered forwarding state [ 30.060813][ T305] br1: port 2(veth2) entered blocking state [ 30.061150][ T305] br1: port 2(veth2) entered disabled state [ 30.061406][ T305] veth2: entered allmulticast mode [ 30.063312][ T305] veth2: entered promiscuous mode [ 30.200668][ T7] br1: port 2(veth2) entered blocking state [ 30.200934][ T7] br1: port 2(veth2) entered forwarding state [ 30.554979][ T309] 8021q: 802.1Q VLAN Support v1.8 [ 31.603081][ T319] GACT probability NOT on [ 40.354038][ T360] Mirror/redirect action on [ 45.357922][ C0] [ 45.358062][ C0] ======================================================== [ 45.358328][ C0] WARNING: possible irq lock inversion dependency detected [ 45.358586][ C0] 6.9.0-rc1-virtme #1 Not tainted [ 45.358761][ C0] -------------------------------------------------------- [ 45.359034][ C0] swapper/0/0 just changed the state of lock: [ 45.359250][ C0] ffff888007c7ac38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.359692][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 45.359954][ C0] (&p->alloc_lock){+.+.}-{2:2} [ 45.359958][ C0] [ 45.359958][ C0] [ 45.359958][ C0] and interrupts could create inverse lock ordering between them. [ 45.359958][ C0] [ 45.360591][ C0] [ 45.360591][ C0] other info that might help us debug this: [ 45.360847][ C0] Chain exists of: [ 45.360847][ C0] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 45.360847][ C0] [ 45.361251][ C0] Possible interrupt unsafe locking scenario: [ 45.361251][ C0] [ 45.361513][ C0] CPU0 CPU1 [ 45.361686][ C0] ---- ---- [ 45.361860][ C0] lock(&p->alloc_lock); [ 45.361996][ C0] local_irq_disable(); [ 45.362212][ C0] lock(&br->lock); [ 45.362435][ C0] lock(lweventlist_lock); [ 45.362665][ C0] [ 45.362797][ C0] lock(&br->lock); [ 45.362941][ C0] [ 45.362941][ C0] *** DEADLOCK *** [ 45.362941][ C0] [ 45.363200][ C0] 1 lock held by swapper/0/0: [ 45.363377][ C0] #0: ffffc90000007d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 45.363746][ C0] [ 45.363746][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 45.364051][ C0] -> (&p->alloc_lock){+.+.}-{2:2} { [ 45.364233][ C0] HARDIRQ-ON-W at: [ 45.364369][ C0] __lock_acquire+0x797/0x1570 [ 45.364592][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.364812][ C0] _raw_spin_lock+0x30/0x40 [ 45.365042][ C0] set_mems_allowed+0x1d/0x210 [ 45.365266][ C0] kernel_init_freeable+0x72/0x310 [ 45.365489][ C0] kernel_init+0x20/0x200 [ 45.365711][ C0] ret_from_fork+0x31/0x70 [ 45.365936][ C0] ret_from_fork_asm+0x1a/0x30 [ 45.366154][ C0] SOFTIRQ-ON-W at: [ 45.366293][ C0] __lock_acquire+0x797/0x1570 [ 45.366513][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.366742][ C0] _raw_spin_lock+0x30/0x40 [ 45.366961][ C0] set_mems_allowed+0x1d/0x210 [ 45.367182][ C0] kernel_init_freeable+0x72/0x310 [ 45.367401][ C0] kernel_init+0x20/0x200 [ 45.367629][ C0] ret_from_fork+0x31/0x70 [ 45.367848][ C0] ret_from_fork_asm+0x1a/0x30 [ 45.368066][ C0] INITIAL USE at: [ 45.368198][ C0] __lock_acquire+0x797/0x1570 [ 45.368420][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.368641][ C0] _raw_spin_lock+0x30/0x40 [ 45.368860][ C0] set_mems_allowed+0x1d/0x210 [ 45.369086][ C0] kernel_init_freeable+0x72/0x310 [ 45.369309][ C0] kernel_init+0x20/0x200 [ 45.369530][ C0] ret_from_fork+0x31/0x70 [ 45.369752][ C0] ret_from_fork_asm+0x1a/0x30 [ 45.369975][ C0] } [ 45.370067][ C0] ... key at: [] __key.387+0x0/0x40 [ 45.370353][ C0] ... acquired at: [ 45.370489][ C0] __lock_acquire+0xaf0/0x1570 [ 45.370673][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.370850][ C0] _raw_spin_lock+0x30/0x40 [ 45.371030][ C0] __get_task_comm+0x27/0x70 [ 45.371209][ C0] ref_tracker_alloc+0x2ee/0x490 [ 45.371391][ C0] linkwatch_fire_event+0x196/0x200 [ 45.371569][ C0] veth_newlink+0x367/0x830 [veth] [ 45.371768][ C0] rtnl_newlink_create+0x341/0x850 [ 45.371944][ C0] __rtnl_newlink+0xac9/0xd80 [ 45.372120][ C0] rtnl_newlink+0x63/0xa0 [ 45.372298][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.372486][ C0] netlink_rcv_skb+0x130/0x360 [ 45.372668][ C0] netlink_unicast+0x449/0x710 [ 45.372843][ C0] netlink_sendmsg+0x723/0xbe0 [ 45.373018][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 45.373197][ C0] ___sys_sendmsg+0xee/0x170 [ 45.373383][ C0] __sys_sendmsg+0xcd/0x170 [ 45.373560][ C0] do_syscall_64+0xc6/0x1e0 [ 45.373739][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.373956][ C0] [ 45.374051][ C0] -> (lweventlist_lock){....}-{2:2} { [ 45.374231][ C0] INITIAL USE at: [ 45.374365][ C0] __lock_acquire+0x797/0x1570 [ 45.374588][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.374816][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.375036][ C0] linkwatch_sync_dev+0x29/0x1f0 [ 45.375258][ C0] rtnl_getlink+0x4c9/0x970 [ 45.375482][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.375701][ C0] netlink_rcv_skb+0x130/0x360 [ 45.375920][ C0] netlink_unicast+0x449/0x710 [ 45.376147][ C0] netlink_sendmsg+0x723/0xbe0 [ 45.376367][ C0] __sys_sendto+0x37d/0x410 [ 45.376586][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 45.376805][ C0] do_syscall_64+0xc6/0x1e0 [ 45.377024][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.377284][ C0] } [ 45.377381][ C0] ... key at: [] lweventlist_lock+0x18/0x60 [ 45.377647][ C0] ... acquired at: [ 45.377780][ C0] __lock_acquire+0xaf0/0x1570 [ 45.377955][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.378128][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.378303][ C0] linkwatch_fire_event+0x74/0x200 [ 45.378478][ C0] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 45.378745][ C0] br_set_mac_address+0x1f3/0x260 [bridge] [ 45.378998][ C0] dev_set_mac_address+0x28a/0x410 [ 45.379174][ C0] dev_set_mac_address_user+0x31/0x50 [ 45.379348][ C0] do_setlink+0x17b4/0x21e0 [ 45.379522][ C0] rtnl_setlink+0x1f7/0x310 [ 45.379700][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.379873][ C0] netlink_rcv_skb+0x130/0x360 [ 45.380053][ C0] netlink_unicast+0x449/0x710 [ 45.380240][ C0] netlink_sendmsg+0x723/0xbe0 [ 45.380418][ C0] __sys_sendto+0x37d/0x410 [ 45.380594][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 45.380773][ C0] do_syscall_64+0xc6/0x1e0 [ 45.380949][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.381166][ C0] [ 45.381256][ C0] -> (&br->lock){+.-.}-{2:2} { [ 45.381435][ C0] HARDIRQ-ON-W at: [ 45.381572][ C0] __lock_acquire+0x797/0x1570 [ 45.381802][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.382023][ C0] _raw_spin_lock_bh+0x38/0x50 [ 45.382243][ C0] recalculate_group_addr+0x55/0x130 [bridge] [ 45.382563][ C0] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 45.382863][ C0] br_changelink+0x36c/0x1360 [bridge] [ 45.383117][ C0] br_dev_newlink+0xa5/0x100 [bridge] [ 45.383378][ C0] rtnl_newlink_create+0x341/0x850 [ 45.383597][ C0] __rtnl_newlink+0xac9/0xd80 [ 45.383815][ C0] rtnl_newlink+0x63/0xa0 [ 45.384033][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.384249][ C0] netlink_rcv_skb+0x130/0x360 [ 45.384465][ C0] netlink_unicast+0x449/0x710 [ 45.384689][ C0] netlink_sendmsg+0x723/0xbe0 [ 45.385005][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 45.385224][ C0] ___sys_sendmsg+0xee/0x170 [ 45.385442][ C0] __sys_sendmsg+0xcd/0x170 [ 45.385663][ C0] do_syscall_64+0xc6/0x1e0 [ 45.385879][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.386140][ C0] IN-SOFTIRQ-W at: [ 45.386279][ C0] __lock_acquire+0x797/0x1570 [ 45.386498][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.386713][ C0] _raw_spin_lock+0x30/0x40 [ 45.386931][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.387409][ C0] call_timer_fn+0x13b/0x230 [ 45.387635][ C0] __run_timers+0x545/0x810 [ 45.387854][ C0] run_timer_softirq+0xe8/0x1b0 [ 45.388083][ C0] __do_softirq+0x1f8/0x5df [ 45.388395][ C0] irq_exit_rcu+0x97/0xc0 [ 45.388617][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.388881][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.389233][ C0] default_idle+0xf/0x20 [ 45.389452][ C0] default_idle_call+0x6d/0xb0 [ 45.389680][ C0] cpuidle_idle_call+0x1f4/0x280 [ 45.389999][ C0] do_idle+0xf9/0x160 [ 45.390174][ C0] cpu_startup_entry+0x54/0x60 [ 45.390395][ C0] rest_init+0x14f/0x260 [ 45.390616][ C0] start_kernel+0x318/0x3d0 [ 45.390837][ C0] x86_64_start_reservations+0x18/0x30 [ 45.391062][ C0] x86_64_start_kernel+0xba/0x110 [ 45.391284][ C0] common_startup_64+0x12c/0x138 [ 45.391504][ C0] INITIAL USE at: [ 45.391636][ C0] __lock_acquire+0x797/0x1570 [ 45.391855][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.392073][ C0] _raw_spin_lock_bh+0x38/0x50 [ 45.392382][ C0] recalculate_group_addr+0x55/0x130 [bridge] [ 45.392706][ C0] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 45.393014][ C0] br_changelink+0x36c/0x1360 [bridge] [ 45.393361][ C0] br_dev_newlink+0xa5/0x100 [bridge] [ 45.393620][ C0] rtnl_newlink_create+0x341/0x850 [ 45.393838][ C0] __rtnl_newlink+0xac9/0xd80 [ 45.394150][ C0] rtnl_newlink+0x63/0xa0 [ 45.394373][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.394594][ C0] netlink_rcv_skb+0x130/0x360 [ 45.394813][ C0] netlink_unicast+0x449/0x710 [ 45.395122][ C0] netlink_sendmsg+0x723/0xbe0 [ 45.395340][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 45.395559][ C0] ___sys_sendmsg+0xee/0x170 [ 45.395878][ C0] __sys_sendmsg+0xcd/0x170 [ 45.396100][ C0] do_syscall_64+0xc6/0x1e0 [ 45.396320][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.396673][ C0] } [ 45.396764][ C0] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 45.397102][ C0] ... acquired at: [ 45.397232][ C0] mark_lock+0x28d/0x3e0 [ 45.397497][ C0] mark_usage+0xd9/0x2a0 [ 45.397681][ C0] __lock_acquire+0x797/0x1570 [ 45.397868][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.398044][ C0] _raw_spin_lock+0x30/0x40 [ 45.398219][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.398564][ C0] call_timer_fn+0x13b/0x230 [ 45.398741][ C0] __run_timers+0x545/0x810 [ 45.398916][ C0] run_timer_softirq+0xe8/0x1b0 [ 45.399092][ C0] __do_softirq+0x1f8/0x5df [ 45.399363][ C0] irq_exit_rcu+0x97/0xc0 [ 45.399540][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.399759][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.400067][ C0] default_idle+0xf/0x20 [ 45.400243][ C0] default_idle_call+0x6d/0xb0 [ 45.400420][ C0] cpuidle_idle_call+0x1f4/0x280 [ 45.400596][ C0] do_idle+0xf9/0x160 [ 45.400729][ C0] cpu_startup_entry+0x54/0x60 [ 45.401011][ C0] rest_init+0x14f/0x260 [ 45.401186][ C0] start_kernel+0x318/0x3d0 [ 45.401360][ C0] x86_64_start_reservations+0x18/0x30 [ 45.401534][ C0] x86_64_start_kernel+0xba/0x110 [ 45.401709][ C0] common_startup_64+0x12c/0x138 [ 45.401890][ C0] [ 45.401979][ C0] [ 45.401979][ C0] stack backtrace: [ 45.402201][ C0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.9.0-rc1-virtme #1 [ 45.402467][ C0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 45.402873][ C0] Call Trace: [ 45.403015][ C0] [ 45.403110][ C0] dump_stack_lvl+0x82/0xd0 [ 45.403381][ C0] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 45.403602][ C0] ? common_startup_64+0x12c/0x138 [ 45.403776][ C0] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 45.403998][ C0] ? __pfx_usage_skip+0x10/0x10 [ 45.404262][ C0] ? __pfx_usage_match+0x10/0x10 [ 45.404436][ C0] ? arch_stack_walk+0x8c/0xf0 [ 45.404612][ C0] mark_lock_irq+0x4cd/0xa10 [ 45.404788][ C0] ? __pfx_mark_lock_irq+0x10/0x10 [ 45.405053][ C0] ? stack_trace_save+0x94/0xd0 [ 45.405232][ C0] ? save_trace+0x8f/0x5b0 [ 45.405406][ C0] mark_lock+0x28d/0x3e0 [ 45.405538][ C0] mark_usage+0xd9/0x2a0 [ 45.405676][ C0] __lock_acquire+0x797/0x1570 [ 45.405947][ C0] ? trace_rcu_dyntick+0x112/0x180 [ 45.406125][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.406421][ C0] lock_acquire.part.0+0xeb/0x330 [ 45.406597][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.406849][ C0] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 45.407022][ C0] ? trace_lock_acquire+0x135/0x1c0 [ 45.407203][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.407455][ C0] ? lock_acquire+0x32/0xc0 [ 45.407629][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.407880][ C0] _raw_spin_lock+0x30/0x40 [ 45.408053][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.408394][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.408653][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.408950][ C0] call_timer_fn+0x13b/0x230 [ 45.409216][ C0] ? call_timer_fn+0xe8/0x230 [ 45.409390][ C0] ? call_timer_fn+0xe8/0x230 [ 45.409565][ C0] ? __pfx_call_timer_fn+0x10/0x10 [ 45.409738][ C0] ? mark_lock+0x38/0x3e0 [ 45.409878][ C0] __run_timers+0x545/0x810 [ 45.410139][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.410442][ C0] ? __pfx___run_timers+0x10/0x10 [ 45.410619][ C0] ? do_raw_spin_lock+0x131/0x270 [ 45.410794][ C0] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 45.411059][ C0] ? lock_acquire+0x32/0xc0 [ 45.411231][ C0] ? run_timer_softirq+0xe0/0x1b0 [ 45.411406][ C0] run_timer_softirq+0xe8/0x1b0 [ 45.411581][ C0] __do_softirq+0x1f8/0x5df [ 45.411755][ C0] irq_exit_rcu+0x97/0xc0 [ 45.411888][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.412068][ C0] [ 45.412157][ C0] [ 45.412246][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.412467][ C0] RIP: 0010:default_idle+0xf/0x20 [ 45.412659][ C0] 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.413369][ C0] RSP: 0018:ffffffffa6607e00 EFLAGS: 00000246 [ 45.413598][ C0] RAX: 00000000000c73c3 RBX: 1ffffffff4cc0fc2 RCX: ffffffffa570e9d5 [ 45.413860][ C0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffa30aa4a4 [ 45.414302][ C0] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c0709c [ 45.414560][ C0] R10: ffff8880360384e3 R11: ffff88803603dc80 R12: 0000000000000000 [ 45.414821][ C0] R13: ffffffffa661d000 R14: dffffc0000000000 R15: 0000000000014770 [ 45.415188][ C0] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 45.415364][ C0] ? cpuidle_idle_call+0x1f4/0x280 [ 45.415542][ C0] default_idle_call+0x6d/0xb0 [ 45.415715][ C0] cpuidle_idle_call+0x1f4/0x280 [ 45.415984][ C0] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 45.416161][ C0] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 45.416337][ C0] do_idle+0xf9/0x160 [ 45.416474][ C0] cpu_startup_entry+0x54/0x60 [ 45.416648][ C0] rest_init+0x14f/0x260 [ 45.416782][ C0] start_kernel+0x318/0x3d0 [ 45.416958][ C0] x86_64_start_reservations+0x18/0x30 [ 45.417141][ C0] x86_64_start_kernel+0xba/0x110 [ 45.417314][ C0] common_startup_64+0x12c/0x138 [ 45.417494][ C0] [ 76.323520][ T532] br1: port 1(veth1) entered disabled state [ 76.413952][ T534] br1: port 2(veth2) entered disabled state [ 76.515142][ T535] veth2: left allmulticast mode [ 76.515406][ T535] veth2: left promiscuous mode [ 76.515671][ T535] br1: port 2(veth2) entered disabled state [ 76.516707][ T535] veth1: left allmulticast mode [ 76.517219][ T535] veth1: left promiscuous mode [ 76.517473][ T535] br1: port 1(veth1) entered disabled state