[ 30.662346][ T303] br0: port 1(veth1) entered blocking state [ 30.662739][ T303] br0: port 1(veth1) entered disabled state [ 30.663047][ T303] veth1: entered allmulticast mode [ 30.664983][ T303] veth1: entered promiscuous mode [ 30.824163][ T305] br0: port 2(veth2) entered blocking state [ 30.826062][ T305] br0: port 2(veth2) entered disabled state [ 30.826448][ T305] veth2: entered allmulticast mode [ 30.829575][ T305] veth2: entered promiscuous mode [ 30.949191][ T306] br0: port 3(veth4) entered blocking state [ 30.949461][ T306] br0: port 3(veth4) entered disabled state [ 30.950101][ T306] veth4: entered allmulticast mode [ 30.951946][ T306] veth4: entered promiscuous mode [ 31.580603][ T7] br0: port 1(veth1) entered blocking state [ 31.581004][ T7] br0: port 1(veth1) entered forwarding state [ 31.724637][ T51] br0: port 2(veth2) entered blocking state [ 31.724940][ T51] br0: port 2(veth2) entered forwarding state [ 31.834012][ T51] br0: port 3(veth4) entered blocking state [ 31.834317][ T51] br0: port 3(veth4) entered forwarding state [ 46.902625][ C2] [ 46.902734][ C2] ======================================================== [ 46.902944][ C2] WARNING: possible irq lock inversion dependency detected [ 46.903164][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 46.903302][ C2] -------------------------------------------------------- [ 46.903509][ C2] swapper/2/0 just changed the state of lock: [ 46.903683][ C2] ffff8880089bac38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.904047][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 46.904264][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 46.904270][ C2] [ 46.904270][ C2] [ 46.904270][ C2] and interrupts could create inverse lock ordering between them. [ 46.904270][ C2] [ 46.904783][ C2] [ 46.904783][ C2] other info that might help us debug this: [ 46.904994][ C2] Chain exists of: [ 46.904994][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 46.904994][ C2] [ 46.905316][ C2] Possible interrupt unsafe locking scenario: [ 46.905316][ C2] [ 46.905520][ C2] CPU0 CPU1 [ 46.905659][ C2] ---- ---- [ 46.905796][ C2] lock(&p->alloc_lock); [ 46.905904][ C2] local_irq_disable(); [ 46.906081][ C2] lock(&br->lock); [ 46.906253][ C2] lock(lweventlist_lock); [ 46.906429][ C2] [ 46.906536][ C2] lock(&br->lock); [ 46.906645][ C2] [ 46.906645][ C2] *** DEADLOCK *** [ 46.906645][ C2] [ 46.906846][ C2] 1 lock held by swapper/2/0: [ 46.906986][ C2] #0: ffffc90000230b68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 46.907275][ C2] [ 46.907275][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 46.907517][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 46.907663][ C2] HARDIRQ-ON-W at: [ 46.907770][ C2] __lock_acquire+0x797/0x1570 [ 46.907950][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.908125][ C2] _raw_spin_lock+0x30/0x40 [ 46.908302][ C2] set_mems_allowed+0x1d/0x210 [ 46.908482][ C2] kernel_init_freeable+0x72/0x310 [ 46.908659][ C2] kernel_init+0x20/0x200 [ 46.908833][ C2] ret_from_fork+0x31/0x70 [ 46.909010][ C2] ret_from_fork_asm+0x1a/0x30 [ 46.909183][ C2] SOFTIRQ-ON-W at: [ 46.909292][ C2] __lock_acquire+0x797/0x1570 [ 46.909471][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.909646][ C2] _raw_spin_lock+0x30/0x40 [ 46.909820][ C2] set_mems_allowed+0x1d/0x210 [ 46.909994][ C2] kernel_init_freeable+0x72/0x310 [ 46.910172][ C2] kernel_init+0x20/0x200 [ 46.910345][ C2] ret_from_fork+0x31/0x70 [ 46.910526][ C2] ret_from_fork_asm+0x1a/0x30 [ 46.910703][ C2] INITIAL USE at: [ 46.910807][ C2] __lock_acquire+0x797/0x1570 [ 46.910981][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.911154][ C2] _raw_spin_lock+0x30/0x40 [ 46.911335][ C2] set_mems_allowed+0x1d/0x210 [ 46.911510][ C2] kernel_init_freeable+0x72/0x310 [ 46.911689][ C2] kernel_init+0x20/0x200 [ 46.911863][ C2] ret_from_fork+0x31/0x70 [ 46.912035][ C2] ret_from_fork_asm+0x1a/0x30 [ 46.912208][ C2] } [ 46.912281][ C2] ... key at: [] __key.387+0x0/0x40 [ 46.912499][ C2] ... acquired at: [ 46.912606][ C2] __lock_acquire+0xaf0/0x1570 [ 46.912750][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.912889][ C2] _raw_spin_lock+0x30/0x40 [ 46.913031][ C2] __get_task_comm+0x27/0x70 [ 46.913173][ C2] ref_tracker_alloc+0x2ee/0x490 [ 46.913313][ C2] linkwatch_fire_event+0x196/0x200 [ 46.913453][ C2] veth_newlink+0x367/0x830 [veth] [ 46.913605][ C2] rtnl_newlink_create+0x341/0x850 [ 46.913748][ C2] __rtnl_newlink+0xac9/0xd80 [ 46.913887][ C2] rtnl_newlink+0x63/0xa0 [ 46.914025][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.914161][ C2] netlink_rcv_skb+0x130/0x360 [ 46.914308][ C2] netlink_unicast+0x449/0x710 [ 46.914461][ C2] netlink_sendmsg+0x723/0xbe0 [ 46.914599][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 46.914738][ C2] ___sys_sendmsg+0xee/0x170 [ 46.914883][ C2] __sys_sendmsg+0xcd/0x170 [ 46.915028][ C2] do_syscall_64+0xc6/0x1e0 [ 46.915167][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.915340][ C2] [ 46.915412][ C2] -> (lweventlist_lock){....}-{2:2} { [ 46.915558][ C2] INITIAL USE at: [ 46.915663][ C2] __lock_acquire+0x797/0x1570 [ 46.915837][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.916010][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 46.916193][ C2] linkwatch_sync_dev+0x29/0x1f0 [ 46.916367][ C2] rtnl_getlink+0x4c9/0x970 [ 46.916541][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.916717][ C2] netlink_rcv_skb+0x130/0x360 [ 46.916889][ C2] netlink_unicast+0x449/0x710 [ 46.917063][ C2] netlink_sendmsg+0x723/0xbe0 [ 46.917240][ C2] __sys_sendto+0x37d/0x410 [ 46.917421][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 46.917593][ C2] do_syscall_64+0xc6/0x1e0 [ 46.917768][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.917980][ C2] } [ 46.918049][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 46.918256][ C2] ... acquired at: [ 46.918358][ C2] __lock_acquire+0xaf0/0x1570 [ 46.918506][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.918649][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 46.918789][ C2] linkwatch_fire_event+0x74/0x200 [ 46.918926][ C2] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 46.919143][ C2] br_set_mac_address+0x1f3/0x260 [bridge] [ 46.919352][ C2] dev_set_mac_address+0x28a/0x410 [ 46.919492][ C2] dev_set_mac_address_user+0x31/0x50 [ 46.919632][ C2] do_setlink+0x17b4/0x21e0 [ 46.919777][ C2] rtnl_setlink+0x1f7/0x310 [ 46.919914][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.920051][ C2] netlink_rcv_skb+0x130/0x360 [ 46.920189][ C2] netlink_unicast+0x449/0x710 [ 46.920333][ C2] netlink_sendmsg+0x723/0xbe0 [ 46.920478][ C2] __sys_sendto+0x37d/0x410 [ 46.920621][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 46.920759][ C2] do_syscall_64+0xc6/0x1e0 [ 46.920895][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.921152][ C2] [ 46.921222][ C2] -> (&br->lock){+.-.}-{2:2} { [ 46.921365][ C2] HARDIRQ-ON-W at: [ 46.921468][ C2] __lock_acquire+0x797/0x1570 [ 46.921737][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.921918][ C2] _raw_spin_lock_bh+0x38/0x50 [ 46.922096][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 46.922337][ C2] dev_set_mac_address+0x28a/0x410 [ 46.922592][ C2] dev_set_mac_address_user+0x31/0x50 [ 46.922766][ C2] do_setlink+0x17b4/0x21e0 [ 46.922939][ C2] rtnl_setlink+0x1f7/0x310 [ 46.923194][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.923372][ C2] netlink_rcv_skb+0x130/0x360 [ 46.923544][ C2] netlink_unicast+0x449/0x710 [ 46.923800][ C2] netlink_sendmsg+0x723/0xbe0 [ 46.923972][ C2] __sys_sendto+0x37d/0x410 [ 46.924145][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 46.924318][ C2] do_syscall_64+0xc6/0x1e0 [ 46.924591][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.924798][ C2] IN-SOFTIRQ-W at: [ 46.924903][ C2] __lock_acquire+0x797/0x1570 [ 46.925163][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.925367][ C2] _raw_spin_lock+0x30/0x40 [ 46.925555][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.925807][ C2] call_timer_fn+0x13b/0x230 [ 46.926067][ C2] __run_timers+0x545/0x810 [ 46.926239][ C2] timer_expire_remote+0x9b/0xe0 [ 46.926412][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 46.926682][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 46.926853][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 46.927031][ C2] __do_softirq+0x1f8/0x5df [ 46.927204][ C2] irq_exit_rcu+0x97/0xc0 [ 46.927380][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.927604][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.927907][ C2] default_idle+0xf/0x20 [ 46.928081][ C2] default_idle_call+0x6d/0xb0 [ 46.928254][ C2] cpuidle_idle_call+0x1f4/0x280 [ 46.928430][ C2] do_idle+0xf9/0x160 [ 46.928678][ C2] cpu_startup_entry+0x54/0x60 [ 46.928856][ C2] start_secondary+0x21c/0x2b0 [ 46.929031][ C2] common_startup_64+0x12c/0x138 [ 46.929205][ C2] INITIAL USE at: [ 46.929310][ C2] __lock_acquire+0x797/0x1570 [ 46.929485][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.929665][ C2] _raw_spin_lock_bh+0x38/0x50 [ 46.930004][ C2] br_set_mac_address+0xd2/0x260 [bridge] [ 46.930250][ C2] dev_set_mac_address+0x28a/0x410 [ 46.930426][ C2] dev_set_mac_address_user+0x31/0x50 [ 46.930684][ C2] do_setlink+0x17b4/0x21e0 [ 46.930862][ C2] rtnl_setlink+0x1f7/0x310 [ 46.931037][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 46.931209][ C2] netlink_rcv_skb+0x130/0x360 [ 46.931466][ C2] netlink_unicast+0x449/0x710 [ 46.931647][ C2] netlink_sendmsg+0x723/0xbe0 [ 46.931825][ C2] __sys_sendto+0x37d/0x410 [ 46.932082][ C2] __x64_sys_sendto+0xe0/0x1c0 [ 46.932259][ C2] do_syscall_64+0xc6/0x1e0 [ 46.932431][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 46.932724][ C2] } [ 46.932796][ C2] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 46.933072][ C2] ... acquired at: [ 46.933178][ C2] mark_lock+0x28d/0x3e0 [ 46.933320][ C2] mark_usage+0xd9/0x2a0 [ 46.933540][ C2] __lock_acquire+0x797/0x1570 [ 46.933680][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.933820][ C2] _raw_spin_lock+0x30/0x40 [ 46.933958][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.934249][ C2] call_timer_fn+0x13b/0x230 [ 46.934399][ C2] __run_timers+0x545/0x810 [ 46.934540][ C2] timer_expire_remote+0x9b/0xe0 [ 46.934684][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 46.934909][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 46.935054][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 46.935193][ C2] __do_softirq+0x1f8/0x5df [ 46.935331][ C2] irq_exit_rcu+0x97/0xc0 [ 46.935550][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.935725][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.935899][ C2] default_idle+0xf/0x20 [ 46.936043][ C2] default_idle_call+0x6d/0xb0 [ 46.936269][ C2] cpuidle_idle_call+0x1f4/0x280 [ 46.936416][ C2] do_idle+0xf9/0x160 [ 46.936525][ C2] cpu_startup_entry+0x54/0x60 [ 46.936664][ C2] start_secondary+0x21c/0x2b0 [ 46.936886][ C2] common_startup_64+0x12c/0x138 [ 46.937025][ C2] [ 46.937094][ C2] [ 46.937094][ C2] stack backtrace: [ 46.937264][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 46.937559][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 46.937867][ C2] Call Trace: [ 46.937972][ C2] [ 46.938045][ C2] dump_stack_lvl+0x82/0xd0 [ 46.938189][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 46.938359][ C2] ? common_startup_64+0x12c/0x138 [ 46.938507][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 46.938685][ C2] ? __pfx_usage_skip+0x10/0x10 [ 46.938905][ C2] ? __pfx_usage_match+0x10/0x10 [ 46.939042][ C2] ? arch_stack_walk+0x8c/0xf0 [ 46.939180][ C2] mark_lock_irq+0x4cd/0xa10 [ 46.939321][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 46.939539][ C2] ? stack_trace_save+0x94/0xd0 [ 46.939680][ C2] ? save_trace+0x8f/0x5b0 [ 46.939821][ C2] mark_lock+0x28d/0x3e0 [ 46.939926][ C2] ? __pfx_validate_chain+0x10/0x10 [ 46.940066][ C2] mark_usage+0xd9/0x2a0 [ 46.940252][ C2] __lock_acquire+0x797/0x1570 [ 46.940395][ C2] ? __lock_acquire+0xaf0/0x1570 [ 46.940533][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.940790][ C2] lock_acquire.part.0+0xeb/0x330 [ 46.941092][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.941305][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 46.941446][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 46.941589][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.941878][ C2] ? lock_acquire+0x32/0xc0 [ 46.942021][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.942229][ C2] _raw_spin_lock+0x30/0x40 [ 46.942450][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.942664][ C2] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 46.942874][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.943117][ C2] call_timer_fn+0x13b/0x230 [ 46.943336][ C2] ? call_timer_fn+0xe8/0x230 [ 46.943475][ C2] ? call_timer_fn+0xe8/0x230 [ 46.943613][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 46.943750][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 46.943969][ C2] __run_timers+0x545/0x810 [ 46.944107][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 46.944358][ C2] ? __pfx___run_timers+0x10/0x10 [ 46.944518][ C2] ? __lock_release+0x103/0x460 [ 46.944749][ C2] ? do_raw_spin_lock+0x131/0x270 [ 46.944892][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 46.945045][ C2] ? lock_acquire+0x32/0xc0 [ 46.945186][ C2] ? timer_expire_remote+0x93/0xe0 [ 46.945331][ C2] timer_expire_remote+0x9b/0xe0 [ 46.945471][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 46.945615][ C2] ? __pfx_tmigr_handle_remote_cpu+0x10/0x10 [ 46.945791][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 46.946012][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 46.946154][ C2] ? __pfx_tmigr_handle_remote+0x10/0x10 [ 46.946296][ C2] __do_softirq+0x1f8/0x5df [ 46.946439][ C2] irq_exit_rcu+0x97/0xc0 [ 46.946630][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 46.946771][ C2] [ 46.946843][ C2] [ 46.946914][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 46.947086][ C2] RIP: 0010:default_idle+0xf/0x20 [ 46.947230][ 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 [ 46.947727][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000242 [ 46.947999][ C2] RAX: 00000000000f258f RBX: 1ffff9200002bfc1 RCX: ffffffffa1f0e9d5 [ 46.948210][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff9f8aa4a4 [ 46.948419][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 46.948715][ C2] R10: ffff8880361384e3 R11: ffff88803613dc80 R12: 0000000000000000 [ 46.948921][ C2] R13: ffff888001b7c5c0 R14: dffffc0000000000 R15: 0000000000000000 [ 46.949146][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 46.949285][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 46.949428][ C2] default_idle_call+0x6d/0xb0 [ 46.949566][ C2] cpuidle_idle_call+0x1f4/0x280 [ 46.949705][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 46.949938][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 46.950086][ C2] do_idle+0xf9/0x160 [ 46.950200][ C2] cpu_startup_entry+0x54/0x60 [ 46.950340][ C2] start_secondary+0x21c/0x2b0 [ 46.950478][ C2] ? __pfx_start_secondary+0x10/0x10 [ 46.950709][ C2] common_startup_64+0x12c/0x138 [ 46.950850][ C2] [ 48.032461][ T351] veth3: entered promiscuous mode [ 48.592872][ T357] GACT probability NOT on [ 50.414113][ T364] veth3: left promiscuous mode [ 50.509920][ T365] veth3: entered promiscuous mode [ 52.409993][ T374] veth3: left promiscuous mode [ 52.518482][ T376] br0: port 3(veth4) entered disabled state [ 52.617179][ T377] br0: port 2(veth2) entered disabled state [ 52.727054][ T378] br0: port 1(veth1) entered disabled state [ 52.836180][ T379] veth4: left allmulticast mode [ 52.836384][ T379] veth4: left promiscuous mode [ 52.836655][ T379] br0: port 3(veth4) entered disabled state [ 52.837622][ T379] veth2: left allmulticast mode [ 52.837796][ T379] veth2: left promiscuous mode [ 52.838047][ T379] br0: port 2(veth2) entered disabled state [ 52.839012][ T379] veth1: left allmulticast mode [ 52.839171][ T379] veth1: left promiscuous mode [ 52.839437][ T379] br0: port 1(veth1) entered disabled state