[ 55.341912][ T535] fab-br0: port 1(fbond) entered blocking state
[ 55.342192][ T535] fab-br0: port 1(fbond) entered disabled state
[ 55.342470][ T535] fbond: entered allmulticast mode
[ 55.344849][ T535] fbond: entered promiscuous mode
[ 55.457315][ T538] veth1-bond: entered promiscuous mode
[ 55.457695][ T538] veth1-bond: entered allmulticast mode
[ 55.458480][ T538] fbond: (slave veth1-bond): Enslaving as a backup interface with a down link
[ 55.596855][ T539] veth2-bond: entered promiscuous mode
[ 55.597314][ T539] veth2-bond: entered allmulticast mode
[ 55.597844][ T539] fbond: (slave veth2-bond): Enslaving as a backup interface with a down link
[ 55.764519][ T239] fbond: (slave veth1-bond): link status definitely up, 10000 Mbps full duplex
[ 55.765115][ T239] fbond: Warning: No 802.3ad response from the link partner for any adapters in the bond
[ 55.765874][ T239] fbond: active interface up!
[ 55.970222][ T71] fbond: (slave veth2-bond): link status definitely up, 10000 Mbps full duplex
[ 55.999511][ T542] fab-br0: port 1(fbond) entered blocking state
[ 55.999948][ T542] fab-br0: port 1(fbond) entered forwarding state
[ 56.153912][ C2]
[ 56.154079][ C2] ========================================================
[ 56.154345][ C2] WARNING: possible irq lock inversion dependency detected
[ 56.154591][ C2] 6.9.0-rc1-virtme #1 Not tainted
[ 56.154759][ C2] --------------------------------------------------------
[ 56.154996][ C2] swapper/2/0 just changed the state of lock:
[ 56.155197][ C2] ffff888008b9ac18 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440
[ 56.155501][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past:
[ 56.155737][ C2] (&p->alloc_lock){+.+.}-{2:2}
[ 56.155741][ C2]
[ 56.155741][ C2]
[ 56.155741][ C2] and interrupts could create inverse lock ordering between them.
[ 56.155741][ C2]
[ 56.156342][ C2]
[ 56.156342][ C2] other info that might help us debug this:
[ 56.156582][ C2] Chain exists of:
[ 56.156582][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock
[ 56.156582][ C2]
[ 56.156938][ C2] Possible interrupt unsafe locking scenario:
[ 56.156938][ C2]
[ 56.157172][ C2] CPU0 CPU1
[ 56.157325][ C2] ---- ----
[ 56.157484][ C2] lock(&p->alloc_lock);
[ 56.157603][ C2] local_irq_disable();
[ 56.157824][ C2] lock(&br->lock);
[ 56.158022][ C2] lock(lweventlist_lock);
[ 56.158251][ C2] <Interrupt>
[ 56.158371][ C2] lock(&br->lock);
[ 56.158497][ C2]
[ 56.158497][ C2] *** DEADLOCK ***
[ 56.158497][ C2]
[ 56.158719][ C2] 1 lock held by swapper/2/0:
[ 56.158872][ C2] #0: ffffc90000230b68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230
[ 56.159187][ C2]
[ 56.159187][ C2] the shortest dependencies between 2nd lock and 1st lock:
[ 56.159456][ C2] -> (&p->alloc_lock){+.+.}-{2:2} {
[ 56.159614][ C2] HARDIRQ-ON-W at:
[ 56.159732][ C2] __lock_acquire+0x797/0x1570
[ 56.159932][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.160129][ C2] _raw_spin_lock+0x30/0x40
[ 56.160326][ C2] set_mems_allowed+0x1d/0x210
[ 56.160525][ C2] kernel_init_freeable+0x72/0x310
[ 56.160719][ C2] kernel_init+0x20/0x200
[ 56.160910][ C2] ret_from_fork+0x31/0x70
[ 56.161103][ C2] ret_from_fork_asm+0x1a/0x30
[ 56.161295][ C2] SOFTIRQ-ON-W at:
[ 56.161413][ C2] __lock_acquire+0x797/0x1570
[ 56.161607][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.161815][ C2] _raw_spin_lock+0x30/0x40
[ 56.162009][ C2] set_mems_allowed+0x1d/0x210
[ 56.162198][ C2] kernel_init_freeable+0x72/0x310
[ 56.162387][ C2] kernel_init+0x20/0x200
[ 56.162581][ C2] ret_from_fork+0x31/0x70
[ 56.162780][ C2] ret_from_fork_asm+0x1a/0x30
[ 56.162978][ C2] INITIAL USE at:
[ 56.163101][ C2] __lock_acquire+0x797/0x1570
[ 56.163292][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.163483][ C2] _raw_spin_lock+0x30/0x40
[ 56.163703][ C2] set_mems_allowed+0x1d/0x210
[ 56.163917][ C2] kernel_init_freeable+0x72/0x310
[ 56.164118][ C2] kernel_init+0x20/0x200
[ 56.164319][ C2] ret_from_fork+0x31/0x70
[ 56.164516][ C2] ret_from_fork_asm+0x1a/0x30
[ 56.164714][ C2] }
[ 56.164793][ C2] ... key at: [<ffffffffb5a2fd20>] __key.387+0x0/0x40
[ 56.165036][ C2] ... acquired at:
[ 56.165155][ C2] __lock_acquire+0xaf0/0x1570
[ 56.165321][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.165476][ C2] _raw_spin_lock+0x30/0x40
[ 56.165626][ C2] __get_task_comm+0x27/0x70
[ 56.165784][ C2] ref_tracker_alloc+0x2ee/0x490
[ 56.165948][ C2] linkwatch_fire_event+0x196/0x200
[ 56.166106][ C2] bond_create+0xba/0x110
[ 56.166263][ C2] bonding_init+0x91/0xe0
[ 56.166422][ C2] do_one_initcall+0x8d/0x1e0
[ 56.166591][ C2] do_initcalls+0x1b2/0x3e0
[ 56.166746][ C2] kernel_init_freeable+0x232/0x310
[ 56.166905][ C2] kernel_init+0x20/0x200
[ 56.167063][ C2] ret_from_fork+0x31/0x70
[ 56.167218][ C2] ret_from_fork_asm+0x1a/0x30
[ 56.167379][ C2]
[ 56.167461][ C2] -> (lweventlist_lock){....}-{2:2} {
[ 56.167617][ C2] INITIAL USE at:
[ 56.167734][ C2] __lock_acquire+0x797/0x1570
[ 56.167937][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.168109][ C2] _raw_spin_lock_irqsave+0x3f/0x60
[ 56.168284][ C2] linkwatch_fire_event+0x74/0x200
[ 56.168469][ C2] bond_create+0xba/0x110
[ 56.168667][ C2] bonding_init+0x91/0xe0
[ 56.168861][ C2] do_one_initcall+0x8d/0x1e0
[ 56.169054][ C2] do_initcalls+0x1b2/0x3e0
[ 56.169249][ C2] kernel_init_freeable+0x232/0x310
[ 56.169440][ C2] kernel_init+0x20/0x200
[ 56.169643][ C2] ret_from_fork+0x31/0x70
[ 56.169833][ C2] ret_from_fork_asm+0x1a/0x30
[ 56.170022][ C2] }
[ 56.170098][ C2] ... key at: [<ffffffffb49b0b38>] lweventlist_lock+0x18/0x60
[ 56.170325][ C2] ... acquired at:
[ 56.170435][ C2] __lock_acquire+0xaf0/0x1570
[ 56.170587][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.170738][ C2] _raw_spin_lock_irqsave+0x3f/0x60
[ 56.170888][ C2] linkwatch_fire_event+0x74/0x200
[ 56.171040][ C2] br_stp_change_bridge_id+0x25f/0x360
[ 56.171193][ C2] br_dev_newlink+0x8c/0x100
[ 56.171351][ C2] rtnl_newlink_create+0x341/0x850
[ 56.171503][ C2] __rtnl_newlink+0xac9/0xd80
[ 56.171655][ C2] rtnl_newlink+0x63/0xa0
[ 56.171807][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0
[ 56.171957][ C2] netlink_rcv_skb+0x130/0x360
[ 56.172108][ C2] netlink_unicast+0x449/0x710
[ 56.172258][ C2] netlink_sendmsg+0x723/0xbe0
[ 56.172406][ C2] ____sys_sendmsg+0x7b2/0xa10
[ 56.172568][ C2] ___sys_sendmsg+0xee/0x170
[ 56.172723][ C2] __sys_sendmsg+0xcd/0x170
[ 56.172881][ C2] do_syscall_64+0xc6/0x1e0
[ 56.173034][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75
[ 56.173225][ C2]
[ 56.173301][ C2] -> (&br->lock){+.-.}-{2:2} {
[ 56.173466][ C2] HARDIRQ-ON-W at:
[ 56.173580][ C2] __lock_acquire+0x797/0x1570
[ 56.173792][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.174000][ C2] _raw_spin_lock_bh+0x38/0x50
[ 56.174201][ C2] br_dev_newlink+0x65/0x100
[ 56.174401][ C2] rtnl_newlink_create+0x341/0x850
[ 56.174599][ C2] __rtnl_newlink+0xac9/0xd80
[ 56.174794][ C2] rtnl_newlink+0x63/0xa0
[ 56.174981][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0
[ 56.175173][ C2] netlink_rcv_skb+0x130/0x360
[ 56.175366][ C2] netlink_unicast+0x449/0x710
[ 56.175545][ C2] netlink_sendmsg+0x723/0xbe0
[ 56.175725][ C2] ____sys_sendmsg+0x7b2/0xa10
[ 56.175922][ C2] ___sys_sendmsg+0xee/0x170
[ 56.176114][ C2] __sys_sendmsg+0xcd/0x170
[ 56.176308][ C2] do_syscall_64+0xc6/0x1e0
[ 56.176509][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75
[ 56.176751][ C2] IN-SOFTIRQ-W at:
[ 56.176869][ C2] __lock_acquire+0x797/0x1570
[ 56.177061][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.177259][ C2] _raw_spin_lock+0x30/0x40
[ 56.177450][ C2] br_forward_delay_timer_expired+0x48/0x440
[ 56.177668][ C2] call_timer_fn+0x13b/0x230
[ 56.177865][ C2] __run_timers+0x545/0x810
[ 56.178054][ C2] timer_expire_remote+0x9b/0xe0
[ 56.178244][ C2] tmigr_handle_remote_cpu+0x270/0x430
[ 56.178444][ C2] tmigr_handle_remote_up+0x19f/0x2e0
[ 56.178632][ C2] tmigr_handle_remote+0x21d/0x3a0
[ 56.178824][ C2] __do_softirq+0x1f8/0x5df
[ 56.179035][ C2] irq_exit_rcu+0x97/0xc0
[ 56.179235][ C2] sysvec_apic_timer_interrupt+0x75/0x80
[ 56.179470][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 56.179702][ C2] default_idle+0xf/0x20
[ 56.179893][ C2] default_idle_call+0x6d/0xb0
[ 56.180082][ C2] cpuidle_idle_call+0x1f4/0x280
[ 56.180271][ C2] do_idle+0xf9/0x160
[ 56.180430][ C2] cpu_startup_entry+0x54/0x60
[ 56.180620][ C2] start_secondary+0x21c/0x2b0
[ 56.180813][ C2] common_startup_64+0x12c/0x138
[ 56.181007][ C2] INITIAL USE at:
[ 56.181126][ C2] __lock_acquire+0x797/0x1570
[ 56.181320][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.181512][ C2] _raw_spin_lock_bh+0x38/0x50
[ 56.181700][ C2] br_dev_newlink+0x65/0x100
[ 56.181890][ C2] rtnl_newlink_create+0x341/0x850
[ 56.182080][ C2] __rtnl_newlink+0xac9/0xd80
[ 56.182267][ C2] rtnl_newlink+0x63/0xa0
[ 56.182446][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0
[ 56.182635][ C2] netlink_rcv_skb+0x130/0x360
[ 56.182827][ C2] netlink_unicast+0x449/0x710
[ 56.183017][ C2] netlink_sendmsg+0x723/0xbe0
[ 56.183198][ C2] ____sys_sendmsg+0x7b2/0xa10
[ 56.183371][ C2] ___sys_sendmsg+0xee/0x170
[ 56.183545][ C2] __sys_sendmsg+0xcd/0x170
[ 56.183792][ C2] do_syscall_64+0xc6/0x1e0
[ 56.183979][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75
[ 56.184200][ C2] }
[ 56.184276][ C2] ... key at: [<ffffffffb6a89b60>] __key.6+0x0/0x40
[ 56.184453][ C2] ... acquired at:
[ 56.184559][ C2] mark_lock+0x28d/0x3e0
[ 56.184709][ C2] mark_usage+0xd9/0x2a0
[ 56.184850][ C2] __lock_acquire+0x797/0x1570
[ 56.184998][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.185142][ C2] _raw_spin_lock+0x30/0x40
[ 56.185289][ C2] br_forward_delay_timer_expired+0x48/0x440
[ 56.185469][ C2] call_timer_fn+0x13b/0x230
[ 56.185616][ C2] __run_timers+0x545/0x810
[ 56.185761][ C2] timer_expire_remote+0x9b/0xe0
[ 56.185898][ C2] tmigr_handle_remote_cpu+0x270/0x430
[ 56.186045][ C2] tmigr_handle_remote_up+0x19f/0x2e0
[ 56.186276][ C2] tmigr_handle_remote+0x21d/0x3a0
[ 56.186417][ C2] __do_softirq+0x1f8/0x5df
[ 56.186566][ C2] irq_exit_rcu+0x97/0xc0
[ 56.186709][ C2] sysvec_apic_timer_interrupt+0x75/0x80
[ 56.187018][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 56.187200][ C2] default_idle+0xf/0x20
[ 56.187341][ C2] default_idle_call+0x6d/0xb0
[ 56.187491][ C2] cpuidle_idle_call+0x1f4/0x280
[ 56.187637][ C2] do_idle+0xf9/0x160
[ 56.187745][ C2] cpu_startup_entry+0x54/0x60
[ 56.187900][ C2] start_secondary+0x21c/0x2b0
[ 56.188046][ C2] common_startup_64+0x12c/0x138
[ 56.188193][ C2]
[ 56.188262][ C2]
[ 56.188262][ C2] stack backtrace:
[ 56.188441][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1
[ 56.188658][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014
[ 56.188991][ C2] Call Trace:
[ 56.189107][ C2] <IRQ>
[ 56.189179][ C2] dump_stack_lvl+0x82/0xd0
[ 56.189330][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570
[ 56.189588][ C2] ? common_startup_64+0x12c/0x138
[ 56.189730][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10
[ 56.189901][ C2] ? __pfx_usage_skip+0x10/0x10
[ 56.190037][ C2] ? __pfx_usage_match+0x10/0x10
[ 56.190258][ C2] ? arch_stack_walk+0x8c/0xf0
[ 56.190401][ C2] mark_lock_irq+0x4cd/0xa10
[ 56.190542][ C2] ? __pfx_mark_lock_irq+0x10/0x10
[ 56.190679][ C2] ? stack_trace_save+0x94/0xd0
[ 56.190924][ C2] ? add_chain_cache+0x248/0x8b0
[ 56.191068][ C2] ? save_trace+0x8f/0x5b0
[ 56.191210][ C2] mark_lock+0x28d/0x3e0
[ 56.191316][ C2] mark_usage+0xd9/0x2a0
[ 56.191421][ C2] __lock_acquire+0x797/0x1570
[ 56.191565][ C2] ? __lock_acquire+0xaf0/0x1570
[ 56.191708][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10
[ 56.191879][ C2] lock_acquire.part.0+0xeb/0x330
[ 56.192021][ C2] ? br_forward_delay_timer_expired+0x48/0x440
[ 56.192198][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10
[ 56.192336][ C2] ? trace_lock_acquire+0x135/0x1c0
[ 56.192482][ C2] ? br_forward_delay_timer_expired+0x48/0x440
[ 56.192654][ C2] ? lock_acquire+0x32/0xc0
[ 56.192884][ C2] ? br_forward_delay_timer_expired+0x48/0x440
[ 56.193070][ C2] _raw_spin_lock+0x30/0x40
[ 56.193206][ C2] ? br_forward_delay_timer_expired+0x48/0x440
[ 56.193381][ C2] br_forward_delay_timer_expired+0x48/0x440
[ 56.193631][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10
[ 56.193890][ C2] call_timer_fn+0x13b/0x230
[ 56.194055][ C2] ? call_timer_fn+0xe8/0x230
[ 56.194320][ C2] ? call_timer_fn+0xe8/0x230
[ 56.194499][ C2] ? __pfx_call_timer_fn+0x10/0x10
[ 56.194661][ C2] ? mark_lock+0x38/0x3e0
[ 56.194787][ C2] __run_timers+0x545/0x810
[ 56.194949][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10
[ 56.195154][ C2] ? __pfx___run_timers+0x10/0x10
[ 56.195319][ C2] ? __lock_release+0x103/0x460
[ 56.195486][ C2] ? do_raw_spin_lock+0x131/0x270
[ 56.195652][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10
[ 56.195907][ C2] ? lock_acquire+0x32/0xc0
[ 56.196071][ C2] ? timer_expire_remote+0x93/0xe0
[ 56.196236][ C2] timer_expire_remote+0x9b/0xe0
[ 56.196398][ C2] tmigr_handle_remote_cpu+0x270/0x430
[ 56.196650][ C2] ? __pfx_tmigr_handle_remote_cpu+0x10/0x10
[ 56.196863][ C2] tmigr_handle_remote_up+0x19f/0x2e0
[ 56.197029][ C2] tmigr_handle_remote+0x21d/0x3a0
[ 56.197189][ C2] ? __pfx_tmigr_handle_remote+0x10/0x10
[ 56.197437][ C2] __do_softirq+0x1f8/0x5df
[ 56.197603][ C2] irq_exit_rcu+0x97/0xc0
[ 56.197725][ C2] sysvec_apic_timer_interrupt+0x75/0x80
[ 56.197893][ C2] </IRQ>
[ 56.197975][ C2] <TASK>
[ 56.198066][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20
[ 56.198350][ C2] RIP: 0010:default_idle+0xf/0x20
[ 56.198517][ 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 b3 f7 2d 00 fb f4 <fa> c3 cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 90 90 90 90 90
[ 56.199179][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000246
[ 56.199389][ C2] RAX: 000000000016caf5 RBX: 1ffff9200002bfc1 RCX: ffffffffb2f822c5
[ 56.199630][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffffb08aa4a4
[ 56.199949][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c
[ 56.200188][ C2] R10: ffff8880361384e3 R11: ffff88803613dc40 R12: 0000000000000000
[ 56.200504][ C2] R13: ffff888001b845c0 R14: dffffc0000000000 R15: 0000000000000000
[ 56.200740][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0
[ 56.200904][ C2] ? cpuidle_idle_call+0x1f4/0x280
[ 56.201065][ C2] default_idle_call+0x6d/0xb0
[ 56.201299][ C2] cpuidle_idle_call+0x1f4/0x280
[ 56.201460][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10
[ 56.201621][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0
[ 56.201780][ C2] do_idle+0xf9/0x160
[ 56.201901][ C2] cpu_startup_entry+0x54/0x60
[ 56.202137][ C2] start_secondary+0x21c/0x2b0
[ 56.202307][ C2] ? __pfx_start_secondary+0x10/0x10
[ 56.202468][ C2] common_startup_64+0x12c/0x138
[ 56.202630][ C2] </TASK>
[ 58.181195][ T573] fbond: left allmulticast mode
[ 58.181399][ T573] veth1-bond: left allmulticast mode
[ 58.181540][ T573] veth2-bond: left allmulticast mode
[ 58.181669][ T573] fbond: left promiscuous mode
[ 58.181794][ T573] veth1-bond: left promiscuous mode
[ 58.182112][ T573] veth2-bond: left promiscuous mode
[ 58.182525][ T573] fab-br0: port 1(fbond) entered disabled state
[ 58.319306][ T574] fbond (unregistering): (slave veth1-bond): Removing an active aggregator
[ 58.320034][ T574] fbond (unregistering): (slave veth1-bond): Releasing backup interface
[ 58.343112][ T574] fbond (unregistering): (slave veth2-bond): Removing an active aggregator
[ 58.343974][ T574] fbond (unregistering): (slave veth2-bond): Releasing backup interface
[ 58.361644][ T574] fbond (unregistering): Released all slaves