[ 25.202788][ T270] fab-br0: port 1(fbond) entered blocking state [ 25.203102][ T270] fab-br0: port 1(fbond) entered disabled state [ 25.203543][ T270] fbond: entered allmulticast mode [ 25.205083][ T270] fbond: entered promiscuous mode [ 25.317928][ T273] veth1-bond: entered promiscuous mode [ 25.318289][ T273] veth1-bond: entered allmulticast mode [ 25.319097][ T273] fbond: (slave veth1-bond): Enslaving as a backup interface with a down link [ 25.465969][ T274] veth2-bond: entered promiscuous mode [ 25.466368][ T274] veth2-bond: entered allmulticast mode [ 25.466829][ T274] fbond: (slave veth2-bond): Enslaving as a backup interface with a down link [ 25.620717][ T73] fbond: Warning: No 802.3ad response from the link partner for any adapters in the bond [ 25.718187][ T277] fbond: (slave veth1-bond): link status definitely up, 10000 Mbps full duplex [ 25.719104][ T277] fbond: (slave veth2-bond): link status definitely up, 10000 Mbps full duplex [ 25.719521][ T277] fbond: active interface up! [ 25.816703][ T278] fab-br0: port 1(fbond) entered blocking state [ 25.817050][ T278] fab-br0: port 1(fbond) entered forwarding state [ 25.972673][ C2] [ 25.972773][ C2] ======================================================== [ 25.972978][ C2] WARNING: possible irq lock inversion dependency detected [ 25.973184][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 25.973322][ C2] -------------------------------------------------------- [ 25.973526][ C2] swapper/2/0 just changed the state of lock: [ 25.973700][ C2] ffff888006652c18 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [ 25.973952][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 25.974149][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 25.974153][ C2] [ 25.974153][ C2] [ 25.974153][ C2] and interrupts could create inverse lock ordering between them. [ 25.974153][ C2] [ 25.974637][ C2] [ 25.974637][ C2] other info that might help us debug this: [ 25.974836][ C2] Chain exists of: [ 25.974836][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 25.974836][ C2] [ 25.975145][ C2] Possible interrupt unsafe locking scenario: [ 25.975145][ C2] [ 25.975344][ C2] CPU0 CPU1 [ 25.975477][ C2] ---- ---- [ 25.975611][ C2] lock(&p->alloc_lock); [ 25.975714][ C2] local_irq_disable(); [ 25.975884][ C2] lock(&br->lock); [ 25.976052][ C2] lock(lweventlist_lock); [ 25.976221][ C2] [ 25.976324][ C2] lock(&br->lock); [ 25.976429][ C2] [ 25.976429][ C2] *** DEADLOCK *** [ 25.976429][ C2] [ 25.976629][ C2] 1 lock held by swapper/2/0: [ 25.976765][ C2] #0: ffffc90000230b68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 25.977045][ C2] [ 25.977045][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 25.977276][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 25.977417][ C2] HARDIRQ-ON-W at: [ 25.977522][ C2] __lock_acquire+0x797/0x1570 [ 25.977691][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.977861][ C2] _raw_spin_lock+0x30/0x40 [ 25.978033][ C2] set_mems_allowed+0x1d/0x210 [ 25.978203][ C2] kernel_init_freeable+0x72/0x310 [ 25.978375][ C2] kernel_init+0x20/0x200 [ 25.978546][ C2] ret_from_fork+0x31/0x70 [ 25.978717][ C2] ret_from_fork_asm+0x1a/0x30 [ 25.978889][ C2] SOFTIRQ-ON-W at: [ 25.978994][ C2] __lock_acquire+0x797/0x1570 [ 25.979163][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.979334][ C2] _raw_spin_lock+0x30/0x40 [ 25.979503][ C2] set_mems_allowed+0x1d/0x210 [ 25.979674][ C2] kernel_init_freeable+0x72/0x310 [ 25.979844][ C2] kernel_init+0x20/0x200 [ 25.980029][ C2] ret_from_fork+0x31/0x70 [ 25.980199][ C2] ret_from_fork_asm+0x1a/0x30 [ 25.980369][ C2] INITIAL USE at: [ 25.980471][ C2] __lock_acquire+0x797/0x1570 [ 25.980642][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.980813][ C2] _raw_spin_lock+0x30/0x40 [ 25.980985][ C2] set_mems_allowed+0x1d/0x210 [ 25.981156][ C2] kernel_init_freeable+0x72/0x310 [ 25.981326][ C2] kernel_init+0x20/0x200 [ 25.981496][ C2] ret_from_fork+0x31/0x70 [ 25.981668][ C2] ret_from_fork_asm+0x1a/0x30 [ 25.981838][ C2] } [ 25.981907][ C2] ... key at: [] __key.387+0x0/0x40 [ 25.982115][ C2] ... acquired at: [ 25.982218][ C2] __lock_acquire+0xaf0/0x1570 [ 25.982359][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.982495][ C2] _raw_spin_lock+0x30/0x40 [ 25.982631][ C2] __get_task_comm+0x27/0x70 [ 25.982768][ C2] ref_tracker_alloc+0x2ee/0x490 [ 25.982906][ C2] linkwatch_fire_event+0x196/0x200 [ 25.983042][ C2] bond_create+0xba/0x110 [ 25.983181][ C2] bonding_init+0x91/0xe0 [ 25.983318][ C2] do_one_initcall+0x8d/0x1e0 [ 25.983455][ C2] do_initcalls+0x1b2/0x3e0 [ 25.983590][ C2] kernel_init_freeable+0x232/0x310 [ 25.983726][ C2] kernel_init+0x20/0x200 [ 25.983861][ C2] ret_from_fork+0x31/0x70 [ 25.983998][ C2] ret_from_fork_asm+0x1a/0x30 [ 25.984134][ C2] [ 25.984203][ C2] -> (lweventlist_lock){....}-{2:2} { [ 25.984345][ C2] INITIAL USE at: [ 25.984447][ C2] __lock_acquire+0x797/0x1570 [ 25.984621][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.984790][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 25.984960][ C2] linkwatch_fire_event+0x74/0x200 [ 25.985130][ C2] bond_create+0xba/0x110 [ 25.985302][ C2] bonding_init+0x91/0xe0 [ 25.985473][ C2] do_one_initcall+0x8d/0x1e0 [ 25.985642][ C2] do_initcalls+0x1b2/0x3e0 [ 25.985814][ C2] kernel_init_freeable+0x232/0x310 [ 25.985982][ C2] kernel_init+0x20/0x200 [ 25.986151][ C2] ret_from_fork+0x31/0x70 [ 25.986321][ C2] ret_from_fork_asm+0x1a/0x30 [ 25.986493][ C2] } [ 25.986561][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 25.986760][ C2] ... acquired at: [ 25.986859][ C2] __lock_acquire+0xaf0/0x1570 [ 25.987010][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.987149][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 25.987283][ C2] linkwatch_fire_event+0x74/0x200 [ 25.987421][ C2] br_stp_change_bridge_id+0x25f/0x360 [ 25.987558][ C2] br_dev_newlink+0x8c/0x100 [ 25.987694][ C2] rtnl_newlink_create+0x341/0x850 [ 25.987830][ C2] __rtnl_newlink+0xac9/0xd80 [ 25.987967][ C2] rtnl_newlink+0x63/0xa0 [ 25.988104][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 25.988240][ C2] netlink_rcv_skb+0x130/0x360 [ 25.988379][ C2] netlink_unicast+0x449/0x710 [ 25.988517][ C2] netlink_sendmsg+0x723/0xbe0 [ 25.988654][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 25.988795][ C2] ___sys_sendmsg+0xee/0x170 [ 25.988929][ C2] __sys_sendmsg+0xcd/0x170 [ 25.989065][ C2] do_syscall_64+0xc6/0x1e0 [ 25.989203][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 25.989375][ C2] [ 25.989444][ C2] -> (&br->lock){+.-.}-{2:2} { [ 25.989583][ C2] HARDIRQ-ON-W at: [ 25.989685][ C2] __lock_acquire+0x797/0x1570 [ 25.989865][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.990043][ C2] _raw_spin_lock_bh+0x38/0x50 [ 25.990212][ C2] br_dev_newlink+0x65/0x100 [ 25.990382][ C2] rtnl_newlink_create+0x341/0x850 [ 25.990552][ C2] __rtnl_newlink+0xac9/0xd80 [ 25.990722][ C2] rtnl_newlink+0x63/0xa0 [ 25.990897][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 25.991150][ C2] netlink_rcv_skb+0x130/0x360 [ 25.991321][ C2] netlink_unicast+0x449/0x710 [ 25.991490][ C2] netlink_sendmsg+0x723/0xbe0 [ 25.991660][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 25.991911][ C2] ___sys_sendmsg+0xee/0x170 [ 25.992082][ C2] __sys_sendmsg+0xcd/0x170 [ 25.992256][ C2] do_syscall_64+0xc6/0x1e0 [ 25.992426][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 25.992636][ C2] IN-SOFTIRQ-W at: [ 25.992742][ C2] __lock_acquire+0x797/0x1570 [ 25.992912][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.993166][ C2] _raw_spin_lock+0x30/0x40 [ 25.993337][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 25.993546][ C2] call_timer_fn+0x13b/0x230 [ 25.993719][ C2] __run_timers+0x545/0x810 [ 25.993888][ C2] timer_expire_remote+0x9b/0xe0 [ 25.994057][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 25.994309][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 25.994477][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 25.994650][ C2] __do_softirq+0x1f8/0x5df [ 25.994822][ C2] irq_exit_rcu+0x97/0xc0 [ 25.994994][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 25.995197][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 25.995401][ C2] default_idle+0xf/0x20 [ 25.995652][ C2] default_idle_call+0x6d/0xb0 [ 25.995825][ C2] cpuidle_idle_call+0x1f4/0x280 [ 25.995998][ C2] do_idle+0xf9/0x160 [ 25.996137][ C2] cpu_startup_entry+0x54/0x60 [ 25.996316][ C2] start_secondary+0x21c/0x2b0 [ 25.996485][ C2] common_startup_64+0x12c/0x138 [ 25.996655][ C2] INITIAL USE at: [ 25.996836][ C2] __lock_acquire+0x797/0x1570 [ 25.997009][ C2] lock_acquire.part.0+0xeb/0x330 [ 25.997180][ C2] _raw_spin_lock_bh+0x38/0x50 [ 25.997352][ C2] br_dev_newlink+0x65/0x100 [ 25.997521][ C2] rtnl_newlink_create+0x341/0x850 [ 25.997691][ C2] __rtnl_newlink+0xac9/0xd80 [ 25.997865][ C2] rtnl_newlink+0x63/0xa0 [ 25.998123][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 25.998293][ C2] netlink_rcv_skb+0x130/0x360 [ 25.998464][ C2] netlink_unicast+0x449/0x710 [ 25.998634][ C2] netlink_sendmsg+0x723/0xbe0 [ 25.998804][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 25.998976][ C2] ___sys_sendmsg+0xee/0x170 [ 25.999148][ C2] __sys_sendmsg+0xcd/0x170 [ 25.999403][ C2] do_syscall_64+0xc6/0x1e0 [ 25.999573][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 25.999776][ C2] } [ 25.999845][ C2] ... key at: [] __key.6+0x0/0x40 [ 26.000023][ C2] ... acquired at: [ 26.000123][ C2] mark_lock+0x28d/0x3e0 [ 26.000261][ C2] mark_usage+0xd9/0x2a0 [ 26.000399][ C2] __lock_acquire+0x797/0x1570 [ 26.000620][ C2] lock_acquire.part.0+0xeb/0x330 [ 26.000755][ C2] _raw_spin_lock+0x30/0x40 [ 26.000892][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 26.001059][ C2] call_timer_fn+0x13b/0x230 [ 26.001195][ C2] __run_timers+0x545/0x810 [ 26.001331][ C2] timer_expire_remote+0x9b/0xe0 [ 26.001465][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 26.001600][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 26.001826][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 26.001962][ C2] __do_softirq+0x1f8/0x5df [ 26.002097][ C2] irq_exit_rcu+0x97/0xc0 [ 26.002232][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 26.002400][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.002567][ C2] default_idle+0xf/0x20 [ 26.002702][ C2] default_idle_call+0x6d/0xb0 [ 26.002836][ C2] cpuidle_idle_call+0x1f4/0x280 [ 26.003057][ C2] do_idle+0xf9/0x160 [ 26.003159][ C2] cpu_startup_entry+0x54/0x60 [ 26.003296][ C2] start_secondary+0x21c/0x2b0 [ 26.003430][ C2] common_startup_64+0x12c/0x138 [ 26.003565][ C2] [ 26.003633][ C2] [ 26.003633][ C2] stack backtrace: [ 26.003798][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 26.004003][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 26.004385][ C2] Call Trace: [ 26.004494][ C2] [ 26.004566][ C2] dump_stack_lvl+0x82/0xd0 [ 26.004708][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 26.004876][ C2] ? common_startup_64+0x12c/0x138 [ 26.005012][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 26.005182][ C2] ? __pfx_usage_skip+0x10/0x10 [ 26.005317][ C2] ? __pfx_usage_match+0x10/0x10 [ 26.005531][ C2] ? arch_stack_walk+0x8c/0xf0 [ 26.005668][ C2] mark_lock_irq+0x4cd/0xa10 [ 26.005805][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 26.005940][ C2] ? stack_trace_save+0x94/0xd0 [ 26.006076][ C2] ? add_chain_cache+0x248/0x8b0 [ 26.006211][ C2] ? save_trace+0x8f/0x5b0 [ 26.006347][ C2] mark_lock+0x28d/0x3e0 [ 26.006453][ C2] mark_usage+0xd9/0x2a0 [ 26.006554][ C2] __lock_acquire+0x797/0x1570 [ 26.006780][ C2] ? __lock_acquire+0xaf0/0x1570 [ 26.006914][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 26.007079][ C2] lock_acquire.part.0+0xeb/0x330 [ 26.007214][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 26.007380][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 26.007515][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 26.007653][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 26.007818][ C2] ? lock_acquire+0x32/0xc0 [ 26.007951][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 26.008118][ C2] _raw_spin_lock+0x30/0x40 [ 26.008252][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 26.008420][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 26.008587][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 26.008756][ C2] call_timer_fn+0x13b/0x230 [ 26.008892][ C2] ? call_timer_fn+0xe8/0x230 [ 26.009108][ C2] ? call_timer_fn+0xe8/0x230 [ 26.009242][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 26.009377][ C2] ? mark_lock+0x38/0x3e0 [ 26.009483][ C2] __run_timers+0x545/0x810 [ 26.009618][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 26.009787][ C2] ? __pfx___run_timers+0x10/0x10 [ 26.009923][ C2] ? __lock_release+0x103/0x460 [ 26.010070][ C2] ? do_raw_spin_lock+0x131/0x270 [ 26.010206][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 26.010422][ C2] ? lock_acquire+0x32/0xc0 [ 26.010555][ C2] ? timer_expire_remote+0x93/0xe0 [ 26.010690][ C2] timer_expire_remote+0x9b/0xe0 [ 26.010825][ C2] tmigr_handle_remote_cpu+0x270/0x430 [ 26.010960][ C2] ? __pfx_tmigr_handle_remote_cpu+0x10/0x10 [ 26.011129][ C2] tmigr_handle_remote_up+0x19f/0x2e0 [ 26.011267][ C2] tmigr_handle_remote+0x21d/0x3a0 [ 26.011403][ C2] ? __pfx_tmigr_handle_remote+0x10/0x10 [ 26.011627][ C2] __do_softirq+0x1f8/0x5df [ 26.011763][ C2] irq_exit_rcu+0x97/0xc0 [ 26.011865][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 26.012001][ C2] [ 26.012071][ C2] [ 26.012140][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.012313][ C2] RIP: 0010:default_idle+0xf/0x20 [ 26.012454][ 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 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 [ 26.013018][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000242 [ 26.013190][ C2] RAX: 000000000009aa6b RBX: 1ffff9200002bfc1 RCX: ffffffffa91822b5 [ 26.013396][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffa6aaa4a4 [ 26.013596][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 26.013798][ C2] R10: ffff8880361384e3 R11: ffff88803613dc40 R12: 0000000000000000 [ 26.014080][ C2] R13: ffff888001b845c0 R14: dffffc0000000000 R15: 0000000000000000 [ 26.014281][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 26.014420][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 26.014557][ C2] default_idle_call+0x6d/0xb0 [ 26.014692][ C2] cpuidle_idle_call+0x1f4/0x280 [ 26.014827][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 26.014963][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 26.015098][ C2] do_idle+0xf9/0x160 [ 26.015280][ C2] cpu_startup_entry+0x54/0x60 [ 26.015414][ C2] start_secondary+0x21c/0x2b0 [ 26.015548][ C2] ? __pfx_start_secondary+0x10/0x10 [ 26.015685][ C2] common_startup_64+0x12c/0x138 [ 26.015823][ C2] [ 28.131120][ T315] fbond: left allmulticast mode [ 28.131279][ T315] veth1-bond: left allmulticast mode [ 28.131414][ T315] veth2-bond: left allmulticast mode [ 28.131546][ T315] fbond: left promiscuous mode [ 28.131687][ T315] veth1-bond: left promiscuous mode [ 28.131981][ T315] veth2-bond: left promiscuous mode [ 28.132356][ T315] fab-br0: port 1(fbond) entered disabled state [ 28.257680][ T316] fbond (unregistering): (slave veth1-bond): Removing an active aggregator [ 28.258262][ T316] fbond (unregistering): (slave veth1-bond): Releasing backup interface [ 28.278694][ T316] fbond (unregistering): (slave veth2-bond): Removing an active aggregator [ 28.279457][ T316] fbond (unregistering): (slave veth2-bond): Releasing backup interface [ 28.293814][ T316] fbond (unregistering): Released all slaves