[ 27.264712][ T286] br1: port 1(veth1) entered blocking state [ 27.265798][ T286] br1: port 1(veth1) entered disabled state [ 27.266450][ T286] veth1: entered allmulticast mode [ 27.268426][ T286] veth1: entered promiscuous mode [ 27.401831][ T7] br1: port 1(veth1) entered blocking state [ 27.402175][ T7] br1: port 1(veth1) entered forwarding state [ 27.508553][ T289] br1: port 2(veth2) entered blocking state [ 27.508793][ T289] br1: port 2(veth2) entered disabled state [ 27.510153][ T289] veth2: entered allmulticast mode [ 27.512011][ T289] veth2: entered promiscuous mode [ 27.636468][ T50] br1: port 2(veth2) entered blocking state [ 27.636718][ T50] br1: port 2(veth2) entered forwarding state [ 34.077077][ T308] GACT probability NOT on [ 34.100515][ T306] tc (306) used greatest stack depth: 23424 bytes left [ 42.796188][ C0] [ 42.796421][ C0] ======================================================== [ 42.796669][ C0] WARNING: possible irq lock inversion dependency detected [ 42.796902][ C0] 6.9.0-rc1-virtme #1 Not tainted [ 42.797055][ C0] -------------------------------------------------------- [ 42.797285][ C0] swapper/0/0 just changed the state of lock: [ 42.797479][ C0] ffff888005ef2c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.797869][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 42.798088][ C0] (&p->alloc_lock){+.+.}-{2:2} [ 42.798093][ C0] [ 42.798093][ C0] [ 42.798093][ C0] and interrupts could create inverse lock ordering between them. [ 42.798093][ C0] [ 42.798644][ C0] [ 42.798644][ C0] other info that might help us debug this: [ 42.798860][ C0] Chain exists of: [ 42.798860][ C0] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 42.798860][ C0] [ 42.799193][ C0] Possible interrupt unsafe locking scenario: [ 42.799193][ C0] [ 42.799411][ C0] CPU0 CPU1 [ 42.799558][ C0] ---- ---- [ 42.799704][ C0] lock(&p->alloc_lock); [ 42.799817][ C0] local_irq_disable(); [ 42.800003][ C0] lock(&br->lock); [ 42.800224][ C0] lock(lweventlist_lock); [ 42.800419][ C0] [ 42.800534][ C0] lock(&br->lock); [ 42.800656][ C0] [ 42.800656][ C0] *** DEADLOCK *** [ 42.800656][ C0] [ 42.800878][ C0] 1 lock held by swapper/0/0: [ 42.801032][ C0] #0: ffffc90000007d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 42.801338][ C0] [ 42.801338][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 42.801592][ C0] -> (&p->alloc_lock){+.+.}-{2:2} { [ 42.801749][ C0] HARDIRQ-ON-W at: [ 42.801864][ C0] __lock_acquire+0x797/0x1570 [ 42.802054][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.802243][ C0] _raw_spin_lock+0x30/0x40 [ 42.802431][ C0] set_mems_allowed+0x1d/0x210 [ 42.802617][ C0] kernel_init_freeable+0x72/0x310 [ 42.802803][ C0] kernel_init+0x20/0x200 [ 42.802989][ C0] ret_from_fork+0x31/0x70 [ 42.803180][ C0] ret_from_fork_asm+0x1a/0x30 [ 42.803370][ C0] SOFTIRQ-ON-W at: [ 42.803482][ C0] __lock_acquire+0x797/0x1570 [ 42.803668][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.803853][ C0] _raw_spin_lock+0x30/0x40 [ 42.804036][ C0] set_mems_allowed+0x1d/0x210 [ 42.804223][ C0] kernel_init_freeable+0x72/0x310 [ 42.804415][ C0] kernel_init+0x20/0x200 [ 42.804604][ C0] ret_from_fork+0x31/0x70 [ 42.804790][ C0] ret_from_fork_asm+0x1a/0x30 [ 42.804974][ C0] INITIAL USE at: [ 42.805090][ C0] __lock_acquire+0x797/0x1570 [ 42.805275][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.805467][ C0] _raw_spin_lock+0x30/0x40 [ 42.805653][ C0] set_mems_allowed+0x1d/0x210 [ 42.805838][ C0] kernel_init_freeable+0x72/0x310 [ 42.806023][ C0] kernel_init+0x20/0x200 [ 42.806208][ C0] ret_from_fork+0x31/0x70 [ 42.806394][ C0] ret_from_fork_asm+0x1a/0x30 [ 42.806582][ C0] } [ 42.806659][ C0] ... key at: [] __key.387+0x0/0x40 [ 42.806883][ C0] ... acquired at: [ 42.806995][ C0] __lock_acquire+0xaf0/0x1570 [ 42.807145][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.807293][ C0] _raw_spin_lock+0x30/0x40 [ 42.807440][ C0] __get_task_comm+0x27/0x70 [ 42.807589][ C0] ref_tracker_alloc+0x2ee/0x490 [ 42.807738][ C0] linkwatch_fire_event+0x196/0x200 [ 42.807893][ C0] veth_newlink+0x367/0x830 [veth] [ 42.808050][ C0] rtnl_newlink_create+0x341/0x850 [ 42.808196][ C0] __rtnl_newlink+0xac9/0xd80 [ 42.808346][ C0] rtnl_newlink+0x63/0xa0 [ 42.808493][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 42.808644][ C0] netlink_rcv_skb+0x130/0x360 [ 42.808791][ C0] netlink_unicast+0x449/0x710 [ 42.808939][ C0] netlink_sendmsg+0x723/0xbe0 [ 42.809091][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 42.809240][ C0] ___sys_sendmsg+0xee/0x170 [ 42.809391][ C0] __sys_sendmsg+0xcd/0x170 [ 42.809541][ C0] do_syscall_64+0xc6/0x1e0 [ 42.809690][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 42.809877][ C0] [ 42.809953][ C0] -> (lweventlist_lock){....}-{2:2} { [ 42.810113][ C0] INITIAL USE at: [ 42.810229][ C0] __lock_acquire+0x797/0x1570 [ 42.810420][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.810606][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 42.810793][ C0] linkwatch_sync_dev+0x29/0x1f0 [ 42.810976][ C0] rtnl_getlink+0x4c9/0x970 [ 42.811160][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 42.811349][ C0] netlink_rcv_skb+0x130/0x360 [ 42.811536][ C0] netlink_unicast+0x449/0x710 [ 42.811722][ C0] netlink_sendmsg+0x723/0xbe0 [ 42.811906][ C0] __sys_sendto+0x37d/0x410 [ 42.812091][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 42.812276][ C0] do_syscall_64+0xc6/0x1e0 [ 42.812465][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 42.812693][ C0] } [ 42.812768][ C0] ... key at: [] lweventlist_lock+0x18/0x60 [ 42.812987][ C0] ... acquired at: [ 42.813096][ C0] __lock_acquire+0xaf0/0x1570 [ 42.813245][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.813507][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 42.813657][ C0] linkwatch_fire_event+0x74/0x200 [ 42.813809][ C0] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 42.814036][ C0] br_set_mac_address+0x1f3/0x260 [bridge] [ 42.814254][ C0] dev_set_mac_address+0x28a/0x410 [ 42.814404][ C0] dev_set_mac_address_user+0x31/0x50 [ 42.814551][ C0] do_setlink+0x17b4/0x21e0 [ 42.814699][ C0] rtnl_setlink+0x1f7/0x310 [ 42.814848][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 42.815001][ C0] netlink_rcv_skb+0x130/0x360 [ 42.815151][ C0] netlink_unicast+0x449/0x710 [ 42.815300][ C0] netlink_sendmsg+0x723/0xbe0 [ 42.815450][ C0] __sys_sendto+0x37d/0x410 [ 42.815602][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 42.815750][ C0] do_syscall_64+0xc6/0x1e0 [ 42.815899][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 42.816085][ C0] [ 42.816160][ C0] -> (&br->lock){+.-.}-{2:2} { [ 42.816314][ C0] HARDIRQ-ON-W at: [ 42.816425][ C0] __lock_acquire+0x797/0x1570 [ 42.816612][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.816800][ C0] _raw_spin_lock_bh+0x38/0x50 [ 42.816988][ C0] br_stp_enable_bridge+0x1f/0x2f0 [bridge] [ 42.817245][ C0] br_dev_open+0xa2/0x120 [bridge] [ 42.817463][ C0] __dev_open+0x221/0x430 [ 42.817650][ C0] __dev_change_flags+0x469/0x6c0 [ 42.817834][ C0] rtnl_configure_link+0x118/0x200 [ 42.818023][ C0] rtnl_newlink_create+0x36e/0x850 [ 42.818209][ C0] __rtnl_newlink+0xac9/0xd80 [ 42.818393][ C0] rtnl_newlink+0x63/0xa0 [ 42.818577][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 42.818772][ C0] netlink_rcv_skb+0x130/0x360 [ 42.818958][ C0] netlink_unicast+0x449/0x710 [ 42.819142][ C0] netlink_sendmsg+0x723/0xbe0 [ 42.819328][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 42.819514][ C0] ___sys_sendmsg+0xee/0x170 [ 42.819703][ C0] __sys_sendmsg+0xcd/0x170 [ 42.819889][ C0] do_syscall_64+0xc6/0x1e0 [ 42.820083][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 42.820322][ C0] IN-SOFTIRQ-W at: [ 42.820436][ C0] __lock_acquire+0x797/0x1570 [ 42.820623][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.820806][ C0] _raw_spin_lock+0x30/0x40 [ 42.820991][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.821256][ C0] call_timer_fn+0x13b/0x230 [ 42.821442][ C0] __run_timers+0x545/0x810 [ 42.821625][ C0] run_timer_softirq+0xe8/0x1b0 [ 42.821811][ C0] __do_softirq+0x1f8/0x5df [ 42.821997][ C0] irq_exit_rcu+0x97/0xc0 [ 42.822181][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 42.822403][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 42.822633][ C0] default_idle+0xf/0x20 [ 42.822817][ C0] default_idle_call+0x6d/0xb0 [ 42.823010][ C0] cpuidle_idle_call+0x1f4/0x280 [ 42.823195][ C0] do_idle+0xf9/0x160 [ 42.823345][ C0] cpu_startup_entry+0x54/0x60 [ 42.823530][ C0] rest_init+0x14f/0x260 [ 42.823718][ C0] start_kernel+0x318/0x3d0 [ 42.823907][ C0] x86_64_start_reservations+0x18/0x30 [ 42.824092][ C0] x86_64_start_kernel+0xba/0x110 [ 42.824276][ C0] common_startup_64+0x12c/0x138 [ 42.824462][ C0] INITIAL USE at: [ 42.824574][ C0] __lock_acquire+0x797/0x1570 [ 42.824759][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.824947][ C0] _raw_spin_lock_bh+0x38/0x50 [ 42.825134][ C0] br_stp_enable_bridge+0x1f/0x2f0 [bridge] [ 42.825393][ C0] br_dev_open+0xa2/0x120 [bridge] [ 42.825608][ C0] __dev_open+0x221/0x430 [ 42.825794][ C0] __dev_change_flags+0x469/0x6c0 [ 42.825977][ C0] rtnl_configure_link+0x118/0x200 [ 42.826168][ C0] rtnl_newlink_create+0x36e/0x850 [ 42.826351][ C0] __rtnl_newlink+0xac9/0xd80 [ 42.826536][ C0] rtnl_newlink+0x63/0xa0 [ 42.826720][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 42.826902][ C0] netlink_rcv_skb+0x130/0x360 [ 42.827088][ C0] netlink_unicast+0x449/0x710 [ 42.827277][ C0] netlink_sendmsg+0x723/0xbe0 [ 42.827461][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 42.827646][ C0] ___sys_sendmsg+0xee/0x170 [ 42.827923][ C0] __sys_sendmsg+0xcd/0x170 [ 42.828107][ C0] do_syscall_64+0xc6/0x1e0 [ 42.828291][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 42.828600][ C0] } [ 42.828681][ C0] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 42.828969][ C0] ... acquired at: [ 42.829077][ C0] mark_lock+0x28d/0x3e0 [ 42.829313][ C0] mark_usage+0xd9/0x2a0 [ 42.829459][ C0] __lock_acquire+0x797/0x1570 [ 42.829604][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.829751][ C0] _raw_spin_lock+0x30/0x40 [ 42.829990][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.830224][ C0] call_timer_fn+0x13b/0x230 [ 42.830372][ C0] __run_timers+0x545/0x810 [ 42.830518][ C0] run_timer_softirq+0xe8/0x1b0 [ 42.830754][ C0] __do_softirq+0x1f8/0x5df [ 42.830902][ C0] irq_exit_rcu+0x97/0xc0 [ 42.831050][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 42.831260][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 42.831540][ C0] default_idle+0xf/0x20 [ 42.831691][ C0] default_idle_call+0x6d/0xb0 [ 42.831840][ C0] cpuidle_idle_call+0x1f4/0x280 [ 42.831986][ C0] do_idle+0xf9/0x160 [ 42.832187][ C0] cpu_startup_entry+0x54/0x60 [ 42.832334][ C0] rest_init+0x14f/0x260 [ 42.832479][ C0] start_kernel+0x318/0x3d0 [ 42.832625][ C0] x86_64_start_reservations+0x18/0x30 [ 42.832771][ C0] x86_64_start_kernel+0xba/0x110 [ 42.833100][ C0] common_startup_64+0x12c/0x138 [ 42.833248][ C0] [ 42.833322][ C0] [ 42.833322][ C0] stack backtrace: [ 42.833501][ C0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.9.0-rc1-virtme #1 [ 42.833724][ C0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 42.834047][ C0] Call Trace: [ 42.834158][ C0] [ 42.834239][ C0] dump_stack_lvl+0x82/0xd0 [ 42.834390][ C0] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 42.834578][ C0] ? common_startup_64+0x12c/0x138 [ 42.834725][ C0] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 42.834997][ C0] ? __pfx_usage_skip+0x10/0x10 [ 42.835143][ C0] ? __pfx_usage_match+0x10/0x10 [ 42.835288][ C0] ? arch_stack_walk+0x8c/0xf0 [ 42.835435][ C0] mark_lock_irq+0x4cd/0xa10 [ 42.835679][ C0] ? __pfx_mark_lock_irq+0x10/0x10 [ 42.835827][ C0] ? stack_trace_save+0x94/0xd0 [ 42.835974][ C0] ? add_chain_cache+0x248/0x8b0 [ 42.836122][ C0] ? save_trace+0x8f/0x5b0 [ 42.836270][ C0] mark_lock+0x28d/0x3e0 [ 42.836472][ C0] mark_usage+0xd9/0x2a0 [ 42.836583][ C0] __lock_acquire+0x797/0x1570 [ 42.836730][ C0] ? __lock_acquire+0xaf0/0x1570 [ 42.836876][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 42.837230][ C0] lock_acquire.part.0+0xeb/0x330 [ 42.837377][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.837598][ C0] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 42.837744][ C0] ? trace_lock_acquire+0x135/0x1c0 [ 42.837890][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.838106][ C0] ? lock_acquire+0x32/0xc0 [ 42.838252][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.838474][ C0] _raw_spin_lock+0x30/0x40 [ 42.838712][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.838928][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 42.839147][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 42.839489][ C0] call_timer_fn+0x13b/0x230 [ 42.839636][ C0] ? call_timer_fn+0xe8/0x230 [ 42.839781][ C0] ? call_timer_fn+0xe8/0x230 [ 42.839939][ C0] ? __pfx_call_timer_fn+0x10/0x10 [ 42.840187][ C0] ? mark_lock+0x38/0x3e0 [ 42.840303][ C0] __run_timers+0x545/0x810 [ 42.840450][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 42.840705][ C0] ? __pfx___run_timers+0x10/0x10 [ 42.840943][ C0] ? do_raw_spin_lock+0x131/0x270 [ 42.841090][ C0] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 42.841235][ C0] ? lock_acquire+0x32/0xc0 [ 42.841393][ C0] ? run_timer_softirq+0xe0/0x1b0 [ 42.841631][ C0] run_timer_softirq+0xe8/0x1b0 [ 42.841777][ C0] __do_softirq+0x1f8/0x5df [ 42.841924][ C0] irq_exit_rcu+0x97/0xc0 [ 42.842036][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 42.842182][ C0] [ 42.842348][ C0] [ 42.842423][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 42.842605][ C0] RIP: 0010:default_idle+0xf/0x20 [ 42.842762][ 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 [ 42.843384][ C0] RSP: 0018:ffffffff98607e00 EFLAGS: 00000242 [ 42.843575][ C0] RAX: 00000000000aa073 RBX: 1ffffffff30c0fc2 RCX: ffffffff9770e9d5 [ 42.843797][ C0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff950aa4a4 [ 42.844022][ C0] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c0709c [ 42.844241][ C0] R10: ffff8880360384e3 R11: ffff88803602d9b0 R12: 0000000000000000 [ 42.844555][ C0] R13: ffffffff9861d000 R14: dffffc0000000000 R15: 0000000000014770 [ 42.844775][ C0] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 42.844921][ C0] ? cpuidle_idle_call+0x1f4/0x280 [ 42.845162][ C0] default_idle_call+0x6d/0xb0 [ 42.845309][ C0] cpuidle_idle_call+0x1f4/0x280 [ 42.845457][ C0] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 42.845604][ C0] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 42.845752][ C0] do_idle+0xf9/0x160 [ 42.845953][ C0] cpu_startup_entry+0x54/0x60 [ 42.846099][ C0] rest_init+0x14f/0x260 [ 42.846212][ C0] start_kernel+0x318/0x3d0 [ 42.846359][ C0] x86_64_start_reservations+0x18/0x30 [ 42.846603][ C0] x86_64_start_kernel+0xba/0x110 [ 42.846753][ C0] common_startup_64+0x12c/0x138 [ 42.846904][ C0] [ 54.721533][ T474] br1: port 2(veth2) entered disabled state [ 54.831405][ T475] veth2: left allmulticast mode [ 54.831753][ T475] veth2: left promiscuous mode [ 54.832167][ T475] br1: port 2(veth2) entered disabled state [ 54.949241][ T476] br1: port 1(veth1) entered disabled state [ 55.045353][ T477] veth1: left allmulticast mode [ 55.045625][ T477] veth1: left promiscuous mode [ 55.045926][ T477] br1: port 1(veth1) entered disabled state