[ 29.994537][ T292] br0: port 1(veth1) entered blocking state [ 29.994937][ T292] br0: port 1(veth1) entered disabled state [ 29.996758][ T292] veth1: entered allmulticast mode [ 29.998908][ T292] veth1: entered promiscuous mode [ 30.104181][ T294] br0: port 2(veth3) entered blocking state [ 30.104473][ T294] br0: port 2(veth3) entered disabled state [ 30.104735][ T294] veth3: entered allmulticast mode [ 30.113839][ T294] veth3: entered promiscuous mode [ 30.484414][ T51] br0: port 1(veth1) entered blocking state [ 30.484959][ T51] br0: port 1(veth1) entered forwarding state [ 30.607766][ T50] br0: port 2(veth3) entered blocking state [ 30.608398][ T50] br0: port 2(veth3) entered forwarding state [ 45.873371][ C3] [ 45.873491][ C3] ======================================================== [ 45.873693][ C3] WARNING: possible irq lock inversion dependency detected [ 45.873919][ C3] 6.9.0-rc1-virtme #1 Not tainted [ 45.874077][ C3] -------------------------------------------------------- [ 45.874292][ C3] swapper/3/0 just changed the state of lock: [ 45.874464][ C3] ffff888008852c38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.874852][ C3] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 45.875058][ C3] (&p->alloc_lock){+.+.}-{2:2} [ 45.875062][ C3] [ 45.875062][ C3] [ 45.875062][ C3] and interrupts could create inverse lock ordering between them. [ 45.875062][ C3] [ 45.875624][ C3] [ 45.875624][ C3] other info that might help us debug this: [ 45.875845][ C3] Chain exists of: [ 45.875845][ C3] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 45.875845][ C3] [ 45.876170][ C3] Possible interrupt unsafe locking scenario: [ 45.876170][ C3] [ 45.876376][ C3] CPU0 CPU1 [ 45.876521][ C3] ---- ---- [ 45.876658][ C3] lock(&p->alloc_lock); [ 45.876767][ C3] local_irq_disable(); [ 45.876941][ C3] lock(&br->lock); [ 45.877129][ C3] lock(lweventlist_lock); [ 45.877303][ C3] [ 45.877406][ C3] lock(&br->lock); [ 45.877512][ C3] [ 45.877512][ C3] *** DEADLOCK *** [ 45.877512][ C3] [ 45.877707][ C3] 1 lock held by swapper/3/0: [ 45.877843][ C3] #0: ffffc90000288d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 45.878129][ C3] [ 45.878129][ C3] the shortest dependencies between 2nd lock and 1st lock: [ 45.878366][ C3] -> (&p->alloc_lock){+.+.}-{2:2} { [ 45.878510][ C3] HARDIRQ-ON-W at: [ 45.878634][ C3] __lock_acquire+0x797/0x1570 [ 45.878809][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.879004][ C3] _raw_spin_lock+0x30/0x40 [ 45.879189][ C3] set_mems_allowed+0x1d/0x210 [ 45.879388][ C3] kernel_init_freeable+0x72/0x310 [ 45.879579][ C3] kernel_init+0x20/0x200 [ 45.879766][ C3] ret_from_fork+0x31/0x70 [ 45.879949][ C3] ret_from_fork_asm+0x1a/0x30 [ 45.880137][ C3] SOFTIRQ-ON-W at: [ 45.880239][ C3] __lock_acquire+0x797/0x1570 [ 45.880421][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.880590][ C3] _raw_spin_lock+0x30/0x40 [ 45.880773][ C3] set_mems_allowed+0x1d/0x210 [ 45.880941][ C3] kernel_init_freeable+0x72/0x310 [ 45.881143][ C3] kernel_init+0x20/0x200 [ 45.881335][ C3] ret_from_fork+0x31/0x70 [ 45.881516][ C3] ret_from_fork_asm+0x1a/0x30 [ 45.881704][ C3] INITIAL USE at: [ 45.881809][ C3] __lock_acquire+0x797/0x1570 [ 45.881992][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.882191][ C3] _raw_spin_lock+0x30/0x40 [ 45.882369][ C3] set_mems_allowed+0x1d/0x210 [ 45.882557][ C3] kernel_init_freeable+0x72/0x310 [ 45.882740][ C3] kernel_init+0x20/0x200 [ 45.882912][ C3] ret_from_fork+0x31/0x70 [ 45.883100][ C3] ret_from_fork_asm+0x1a/0x30 [ 45.883269][ C3] } [ 45.883339][ C3] ... key at: [] __key.387+0x0/0x40 [ 45.883579][ C3] ... acquired at: [ 45.883686][ C3] __lock_acquire+0xaf0/0x1570 [ 45.883830][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.883963][ C3] _raw_spin_lock+0x30/0x40 [ 45.884105][ C3] __get_task_comm+0x27/0x70 [ 45.884247][ C3] ref_tracker_alloc+0x2ee/0x490 [ 45.884388][ C3] linkwatch_fire_event+0x196/0x200 [ 45.884527][ C3] veth_newlink+0x367/0x830 [veth] [ 45.884678][ C3] rtnl_newlink_create+0x341/0x850 [ 45.884817][ C3] __rtnl_newlink+0xac9/0xd80 [ 45.884955][ C3] rtnl_newlink+0x63/0xa0 [ 45.885097][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.885231][ C3] netlink_rcv_skb+0x130/0x360 [ 45.885373][ C3] netlink_unicast+0x449/0x710 [ 45.885507][ C3] netlink_sendmsg+0x723/0xbe0 [ 45.885654][ C3] ____sys_sendmsg+0x7b2/0xa10 [ 45.885795][ C3] ___sys_sendmsg+0xee/0x170 [ 45.885942][ C3] __sys_sendmsg+0xcd/0x170 [ 45.886080][ C3] do_syscall_64+0xc6/0x1e0 [ 45.886214][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.886384][ C3] [ 45.886457][ C3] -> (lweventlist_lock){....}-{2:2} { [ 45.886597][ C3] INITIAL USE at: [ 45.886704][ C3] __lock_acquire+0x797/0x1570 [ 45.886872][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.887046][ C3] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.887220][ C3] linkwatch_sync_dev+0x29/0x1f0 [ 45.887394][ C3] rtnl_getlink+0x4c9/0x970 [ 45.887585][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.887754][ C3] netlink_rcv_skb+0x130/0x360 [ 45.887930][ C3] netlink_unicast+0x449/0x710 [ 45.888107][ C3] netlink_sendmsg+0x723/0xbe0 [ 45.888278][ C3] __sys_sendto+0x37d/0x410 [ 45.888452][ C3] __x64_sys_sendto+0xe0/0x1c0 [ 45.888623][ C3] do_syscall_64+0xc6/0x1e0 [ 45.888793][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.888999][ C3] } [ 45.889067][ C3] ... key at: [] lweventlist_lock+0x18/0x60 [ 45.889283][ C3] ... acquired at: [ 45.889382][ C3] __lock_acquire+0xaf0/0x1570 [ 45.889530][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.889665][ C3] _raw_spin_lock_irqsave+0x3f/0x60 [ 45.889803][ C3] linkwatch_fire_event+0x74/0x200 [ 45.889940][ C3] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 45.890228][ C3] br_set_mac_address+0x1f3/0x260 [bridge] [ 45.890440][ C3] dev_set_mac_address+0x28a/0x410 [ 45.890574][ C3] dev_set_mac_address_user+0x31/0x50 [ 45.890708][ C3] do_setlink+0x17b4/0x21e0 [ 45.890925][ C3] rtnl_setlink+0x1f7/0x310 [ 45.891061][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.891193][ C3] netlink_rcv_skb+0x130/0x360 [ 45.891330][ C3] netlink_unicast+0x449/0x710 [ 45.891484][ C3] netlink_sendmsg+0x723/0xbe0 [ 45.891710][ C3] __sys_sendto+0x37d/0x410 [ 45.891845][ C3] __x64_sys_sendto+0xe0/0x1c0 [ 45.891981][ C3] do_syscall_64+0xc6/0x1e0 [ 45.892115][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.892361][ C3] [ 45.892429][ C3] -> (&br->lock){+.-.}-{2:2} { [ 45.892568][ C3] HARDIRQ-ON-W at: [ 45.892669][ C3] __lock_acquire+0x797/0x1570 [ 45.892841][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.893015][ C3] _raw_spin_lock_bh+0x38/0x50 [ 45.893184][ C3] br_set_mac_address+0xd2/0x260 [bridge] [ 45.893420][ C3] dev_set_mac_address+0x28a/0x410 [ 45.893589][ C3] dev_set_mac_address_user+0x31/0x50 [ 45.893758][ C3] do_setlink+0x17b4/0x21e0 [ 45.893926][ C3] rtnl_setlink+0x1f7/0x310 [ 45.894180][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.894346][ C3] netlink_rcv_skb+0x130/0x360 [ 45.894514][ C3] netlink_unicast+0x449/0x710 [ 45.894761][ C3] netlink_sendmsg+0x723/0xbe0 [ 45.894935][ C3] __sys_sendto+0x37d/0x410 [ 45.895105][ C3] __x64_sys_sendto+0xe0/0x1c0 [ 45.895275][ C3] do_syscall_64+0xc6/0x1e0 [ 45.895557][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.895795][ C3] IN-SOFTIRQ-W at: [ 45.895897][ C3] __lock_acquire+0x797/0x1570 [ 45.896154][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.896323][ C3] _raw_spin_lock+0x30/0x40 [ 45.896497][ C3] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.896746][ C3] call_timer_fn+0x13b/0x230 [ 45.896994][ C3] __run_timers+0x545/0x810 [ 45.897173][ C3] run_timer_softirq+0xe8/0x1b0 [ 45.897340][ C3] __do_softirq+0x1f8/0x5df [ 45.897587][ C3] irq_exit_rcu+0x97/0xc0 [ 45.897757][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.897961][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.898252][ C3] default_idle+0xf/0x20 [ 45.898420][ C3] default_idle_call+0x6d/0xb0 [ 45.898587][ C3] cpuidle_idle_call+0x1f4/0x280 [ 45.898849][ C3] do_idle+0xf9/0x160 [ 45.898986][ C3] cpu_startup_entry+0x54/0x60 [ 45.899183][ C3] start_secondary+0x21c/0x2b0 [ 45.899364][ C3] common_startup_64+0x12c/0x138 [ 45.899634][ C3] INITIAL USE at: [ 45.899737][ C3] __lock_acquire+0x797/0x1570 [ 45.899913][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.900083][ C3] _raw_spin_lock_bh+0x38/0x50 [ 45.900331][ C3] br_set_mac_address+0xd2/0x260 [bridge] [ 45.900571][ C3] dev_set_mac_address+0x28a/0x410 [ 45.900747][ C3] dev_set_mac_address_user+0x31/0x50 [ 45.900998][ C3] do_setlink+0x17b4/0x21e0 [ 45.901171][ C3] rtnl_setlink+0x1f7/0x310 [ 45.901344][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 45.901588][ C3] netlink_rcv_skb+0x130/0x360 [ 45.901761][ C3] netlink_unicast+0x449/0x710 [ 45.901936][ C3] netlink_sendmsg+0x723/0xbe0 [ 45.902111][ C3] __sys_sendto+0x37d/0x410 [ 45.902371][ C3] __x64_sys_sendto+0xe0/0x1c0 [ 45.902550][ C3] do_syscall_64+0xc6/0x1e0 [ 45.902722][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 45.902927][ C3] } [ 45.902998][ C3] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 45.903269][ C3] ... acquired at: [ 45.903376][ C3] mark_lock+0x28d/0x3e0 [ 45.903535][ C3] mark_usage+0xd9/0x2a0 [ 45.903674][ C3] __lock_acquire+0x797/0x1570 [ 45.903809][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.903946][ C3] _raw_spin_lock+0x30/0x40 [ 45.904159][ C3] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.904365][ C3] call_timer_fn+0x13b/0x230 [ 45.904510][ C3] __run_timers+0x545/0x810 [ 45.904644][ C3] run_timer_softirq+0xe8/0x1b0 [ 45.904856][ C3] __do_softirq+0x1f8/0x5df [ 45.904992][ C3] irq_exit_rcu+0x97/0xc0 [ 45.905136][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.905321][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.905580][ C3] default_idle+0xf/0x20 [ 45.905740][ C3] default_idle_call+0x6d/0xb0 [ 45.905878][ C3] cpuidle_idle_call+0x1f4/0x280 [ 45.906036][ C3] do_idle+0xf9/0x160 [ 45.906149][ C3] cpu_startup_entry+0x54/0x60 [ 45.906382][ C3] start_secondary+0x21c/0x2b0 [ 45.906531][ C3] common_startup_64+0x12c/0x138 [ 45.906665][ C3] [ 45.906732][ C3] [ 45.906732][ C3] stack backtrace: [ 45.906920][ C3] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 6.9.0-rc1-virtme #1 [ 45.907150][ C3] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 45.907495][ C3] Call Trace: [ 45.907608][ C3] [ 45.907687][ C3] dump_stack_lvl+0x82/0xd0 [ 45.907826][ C3] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 45.908004][ C3] ? common_startup_64+0x12c/0x138 [ 45.908159][ C3] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 45.908353][ C3] ? __pfx_usage_skip+0x10/0x10 [ 45.908489][ C3] ? __pfx_usage_match+0x10/0x10 [ 45.908632][ C3] ? arch_stack_walk+0x8c/0xf0 [ 45.908857][ C3] mark_lock_irq+0x4cd/0xa10 [ 45.908994][ C3] ? __pfx_mark_lock_irq+0x10/0x10 [ 45.909175][ C3] ? stack_trace_save+0x94/0xd0 [ 45.909312][ C3] ? save_trace+0x8f/0x5b0 [ 45.909446][ C3] mark_lock+0x28d/0x3e0 [ 45.909638][ C3] ? __pfx_validate_chain+0x10/0x10 [ 45.909788][ C3] mark_usage+0xd9/0x2a0 [ 45.909891][ C3] __lock_acquire+0x797/0x1570 [ 45.910037][ C3] ? __lock_acquire+0xaf0/0x1570 [ 45.910261][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.910514][ C3] lock_acquire.part.0+0xeb/0x330 [ 45.910660][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.910871][ C3] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 45.911010][ C3] ? trace_lock_acquire+0x135/0x1c0 [ 45.911165][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.911369][ C3] ? lock_acquire+0x32/0xc0 [ 45.911526][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.911737][ C3] _raw_spin_lock+0x30/0x40 [ 45.911870][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.912080][ C3] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 45.912293][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.912525][ C3] call_timer_fn+0x13b/0x230 [ 45.912659][ C3] ? call_timer_fn+0xe8/0x230 [ 45.912792][ C3] ? call_timer_fn+0xe8/0x230 [ 45.913002][ C3] ? __pfx_call_timer_fn+0x10/0x10 [ 45.913150][ C3] ? mark_lock+0x38/0x3e0 [ 45.913257][ C3] __run_timers+0x545/0x810 [ 45.913390][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 45.913709][ C3] ? __pfx___run_timers+0x10/0x10 [ 45.913845][ C3] ? do_raw_spin_lock+0x131/0x270 [ 45.913979][ C3] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 45.914146][ C3] ? lock_acquire+0x32/0xc0 [ 45.914361][ C3] ? run_timer_softirq+0xe0/0x1b0 [ 45.914496][ C3] run_timer_softirq+0xe8/0x1b0 [ 45.914633][ C3] __do_softirq+0x1f8/0x5df [ 45.914768][ C3] irq_exit_rcu+0x97/0xc0 [ 45.914872][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 45.915166][ C3] [ 45.915236][ C3] [ 45.915305][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 45.915497][ C3] RIP: 0010:default_idle+0xf/0x20 [ 45.915643][ C3] 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 [ 45.916232][ C3] RSP: 0018:ffffc9000016fdf8 EFLAGS: 00000242 [ 45.916480][ C3] RAX: 00000000000b8443 RBX: 1ffff9200002dfc1 RCX: ffffffff8570e9d5 [ 45.916679][ C3] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff830aa4a4 [ 45.916878][ C3] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c3709c [ 45.917181][ C3] R10: ffff8880361b84e3 R11: ffff8880361bdc80 R12: 0000000000000000 [ 45.917399][ C3] R13: ffff888001b88040 R14: dffffc0000000000 R15: 0000000000000000 [ 45.917606][ C3] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 45.917831][ C3] ? cpuidle_idle_call+0x1f4/0x280 [ 45.917975][ C3] default_idle_call+0x6d/0xb0 [ 45.918121][ C3] cpuidle_idle_call+0x1f4/0x280 [ 45.918275][ C3] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 45.918411][ C3] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 45.918643][ C3] do_idle+0xf9/0x160 [ 45.918744][ C3] cpu_startup_entry+0x54/0x60 [ 45.918888][ C3] start_secondary+0x21c/0x2b0 [ 45.919028][ C3] ? __pfx_start_secondary+0x10/0x10 [ 45.919253][ C3] common_startup_64+0x12c/0x138 [ 45.919411][ C3] [ 49.797544][ T532] br0: port 3(veth5) entered blocking state [ 49.797816][ T532] br0: port 3(veth5) entered disabled state [ 49.798065][ T532] veth5: entered allmulticast mode [ 49.799583][ T532] veth5: entered promiscuous mode [ 50.026538][ T537] veth5: left allmulticast mode [ 50.026721][ T537] veth5: left promiscuous mode [ 50.026972][ T537] br0: port 3(veth5) entered disabled state [ 51.131216][ T552] br0: port 3(veth5) entered blocking state [ 51.131483][ T552] br0: port 3(veth5) entered disabled state [ 51.131707][ T552] veth5: entered allmulticast mode [ 51.133331][ T552] veth5: entered promiscuous mode [ 51.133620][ T552] br0: adding interface veth5 with same address as a received packet (addr:de:ad:be:ef:42:00, vlan:0) [ 51.354032][ T557] veth5: left allmulticast mode [ 51.354210][ T557] veth5: left promiscuous mode [ 51.354482][ T557] br0: port 3(veth5) entered disabled state [ 105.267255][ T1289] br0: port 3(veth5) entered blocking state [ 105.267478][ T1289] br0: port 3(veth5) entered disabled state [ 105.267691][ T1289] veth5: entered allmulticast mode [ 105.269183][ T1289] veth5: entered promiscuous mode [ 105.500124][ T1295] br0: port 3(veth5) entered disabled state [ 105.605188][ T1296] br0: port 2(veth3) entered disabled state [ 105.694288][ T1298] br0: port 1(veth1) entered disabled state [ 105.794052][ T1299] veth5: left allmulticast mode [ 105.794222][ T1299] veth5: left promiscuous mode [ 105.794481][ T1299] br0: port 3(veth5) entered disabled state [ 105.795453][ T1299] veth3: left allmulticast mode [ 105.795600][ T1299] veth3: left promiscuous mode [ 105.795841][ T1299] br0: port 2(veth3) entered disabled state [ 105.802059][ T1299] veth1: left allmulticast mode [ 105.802222][ T1299] veth1: left promiscuous mode [ 105.802474][ T1299] br0: port 1(veth1) entered disabled state