[ 27.121918][ T282] 8021q: 802.1Q VLAN Support v1.8 [ 30.988876][ T325] GACT probability NOT on [ 32.362312][ T340] br10: port 1(veth1.10) entered blocking state [ 32.362736][ T340] br10: port 1(veth1.10) entered disabled state [ 32.363037][ T340] veth1.10: entered allmulticast mode [ 32.363974][ T340] veth1: entered allmulticast mode [ 32.365813][ T340] veth1.10: entered promiscuous mode [ 32.365985][ T340] veth1: entered promiscuous mode [ 32.840934][ T345] br11: port 1(veth1.11) entered blocking state [ 32.841307][ T345] br11: port 1(veth1.11) entered disabled state [ 32.841560][ T345] veth1.11: entered allmulticast mode [ 32.843547][ T345] veth1.11: entered promiscuous mode [ 33.710851][ T355] br10: port 2(veth2.10) entered blocking state [ 33.711197][ T355] br10: port 2(veth2.10) entered disabled state [ 33.711647][ T355] veth2.10: entered allmulticast mode [ 33.711807][ T355] veth2: entered allmulticast mode [ 33.714764][ T355] veth2.10: entered promiscuous mode [ 33.714963][ T355] veth2: entered promiscuous mode [ 34.205462][ T360] br11: port 2(veth2.11) entered blocking state [ 34.205739][ T360] br11: port 2(veth2.11) entered disabled state [ 34.206019][ T360] veth2.11: entered allmulticast mode [ 34.209252][ T360] veth2.11: entered promiscuous mode [ 34.679524][ T364] br10: port 2(veth2.10) entered blocking state [ 34.679963][ T364] br10: port 2(veth2.10) entered forwarding state [ 34.680844][ T364] br10: port 1(veth1.10) entered blocking state [ 34.681138][ T364] br10: port 1(veth1.10) entered forwarding state [ 34.806940][ T365] br11: port 2(veth2.11) entered blocking state [ 34.807280][ T365] br11: port 2(veth2.11) entered forwarding state [ 34.807697][ T365] br11: port 1(veth1.11) entered blocking state [ 34.807919][ T365] br11: port 1(veth1.11) entered forwarding state [ 49.959209][ C2] [ 49.959341][ C2] ======================================================== [ 49.959556][ C2] WARNING: possible irq lock inversion dependency detected [ 49.959758][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 49.959899][ C2] -------------------------------------------------------- [ 49.960094][ C2] swapper/2/0 just changed the state of lock: [ 49.960270][ C2] ffff8880088cac38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.960636][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 49.960843][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 49.960849][ C2] [ 49.960849][ C2] [ 49.960849][ C2] and interrupts could create inverse lock ordering between them. [ 49.960849][ C2] [ 49.961349][ C2] [ 49.961349][ C2] other info that might help us debug this: [ 49.961552][ C2] Chain exists of: [ 49.961552][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 49.961552][ C2] [ 49.961871][ C2] Possible interrupt unsafe locking scenario: [ 49.961871][ C2] [ 49.962072][ C2] CPU0 CPU1 [ 49.962218][ C2] ---- ---- [ 49.962355][ C2] lock(&p->alloc_lock); [ 49.962463][ C2] local_irq_disable(); [ 49.962634][ C2] lock(&br->lock); [ 49.962804][ C2] lock(lweventlist_lock); [ 49.962989][ C2] [ 49.963095][ C2] lock(&br->lock); [ 49.963225][ C2] [ 49.963225][ C2] *** DEADLOCK *** [ 49.963225][ C2] [ 49.963425][ C2] 1 lock held by swapper/2/0: [ 49.963564][ C2] #0: ffffc90000230d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 49.963848][ C2] [ 49.963848][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 49.964082][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 49.964224][ C2] HARDIRQ-ON-W at: [ 49.964329][ C2] __lock_acquire+0x797/0x1570 [ 49.964505][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.964675][ C2] _raw_spin_lock+0x30/0x40 [ 49.964847][ C2] set_mems_allowed+0x1d/0x210 [ 49.965016][ C2] kernel_init_freeable+0x72/0x310 [ 49.965188][ C2] kernel_init+0x20/0x200 [ 49.965361][ C2] ret_from_fork+0x31/0x70 [ 49.965535][ C2] ret_from_fork_asm+0x1a/0x30 [ 49.965709][ C2] SOFTIRQ-ON-W at: [ 49.965814][ C2] __lock_acquire+0x797/0x1570 [ 49.965988][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.966157][ C2] _raw_spin_lock+0x30/0x40 [ 49.966326][ C2] set_mems_allowed+0x1d/0x210 [ 49.966496][ C2] kernel_init_freeable+0x72/0x310 [ 49.966678][ C2] kernel_init+0x20/0x200 [ 49.966853][ C2] ret_from_fork+0x31/0x70 [ 49.967028][ C2] ret_from_fork_asm+0x1a/0x30 [ 49.967200][ C2] INITIAL USE at: [ 49.967303][ C2] __lock_acquire+0x797/0x1570 [ 49.967475][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.967654][ C2] _raw_spin_lock+0x30/0x40 [ 49.967828][ C2] set_mems_allowed+0x1d/0x210 [ 49.968003][ C2] kernel_init_freeable+0x72/0x310 [ 49.968174][ C2] kernel_init+0x20/0x200 [ 49.968352][ C2] ret_from_fork+0x31/0x70 [ 49.968521][ C2] ret_from_fork_asm+0x1a/0x30 [ 49.968697][ C2] } [ 49.968768][ C2] ... key at: [] __key.387+0x0/0x40 [ 49.968987][ C2] ... acquired at: [ 49.969088][ C2] __lock_acquire+0xaf0/0x1570 [ 49.969233][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.969366][ C2] _raw_spin_lock+0x30/0x40 [ 49.969521][ C2] __get_task_comm+0x27/0x70 [ 49.969659][ C2] ref_tracker_alloc+0x2ee/0x490 [ 49.969800][ C2] linkwatch_fire_event+0x196/0x200 [ 49.969938][ C2] veth_newlink+0x367/0x830 [veth] [ 49.970091][ C2] rtnl_newlink_create+0x341/0x850 [ 49.970224][ C2] __rtnl_newlink+0xac9/0xd80 [ 49.970367][ C2] rtnl_newlink+0x63/0xa0 [ 49.970500][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.970655][ C2] netlink_rcv_skb+0x130/0x360 [ 49.970792][ C2] netlink_unicast+0x449/0x710 [ 49.970934][ C2] netlink_sendmsg+0x723/0xbe0 [ 49.971066][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 49.971205][ C2] ___sys_sendmsg+0xee/0x170 [ 49.971340][ C2] __sys_sendmsg+0xcd/0x170 [ 49.971489][ C2] do_syscall_64+0xc6/0x1e0 [ 49.971624][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.971816][ C2] [ 49.971885][ C2] -> (lweventlist_lock){....}-{2:2} { [ 49.972029][ C2] INITIAL USE at: [ 49.972142][ C2] __lock_acquire+0x797/0x1570 [ 49.972347][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.972519][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 49.972700][ C2] linkwatch_sync_dev+0x29/0x1f0 [ 49.972870][ C2] rtnl_getlink+0x4c9/0x970 [ 49.973046][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.973225][ C2] netlink_rcv_skb+0x130/0x360 [ 49.973396][ C2] netlink_unicast+0x449/0x710 [ 49.973563][ C2] netlink_sendmsg+0x723/0xbe0 [ 49.973740][ C2] __sys_sendto+0x37d/0x410 [ 49.973907][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 49.974082][ C2] do_syscall_64+0xc6/0x1e0 [ 49.974262][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.974462][ C2] } [ 49.974547][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 49.974747][ C2] ... acquired at: [ 49.974848][ C2] __lock_acquire+0xaf0/0x1570 [ 49.974984][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.975122][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 49.975256][ C2] linkwatch_fire_event+0x74/0x200 [ 49.975390][ C2] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 49.975600][ C2] br_set_mac_address+0x1f3/0x260 [bridge] [ 49.975801][ C2] dev_set_mac_address+0x28a/0x410 [ 49.975936][ C2] dev_set_mac_address_user+0x31/0x50 [ 49.976070][ C2] do_setlink+0x17b4/0x21e0 [ 49.976206][ C2] rtnl_setlink+0x1f7/0x310 [ 49.976339][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.976473][ C2] netlink_rcv_skb+0x130/0x360 [ 49.976608][ C2] netlink_unicast+0x449/0x710 [ 49.976742][ C2] netlink_sendmsg+0x723/0xbe0 [ 49.976876][ C2] __sys_sendto+0x37d/0x410 [ 49.977010][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 49.977145][ C2] do_syscall_64+0xc6/0x1e0 [ 49.977281][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.977456][ C2] [ 49.977524][ C2] -> (&br->lock){+.-.}-{2:2} { [ 49.977662][ C2] HARDIRQ-ON-W at: [ 49.977765][ C2] __lock_acquire+0x797/0x1570 [ 49.977939][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.978108][ C2] _raw_spin_lock_bh+0x38/0x50 [ 49.978280][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 49.978524][ C2] dev_set_mac_address+0x28a/0x410 [ 49.978695][ C2] dev_set_mac_address_user+0x31/0x50 [ 49.978863][ C2] do_setlink+0x17b4/0x21e0 [ 49.979033][ C2] rtnl_setlink+0x1f7/0x310 [ 49.979206][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.979374][ C2] netlink_rcv_skb+0x130/0x360 [ 49.979557][ C2] netlink_unicast+0x449/0x710 [ 49.979815][ C2] netlink_sendmsg+0x723/0xbe0 [ 49.979983][ C2] __sys_sendto+0x37d/0x410 [ 49.980154][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 49.980399][ C2] do_syscall_64+0xc6/0x1e0 [ 49.980566][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.980767][ C2] IN-SOFTIRQ-W at: [ 49.980871][ C2] __lock_acquire+0x797/0x1570 [ 49.981121][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.981289][ C2] _raw_spin_lock+0x30/0x40 [ 49.981458][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.981773][ C2] call_timer_fn+0x13b/0x230 [ 49.981945][ C2] __run_timers+0x545/0x810 [ 49.982114][ C2] run_timer_softirq+0xe8/0x1b0 [ 49.982441][ C2] __do_softirq+0x1f8/0x5df [ 49.982627][ C2] irq_exit_rcu+0x97/0xc0 [ 49.982797][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.983077][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 49.983280][ C2] default_idle+0xf/0x20 [ 49.983459][ C2] default_idle_call+0x6d/0xb0 [ 49.983630][ C2] cpuidle_idle_call+0x1f4/0x280 [ 49.983880][ C2] do_idle+0xf9/0x160 [ 49.984014][ C2] cpu_startup_entry+0x54/0x60 [ 49.984179][ C2] start_secondary+0x21c/0x2b0 [ 49.984425][ C2] common_startup_64+0x12c/0x138 [ 49.984596][ C2] INITIAL USE at: [ 49.984697][ C2] __lock_acquire+0x797/0x1570 [ 49.984867][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.985118][ C2] _raw_spin_lock_bh+0x38/0x50 [ 49.985293][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 49.985529][ C2] dev_set_mac_address+0x28a/0x410 [ 49.985780][ C2] dev_set_mac_address_user+0x31/0x50 [ 49.985948][ C2] do_setlink+0x17b4/0x21e0 [ 49.986128][ C2] rtnl_setlink+0x1f7/0x310 [ 49.986295][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.986545][ C2] netlink_rcv_skb+0x130/0x360 [ 49.986714][ C2] netlink_unicast+0x449/0x710 [ 49.986881][ C2] netlink_sendmsg+0x723/0xbe0 [ 49.987128][ C2] __sys_sendto+0x37d/0x410 [ 49.987295][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 49.987469][ C2] do_syscall_64+0xc6/0x1e0 [ 49.987717][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.987918][ C2] } [ 49.987996][ C2] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 49.988268][ C2] ... acquired at: [ 49.988445][ C2] mark_lock+0x28d/0x3e0 [ 49.988579][ C2] mark_usage+0xd9/0x2a0 [ 49.988721][ C2] __lock_acquire+0x797/0x1570 [ 49.988855][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.989072][ C2] _raw_spin_lock+0x30/0x40 [ 49.989209][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.989412][ C2] call_timer_fn+0x13b/0x230 [ 49.989563][ C2] __run_timers+0x545/0x810 [ 49.989778][ C2] run_timer_softirq+0xe8/0x1b0 [ 49.989915][ C2] __do_softirq+0x1f8/0x5df [ 49.990052][ C2] irq_exit_rcu+0x97/0xc0 [ 49.990187][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.990432][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 49.990600][ C2] default_idle+0xf/0x20 [ 49.990732][ C2] default_idle_call+0x6d/0xb0 [ 49.990865][ C2] cpuidle_idle_call+0x1f4/0x280 [ 49.991075][ C2] do_idle+0xf9/0x160 [ 49.991176][ C2] cpu_startup_entry+0x54/0x60 [ 49.991309][ C2] start_secondary+0x21c/0x2b0 [ 49.991448][ C2] common_startup_64+0x12c/0x138 [ 49.991582][ C2] [ 49.991723][ C2] [ 49.991723][ C2] stack backtrace: [ 49.991886][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 49.992095][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 49.992467][ C2] Call Trace: [ 49.992572][ C2] [ 49.992644][ C2] dump_stack_lvl+0x82/0xd0 [ 49.992786][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 49.993102][ C2] ? common_startup_64+0x12c/0x138 [ 49.993237][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 49.993403][ C2] ? __pfx_usage_skip+0x10/0x10 [ 49.993535][ C2] ? __pfx_usage_match+0x10/0x10 [ 49.993742][ C2] ? arch_stack_walk+0x8c/0xf0 [ 49.993877][ C2] mark_lock_irq+0x4cd/0xa10 [ 49.994016][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 49.994149][ C2] ? stack_trace_save+0x94/0xd0 [ 49.994285][ C2] ? save_trace+0x8f/0x5b0 [ 49.994495][ C2] mark_lock+0x28d/0x3e0 [ 49.994597][ C2] mark_usage+0xd9/0x2a0 [ 49.994698][ C2] __lock_acquire+0x797/0x1570 [ 49.994832][ C2] ? trace_rcu_dyntick+0x112/0x180 [ 49.995042][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.995282][ C2] lock_acquire.part.0+0xeb/0x330 [ 49.995416][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.995617][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 49.995825][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 49.995958][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.996160][ C2] ? lock_acquire+0x32/0xc0 [ 49.996293][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.996578][ C2] _raw_spin_lock+0x30/0x40 [ 49.996711][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.996913][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.997190][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.997425][ C2] call_timer_fn+0x13b/0x230 [ 49.997558][ C2] ? call_timer_fn+0xe8/0x230 [ 49.997694][ C2] ? call_timer_fn+0xe8/0x230 [ 49.997909][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 49.998042][ C2] ? mark_lock+0x38/0x3e0 [ 49.998158][ C2] __run_timers+0x545/0x810 [ 49.998295][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.998616][ C2] ? __pfx___run_timers+0x10/0x10 [ 49.998751][ C2] ? do_raw_spin_lock+0x131/0x270 [ 49.998894][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 49.999026][ C2] ? lock_acquire+0x32/0xc0 [ 49.999268][ C2] ? run_timer_softirq+0xe0/0x1b0 [ 49.999404][ C2] run_timer_softirq+0xe8/0x1b0 [ 49.999553][ C2] __do_softirq+0x1f8/0x5df [ 49.999690][ C2] irq_exit_rcu+0x97/0xc0 [ 49.999796][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.999932][ C2] [ 50.000002][ C2] [ 50.000079][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 50.000247][ C2] RIP: 0010:default_idle+0xf/0x20 [ 50.000395][ 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 [ 50.000954][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000242 [ 50.001203][ C2] RAX: 000000000016be0b RBX: 1ffff9200002bfc1 RCX: ffffffffb610e9d5 [ 50.001408][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffb3aaa4a4 [ 50.001616][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 50.001902][ C2] R10: ffff8880361384e3 R11: ffff88803613dc80 R12: 0000000000000000 [ 50.002105][ C2] R13: ffff888001b7c5c0 R14: dffffc0000000000 R15: 0000000000000000 [ 50.002306][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 50.002516][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 50.002656][ C2] default_idle_call+0x6d/0xb0 [ 50.002790][ C2] cpuidle_idle_call+0x1f4/0x280 [ 50.002923][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 50.003057][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 50.003269][ C2] do_idle+0xf9/0x160 [ 50.003375][ C2] cpu_startup_entry+0x54/0x60 [ 50.003509][ C2] start_secondary+0x21c/0x2b0 [ 50.003643][ C2] ? __pfx_start_secondary+0x10/0x10 [ 50.003933][ C2] common_startup_64+0x12c/0x138 [ 50.004071][ C2] [ 115.592467][ T614] br11: port 2(veth2.11) entered disabled state [ 115.592909][ T614] br11: port 1(veth1.11) entered disabled state [ 115.693506][ T615] br10: port 2(veth2.10) entered disabled state [ 115.693938][ T615] br10: port 1(veth1.10) entered disabled state [ 115.883018][ T617] veth2.11: left allmulticast mode [ 115.883204][ T617] veth2.11: left promiscuous mode [ 115.883462][ T617] br11: port 2(veth2.11) entered disabled state [ 116.087838][ T619] veth2: left allmulticast mode [ 116.088001][ T619] veth2: left promiscuous mode [ 116.210275][ T622] veth2.10: left allmulticast mode [ 116.210446][ T622] veth2.10: left promiscuous mode [ 116.210692][ T622] br10: port 2(veth2.10) entered disabled state [ 116.710759][ T627] veth1.11: left allmulticast mode [ 116.710920][ T627] veth1.11: left promiscuous mode [ 116.711174][ T627] br11: port 1(veth1.11) entered disabled state [ 116.949361][ T629] veth1: left allmulticast mode [ 116.949526][ T629] veth1: left promiscuous mode [ 117.056314][ T630] veth1.10: left allmulticast mode [ 117.056490][ T630] veth1.10: left promiscuous mode [ 117.056737][ T630] br10: port 1(veth1.10) entered disabled state