[ 27.191918][ T273] fab-br0: port 1(fbond) entered blocking state [ 27.192672][ T273] fab-br0: port 1(fbond) entered disabled state [ 27.193005][ T273] fbond: entered allmulticast mode [ 27.194640][ T273] fbond: entered promiscuous mode [ 27.328126][ T275] veth1-bond: entered promiscuous mode [ 27.328623][ T275] veth1-bond: entered allmulticast mode [ 27.329671][ T275] fbond: (slave veth1-bond): Enslaving as a backup interface with a down link [ 27.465208][ T276] veth2-bond: entered promiscuous mode [ 27.465557][ T276] veth2-bond: entered allmulticast mode [ 27.466026][ T276] fbond: (slave veth2-bond): Enslaving as a backup interface with a down link [ 27.639546][ T75] fbond: (slave veth1-bond): link status definitely up, 10000 Mbps full duplex [ 27.640018][ T75] fbond: Warning: No 802.3ad response from the link partner for any adapters in the bond [ 27.640621][ T75] fbond: active interface up! [ 27.847723][ T75] fbond: (slave veth2-bond): link status definitely up, 10000 Mbps full duplex [ 27.857824][ T279] fab-br0: port 1(fbond) entered blocking state [ 27.858189][ T279] fab-br0: port 1(fbond) entered forwarding state [ 28.016167][ C3] [ 28.016278][ C3] ======================================================== [ 28.016503][ C3] WARNING: possible irq lock inversion dependency detected [ 28.016733][ C3] 6.9.0-rc1-virtme #1 Not tainted [ 28.016888][ C3] -------------------------------------------------------- [ 28.017122][ C3] swapper/3/0 just changed the state of lock: [ 28.017317][ C3] ffff8880057e2c18 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [ 28.017587][ C3] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 28.017825][ C3] (&p->alloc_lock){+.+.}-{2:2} [ 28.017829][ C3] [ 28.017829][ C3] [ 28.017829][ C3] and interrupts could create inverse lock ordering between them. [ 28.017829][ C3] [ 28.018381][ C3] [ 28.018381][ C3] other info that might help us debug this: [ 28.018601][ C3] Chain exists of: [ 28.018601][ C3] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 28.018601][ C3] [ 28.018945][ C3] Possible interrupt unsafe locking scenario: [ 28.018945][ C3] [ 28.019172][ C3] CPU0 CPU1 [ 28.019328][ C3] ---- ---- [ 28.019481][ C3] lock(&p->alloc_lock); [ 28.019598][ C3] local_irq_disable(); [ 28.019779][ C3] lock(&br->lock); [ 28.019971][ C3] lock(lweventlist_lock); [ 28.020164][ C3] [ 28.020279][ C3] lock(&br->lock); [ 28.020400][ C3] [ 28.020400][ C3] *** DEADLOCK *** [ 28.020400][ C3] [ 28.020624][ C3] 1 lock held by swapper/3/0: [ 28.020780][ C3] #0: ffffc90000288d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 28.021093][ C3] [ 28.021093][ C3] the shortest dependencies between 2nd lock and 1st lock: [ 28.021356][ C3] -> (&p->alloc_lock){+.+.}-{2:2} { [ 28.021515][ C3] HARDIRQ-ON-W at: [ 28.021631][ C3] __lock_acquire+0x797/0x1570 [ 28.021884][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.022194][ C3] _raw_spin_lock+0x30/0x40 [ 28.022488][ C3] set_mems_allowed+0x1d/0x210 [ 28.022785][ C3] kernel_init_freeable+0x72/0x310 [ 28.023000][ C3] kernel_init+0x20/0x200 [ 28.023196][ C3] ret_from_fork+0x31/0x70 [ 28.023390][ C3] ret_from_fork_asm+0x1a/0x30 [ 28.023586][ C3] SOFTIRQ-ON-W at: [ 28.023700][ C3] __lock_acquire+0x797/0x1570 [ 28.023906][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.024096][ C3] _raw_spin_lock+0x30/0x40 [ 28.024285][ C3] set_mems_allowed+0x1d/0x210 [ 28.024470][ C3] kernel_init_freeable+0x72/0x310 [ 28.024673][ C3] kernel_init+0x20/0x200 [ 28.024890][ C3] ret_from_fork+0x31/0x70 [ 28.025082][ C3] ret_from_fork_asm+0x1a/0x30 [ 28.025275][ C3] INITIAL USE at: [ 28.025396][ C3] __lock_acquire+0x797/0x1570 [ 28.025591][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.025784][ C3] _raw_spin_lock+0x30/0x40 [ 28.025969][ C3] set_mems_allowed+0x1d/0x210 [ 28.026167][ C3] kernel_init_freeable+0x72/0x310 [ 28.026361][ C3] kernel_init+0x20/0x200 [ 28.026550][ C3] ret_from_fork+0x31/0x70 [ 28.026738][ C3] ret_from_fork_asm+0x1a/0x30 [ 28.026926][ C3] } [ 28.027002][ C3] ... key at: [] __key.387+0x0/0x40 [ 28.027236][ C3] ... acquired at: [ 28.027349][ C3] __lock_acquire+0xaf0/0x1570 [ 28.027506][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.027657][ C3] _raw_spin_lock+0x30/0x40 [ 28.027814][ C3] __get_task_comm+0x27/0x70 [ 28.027964][ C3] ref_tracker_alloc+0x2ee/0x490 [ 28.028118][ C3] linkwatch_fire_event+0x196/0x200 [ 28.028268][ C3] bond_create+0xba/0x110 [ 28.028417][ C3] bonding_init+0x91/0xe0 [ 28.028570][ C3] do_one_initcall+0x8d/0x1e0 [ 28.028723][ C3] do_initcalls+0x1b2/0x3e0 [ 28.028880][ C3] kernel_init_freeable+0x232/0x310 [ 28.029030][ C3] kernel_init+0x20/0x200 [ 28.029182][ C3] ret_from_fork+0x31/0x70 [ 28.029334][ C3] ret_from_fork_asm+0x1a/0x30 [ 28.029487][ C3] [ 28.029564][ C3] -> (lweventlist_lock){....}-{2:2} { [ 28.029718][ C3] INITIAL USE at: [ 28.029849][ C3] __lock_acquire+0x797/0x1570 [ 28.030040][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.030241][ C3] _raw_spin_lock_irqsave+0x3f/0x60 [ 28.030433][ C3] linkwatch_fire_event+0x74/0x200 [ 28.030623][ C3] bond_create+0xba/0x110 [ 28.030814][ C3] bonding_init+0x91/0xe0 [ 28.031004][ C3] do_one_initcall+0x8d/0x1e0 [ 28.031194][ C3] do_initcalls+0x1b2/0x3e0 [ 28.031389][ C3] kernel_init_freeable+0x232/0x310 [ 28.031576][ C3] kernel_init+0x20/0x200 [ 28.031773][ C3] ret_from_fork+0x31/0x70 [ 28.031962][ C3] ret_from_fork_asm+0x1a/0x30 [ 28.032159][ C3] } [ 28.032232][ C3] ... key at: [] lweventlist_lock+0x18/0x60 [ 28.032456][ C3] ... acquired at: [ 28.032568][ C3] __lock_acquire+0xaf0/0x1570 [ 28.032722][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.032971][ C3] _raw_spin_lock_irqsave+0x3f/0x60 [ 28.033124][ C3] linkwatch_fire_event+0x74/0x200 [ 28.033271][ C3] br_stp_change_bridge_id+0x25f/0x360 [ 28.033428][ C3] br_dev_newlink+0x8c/0x100 [ 28.033581][ C3] rtnl_newlink_create+0x341/0x850 [ 28.033820][ C3] __rtnl_newlink+0xac9/0xd80 [ 28.033974][ C3] rtnl_newlink+0x63/0xa0 [ 28.034134][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 28.034290][ C3] netlink_rcv_skb+0x130/0x360 [ 28.034445][ C3] netlink_unicast+0x449/0x710 [ 28.034677][ C3] netlink_sendmsg+0x723/0xbe0 [ 28.034838][ C3] ____sys_sendmsg+0x7b2/0xa10 [ 28.035069][ C3] ___sys_sendmsg+0xee/0x170 [ 28.035222][ C3] __sys_sendmsg+0xcd/0x170 [ 28.035450][ C3] do_syscall_64+0xc6/0x1e0 [ 28.035606][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 28.035800][ C3] [ 28.035876][ C3] -> (&br->lock){+.-.}-{2:2} { [ 28.036035][ C3] HARDIRQ-ON-W at: [ 28.036241][ C3] __lock_acquire+0x797/0x1570 [ 28.036439][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.036630][ C3] _raw_spin_lock_bh+0x38/0x50 [ 28.036921][ C3] br_dev_newlink+0x65/0x100 [ 28.037114][ C3] rtnl_newlink_create+0x341/0x850 [ 28.037393][ C3] __rtnl_newlink+0xac9/0xd80 [ 28.037584][ C3] rtnl_newlink+0x63/0xa0 [ 28.037780][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 28.038134][ C3] netlink_rcv_skb+0x130/0x360 [ 28.038417][ C3] netlink_unicast+0x449/0x710 [ 28.038700][ C3] netlink_sendmsg+0x723/0xbe0 [ 28.038994][ C3] ____sys_sendmsg+0x7b2/0xa10 [ 28.039453][ C3] ___sys_sendmsg+0xee/0x170 [ 28.039756][ C3] __sys_sendmsg+0xcd/0x170 [ 28.040059][ C3] do_syscall_64+0xc6/0x1e0 [ 28.040507][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 28.040759][ C3] IN-SOFTIRQ-W at: [ 28.040876][ C3] __lock_acquire+0x797/0x1570 [ 28.041066][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.041432][ C3] _raw_spin_lock+0x30/0x40 [ 28.041627][ C3] br_forward_delay_timer_expired+0x48/0x440 [ 28.041862][ C3] call_timer_fn+0x13b/0x230 [ 28.042139][ C3] __run_timers+0x545/0x810 [ 28.042331][ C3] run_timer_softirq+0xe8/0x1b0 [ 28.042608][ C3] __do_softirq+0x1f8/0x5df [ 28.042807][ C3] irq_exit_rcu+0x97/0xc0 [ 28.042998][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 28.043225][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 28.043665][ C3] default_idle+0xf/0x20 [ 28.044077][ C3] default_idle_call+0x6d/0xb0 [ 28.044375][ C3] cpuidle_idle_call+0x1f4/0x280 [ 28.044670][ C3] do_idle+0xf9/0x160 [ 28.045070][ C3] cpu_startup_entry+0x54/0x60 [ 28.045367][ C3] start_secondary+0x21c/0x2b0 [ 28.045662][ C3] common_startup_64+0x12c/0x138 [ 28.046030][ C3] INITIAL USE at: [ 28.046153][ C3] __lock_acquire+0x797/0x1570 [ 28.046342][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.046531][ C3] _raw_spin_lock_bh+0x38/0x50 [ 28.046803][ C3] br_dev_newlink+0x65/0x100 [ 28.046996][ C3] rtnl_newlink_create+0x341/0x850 [ 28.047197][ C3] __rtnl_newlink+0xac9/0xd80 [ 28.047387][ C3] rtnl_newlink+0x63/0xa0 [ 28.047654][ C3] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 28.047850][ C3] netlink_rcv_skb+0x130/0x360 [ 28.048039][ C3] netlink_unicast+0x449/0x710 [ 28.048334][ C3] netlink_sendmsg+0x723/0xbe0 [ 28.048613][ C3] ____sys_sendmsg+0x7b2/0xa10 [ 28.048895][ C3] ___sys_sendmsg+0xee/0x170 [ 28.049328][ C3] __sys_sendmsg+0xcd/0x170 [ 28.049624][ C3] do_syscall_64+0xc6/0x1e0 [ 28.049914][ C3] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 28.050272][ C3] } [ 28.050678][ C3] ... key at: [] __key.6+0x0/0x40 [ 28.050906][ C3] ... acquired at: [ 28.051019][ C3] mark_lock+0x28d/0x3e0 [ 28.051174][ C3] mark_usage+0xd9/0x2a0 [ 28.051407][ C3] __lock_acquire+0x797/0x1570 [ 28.051561][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.051709][ C3] _raw_spin_lock+0x30/0x40 [ 28.051867][ C3] br_forward_delay_timer_expired+0x48/0x440 [ 28.052134][ C3] call_timer_fn+0x13b/0x230 [ 28.052290][ C3] __run_timers+0x545/0x810 [ 28.052441][ C3] run_timer_softirq+0xe8/0x1b0 [ 28.052591][ C3] __do_softirq+0x1f8/0x5df [ 28.052756][ C3] irq_exit_rcu+0x97/0xc0 [ 28.053133][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 28.053429][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 28.053724][ C3] default_idle+0xf/0x20 [ 28.054011][ C3] default_idle_call+0x6d/0xb0 [ 28.054276][ C3] cpuidle_idle_call+0x1f4/0x280 [ 28.054450][ C3] do_idle+0xf9/0x160 [ 28.054576][ C3] cpu_startup_entry+0x54/0x60 [ 28.054751][ C3] start_secondary+0x21c/0x2b0 [ 28.055016][ C3] common_startup_64+0x12c/0x138 [ 28.055399][ C3] [ 28.055528][ C3] [ 28.055528][ C3] stack backtrace: [ 28.055807][ C3] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 6.9.0-rc1-virtme #1 [ 28.056158][ C3] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 28.056520][ C3] Call Trace: [ 28.056648][ C3] [ 28.056741][ C3] dump_stack_lvl+0x82/0xd0 [ 28.056912][ C3] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 28.057126][ C3] ? common_startup_64+0x12c/0x138 [ 28.057296][ C3] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 28.057582][ C3] ? __pfx_usage_skip+0x10/0x10 [ 28.057753][ C3] ? __pfx_usage_match+0x10/0x10 [ 28.057914][ C3] ? arch_stack_walk+0x8c/0xf0 [ 28.058077][ C3] mark_lock_irq+0x4cd/0xa10 [ 28.058239][ C3] ? __pfx_mark_lock_irq+0x10/0x10 [ 28.058479][ C3] ? stack_trace_save+0x94/0xd0 [ 28.058647][ C3] ? add_chain_cache+0x248/0x8b0 [ 28.058855][ C3] ? save_trace+0x8f/0x5b0 [ 28.059240][ C3] mark_lock+0x28d/0x3e0 [ 28.059430][ C3] mark_usage+0xd9/0x2a0 [ 28.059611][ C3] __lock_acquire+0x797/0x1570 [ 28.059789][ C3] ? __lock_acquire+0xaf0/0x1570 [ 28.059956][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 28.060236][ C3] lock_acquire.part.0+0xeb/0x330 [ 28.060398][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [ 28.060607][ C3] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 28.060777][ C3] ? trace_lock_acquire+0x135/0x1c0 [ 28.061017][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [ 28.061299][ C3] ? lock_acquire+0x32/0xc0 [ 28.061467][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [ 28.061669][ C3] _raw_spin_lock+0x30/0x40 [ 28.061841][ C3] ? br_forward_delay_timer_expired+0x48/0x440 [ 28.062104][ C3] br_forward_delay_timer_expired+0x48/0x440 [ 28.062305][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 28.062492][ C3] call_timer_fn+0x13b/0x230 [ 28.062740][ C3] ? call_timer_fn+0xe8/0x230 [ 28.062917][ C3] ? call_timer_fn+0xe8/0x230 [ 28.063075][ C3] ? __pfx_call_timer_fn+0x10/0x10 [ 28.063239][ C3] ? mark_lock+0x38/0x3e0 [ 28.063535][ C3] __run_timers+0x545/0x810 [ 28.063696][ C3] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 28.063901][ C3] ? __pfx___run_timers+0x10/0x10 [ 28.064063][ C3] ? do_raw_spin_lock+0x131/0x270 [ 28.064224][ C3] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 28.064386][ C3] ? lock_acquire+0x32/0xc0 [ 28.064545][ C3] ? run_timer_softirq+0xe0/0x1b0 [ 28.064705][ C3] run_timer_softirq+0xe8/0x1b0 [ 28.064966][ C3] __do_softirq+0x1f8/0x5df [ 28.065133][ C3] irq_exit_rcu+0x97/0xc0 [ 28.065256][ C3] sysvec_apic_timer_interrupt+0x75/0x80 [ 28.065423][ C3] [ 28.065506][ C3] [ 28.065589][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 28.065882][ C3] RIP: 0010:default_idle+0xf/0x20 [ 28.066053][ 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 c3 f7 2d 00 fb f4 c3 cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90 [ 28.066701][ C3] RSP: 0018:ffffc9000016fdf8 EFLAGS: 00000246 [ 28.066927][ C3] RAX: 000000000005f339 RBX: 1ffff9200002dfc1 RCX: ffffffffac1822b5 [ 28.067172][ C3] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffa9aaa4a4 [ 28.067538][ C3] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1005f3709c [ 28.067783][ C3] R10: ffff88802f9b84e3 R11: ffff88802f9bdc40 R12: 0000000000000000 [ 28.068021][ C3] R13: ffff888001b90040 R14: dffffc0000000000 R15: 0000000000000000 [ 28.068360][ C3] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 28.068523][ C3] ? cpuidle_idle_call+0x1f4/0x280 [ 28.068687][ C3] default_idle_call+0x6d/0xb0 [ 28.068856][ C3] cpuidle_idle_call+0x1f4/0x280 [ 28.069026][ C3] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 28.069193][ C3] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 28.069357][ C3] do_idle+0xf9/0x160 [ 28.069483][ C3] cpu_startup_entry+0x54/0x60 [ 28.069815][ C3] start_secondary+0x21c/0x2b0 [ 28.069977][ C3] ? __pfx_start_secondary+0x10/0x10 [ 28.070144][ C3] common_startup_64+0x12c/0x138 [ 28.070311][ C3] [ 30.098712][ T310] fbond: left allmulticast mode [ 30.098879][ T310] veth1-bond: left allmulticast mode [ 30.099014][ T310] veth2-bond: left allmulticast mode [ 30.099156][ T310] fbond: left promiscuous mode [ 30.099288][ T310] veth1-bond: left promiscuous mode [ 30.099579][ T310] veth2-bond: left promiscuous mode [ 30.099959][ T310] fab-br0: port 1(fbond) entered disabled state [ 30.265363][ T312] fbond (unregistering): (slave veth1-bond): Removing an active aggregator [ 30.265922][ T312] fbond (unregistering): (slave veth1-bond): Releasing backup interface [ 30.288315][ T312] fbond (unregistering): (slave veth2-bond): Removing an active aggregator [ 30.288892][ T312] fbond (unregistering): (slave veth2-bond): Releasing backup interface [ 30.312306][ T312] fbond (unregistering): Released all slaves