[ 33.927788][ T284] br0: port 1(veth1) entered blocking state [ 33.928963][ T284] br0: port 1(veth1) entered disabled state [ 33.929306][ T284] veth1: entered allmulticast mode [ 33.931289][ T284] veth1: entered promiscuous mode [ 34.087463][ T286] br0: port 2(veth2) entered blocking state [ 34.087756][ T286] br0: port 2(veth2) entered disabled state [ 34.088032][ T286] veth2: entered allmulticast mode [ 34.090407][ T286] veth2: entered promiscuous mode [ 34.358115][ T283] br0: port 1(veth1) entered blocking state [ 34.358622][ T283] br0: port 1(veth1) entered forwarding state [ 34.480654][ T51] br0: port 2(veth2) entered blocking state [ 34.480946][ T51] br0: port 2(veth2) entered forwarding state [ 49.696595][ T336] GACT probability NOT on [ 49.736064][ C1] [ 49.736190][ C1] ======================================================== [ 49.736431][ C1] WARNING: possible irq lock inversion dependency detected [ 49.736650][ C1] 6.9.0-rc1-virtme #1 Not tainted [ 49.736809][ C1] -------------------------------------------------------- [ 49.737029][ C1] swapper/1/0 just changed the state of lock: [ 49.737253][ C1] ffff888007baac38 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.737616][ C1] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 49.737849][ C1] (&p->alloc_lock){+.+.}-{2:2} [ 49.737854][ C1] [ 49.737854][ C1] [ 49.737854][ C1] and interrupts could create inverse lock ordering between them. [ 49.737854][ C1] [ 49.738423][ C1] [ 49.738423][ C1] other info that might help us debug this: [ 49.738624][ C1] Chain exists of: [ 49.738624][ C1] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 49.738624][ C1] [ 49.738952][ C1] Possible interrupt unsafe locking scenario: [ 49.738952][ C1] [ 49.739167][ C1] CPU0 CPU1 [ 49.739336][ C1] ---- ---- [ 49.739493][ C1] lock(&p->alloc_lock); [ 49.739610][ C1] local_irq_disable(); [ 49.739793][ C1] lock(&br->lock); [ 49.739987][ C1] lock(lweventlist_lock); [ 49.740182][ C1] [ 49.740301][ C1] lock(&br->lock); [ 49.740423][ C1] [ 49.740423][ C1] *** DEADLOCK *** [ 49.740423][ C1] [ 49.740653][ C1] 1 lock held by swapper/1/0: [ 49.740804][ C1] #0: ffffc900001d8d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 49.741238][ C1] [ 49.741238][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 49.741520][ C1] -> (&p->alloc_lock){+.+.}-{2:2} { [ 49.741700][ C1] HARDIRQ-ON-W at: [ 49.741823][ C1] __lock_acquire+0x797/0x1570 [ 49.742044][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.742256][ C1] _raw_spin_lock+0x30/0x40 [ 49.742453][ C1] set_mems_allowed+0x1d/0x210 [ 49.742659][ C1] kernel_init_freeable+0x72/0x310 [ 49.742864][ C1] kernel_init+0x20/0x200 [ 49.743062][ C1] ret_from_fork+0x31/0x70 [ 49.743276][ C1] ret_from_fork_asm+0x1a/0x30 [ 49.743473][ C1] SOFTIRQ-ON-W at: [ 49.743590][ C1] __lock_acquire+0x797/0x1570 [ 49.743807][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.743994][ C1] _raw_spin_lock+0x30/0x40 [ 49.744170][ C1] set_mems_allowed+0x1d/0x210 [ 49.744368][ C1] kernel_init_freeable+0x72/0x310 [ 49.744556][ C1] kernel_init+0x20/0x200 [ 49.744740][ C1] ret_from_fork+0x31/0x70 [ 49.744926][ C1] ret_from_fork_asm+0x1a/0x30 [ 49.745109][ C1] INITIAL USE at: [ 49.745235][ C1] __lock_acquire+0x797/0x1570 [ 49.745439][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.745641][ C1] _raw_spin_lock+0x30/0x40 [ 49.745818][ C1] set_mems_allowed+0x1d/0x210 [ 49.746037][ C1] kernel_init_freeable+0x72/0x310 [ 49.746234][ C1] kernel_init+0x20/0x200 [ 49.746447][ C1] ret_from_fork+0x31/0x70 [ 49.746643][ C1] ret_from_fork_asm+0x1a/0x30 [ 49.746844][ C1] } [ 49.746926][ C1] ... key at: [] __key.387+0x0/0x40 [ 49.747169][ C1] ... acquired at: [ 49.747290][ C1] __lock_acquire+0xaf0/0x1570 [ 49.747450][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.747600][ C1] _raw_spin_lock+0x30/0x40 [ 49.747765][ C1] __get_task_comm+0x27/0x70 [ 49.748020][ C1] ref_tracker_alloc+0x2ee/0x490 [ 49.748266][ C1] linkwatch_fire_event+0x196/0x200 [ 49.748518][ C1] veth_newlink+0x367/0x830 [veth] [ 49.748687][ C1] rtnl_newlink_create+0x341/0x850 [ 49.748849][ C1] __rtnl_newlink+0xac9/0xd80 [ 49.749004][ C1] rtnl_newlink+0x63/0xa0 [ 49.749260][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.749422][ C1] netlink_rcv_skb+0x130/0x360 [ 49.749585][ C1] netlink_unicast+0x449/0x710 [ 49.749736][ C1] netlink_sendmsg+0x723/0xbe0 [ 49.749892][ C1] ____sys_sendmsg+0x7b2/0xa10 [ 49.750147][ C1] ___sys_sendmsg+0xee/0x170 [ 49.750297][ C1] __sys_sendmsg+0xcd/0x170 [ 49.750454][ C1] do_syscall_64+0xc6/0x1e0 [ 49.750621][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.750812][ C1] [ 49.750978][ C1] -> (lweventlist_lock){....}-{2:2} { [ 49.751144][ C1] INITIAL USE at: [ 49.751264][ C1] __lock_acquire+0x797/0x1570 [ 49.751456][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.751748][ C1] _raw_spin_lock_irqsave+0x3f/0x60 [ 49.751944][ C1] linkwatch_sync_dev+0x29/0x1f0 [ 49.752144][ C1] rtnl_getlink+0x4c9/0x970 [ 49.752338][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.752624][ C1] netlink_rcv_skb+0x130/0x360 [ 49.752813][ C1] netlink_unicast+0x449/0x710 [ 49.753110][ C1] netlink_sendmsg+0x723/0xbe0 [ 49.753328][ C1] __sys_sendto+0x37d/0x410 [ 49.753533][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 49.753730][ C1] do_syscall_64+0xc6/0x1e0 [ 49.754002][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.754228][ C1] } [ 49.754306][ C1] ... key at: [] lweventlist_lock+0x18/0x60 [ 49.754543][ C1] ... acquired at: [ 49.754660][ C1] __lock_acquire+0xaf0/0x1570 [ 49.754819][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.754968][ C1] _raw_spin_lock_irqsave+0x3f/0x60 [ 49.755117][ C1] linkwatch_fire_event+0x74/0x200 [ 49.755270][ C1] br_stp_change_bridge_id+0x25f/0x360 [bridge] [ 49.755676][ C1] br_set_mac_address+0x1f3/0x260 [bridge] [ 49.755912][ C1] dev_set_mac_address+0x28a/0x410 [ 49.756067][ C1] dev_set_mac_address_user+0x31/0x50 [ 49.756217][ C1] do_setlink+0x17b4/0x21e0 [ 49.756371][ C1] rtnl_setlink+0x1f7/0x310 [ 49.756527][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.756679][ C1] netlink_rcv_skb+0x130/0x360 [ 49.756921][ C1] netlink_unicast+0x449/0x710 [ 49.757071][ C1] netlink_sendmsg+0x723/0xbe0 [ 49.757249][ C1] __sys_sendto+0x37d/0x410 [ 49.757403][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 49.757552][ C1] do_syscall_64+0xc6/0x1e0 [ 49.757799][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.757988][ C1] [ 49.758061][ C1] -> (&br->lock){+.-.}-{2:2} { [ 49.758221][ C1] HARDIRQ-ON-W at: [ 49.758337][ C1] __lock_acquire+0x797/0x1570 [ 49.758616][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.758808][ C1] _raw_spin_lock_bh+0x38/0x50 [ 49.758995][ C1] br_set_mac_address+0xd2/0x260 [bridge] [ 49.759336][ C1] dev_set_mac_address+0x28a/0x410 [ 49.759539][ C1] dev_set_mac_address_user+0x31/0x50 [ 49.759742][ C1] do_setlink+0x17b4/0x21e0 [ 49.760015][ C1] rtnl_setlink+0x1f7/0x310 [ 49.760200][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.760389][ C1] netlink_rcv_skb+0x130/0x360 [ 49.760589][ C1] netlink_unicast+0x449/0x710 [ 49.760782][ C1] netlink_sendmsg+0x723/0xbe0 [ 49.760998][ C1] __sys_sendto+0x37d/0x410 [ 49.761241][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 49.761440][ C1] do_syscall_64+0xc6/0x1e0 [ 49.761725][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.761965][ C1] IN-SOFTIRQ-W at: [ 49.762096][ C1] __lock_acquire+0x797/0x1570 [ 49.762321][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.762508][ C1] _raw_spin_lock+0x30/0x40 [ 49.762806][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.763097][ C1] call_timer_fn+0x13b/0x230 [ 49.763292][ C1] __run_timers+0x545/0x810 [ 49.763498][ C1] run_timer_softirq+0xe8/0x1b0 [ 49.763780][ C1] __do_softirq+0x1f8/0x5df [ 49.764074][ C1] irq_exit_rcu+0x97/0xc0 [ 49.764268][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.764512][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 49.764760][ C1] default_idle+0xf/0x20 [ 49.764955][ C1] default_idle_call+0x6d/0xb0 [ 49.765153][ C1] cpuidle_idle_call+0x1f4/0x280 [ 49.765362][ C1] do_idle+0xf9/0x160 [ 49.765524][ C1] cpu_startup_entry+0x54/0x60 [ 49.765718][ C1] start_secondary+0x21c/0x2b0 [ 49.765992][ C1] common_startup_64+0x12c/0x138 [ 49.766189][ C1] INITIAL USE at: [ 49.766301][ C1] __lock_acquire+0x797/0x1570 [ 49.766499][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.766780][ C1] _raw_spin_lock_bh+0x38/0x50 [ 49.766975][ C1] br_set_mac_address+0xd2/0x260 [bridge] [ 49.767253][ C1] dev_set_mac_address+0x28a/0x410 [ 49.767530][ C1] dev_set_mac_address_user+0x31/0x50 [ 49.767724][ C1] do_setlink+0x17b4/0x21e0 [ 49.767919][ C1] rtnl_setlink+0x1f7/0x310 [ 49.768180][ C1] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 49.768624][ C1] netlink_rcv_skb+0x130/0x360 [ 49.768926][ C1] netlink_unicast+0x449/0x710 [ 49.769214][ C1] netlink_sendmsg+0x723/0xbe0 [ 49.769660][ C1] __sys_sendto+0x37d/0x410 [ 49.769965][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 49.770265][ C1] do_syscall_64+0xc6/0x1e0 [ 49.770714][ C1] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 49.771094][ C1] } [ 49.771219][ C1] ... key at: [] __key.6+0x0/0xfffffffffffe5ac0 [bridge] [ 49.771697][ C1] ... acquired at: [ 49.772017][ C1] mark_lock+0x28d/0x3e0 [ 49.772298][ C1] mark_usage+0xd9/0x2a0 [ 49.772538][ C1] __lock_acquire+0x797/0x1570 [ 49.772772][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.773147][ C1] _raw_spin_lock+0x30/0x40 [ 49.773389][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.773900][ C1] call_timer_fn+0x13b/0x230 [ 49.774139][ C1] __run_timers+0x545/0x810 [ 49.774515][ C1] run_timer_softirq+0xe8/0x1b0 [ 49.774754][ C1] __do_softirq+0x1f8/0x5df [ 49.774987][ C1] irq_exit_rcu+0x97/0xc0 [ 49.775218][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.775685][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 49.775984][ C1] default_idle+0xf/0x20 [ 49.776223][ C1] default_idle_call+0x6d/0xb0 [ 49.776454][ C1] cpuidle_idle_call+0x1f4/0x280 [ 49.776836][ C1] do_idle+0xf9/0x160 [ 49.777175][ C1] cpu_startup_entry+0x54/0x60 [ 49.777412][ C1] start_secondary+0x21c/0x2b0 [ 49.777651][ C1] common_startup_64+0x12c/0x138 [ 49.777888][ C1] [ 49.778006][ C1] [ 49.778006][ C1] stack backtrace: [ 49.778299][ C1] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 6.9.0-rc1-virtme #1 [ 49.778662][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 49.779177][ C1] Call Trace: [ 49.779366][ C1] [ 49.779644][ C1] dump_stack_lvl+0x82/0xd0 [ 49.779891][ C1] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 49.780188][ C1] ? common_startup_64+0x12c/0x138 [ 49.780567][ C1] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 49.780861][ C1] ? __pfx_usage_skip+0x10/0x10 [ 49.781108][ C1] ? __pfx_usage_match+0x10/0x10 [ 49.781482][ C1] ? arch_stack_walk+0x8c/0xf0 [ 49.781718][ C1] mark_lock_irq+0x4cd/0xa10 [ 49.781956][ C1] ? __pfx_mark_lock_irq+0x10/0x10 [ 49.782191][ C1] ? stack_trace_save+0x94/0xd0 [ 49.782430][ C1] ? add_chain_cache+0x248/0x8b0 [ 49.782815][ C1] ? save_trace+0x8f/0x5b0 [ 49.783048][ C1] mark_lock+0x28d/0x3e0 [ 49.783229][ C1] mark_usage+0xd9/0x2a0 [ 49.783406][ C1] __lock_acquire+0x797/0x1570 [ 49.783779][ C1] ? __lock_acquire+0xaf0/0x1570 [ 49.784018][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.784428][ C1] lock_acquire.part.0+0xeb/0x330 [ 49.784663][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.785179][ C1] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 49.785420][ C1] ? trace_lock_acquire+0x135/0x1c0 [ 49.785658][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.786014][ C1] ? lock_acquire+0x32/0xc0 [ 49.786251][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.786613][ C1] _raw_spin_lock+0x30/0x40 [ 49.786852][ C1] ? br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.787207][ C1] br_forward_delay_timer_expired+0x48/0x440 [bridge] [ 49.787568][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.787978][ C1] call_timer_fn+0x13b/0x230 [ 49.788210][ C1] ? call_timer_fn+0xe8/0x230 [ 49.788444][ C1] ? call_timer_fn+0xe8/0x230 [ 49.788679][ C1] ? __pfx_call_timer_fn+0x10/0x10 [ 49.788915][ C1] ? mark_lock+0x38/0x3e0 [ 49.789097][ C1] __run_timers+0x545/0x810 [ 49.789332][ C1] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [bridge] [ 49.789879][ C1] ? __pfx___run_timers+0x10/0x10 [ 49.790110][ C1] ? do_raw_spin_lock+0x131/0x270 [ 49.790344][ C1] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 49.790854][ C1] ? lock_acquire+0x32/0xc0 [ 49.791408][ C1] ? run_timer_softirq+0xe0/0x1b0 [ 49.791661][ C1] run_timer_softirq+0xe8/0x1b0 [ 49.791883][ C1] __do_softirq+0x1f8/0x5df [ 49.792117][ C1] irq_exit_rcu+0x97/0xc0 [ 49.792411][ C1] sysvec_apic_timer_interrupt+0x75/0x80 [ 49.792631][ C1] [ 49.792740][ C1] [ 49.792852][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 49.793140][ C1] RIP: 0010:default_idle+0xf/0x20 [ 49.793530][ 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 [ 49.794675][ C1] RSP: 0018:ffffc9000014fdf8 EFLAGS: 00000242 [ 49.794978][ C1] RAX: 000000000007f025 RBX: 1ffff92000029fc1 RCX: ffffffff8790e9d5 [ 49.795320][ C1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff852aa4a4 [ 49.795780][ C1] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c1709c [ 49.796109][ C1] R10: ffff8880360b84e3 R11: ffff8880360bdc80 R12: 0000000000000000 [ 49.796582][ C1] R13: ffff888001b7a300 R14: dffffc0000000000 R15: 0000000000000000 [ 49.796921][ C1] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 49.797145][ C1] ? cpuidle_idle_call+0x1f4/0x280 [ 49.797501][ C1] default_idle_call+0x6d/0xb0 [ 49.797727][ C1] cpuidle_idle_call+0x1f4/0x280 [ 49.797947][ C1] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 49.798178][ C1] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 49.798401][ C1] do_idle+0xf9/0x160 [ 49.798700][ C1] cpu_startup_entry+0x54/0x60 [ 49.798926][ C1] start_secondary+0x21c/0x2b0 [ 49.799150][ C1] ? __pfx_start_secondary+0x10/0x10 [ 49.799364][ C1] common_startup_64+0x12c/0x138 [ 49.799591][ C1] [ 218.628721][ T1475] br0: port 2(veth2) entered disabled state [ 218.751366][ T1477] br0: port 1(veth1) entered disabled state [ 218.845684][ T1478] veth2: left allmulticast mode [ 218.845859][ T1478] veth2: left promiscuous mode [ 218.846569][ T1478] br0: port 2(veth2) entered disabled state [ 218.847539][ T1478] veth1: left allmulticast mode [ 218.847680][ T1478] veth1: left promiscuous mode [ 218.847947][ T1478] br0: port 1(veth1) entered disabled state