[ 57.499004][ T535] fab-br0: port 1(fbond) entered blocking state [ 57.499240][ T535] fab-br0: port 1(fbond) entered disabled state [ 57.499469][ T535] fbond: entered allmulticast mode [ 57.501069][ T535] fbond: entered promiscuous mode [ 57.618312][ T538] veth1-bond: entered promiscuous mode [ 57.618776][ T538] veth1-bond: entered allmulticast mode [ 57.619822][ T538] fbond: (slave veth1-bond): Enslaving as a backup interface with a down link [ 57.759874][ T539] veth2-bond: entered promiscuous mode [ 57.760314][ T539] veth2-bond: entered allmulticast mode [ 57.760811][ T539] fbond: (slave veth2-bond): Enslaving as a backup interface with a down link [ 57.888035][ T10] fbond: Warning: No 802.3ad response from the link partner for any adapters in the bond [ 57.983483][ T10] fbond: (slave veth1-bond): link status definitely up, 10000 Mbps full duplex [ 57.984060][ T10] fbond: active interface up! [ 58.117287][ T542] fab-br0: port 1(fbond) entered blocking state [ 58.117626][ T542] fab-br0: port 1(fbond) entered forwarding state [ 58.192345][ T10] fbond: (slave veth2-bond): link status definitely up, 10000 Mbps full duplex [ 58.271089][ C2] [ 58.271190][ C2] ======================================================== [ 58.271416][ C2] WARNING: possible irq lock inversion dependency detected [ 58.271703][ C2] 6.9.0-rc1-virtme #1 Not tainted [ 58.271916][ C2] -------------------------------------------------------- [ 58.272212][ C2] swapper/2/0 just changed the state of lock: [ 58.272378][ C2] ffff8880057dac18 (&br->lock){+.-.}-{2:2}, at: br_forward_delay_timer_expired+0x48/0x440 [ 58.272665][ C2] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 58.272857][ C2] (&p->alloc_lock){+.+.}-{2:2} [ 58.272862][ C2] [ 58.272862][ C2] [ 58.272862][ C2] and interrupts could create inverse lock ordering between them. [ 58.272862][ C2] [ 58.273364][ C2] [ 58.273364][ C2] other info that might help us debug this: [ 58.273577][ C2] Chain exists of: [ 58.273577][ C2] &br->lock --> lweventlist_lock --> &p->alloc_lock [ 58.273577][ C2] [ 58.273872][ C2] Possible interrupt unsafe locking scenario: [ 58.273872][ C2] [ 58.274084][ C2] CPU0 CPU1 [ 58.274225][ C2] ---- ---- [ 58.274379][ C2] lock(&p->alloc_lock); [ 58.274495][ C2] local_irq_disable(); [ 58.274660][ C2] lock(&br->lock); [ 58.274834][ C2] lock(lweventlist_lock); [ 58.274995][ C2] [ 58.275093][ C2] lock(&br->lock); [ 58.275192][ C2] [ 58.275192][ C2] *** DEADLOCK *** [ 58.275192][ C2] [ 58.275381][ C2] 1 lock held by swapper/2/0: [ 58.275525][ C2] #0: ffffc90000230d68 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0xe8/0x230 [ 58.275800][ C2] [ 58.275800][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 58.276029][ C2] -> (&p->alloc_lock){+.+.}-{2:2} { [ 58.276165][ C2] HARDIRQ-ON-W at: [ 58.276266][ C2] __lock_acquire+0x797/0x1570 [ 58.276467][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.276642][ C2] _raw_spin_lock+0x30/0x40 [ 58.276815][ C2] set_mems_allowed+0x1d/0x210 [ 58.276997][ C2] kernel_init_freeable+0x72/0x310 [ 58.277166][ C2] kernel_init+0x20/0x200 [ 58.277331][ C2] ret_from_fork+0x31/0x70 [ 58.277504][ C2] ret_from_fork_asm+0x1a/0x30 [ 58.277669][ C2] SOFTIRQ-ON-W at: [ 58.277771][ C2] __lock_acquire+0x797/0x1570 [ 58.277935][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.278104][ C2] _raw_spin_lock+0x30/0x40 [ 58.278268][ C2] set_mems_allowed+0x1d/0x210 [ 58.278432][ C2] kernel_init_freeable+0x72/0x310 [ 58.278605][ C2] kernel_init+0x20/0x200 [ 58.278773][ C2] ret_from_fork+0x31/0x70 [ 58.278940][ C2] ret_from_fork_asm+0x1a/0x30 [ 58.279108][ C2] INITIAL USE at: [ 58.279205][ C2] __lock_acquire+0x797/0x1570 [ 58.279369][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.279544][ C2] _raw_spin_lock+0x30/0x40 [ 58.279711][ C2] set_mems_allowed+0x1d/0x210 [ 58.279874][ C2] kernel_init_freeable+0x72/0x310 [ 58.280073][ C2] kernel_init+0x20/0x200 [ 58.280239][ C2] ret_from_fork+0x31/0x70 [ 58.280407][ C2] ret_from_fork_asm+0x1a/0x30 [ 58.280585][ C2] } [ 58.280654][ C2] ... key at: [] __key.387+0x0/0x40 [ 58.280858][ C2] ... acquired at: [ 58.280959][ C2] __lock_acquire+0xaf0/0x1570 [ 58.281096][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.281240][ C2] _raw_spin_lock+0x30/0x40 [ 58.281396][ C2] __get_task_comm+0x27/0x70 [ 58.281541][ C2] ref_tracker_alloc+0x2ee/0x490 [ 58.281675][ C2] linkwatch_fire_event+0x196/0x200 [ 58.281811][ C2] bond_create+0xba/0x110 [ 58.281964][ C2] bonding_init+0x91/0xe0 [ 58.282124][ C2] do_one_initcall+0x8d/0x1e0 [ 58.282256][ C2] do_initcalls+0x1b2/0x3e0 [ 58.282392][ C2] kernel_init_freeable+0x232/0x310 [ 58.282532][ C2] kernel_init+0x20/0x200 [ 58.282664][ C2] ret_from_fork+0x31/0x70 [ 58.282800][ C2] ret_from_fork_asm+0x1a/0x30 [ 58.282933][ C2] [ 58.283005][ C2] -> (lweventlist_lock){....}-{2:2} { [ 58.283144][ C2] INITIAL USE at: [ 58.283243][ C2] __lock_acquire+0x797/0x1570 [ 58.283408][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.283584][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 58.283747][ C2] linkwatch_fire_event+0x74/0x200 [ 58.283910][ C2] bond_create+0xba/0x110 [ 58.284082][ C2] bonding_init+0x91/0xe0 [ 58.284250][ C2] do_one_initcall+0x8d/0x1e0 [ 58.284413][ C2] do_initcalls+0x1b2/0x3e0 [ 58.284623][ C2] kernel_init_freeable+0x232/0x310 [ 58.284813][ C2] kernel_init+0x20/0x200 [ 58.285007][ C2] ret_from_fork+0x31/0x70 [ 58.285183][ C2] ret_from_fork_asm+0x1a/0x30 [ 58.285351][ C2] } [ 58.285423][ C2] ... key at: [] lweventlist_lock+0x18/0x60 [ 58.285627][ C2] ... acquired at: [ 58.285730][ C2] __lock_acquire+0xaf0/0x1570 [ 58.285863][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.285993][ C2] _raw_spin_lock_irqsave+0x3f/0x60 [ 58.286130][ C2] linkwatch_fire_event+0x74/0x200 [ 58.286269][ C2] br_stp_change_bridge_id+0x25f/0x360 [ 58.286401][ C2] br_dev_newlink+0x8c/0x100 [ 58.286542][ C2] rtnl_newlink_create+0x341/0x850 [ 58.286674][ C2] __rtnl_newlink+0xac9/0xd80 [ 58.286805][ C2] rtnl_newlink+0x63/0xa0 [ 58.286940][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 58.287073][ C2] netlink_rcv_skb+0x130/0x360 [ 58.287209][ C2] netlink_unicast+0x449/0x710 [ 58.287340][ C2] netlink_sendmsg+0x723/0xbe0 [ 58.287483][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 58.287622][ C2] ___sys_sendmsg+0xee/0x170 [ 58.287753][ C2] __sys_sendmsg+0xcd/0x170 [ 58.287882][ C2] do_syscall_64+0xc6/0x1e0 [ 58.288013][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 58.288178][ C2] [ 58.288244][ C2] -> (&br->lock){+.-.}-{2:2} { [ 58.288383][ C2] HARDIRQ-ON-W at: [ 58.288492][ C2] __lock_acquire+0x797/0x1570 [ 58.288674][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.288840][ C2] _raw_spin_lock_bh+0x38/0x50 [ 58.289015][ C2] br_dev_newlink+0x65/0x100 [ 58.289181][ C2] rtnl_newlink_create+0x341/0x850 [ 58.289347][ C2] __rtnl_newlink+0xac9/0xd80 [ 58.289523][ C2] rtnl_newlink+0x63/0xa0 [ 58.289691][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 58.289853][ C2] netlink_rcv_skb+0x130/0x360 [ 58.290118][ C2] netlink_unicast+0x449/0x710 [ 58.290291][ C2] netlink_sendmsg+0x723/0xbe0 [ 58.290459][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 58.290627][ C2] ___sys_sendmsg+0xee/0x170 [ 58.290790][ C2] __sys_sendmsg+0xcd/0x170 [ 58.290963][ C2] do_syscall_64+0xc6/0x1e0 [ 58.291129][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 58.291327][ C2] IN-SOFTIRQ-W at: [ 58.291427][ C2] __lock_acquire+0x797/0x1570 [ 58.291599][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.291771][ C2] _raw_spin_lock+0x30/0x40 [ 58.291938][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 58.292157][ C2] call_timer_fn+0x13b/0x230 [ 58.292326][ C2] __run_timers+0x545/0x810 [ 58.292577][ C2] run_timer_softirq+0xe8/0x1b0 [ 58.292744][ C2] __do_softirq+0x1f8/0x5df [ 58.292908][ C2] irq_exit_rcu+0x97/0xc0 [ 58.293169][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 58.293380][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 58.293587][ C2] default_idle+0xf/0x20 [ 58.293832][ C2] default_idle_call+0x6d/0xb0 [ 58.293995][ C2] cpuidle_idle_call+0x1f4/0x280 [ 58.294166][ C2] do_idle+0xf9/0x160 [ 58.294297][ C2] cpu_startup_entry+0x54/0x60 [ 58.294619][ C2] start_secondary+0x21c/0x2b0 [ 58.294788][ C2] common_startup_64+0x12c/0x138 [ 58.294958][ C2] INITIAL USE at: [ 58.295058][ C2] __lock_acquire+0x797/0x1570 [ 58.295304][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.295468][ C2] _raw_spin_lock_bh+0x38/0x50 [ 58.295638][ C2] br_dev_newlink+0x65/0x100 [ 58.295879][ C2] rtnl_newlink_create+0x341/0x850 [ 58.296043][ C2] __rtnl_newlink+0xac9/0xd80 [ 58.296212][ C2] rtnl_newlink+0x63/0xa0 [ 58.296451][ C2] rtnetlink_rcv_msg+0x2fb/0xbf0 [ 58.296616][ C2] netlink_rcv_skb+0x130/0x360 [ 58.296788][ C2] netlink_unicast+0x449/0x710 [ 58.296951][ C2] netlink_sendmsg+0x723/0xbe0 [ 58.297207][ C2] ____sys_sendmsg+0x7b2/0xa10 [ 58.297380][ C2] ___sys_sendmsg+0xee/0x170 [ 58.297544][ C2] __sys_sendmsg+0xcd/0x170 [ 58.297714][ C2] do_syscall_64+0xc6/0x1e0 [ 58.297876][ C2] entry_SYSCALL_64_after_hwframe+0x6d/0x75 [ 58.298077][ C2] } [ 58.298142][ C2] ... key at: [] __key.6+0x0/0x40 [ 58.298310][ C2] ... acquired at: [ 58.298405][ C2] mark_lock+0x28d/0x3e0 [ 58.298537][ C2] mark_usage+0xd9/0x2a0 [ 58.298675][ C2] __lock_acquire+0x797/0x1570 [ 58.298892][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.299034][ C2] _raw_spin_lock+0x30/0x40 [ 58.299175][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 58.299348][ C2] call_timer_fn+0x13b/0x230 [ 58.299564][ C2] __run_timers+0x545/0x810 [ 58.299707][ C2] run_timer_softirq+0xe8/0x1b0 [ 58.299850][ C2] __do_softirq+0x1f8/0x5df [ 58.299996][ C2] irq_exit_rcu+0x97/0xc0 [ 58.300132][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 58.300369][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 58.300530][ C2] default_idle+0xf/0x20 [ 58.300662][ C2] default_idle_call+0x6d/0xb0 [ 58.300873][ C2] cpuidle_idle_call+0x1f4/0x280 [ 58.301006][ C2] do_idle+0xf9/0x160 [ 58.301106][ C2] cpu_startup_entry+0x54/0x60 [ 58.301235][ C2] start_secondary+0x21c/0x2b0 [ 58.301366][ C2] common_startup_64+0x12c/0x138 [ 58.301570][ C2] [ 58.301636][ C2] [ 58.301636][ C2] stack backtrace: [ 58.301794][ C2] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 6.9.0-rc1-virtme #1 [ 58.302001][ C2] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS rel-1.16.3-0-ga6ed6b701f0a-prebuilt.qemu.org 04/01/2014 [ 58.302372][ C2] Call Trace: [ 58.302476][ C2] [ 58.302545][ C2] dump_stack_lvl+0x82/0xd0 [ 58.302684][ C2] print_irq_inversion_bug.part.0+0x3d9/0x570 [ 58.302928][ C2] ? common_startup_64+0x12c/0x138 [ 58.303065][ C2] ? __pfx_print_irq_inversion_bug.part.0+0x10/0x10 [ 58.303236][ C2] ? __pfx_usage_skip+0x10/0x10 [ 58.303442][ C2] ? __pfx_usage_match+0x10/0x10 [ 58.303581][ C2] ? arch_stack_walk+0x8c/0xf0 [ 58.303714][ C2] mark_lock_irq+0x4cd/0xa10 [ 58.303851][ C2] ? __pfx_mark_lock_irq+0x10/0x10 [ 58.304006][ C2] ? stack_trace_save+0x94/0xd0 [ 58.304220][ C2] ? save_trace+0x8f/0x5b0 [ 58.304351][ C2] mark_lock+0x28d/0x3e0 [ 58.304470][ C2] mark_usage+0xd9/0x2a0 [ 58.304579][ C2] __lock_acquire+0x797/0x1570 [ 58.304783][ C2] ? trace_rcu_dyntick+0xf2/0x180 [ 58.304916][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 58.305079][ C2] lock_acquire.part.0+0xeb/0x330 [ 58.305210][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 58.305445][ C2] ? __pfx_lock_acquire.part.0+0x10/0x10 [ 58.305586][ C2] ? trace_lock_acquire+0x135/0x1c0 [ 58.305716][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 58.305883][ C2] ? lock_acquire+0x32/0xc0 [ 58.306096][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 58.306259][ C2] _raw_spin_lock+0x30/0x40 [ 58.306388][ C2] ? br_forward_delay_timer_expired+0x48/0x440 [ 58.306556][ C2] br_forward_delay_timer_expired+0x48/0x440 [ 58.306718][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 58.306881][ C2] call_timer_fn+0x13b/0x230 [ 58.307012][ C2] ? call_timer_fn+0xe8/0x230 [ 58.307152][ C2] ? call_timer_fn+0xe8/0x230 [ 58.307283][ C2] ? __pfx_call_timer_fn+0x10/0x10 [ 58.307416][ C2] ? mark_lock+0x38/0x3e0 [ 58.307522][ C2] __run_timers+0x545/0x810 [ 58.307652][ C2] ? __pfx_br_forward_delay_timer_expired+0x10/0x10 [ 58.307894][ C2] ? __pfx___run_timers+0x10/0x10 [ 58.308051][ C2] ? do_raw_spin_lock+0x131/0x270 [ 58.308190][ C2] ? __pfx_do_raw_spin_lock+0x10/0x10 [ 58.308322][ C2] ? lock_acquire+0x32/0xc0 [ 58.308527][ C2] ? run_timer_softirq+0xe0/0x1b0 [ 58.308658][ C2] run_timer_softirq+0xe8/0x1b0 [ 58.308795][ C2] __do_softirq+0x1f8/0x5df [ 58.308930][ C2] irq_exit_rcu+0x97/0xc0 [ 58.309036][ C2] sysvec_apic_timer_interrupt+0x75/0x80 [ 58.309244][ C2] [ 58.309311][ C2] [ 58.309378][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 58.309552][ C2] RIP: 0010:default_idle+0xf/0x20 [ 58.309695][ 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 [ 58.310264][ C2] RSP: 0018:ffffc9000015fdf8 EFLAGS: 00000246 [ 58.310507][ C2] RAX: 000000000017077b RBX: 1ffff9200002bfc1 RCX: ffffffff96f822b5 [ 58.310704][ C2] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff948aa4a4 [ 58.310915][ C2] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c2709c [ 58.311200][ C2] R10: ffff8880361384e3 R11: ffff88803613dc40 R12: 0000000000000000 [ 58.311408][ C2] R13: ffff888001b845c0 R14: dffffc0000000000 R15: 0000000000000000 [ 58.311603][ C2] ? ct_kernel_exit.constprop.0+0xc5/0xf0 [ 58.311815][ C2] ? cpuidle_idle_call+0x1f4/0x280 [ 58.311946][ C2] default_idle_call+0x6d/0xb0 [ 58.312078][ C2] cpuidle_idle_call+0x1f4/0x280 [ 58.312210][ C2] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 58.312423][ C2] ? tsc_verify_tsc_adjust+0x5e/0x2b0 [ 58.312556][ C2] do_idle+0xf9/0x160 [ 58.312656][ C2] cpu_startup_entry+0x54/0x60 [ 58.312786][ C2] start_secondary+0x21c/0x2b0 [ 58.312917][ C2] ? __pfx_start_secondary+0x10/0x10 [ 58.313131][ C2] common_startup_64+0x12c/0x138 [ 58.313268][ C2] [ 60.349687][ T573] fbond: left allmulticast mode [ 60.349854][ T573] veth1-bond: left allmulticast mode [ 60.350529][ T573] veth2-bond: left allmulticast mode [ 60.350669][ T573] fbond: left promiscuous mode [ 60.350797][ T573] veth1-bond: left promiscuous mode [ 60.351107][ T573] veth2-bond: left promiscuous mode [ 60.351510][ T573] fab-br0: port 1(fbond) entered disabled state [ 60.494250][ T575] fbond (unregistering): (slave veth1-bond): Removing an active aggregator [ 60.494765][ T575] fbond (unregistering): (slave veth1-bond): Releasing backup interface [ 60.522261][ T575] fbond (unregistering): (slave veth2-bond): Removing an active aggregator [ 60.522835][ T575] fbond (unregistering): (slave veth2-bond): Releasing backup interface [ 60.537493][ T575] fbond (unregistering): Released all slaves