[ 26.642372][ T274] 8021q: 802.1Q VLAN Support v1.8 [ 29.057604][ T295] br0: port 1(veth1) entered blocking state [ 29.058212][ T295] br0: port 1(veth1) entered disabled state [ 29.059050][ T295] veth1: entered allmulticast mode [ 29.067040][ T295] veth1: entered promiscuous mode [ 29.184102][ T297] br0: port 2(veth2) entered blocking state [ 29.184354][ T297] br0: port 2(veth2) entered disabled state [ 29.185782][ T297] veth2: entered allmulticast mode [ 29.187709][ T297] veth2: entered promiscuous mode [ 29.586564][ T7] br0: port 1(veth1) entered blocking state [ 29.586981][ T7] br0: port 1(veth1) entered forwarding state [ 29.695873][ T51] br0: port 2(veth2) entered blocking state [ 29.696231][ T51] br0: port 2(veth2) entered forwarding state [ 44.842621][ C0] [ 44.842787][ C0] ======================================================== [ 44.843061][ C0] WARNING: possible irq lock inversion dependency detected [ 44.843431][ C0] 6.9.0-rc1-virtme #1 Not tainted [ 44.843601][ C0] -------------------------------------------------------- [ 44.843848][ C0] swapper/0/0 just changed the state of lock: [ 44.844049][ C0] ffff888031e42c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.844473][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 44.844710][ C0] (&p->alloc_lock){+.+.}-{2:2} [ 44.844714][ C0] [ 44.844714][ C0] [ 44.844714][ C0] and interrupts could create inverse lock ordering between them. [ 44.844714][ C0] [ 44.845317][ C0] [ 44.845317][ C0] other info that might help us debug this: [ 44.845551][ C0] Chain exists of: [ 44.845551][ C0] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 44.845551][ C0] [ 44.845912][ C0] Possible interrupt unsafe locking scenario: [ 44.845912][ C0] [ 44.846201][ C0] CPU0 CPU1 [ 44.846366][ C0] ---- ---- [ 44.846524][ C0] lock(&p->alloc_lock); [ 44.846646][ C0] local_irq_disable(); [ 44.846846][ C0] lock(&br->lock); [ 44.847048][ C0] lock(lweventlist_lock); [ 44.847256][ C0] [ 44.847379][ C0] lock(&br->lock); [ 44.847500][ C0] [ 44.847500][ C0] *** DEADLOCK *** [ 44.847500][ C0] [ 44.847733][ C0] 1 lock held by swapper/0/0: [ 44.847897][ C0] #0: ffffc90000007d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 44.848230][ C0] [ 44.848230][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 44.848516][ C0] -> (&p->alloc_lock){+.+.}-{2:2} { [ 44.848680][ C0] HARDIRQ-ON-W at: [ 44.848804][ C0] __lock_acquire+0x797/0x1570 [ 44.849015][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.849215][ C0] _raw_spin_lock+0x30/0x40 [ 44.849417][ C0] set_mems_allowed+0x1d/0x210 [ 44.849625][ C0] kernel_init_freeable+0x72/0x310 [ 44.849834][ C0] kernel_init+0x20/0x200 [ 44.850050][ C0] ret_from_fork+0x31/0x70 [ 44.850257][ C0] ret_from_fork_asm+0x1a/0x30 [ 44.850460][ C0] SOFTIRQ-ON-W at: [ 44.850580][ C0] __lock_acquire+0x797/0x1570 [ 44.850782][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.850990][ C0] _raw_spin_lock+0x30/0x40 [ 44.851191][ C0] set_mems_allowed+0x1d/0x210 [ 44.851392][ C0] kernel_init_freeable+0x72/0x310 [ 44.851596][ C0] kernel_init+0x20/0x200 [ 44.851799][ C0] ret_from_fork+0x31/0x70 [ 44.851999][ C0] ret_from_fork_asm+0x1a/0x30 [ 44.852204][ C0] INITIAL USE at: [ 44.852328][ C0] __lock_acquire+0x797/0x1570 [ 44.852529][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.852732][ C0] _raw_spin_lock+0x30/0x40 [ 44.852938][ C0] set_mems_allowed+0x1d/0x210 [ 44.853137][ C0] kernel_init_freeable+0x72/0x310 [ 44.853346][ C0] kernel_init+0x20/0x200 [ 44.853547][ C0] ret_from_fork+0x31/0x70 [ 44.853752][ C0] ret_from_fork_asm+0x1a/0x30 [ 44.853952][ C0] } [ 44.854035][ C0] ... key at: [] __key.387+0x0/0x40 [ 44.854287][ C0] ... acquired at: [ 44.854420][ C0] __lock_acquire+0xaf0/0x1570 [ 44.854592][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.854759][ C0] _raw_spin_lock+0x30/0x40 [ 44.854926][ C0] __get_task_comm+0x27/0x70 [ 44.855094][ C0] ref_tracker_alloc+0x2ee/0x490 [ 44.855267][ C0] linkwatch_fire_event+0x196/0x200 [ 44.855435][ C0] veth_newlink+0x367/0x830 [veth] [ 44.855609][ C0] rtnl_newlink_create+0x341/0x850 [ 44.855829][ C0] __rtnl_newlink+0xac9/0xd80 [ 44.856004][ C0] rtnl_newlink+0x63/0xa0 [ 44.856178][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 44.856352][ C0] netlink_rcv_skb+0x130/0x360 [ 44.856520][ C0] netlink_unicast+0x449/0x710 [ 44.856692][ C0] netlink_sendmsg+0x723/0xbe0 [ 44.856859][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 44.857036][ C0] ___sys_sendmsg+0xee/0x170 [ 44.857204][ C0] __sys_sendmsg+0xcd/0x170 [ 44.857373][ C0] do_syscall_64+0xc6/0x1e0 [ 44.857542][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 44.857752][ C0] [ 44.857837][ C0] -> (lweventlist_lock){....}-{2:2} { [ 44.858017][ C0] INITIAL USE at: [ 44.858143][ C0] __lock_acquire+0x797/0x1570 [ 44.858350][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.858557][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 44.858780][ C0] linkwatch_sync_dev+0x29/0x1f0 [ 44.858987][ C0] rtnl_getlink+0x4c9/0x970 [ 44.859198][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 44.859408][ C0] netlink_rcv_skb+0x130/0x360 [ 44.859618][ C0] netlink_unicast+0x449/0x710 [ 44.859824][ C0] netlink_sendmsg+0x723/0xbe0 [ 44.860047][ C0] __sys_sendto+0x37d/0x410 [ 44.860263][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 44.860471][ C0] do_syscall_64+0xc6/0x1e0 [ 44.860677][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 44.860927][ C0] } [ 44.861013][ C0] ... key at: [] lweventlist_lock+0x18/0x60 [ 44.861266][ C0] ... acquired at: [ 44.861389][ C0] __lock_acquire+0xaf0/0x1570 [ 44.861557][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.861725][ C0] _raw_spin_lock_irqsave+0x3f/0x60 [ 44.861892][ C0] linkwatch_fire_event+0x74/0x200 [ 44.862058][ C0] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 44.862306][ C0] br_set_mac_address+0x1f3/0x260 [bridge] [ 44.862551][ C0] dev_set_mac_address+0x28a/0x410 [ 44.862726][ C0] dev_set_mac_address_user+0x31/0x50 [ 44.862891][ C0] do_setlink+0x17b4/0x21e0 [ 44.863056][ C0] rtnl_setlink+0x1f7/0x310 [ 44.863224][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 44.863387][ C0] netlink_rcv_skb+0x130/0x360 [ 44.863552][ C0] netlink_unicast+0x449/0x710 [ 44.863722][ C0] netlink_sendmsg+0x723/0xbe0 [ 44.863894][ C0] __sys_sendto+0x37d/0x410 [ 44.864067][ C0] __x64_sys_sendto+0xe0/0x1c0 [ 44.864232][ C0] do_syscall_64+0xc6/0x1e0 [ 44.864400][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 44.864613][ C0] [ 44.864697][ C0] -> (&br->lock){+.-.}-{2:2} { [ 44.864869][ C0] HARDIRQ-ON-W at: [ 44.864994][ C0] __lock_acquire+0x797/0x1570 [ 44.865212][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.865420][ C0] _raw_spin_lock_bh+0x38/0x50 [ 44.865639][ C0] recalculate_group_addr+0x55/0x130 [bridge] [ 44.865928][ C0] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 44.866222][ C0] br_changelink+0x36c/0x1360 [bridge] [ 44.866474][ C0] br_dev_newlink+0xa5/0x100 [bridge] [ 44.866721][ C0] rtnl_newlink_create+0x341/0x850 [ 44.866938][ C0] __rtnl_newlink+0xac9/0xd80 [ 44.867150][ C0] rtnl_newlink+0x63/0xa0 [ 44.867362][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 44.867575][ C0] netlink_rcv_skb+0x130/0x360 [ 44.867785][ C0] netlink_unicast+0x449/0x710 [ 44.867996][ C0] netlink_sendmsg+0x723/0xbe0 [ 44.868204][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 44.868419][ C0] ___sys_sendmsg+0xee/0x170 [ 44.868630][ C0] __sys_sendmsg+0xcd/0x170 [ 44.868843][ C0] do_syscall_64+0xc6/0x1e0 [ 44.869056][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 44.869307][ C0] IN-SOFTIRQ-W at: [ 44.869434][ C0] __lock_acquire+0x797/0x1570 [ 44.869645][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.869861][ C0] _raw_spin_lock+0x30/0x40 [ 44.870082][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.870368][ C0] call_timer_fn+0x13b/0x230 [ 44.870578][ C0] __run_timers+0x545/0x810 [ 44.870786][ C0] run_timer_softirq+0xe8/0x1b0 [ 44.870996][ C0] __do_softirq+0x1f8/0x5df [ 44.871212][ C0] irq_exit_rcu+0x97/0xc0 [ 44.871422][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 44.871674][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 44.871931][ C0] default_idle+0xf/0x20 [ 44.872145][ C0] default_idle_call+0x6d/0xb0 [ 44.872355][ C0] cpuidle_idle_call+0x1f4/0x280 [ 44.872579][ C0] do_idle+0xf9/0x160 [ 44.872753][ C0] cpu_startup_entry+0x54/0x60 [ 44.872967][ C0] rest_init+0x14f/0x260 [ 44.873183][ C0] start_kernel+0x318/0x3d0 [ 44.873397][ C0] x86_64_start_reservations+0x18/0x30 [ 44.873607][ C0] x86_64_start_kernel+0xba/0x110 [ 44.873814][ C0] common_startup_64+0x12c/0x138 [ 44.874027][ C0] INITIAL USE at: [ 44.874156][ C0] __lock_acquire+0x797/0x1570 [ 44.874367][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.874576][ C0] _raw_spin_lock_bh+0x38/0x50 [ 44.874790][ C0] recalculate_group_addr+0x55/0x130 [bridge] [ 44.875081][ C0] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 44.875375][ C0] br_changelink+0x36c/0x1360 [bridge] [ 44.875621][ C0] br_dev_newlink+0xa5/0x100 [bridge] [ 44.875965][ C0] rtnl_newlink_create+0x341/0x850 [ 44.876172][ C0] __rtnl_newlink+0xac9/0xd80 [ 44.876385][ C0] rtnl_newlink+0x63/0xa0 [ 44.876682][ C0] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 44.876899][ C0] netlink_rcv_skb+0x130/0x360 [ 44.877104][ C0] netlink_unicast+0x449/0x710 [ 44.877311][ C0] netlink_sendmsg+0x723/0xbe0 [ 44.877609][ C0] ____sys_sendmsg+0x7b2/0xa10 [ 44.877815][ C0] ___sys_sendmsg+0xee/0x170 [ 44.878032][ C0] __sys_sendmsg+0xcd/0x170 [ 44.878328][ C0] do_syscall_64+0xc6/0x1e0 [ 44.878543][ C0] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 44.878791][ C0] } [ 44.878876][ C0] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 44.879377][ C0] ... acquired at: [ 44.879500][ C0] mark_lock+0x28d/0x3e0 [ 44.879666][ C0] mark_usage+0xd9/0x2a0 [ 44.879829][ C0] __lock_acquire+0x797/0x1570 [ 44.880096][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.880267][ C0] _raw_spin_lock+0x30/0x40 [ 44.880435][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.880680][ C0] call_timer_fn+0x13b/0x230 [ 44.880933][ C0] __run_timers+0x545/0x810 [ 44.881104][ C0] run_timer_softirq+0xe8/0x1b0 [ 44.881282][ C0] __do_softirq+0x1f8/0x5df [ 44.881447][ C0] irq_exit_rcu+0x97/0xc0 [ 44.881709][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 44.881927][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 44.882135][ C0] default_idle+0xf/0x20 [ 44.882305][ C0] default_idle_call+0x6d/0xb0 [ 44.882561][ C0] cpuidle_idle_call+0x1f4/0x280 [ 44.882732][ C0] do_idle+0xf9/0x160 [ 44.882857][ C0] cpu_startup_entry+0x54/0x60 [ 44.883025][ C0] rest_init+0x14f/0x260 [ 44.883282][ C0] start_kernel+0x318/0x3d0 [ 44.883452][ C0] x86_64_start_reservations+0x18/0x30 [ 44.883625][ C0] x86_64_start_kernel+0xba/0x110 [ 44.883788][ C0] common_startup_64+0x12c/0x138 [ 44.884042][ C0] [ 44.884138][ C0] [ 44.884138][ C0] stack backtrace: [ 44.884344][ C0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 6.9.0-rc1-virtme #1 [ 44.884599][ C0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 44.885063][ C0] Call Trace: [ 44.885188][ C0] [ 44.885273][ C0] dump_stack_lvl+0x82/0xd0 [ 44.885449][ C0] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 44.885745][ C0] ? common_startup_64+0x12c/0x138 [ 44.885914][ C0] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 44.886119][ C0] ? __pfx_usage_skip+0x10/0x10 [ 44.886286][ C0] ? __pfx_usage_match+0x10/0x10 [ 44.886548][ C0] ? arch_stack_walk+0x8c/0xf0 [ 44.886715][ C0] mark_lock_irq+0x4cd/0xa10 [ 44.886882][ C0] ? __pfx_mark_lock_irq+0x10/0x10 [ 44.887050][ C0] ? stack_trace_save+0x94/0xd0 [ 44.887305][ C0] ? add_chain_cache+0x248/0x8b0 [ 44.887472][ C0] ? save_trace+0x8f/0x5b0 [ 44.887638][ C0] mark_lock+0x28d/0x3e0 [ 44.887763][ C0] mark_usage+0xd9/0x2a0 [ 44.887891][ C0] __lock_acquire+0x797/0x1570 [ 44.888151][ C0] ? __lock_acquire+0xaf0/0x1570 [ 44.888317][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 44.888606][ C0] lock_acquire.part.0+0xeb/0x330 [ 44.888769][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.889105][ C0] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 44.889289][ C0] ? trace_lock_acquire+0x135/0x1c0 [ 44.889455][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.889796][ C0] ? lock_acquire+0x32/0xc0 [ 44.889960][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.890220][ C0] _raw_spin_lock+0x30/0x40 [ 44.890385][ C0] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.890719][ C0] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 44.890965][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 44.891252][ C0] call_timer_fn+0x13b/0x230 [ 44.891417][ C0] ? call_timer_fn+0xe8/0x230 [ 44.891689][ C0] ? call_timer_fn+0xe8/0x230 [ 44.891855][ C0] ? __pfx_call_timer_fn+0x10/0x10 [ 44.892023][ C0] ? mark_lock+0x38/0x3e0 [ 44.892155][ C0] __run_timers+0x545/0x810 [ 44.892461][ C0] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 44.892905][ C0] ? __pfx___run_timers+0x10/0x10 [ 44.893144][ C0] ? do_raw_spin_lock+0x131/0x270 [ 44.893389][ C0] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 44.893807][ C0] ? lock_acquire+0x32/0xc0 [ 44.894061][ C0] ? run_timer_softirq+0xe0/0x1b0 [ 44.894320][ C0] run_timer_softirq+0xe8/0x1b0 [ 44.894582][ C0] __do_softirq+0x1f8/0x5df [ 44.894832][ C0] irq_exit_rcu+0x97/0xc0 [ 44.895012][ C0] sysvec_apic_timer_interrupt+0x75/0x80 [ 44.895276][ C0] [ 44.895408][ C0] [ 44.895545][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 44.896035][ C0] RIP: 0010:default_idle+0xf/0x20 [ 44.896307][ 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 [ 44.897383][ C0] RSP: 0018:ffffffff9bc07e00 EFLAGS: 00000246 [ 44.897714][ C0] RAX: 0000000000099edd RBX: 1ffffffff3780fc2 RCX: ffffffff9ad0e9d5 [ 44.898099][ C0] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff986aa4a4 [ 44.898639][ C0] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c0709c [ 44.899012][ C0] R10: ffff8880360384e3 R11: ffff88803602d9b0 R12: 0000000000000000 [ 44.899382][ C0] R13: ffffffff9bc1d000 R14: dffffc0000000000 R15: 0000000000014770 [ 44.899759][ C0] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 44.900018][ C0] ? cpuidle_idle_call+0x1f4/0x280 [ 44.900203][ C0] default_idle_call+0x6d/0xb0 [ 44.900370][ C0] cpuidle_idle_call+0x1f4/0x280 [ 44.900636][ C0] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 44.900801][ C0] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 44.900967][ C0] do_idle+0xf9/0x160 [ 44.901095][ C0] cpu_startup_entry+0x54/0x60 [ 44.901265][ C0] rest_init+0x14f/0x260 [ 44.901391][ C0] start_kernel+0x318/0x3d0 [ 44.901557][ C0] x86_64_start_reservations+0x18/0x30 [ 44.901720][ C0] x86_64_start_kernel+0xba/0x110 [ 44.901885][ C0] common_startup_64+0x12c/0x138 [ 44.902144][ C0] [ 86.860639][ T508] Mirror/redirect action on [ 94.605102][ T538] br0: port 2(veth2) entered disabled state [ 94.710767][ T539] br0: port 1(veth1) entered disabled state [ 94.811220][ T541] veth2: left allmulticast mode [ 94.811465][ T541] veth2: left promiscuous mode [ 94.812514][ T541] br0: port 2(veth2) entered disabled state [ 94.813683][ T541] veth1: left allmulticast mode [ 94.813837][ T541] veth1: left promiscuous mode [ 94.814091][ T541] br0: port 1(veth1) entered disabled state