[ 28.557393][ T278] 8021q: 802.1Q VLAN Support v1.8 [ 31.383035][ T302] br0: port 1(veth1) entered blocking state [ 31.383466][ T302] br0: port 1(veth1) entered disabled state [ 31.384147][ T302] veth1: entered allmulticast mode [ 31.386242][ T302] veth1: entered promiscuous mode [ 31.514224][ T304] br0: port 2(veth2) entered blocking state [ 31.514648][ T304] br0: port 2(veth2) entered disabled state [ 31.515018][ T304] veth2: entered allmulticast mode [ 31.518097][ T304] veth2: entered promiscuous mode [ 31.767398][ T49] br0: port 1(veth1) entered blocking state [ 31.767772][ T49] br0: port 1(veth1) entered forwarding state [ 31.889114][ T50] br0: port 2(veth2) entered blocking state [ 31.889402][ T50] br0: port 2(veth2) entered forwarding state [ 46.890699][ C1] [ 46.890898][ C1] ======================================================== [ 46.891155][ C1] WARNING: possible irq lock inversion dependency detected [ 46.891416][ C1] 6.9.0-rc1-virtme #1 Not tainted [ 46.891581][ C1] -------------------------------------------------------- [ 46.891827][ C1] swapper/1/0 just changed the state of lock: [ 46.892044][ C1] ffff8880089e2c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.892504][ C1] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 46.892707][ C1] (&p->alloc_lock){+.+.}-{2:2} [ 46.892711][ C1] [ 46.892711][ C1] [ 46.892711][ C1] and interrupts could create inverse lock ordering between them. [ 46.892711][ C1] [ 46.893204][ C1] [ 46.893204][ C1] other info that might help us debug this: [ 46.893418][ C1] Chain exists of: [ 46.893418][ C1] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 46.893418][ C1] [ 46.893716][ C1] Possible interrupt unsafe locking scenario: [ 46.893716][ C1] [ 46.893910][ C1] CPU0 CPU1 [ 46.894042][ C1] ---- ---- [ 46.894177][ C1] lock(&p->alloc_lock); [ 46.894299][ C1] local_irq_disable(); [ 46.894471][ C1] lock(&br->lock); [ 46.894647][ C1] lock(lweventlist_lock); [ 46.894815][ C1] [ 46.894921][ C1] lock(&br->lock); [ 46.895023][ C1] [ 46.895023][ C1] *** DEADLOCK *** [ 46.895023][ C1] [ 46.895217][ C1] 1 lock held by swapper/1/0: [ 46.895365][ C1] #0: ffffc900001d8d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 46.895650][ C1] [ 46.895650][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 46.895877][ C1] -> (&p->alloc_lock){+.+.}-{2:2} { [ 46.896017][ C1] HARDIRQ-ON-W at: [ 46.896121][ C1] __lock_acquire+0x797/0x1570 [ 46.896296][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.896470][ C1] _raw_spin_lock+0x30/0x40 [ 46.896642][ C1] set_mems_allowed+0x1d/0x210 [ 46.896810][ C1] kernel_init_freeable+0x72/0x310 [ 46.896978][ C1] kernel_init+0x20/0x200 [ 46.897145][ C1] ret_from_fork+0x31/0x70 [ 46.897335][ C1] ret_from_fork_asm+0x1a/0x30 [ 46.897522][ C1] SOFTIRQ-ON-W at: [ 46.897622][ C1] __lock_acquire+0x797/0x1570 [ 46.897791][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.897962][ C1] _raw_spin_lock+0x30/0x40 [ 46.898129][ C1] set_mems_allowed+0x1d/0x210 [ 46.898316][ C1] kernel_init_freeable+0x72/0x310 [ 46.898498][ C1] kernel_init+0x20/0x200 [ 46.898666][ C1] ret_from_fork+0x31/0x70 [ 46.898839][ C1] ret_from_fork_asm+0x1a/0x30 [ 46.899011][ C1] INITIAL USE at: [ 46.899117][ C1] __lock_acquire+0x797/0x1570 [ 46.899283][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.899466][ C1] _raw_spin_lock+0x30/0x40 [ 46.899636][ C1] set_mems_allowed+0x1d/0x210 [ 46.899801][ C1] kernel_init_freeable+0x72/0x310 [ 46.899967][ C1] kernel_init+0x20/0x200 [ 46.900134][ C1] ret_from_fork+0x31/0x70 [ 46.900305][ C1] ret_from_fork_asm+0x1a/0x30 [ 46.900488][ C1] } [ 46.900562][ C1] ... key at: [] __key.387+0x0/0x40 [ 46.900767][ C1] ... acquired at: [ 46.900872][ C1] __lock_acquire+0xaf0/0x1570 [ 46.901008][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.901141][ C1] _raw_spin_lock+0x30/0x40 [ 46.901272][ C1] __get_task_comm+0x27/0x70 [ 46.901414][ C1] ref_tracker_alloc+0x2ee/0x490 [ 46.901555][ C1] linkwatch_fire_event+0x196/0x200 [ 46.901691][ C1] veth_newlink+0x367/0x830 [veth] [ 46.901832][ C1] rtnl_newlink_create+0x341/0x850 [ 46.901969][ C1] __rtnl_newlink+0xac9/0xd80 [ 46.902102][ C1] rtnl_newlink+0x63/0xa0 [ 46.902247][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.902503][ C1] netlink_rcv_skb+0x130/0x360 [ 46.902645][ C1] netlink_unicast+0x449/0x710 [ 46.902795][ C1] netlink_sendmsg+0x723/0xbe0 [ 46.902927][ C1] ____sys_sendmsg+0x7b2/0xa10 [ 46.903060][ C1] ___sys_sendmsg+0xee/0x170 [ 46.903192][ C1] __sys_sendmsg+0xcd/0x170 [ 46.903332][ C1] do_syscall_64+0xc6/0x1e0 [ 46.903472][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.903639][ C1] [ 46.903709][ C1] -> (lweventlist_lock){....}-{2:2} { [ 46.903847][ C1] INITIAL USE at: [ 46.903953][ C1] __lock_acquire+0x797/0x1570 [ 46.904119][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.904285][ C1] _raw_spin_lock_irqsave+0x3f/0x60 [ 46.904465][ C1] linkwatch_sync_dev+0x29/0x1f0 [ 46.904629][ C1] rtnl_getlink+0x4c9/0x970 [ 46.904796][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.904969][ C1] netlink_rcv_skb+0x130/0x360 [ 46.905136][ C1] netlink_unicast+0x449/0x710 [ 46.905304][ C1] netlink_sendmsg+0x723/0xbe0 [ 46.905475][ C1] __sys_sendto+0x37d/0x410 [ 46.905641][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 46.905808][ C1] do_syscall_64+0xc6/0x1e0 [ 46.905978][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.906179][ C1] } [ 46.906263][ C1] ... key at: [] lweventlist_lock+0x18/0x60 [ 46.906472][ C1] ... acquired at: [ 46.906569][ C1] __lock_acquire+0xaf0/0x1570 [ 46.906703][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.906835][ C1] _raw_spin_lock_irqsave+0x3f/0x60 [ 46.906975][ C1] linkwatch_fire_event+0x74/0x200 [ 46.907127][ C1] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 46.907356][ C1] br_set_mac_address+0x1f3/0x260 [bridge] [ 46.907564][ C1] dev_set_mac_address+0x28a/0x410 [ 46.907700][ C1] dev_set_mac_address_user+0x31/0x50 [ 46.907833][ C1] do_setlink+0x17b4/0x21e0 [ 46.907965][ C1] rtnl_setlink+0x1f7/0x310 [ 46.908096][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.908234][ C1] netlink_rcv_skb+0x130/0x360 [ 46.908367][ C1] netlink_unicast+0x449/0x710 [ 46.908498][ C1] netlink_sendmsg+0x723/0xbe0 [ 46.908631][ C1] __sys_sendto+0x37d/0x410 [ 46.908764][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 46.908897][ C1] do_syscall_64+0xc6/0x1e0 [ 46.909029][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.909198][ C1] [ 46.909265][ C1] -> (&br->lock){+.-.}-{2:2} { [ 46.909415][ C1] HARDIRQ-ON-W at: [ 46.909515][ C1] __lock_acquire+0x797/0x1570 [ 46.909687][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.909858][ C1] _raw_spin_lock_bh+0x38/0x50 [ 46.910026][ C1] recalculate_group_addr+0x55/0x130 [bridge] [ 46.910285][ C1] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 46.910532][ C1] br_changelink+0x36c/0x1360 [bridge] [ 46.910736][ C1] br_dev_newlink+0xa5/0x100 [bridge] [ 46.910942][ C1] rtnl_newlink_create+0x341/0x850 [ 46.911111][ C1] __rtnl_newlink+0xac9/0xd80 [ 46.911279][ C1] rtnl_newlink+0x63/0xa0 [ 46.911448][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.911624][ C1] netlink_rcv_skb+0x130/0x360 [ 46.911789][ C1] netlink_unicast+0x449/0x710 [ 46.911956][ C1] netlink_sendmsg+0x723/0xbe0 [ 46.912121][ C1] ____sys_sendmsg+0x7b2/0xa10 [ 46.912288][ C1] ___sys_sendmsg+0xee/0x170 [ 46.912471][ C1] __sys_sendmsg+0xcd/0x170 [ 46.912639][ C1] do_syscall_64+0xc6/0x1e0 [ 46.912811][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.913013][ C1] IN-SOFTIRQ-W at: [ 46.913114][ C1] __lock_acquire+0x797/0x1570 [ 46.913288][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.913458][ C1] _raw_spin_lock+0x30/0x40 [ 46.913627][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.913861][ C1] call_timer_fn+0x13b/0x230 [ 46.914034][ C1] __run_timers+0x545/0x810 [ 46.914215][ C1] run_timer_softirq+0xe8/0x1b0 [ 46.914383][ C1] __do_softirq+0x1f8/0x5df [ 46.914636][ C1] irq_exit_rcu+0x97/0xc0 [ 46.914807][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.915005][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.915210][ C1] default_idle+0xf/0x20 [ 46.915378][ C1] default_idle_call+0x6d/0xb0 [ 46.915543][ C1] cpuidle_idle_call+0x1f4/0x280 [ 46.915710][ C1] do_idle+0xf9/0x160 [ 46.915849][ C1] cpu_startup_entry+0x54/0x60 [ 46.916013][ C1] start_secondary+0x21c/0x2b0 [ 46.916178][ C1] common_startup_64+0x12c/0x138 [ 46.916425][ C1] INITIAL USE at: [ 46.916526][ C1] __lock_acquire+0x797/0x1570 [ 46.916692][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.916858][ C1] _raw_spin_lock_bh+0x38/0x50 [ 46.917104][ C1] recalculate_group_addr+0x55/0x130 [bridge] [ 46.917342][ C1] br_vlan_filter_toggle+0x77/0x130 [bridge] [ 46.917585][ C1] br_changelink+0x36c/0x1360 [bridge] [ 46.917941][ C1] br_dev_newlink+0xa5/0x100 [bridge] [ 46.918145][ C1] rtnl_newlink_create+0x341/0x850 [ 46.918324][ C1] __rtnl_newlink+0xac9/0xd80 [ 46.918494][ C1] rtnl_newlink+0x63/0xa0 [ 46.918743][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.918910][ C1] netlink_rcv_skb+0x130/0x360 [ 46.919075][ C1] netlink_unicast+0x449/0x710 [ 46.919242][ C1] netlink_sendmsg+0x723/0xbe0 [ 46.919408][ C1] ____sys_sendmsg+0x7b2/0xa10 [ 46.919576][ C1] ___sys_sendmsg+0xee/0x170 [ 46.919748][ C1] __sys_sendmsg+0xcd/0x170 [ 46.919917][ C1] do_syscall_64+0xc6/0x1e0 [ 46.920087][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.920285][ C1] } [ 46.920429][ C1] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 46.920694][ C1] ... acquired at: [ 46.920793][ C1] mark_lock+0x28d/0x3e0 [ 46.920928][ C1] mark_usage+0xd9/0x2a0 [ 46.921138][ C1] __lock_acquire+0x797/0x1570 [ 46.921271][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.921414][ C1] _raw_spin_lock+0x30/0x40 [ 46.921549][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.921826][ C1] call_timer_fn+0x13b/0x230 [ 46.921964][ C1] __run_timers+0x545/0x810 [ 46.922103][ C1] run_timer_softirq+0xe8/0x1b0 [ 46.922251][ C1] __do_softirq+0x1f8/0x5df [ 46.922471][ C1] irq_exit_rcu+0x97/0xc0 [ 46.922605][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.922775][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.922938][ C1] default_idle+0xf/0x20 [ 46.923147][ C1] default_idle_call+0x6d/0xb0 [ 46.923280][ C1] cpuidle_idle_call+0x1f4/0x280 [ 46.923414][ C1] do_idle+0xf9/0x160 [ 46.923515][ C1] cpu_startup_entry+0x54/0x60 [ 46.923723][ C1] start_secondary+0x21c/0x2b0 [ 46.923855][ C1] common_startup_64+0x12c/0x138 [ 46.923991][ C1] [ 46.924058][ C1] [ 46.924058][ C1] stack backtrace: [ 46.924223][ C1] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 6.9.0-rc1-virtme #1 [ 46.924499][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 46.924787][ C1] Call Trace: [ 46.924888][ C1] [ 46.925035][ C1] dump_stack_lvl+0x82/0xd0 [ 46.925175][ C1] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 46.925339][ C1] ? common_startup_64+0x12c/0x138 [ 46.925473][ C1] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 46.925719][ C1] ? __pfx_usage_skip+0x10/0x10 [ 46.925849][ C1] ? __pfx_usage_match+0x10/0x10 [ 46.925979][ C1] ? arch_stack_walk+0x8c/0xf0 [ 46.926111][ C1] mark_lock_irq+0x4cd/0xa10 [ 46.926258][ C1] ? __pfx_mark_lock_irq+0x10/0x10 [ 46.926397][ C1] ? stack_trace_save+0x94/0xd0 [ 46.926532][ C1] ? add_chain_cache+0x248/0x8b0 [ 46.926667][ C1] ? save_trace+0x8f/0x5b0 [ 46.926877][ C1] mark_lock+0x28d/0x3e0 [ 46.926980][ C1] mark_usage+0xd9/0x2a0 [ 46.927080][ C1] __lock_acquire+0x797/0x1570 [ 46.927213][ C1] ? __lock_acquire+0xaf0/0x1570 [ 46.927348][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.927660][ C1] lock_acquire.part.0+0xeb/0x330 [ 46.927798][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.928002][ C1] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 46.928136][ C1] ? trace_lock_acquire+0x135/0x1c0 [ 46.928421][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.928621][ C1] ? lock_acquire+0x32/0xc0 [ 46.928753][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.929035][ C1] _raw_spin_lock+0x30/0x40 [ 46.929167][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.929374][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.929574][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.929887][ C1] call_timer_fn+0x13b/0x230 [ 46.930020][ C1] ? call_timer_fn+0xe8/0x230 [ 46.930151][ C1] ? call_timer_fn+0xe8/0x230 [ 46.930297][ C1] ? __pfx_call_timer_fn+0x10/0x10 [ 46.930509][ C1] ? mark_lock+0x38/0x3e0 [ 46.930612][ C1] __run_timers+0x545/0x810 [ 46.930746][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.930979][ C1] ? __pfx___run_timers+0x10/0x10 [ 46.931189][ C1] ? do_raw_spin_lock+0x131/0x270 [ 46.931319][ C1] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 46.931451][ C1] ? lock_acquire+0x32/0xc0 [ 46.931583][ C1] ? run_timer_softirq+0xe0/0x1b0 [ 46.931800][ C1] run_timer_softirq+0xe8/0x1b0 [ 46.931933][ C1] __do_softirq+0x1f8/0x5df [ 46.932066][ C1] irq_exit_rcu+0x97/0xc0 [ 46.932167][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.932298][ C1] [ 46.932455][ C1] [ 46.932523][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.932687][ C1] RIP: 0010:default_idle+0xf/0x20 [ 46.932825][ C1] 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 [ 46.933383][ C1] RSP: 0018:ffffc9000014fdf8 EFLAGS: 00000242 [ 46.933554][ C1] RAX: 00000000000999cb RBX: 1ffff92000029fc1 RCX: ffffffff8910e9d5 [ 46.933831][ C1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff86aaa4a4 [ 46.934034][ C1] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c1709c [ 46.934249][ C1] R10: ffff8880360b84e3 R11: ffff8880360ad9b0 R12: 0000000000000000 [ 46.934530][ C1] R13: ffff888001b7a300 R14: dffffc0000000000 R15: 0000000000000000 [ 46.934729][ C1] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 46.934864][ C1] ? cpuidle_idle_call+0x1f4/0x280 [ 46.935073][ C1] default_idle_call+0x6d/0xb0 [ 46.935209][ C1] cpuidle_idle_call+0x1f4/0x280 [ 46.935339][ C1] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 46.935474][ C1] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 46.935687][ C1] do_idle+0xf9/0x160 [ 46.935789][ C1] cpu_startup_entry+0x54/0x60 [ 46.935923][ C1] start_secondary+0x21c/0x2b0 [ 46.936053][ C1] ? __pfx_start_secondary+0x10/0x10 [ 46.936186][ C1] common_startup_64+0x12c/0x138 [ 46.936324][ C1] [ 63.378078][ T380] br0: port 2(veth2) entered disabled state [ 63.475450][ T381] br0: port 1(veth1) entered disabled state [ 63.597609][ T382] veth2: left allmulticast mode [ 63.597802][ T382] veth2: left promiscuous mode [ 63.598061][ T382] br0: port 2(veth2) entered disabled state [ 63.598963][ T382] veth1: left allmulticast mode [ 63.599119][ T382] veth1: left promiscuous mode [ 63.599366][ T382] br0: port 1(veth1) entered disabled state