[ 27.973450][ T285] br1: port 1(veth1) entered blocking state [ 27.973887][ T285] br1: port 1(veth1) entered disabled state [ 27.974228][ T285] veth1: entered allmulticast mode [ 27.976242][ T285] veth1: entered promiscuous mode [ 28.216539][ T287] br1: port 2(veth2) entered blocking state [ 28.216829][ T287] br1: port 2(veth2) entered disabled state [ 28.217073][ T287] veth2: entered allmulticast mode [ 28.218906][ T287] veth2: entered promiscuous mode [ 28.448004][ T289] br1: port 2(veth2) entered blocking state [ 28.448388][ T289] br1: port 2(veth2) entered forwarding state [ 28.449172][ T289] br1: port 1(veth1) entered blocking state [ 28.449433][ T289] br1: port 1(veth1) entered forwarding state [ 28.472547][ T289] ip (289) used greatest stack depth: 24224 bytes left [ 35.335308][ T314] GACT probability NOT on [ 43.817926][ C2] [ 43.818030][ C2] ======================================================== [ 43.818233][ C2] WARNING: possible irq lock inversion dependency detected [ 43.818434][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 43.818577][ C2] -------------------------------------------------------- [ 43.818800][ C2] swapper/2/0 just changed the state of lock: [ 43.818976][ C2] ffff888005f22c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.819321][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 43.819537][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 43.819543][ C2] [ 43.819543][ C2] [ 43.819543][ C2] and interrupts could create inverse lock ordering between them. [ 43.819543][ C2] [ 43.820048][ C2] [ 43.820048][ C2] other info that might help us debug this: [ 43.820259][ C2] Chain exists of: [ 43.820259][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 43.820259][ C2] [ 43.820574][ C2] Possible interrupt unsafe locking scenario: [ 43.820574][ C2] [ 43.820776][ C2] CPU0 CPU1 [ 43.820916][ C2] ---- ---- [ 43.821056][ C2] lock(&p->alloc_lock); [ 43.821161][ C2] local_irq_disable(); [ 43.821328][ C2] lock(&br->lock); [ 43.821498][ C2] lock(lweventlist_lock); [ 43.821667][ C2] [ 43.821770][ C2] lock(&br->lock); [ 43.821873][ C2] [ 43.821873][ C2] *** DEADLOCK *** [ 43.821873][ C2] [ 43.822073][ C2] 1 lock held by swapper/2/0: [ 43.822212][ C2] #0: ffffc90000230b68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 43.822499][ C2] [ 43.822499][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 43.822735][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 43.822880][ C2] HARDIRQ-ON-W at: [ 43.822988][ C2] __lock_acquire+0x797/0x1570 [ 43.823167][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.823340][ C2] _raw_spin_lock+0x30/0x40 [ 43.823514][ C2] set_mems_allowed+0x1d/0x210 [ 43.823689][ C2] kernel_init_freeable+0x72/0x310 [ 43.823864][ C2] kernel_init+0x20/0x200 [ 43.824066][ C2] ret_from_fork+0x31/0x70 [ 43.824263][ C2] ret_from_fork_asm+0x1a/0x30 [ 43.824436][ C2] SOFTIRQ-ON-W at: [ 43.824558][ C2] __lock_acquire+0x797/0x1570 [ 43.824732][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.824906][ C2] _raw_spin_lock+0x30/0x40 [ 43.825081][ C2] set_mems_allowed+0x1d/0x210 [ 43.825282][ C2] kernel_init_freeable+0x72/0x310 [ 43.825457][ C2] kernel_init+0x20/0x200 [ 43.825634][ C2] ret_from_fork+0x31/0x70 [ 43.825817][ C2] ret_from_fork_asm+0x1a/0x30 [ 43.825993][ C2] INITIAL USE at: [ 43.826096][ C2] __lock_acquire+0x797/0x1570 [ 43.826272][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.826451][ C2] _raw_spin_lock+0x30/0x40 [ 43.826624][ C2] set_mems_allowed+0x1d/0x210 [ 43.826796][ C2] kernel_init_freeable+0x72/0x310 [ 43.826973][ C2] kernel_init+0x20/0x200 [ 43.827146][ C2] ret_from_fork+0x31/0x70 [ 43.827323][ C2] ret_from_fork_asm+0x1a/0x30 [ 43.827500][ C2] } [ 43.827572][ C2] ... key at: [] __key.387+0x0/0x40 [ 43.827787][ C2] ... acquired at: [ 43.827892][ C2] __lock_acquire+0xaf0/0x1570 [ 43.828034][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.828171][ C2] _raw_spin_lock+0x30/0x40 [ 43.828311][ C2] __get_task_comm+0x27/0x70 [ 43.828459][ C2] ref_tracker_alloc+0x2ee/0x490 [ 43.828603][ C2] linkwatch_fire_event+0x196/0x200 [ 43.828744][ C2] veth_newlink+0x367/0x830 [veth] [ 43.828891][ C2] rtnl_newlink_create+0x341/0x850 [ 43.829028][ C2] __rtnl_newlink+0xac9/0xd80 [ 43.829170][ C2] rtnl_newlink+0x63/0xa0 [ 43.829306][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 43.829445][ C2] netlink_rcv_skb+0x130/0x360 [ 43.829586][ C2] netlink_unicast+0x449/0x710 [ 43.829725][ C2] netlink_sendmsg+0x723/0xbe0 [ 43.829861][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 43.830001][ C2] ___sys_sendmsg+0xee/0x170 [ 43.830138][ C2] __sys_sendmsg+0xcd/0x170 [ 43.830329][ C2] do_syscall_64+0xc6/0x1e0 [ 43.830466][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 43.830645][ C2] [ 43.830715][ C2] -> (lweventlist_lock){....}-{2:2} { [ 43.830860][ C2] INITIAL USE at: [ 43.830964][ C2] __lock_acquire+0x797/0x1570 [ 43.831137][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.831311][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 43.831491][ C2] linkwatch_sync_dev+0x29/0x1f0 [ 43.831663][ C2] rtnl_getlink+0x4c9/0x970 [ 43.831841][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 43.832014][ C2] netlink_rcv_skb+0x130/0x360 [ 43.832189][ C2] netlink_unicast+0x449/0x710 [ 43.832360][ C2] netlink_sendmsg+0x723/0xbe0 [ 43.832544][ C2] __sys_sendto+0x37d/0x410 [ 43.832719][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 43.832898][ C2] do_syscall_64+0xc6/0x1e0 [ 43.833070][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 43.833277][ C2] } [ 43.833347][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 43.833557][ C2] ... acquired at: [ 43.833660][ C2] __lock_acquire+0xaf0/0x1570 [ 43.833798][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.833939][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 43.834081][ C2] linkwatch_fire_event+0x74/0x200 [ 43.834226][ C2] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 43.834439][ C2] br_set_mac_address+0x1f3/0x260 [bridge] [ 43.834640][ C2] dev_set_mac_address+0x28a/0x410 [ 43.834780][ C2] dev_set_mac_address_user+0x31/0x50 [ 43.834924][ C2] do_setlink+0x17b4/0x21e0 [ 43.835061][ C2] rtnl_setlink+0x1f7/0x310 [ 43.835201][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 43.835337][ C2] netlink_rcv_skb+0x130/0x360 [ 43.835478][ C2] netlink_unicast+0x449/0x710 [ 43.835622][ C2] netlink_sendmsg+0x723/0xbe0 [ 43.835758][ C2] __sys_sendto+0x37d/0x410 [ 43.835898][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 43.836035][ C2] do_syscall_64+0xc6/0x1e0 [ 43.836176][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 43.836360][ C2] [ 43.836429][ C2] -> (&br->lock){+.-.}-{2:2} { [ 43.836570][ C2] HARDIRQ-ON-W at: [ 43.836676][ C2] __lock_acquire+0x797/0x1570 [ 43.836849][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.837020][ C2] _raw_spin_lock_bh+0x38/0x50 [ 43.837191][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 43.837432][ C2] dev_set_mac_address+0x28a/0x410 [ 43.837608][ C2] dev_set_mac_address_user+0x31/0x50 [ 43.837782][ C2] do_setlink+0x17b4/0x21e0 [ 43.837956][ C2] rtnl_setlink+0x1f7/0x310 [ 43.838129][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 43.838301][ C2] netlink_rcv_skb+0x130/0x360 [ 43.838474][ C2] netlink_unicast+0x449/0x710 [ 43.838648][ C2] netlink_sendmsg+0x723/0xbe0 [ 43.838820][ C2] __sys_sendto+0x37d/0x410 [ 43.838993][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 43.839166][ C2] do_syscall_64+0xc6/0x1e0 [ 43.839336][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 43.839544][ C2] IN-SOFTIRQ-W at: [ 43.839650][ C2] __lock_acquire+0x797/0x1570 [ 43.839827][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.840000][ C2] _raw_spin_lock+0x30/0x40 [ 43.840173][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.840430][ C2] call_timer_fn+0x13b/0x230 [ 43.840605][ C2] __run_timers+0x545/0x810 [ 43.840778][ C2] timer_expire_remote+0x9b/0xe0 [ 43.840956][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 43.841133][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 43.841305][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 43.841477][ C2] __do_softirq+0x1f8/0x5df [ 43.841650][ C2] irq_exit_rcu+0x97/0xc0 [ 43.841824][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 43.842033][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 43.842242][ C2] default_idle+0xf/0x20 [ 43.842414][ C2] default_idle_call+0x6d/0xb0 [ 43.842586][ C2] cpuidle_idle_call+0x1f4/0x280 [ 43.842764][ C2] do_idle+0xf9/0x160 [ 43.842908][ C2] cpu_startup_entry+0x54/0x60 [ 43.843082][ C2] start_secondary+0x21c/0x2b0 [ 43.843263][ C2] common_startup_64+0x12c/0x138 [ 43.843438][ C2] INITIAL USE at: [ 43.843543][ C2] __lock_acquire+0x797/0x1570 [ 43.843722][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.843935][ C2] _raw_spin_lock_bh+0x38/0x50 [ 43.844115][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 43.844360][ C2] dev_set_mac_address+0x28a/0x410 [ 43.844539][ C2] dev_set_mac_address_user+0x31/0x50 [ 43.844710][ C2] do_setlink+0x17b4/0x21e0 [ 43.844880][ C2] rtnl_setlink+0x1f7/0x310 [ 43.845052][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 43.845231][ C2] netlink_rcv_skb+0x130/0x360 [ 43.845409][ C2] netlink_unicast+0x449/0x710 [ 43.845585][ C2] netlink_sendmsg+0x723/0xbe0 [ 43.845759][ C2] __sys_sendto+0x37d/0x410 [ 43.845938][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 43.846108][ C2] do_syscall_64+0xc6/0x1e0 [ 43.846280][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 43.846574][ C2] } [ 43.846644][ C2] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 43.846923][ C2] ... acquired at: [ 43.847024][ C2] mark_lock+0x28d/0x3e0 [ 43.847162][ C2] mark_usage+0xd9/0x2a0 [ 43.847304][ C2] __lock_acquire+0x797/0x1570 [ 43.847441][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.847578][ C2] _raw_spin_lock+0x30/0x40 [ 43.847838][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.848072][ C2] call_timer_fn+0x13b/0x230 [ 43.848223][ C2] __run_timers+0x545/0x810 [ 43.848372][ C2] timer_expire_remote+0x9b/0xe0 [ 43.848521][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 43.848671][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 43.848826][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 43.848977][ C2] __do_softirq+0x1f8/0x5df [ 43.849215][ C2] irq_exit_rcu+0x97/0xc0 [ 43.849368][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 43.849552][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 43.849739][ C2] default_idle+0xf/0x20 [ 43.849891][ C2] default_idle_call+0x6d/0xb0 [ 43.850029][ C2] cpuidle_idle_call+0x1f4/0x280 [ 43.850166][ C2] do_idle+0xf9/0x160 [ 43.850281][ C2] cpu_startup_entry+0x54/0x60 [ 43.850500][ C2] start_secondary+0x21c/0x2b0 [ 43.850645][ C2] common_startup_64+0x12c/0x138 [ 43.850788][ C2] [ 43.850858][ C2] [ 43.850858][ C2] stack backtrace: [ 43.851028][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 43.851233][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 43.851542][ C2] Call Trace: [ 43.851650][ C2] [ 43.851810][ C2] dump_stack_lvl+0x82/0xd0 [ 43.851953][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 43.852125][ C2] ? common_startup_64+0x12c/0x138 [ 43.852270][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 43.852443][ C2] ? __pfx_usage_skip+0x10/0x10 [ 43.852594][ C2] ? __pfx_usage_match+0x10/0x10 [ 43.852743][ C2] ? arch_stack_walk+0x8c/0xf0 [ 43.852897][ C2] mark_lock_irq+0x4cd/0xa10 [ 43.853130][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 43.853271][ C2] ? stack_trace_save+0x94/0xd0 [ 43.853411][ C2] ? add_chain_cache+0x248/0x8b0 [ 43.853551][ C2] ? save_trace+0x8f/0x5b0 [ 43.853689][ C2] mark_lock+0x28d/0x3e0 [ 43.853795][ C2] mark_usage+0xd9/0x2a0 [ 43.853899][ C2] __lock_acquire+0x797/0x1570 [ 43.854036][ C2] ? __lock_acquire+0xaf0/0x1570 [ 43.854173][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 43.854510][ C2] lock_acquire.part.0+0xeb/0x330 [ 43.854646][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.854852][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 43.854991][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 43.855128][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.855332][ C2] ? lock_acquire+0x32/0xc0 [ 43.855472][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.855771][ C2] _raw_spin_lock+0x30/0x40 [ 43.855908][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.856115][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 43.856322][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 43.856563][ C2] call_timer_fn+0x13b/0x230 [ 43.856699][ C2] ? call_timer_fn+0xe8/0x230 [ 43.856836][ C2] ? call_timer_fn+0xe8/0x230 [ 43.856976][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 43.857112][ C2] ? mark_lock+0x38/0x3e0 [ 43.857220][ C2] __run_timers+0x545/0x810 [ 43.857356][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 43.857597][ C2] ? __pfx___run_timers+0x10/0x10 [ 43.857815][ C2] ? __lock_release+0x103/0x460 [ 43.857959][ C2] ? do_raw_spin_lock+0x131/0x270 [ 43.858095][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 43.858233][ C2] ? lock_acquire+0x32/0xc0 [ 43.858370][ C2] ? timer_expire_remote+0x93/0xe0 [ 43.858513][ C2] timer_expire_remote+0x9b/0xe0 [ 43.858654][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 43.858791][ C2] ? __pfx_tmigr_handle_remote_cpu+0x10/0x10 [ 43.859046][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 43.859183][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 43.859322][ C2] ? do_raw_spin_lock+0x131/0x270 [ 43.859467][ C2] ? __pfx_tmigr_handle_remote+0x10/0x10 [ 43.859604][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 43.859742][ C2] ? lockdep_hardirqs_on_prepare.part.0+0x14f/0x370 [ 43.859914][ C2] __do_softirq+0x1f8/0x5df [ 43.860051][ C2] irq_exit_rcu+0x97/0xc0 [ 43.860160][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 43.860393][ C2] [ 43.860472][ C2] [ 43.860548][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 43.860740][ C2] RIP: 0010:default_idle+0xf/0x20 [ 43.860890][ 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 [ 43.861373][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000242 [ 43.861642][ C2] RAX: 0000000000120925 RBX: 1ffff9200002bfc1 RCX: ffffffff9690e9d5 [ 43.861852][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff942aa4a4 [ 43.862062][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 43.862278][ C2] R10: ffff8880361384e3 R11: ffff88803613dc80 R12: 0000000000000000 [ 43.862489][ C2] R13: ffff888001b7c5c0 R14: dffffc0000000000 R15: 0000000000000000 [ 43.862703][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 43.862923][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 43.863068][ C2] default_idle_call+0x6d/0xb0 [ 43.863209][ C2] cpuidle_idle_call+0x1f4/0x280 [ 43.863346][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 43.863485][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 43.863623][ C2] do_idle+0xf9/0x160 [ 43.863727][ C2] cpu_startup_entry+0x54/0x60 [ 43.863880][ C2] start_secondary+0x21c/0x2b0 [ 43.864018][ C2] ? __pfx_start_secondary+0x10/0x10 [ 43.864253][ C2] common_startup_64+0x12c/0x138 [ 43.864393][ C2] [ 50.472443][ T547] br1: port 2(veth2) entered disabled state [ 50.473063][ T547] br1: port 1(veth1) entered disabled state [ 50.683692][ T549] veth2: left allmulticast mode [ 50.683866][ T549] veth2: left promiscuous mode [ 50.684118][ T549] br1: port 2(veth2) entered disabled state [ 50.887474][ T551] veth1: left allmulticast mode [ 50.887641][ T551] veth1: left promiscuous mode [ 50.887891][ T551] br1: port 1(veth1) entered disabled state