[ 749.443960][ T38] sched: DL replenish lagged too much [ 749.444884][ C3] [ 749.444886][ C3] ======================================================== [ 749.444888][ C3] WARNING: possible irq lock inversion dependency detected [ 749.444890][ C3] 6.17.0-rc2-virtme #1 Not tainted [ 749.444892][ C3] -------------------------------------------------------- [ 749.444893][ C3] swapper/3/0 just changed the state of lock: [ 749.444896][ C3] ffffffff93877e80 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 749.444914][ C3] but this lock took another, HARDIRQ-unsafe lock in the past: [ 749.444916][ C3] (_xmit_ETHER#2){+.-.}-{3:3} [ 749.444920][ C3] [ 749.444920][ C3] [ 749.444920][ C3] and interrupts could create inverse lock ordering between them. [ 749.444920][ C3] [ 749.444921][ C3] [ 749.444921][ C3] other info that might help us debug this: [ 749.444922][ C3] Chain exists of: [ 749.444922][ C3] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 749.444922][ C3] [ 749.444928][ C3] Possible interrupt unsafe locking scenario: [ 749.444928][ C3] [ 749.444929][ C3] CPU0 CPU1 [ 749.444930][ C3] ---- ---- [ 749.444931][ C3] lock(_xmit_ETHER#2); [ 749.444933][ C3] local_irq_disable(); [ 749.444934][ C3] lock(console_owner); [ 749.444936][ C3] lock(target_list_lock); [ 749.444937][ C3] [ 749.444938][ C3] lock(console_owner); [ 749.444940][ C3] [ 749.444940][ C3] *** DEADLOCK *** [ 749.444940][ C3] [ 749.444941][ C3] 2 locks held by swapper/3/0: [ 749.444942][ C3] #0: ffffffff939584e0 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x108/0x210 [ 749.444953][ C3] #1: ffffffff93958550 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x620 [ 749.444959][ C3] [ 749.444959][ C3] the shortest dependencies between 2nd lock and 1st lock: [ 749.444966][ C3] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 749.444970][ C3] HARDIRQ-ON-W at: [ 749.444972][ C3] __lock_acquire+0x20b/0x7e0 [ 749.444978][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.444981][ C3] _raw_spin_trylock+0x69/0x80 [ 749.444987][ C3] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 749.444993][ C3] virtnet_poll+0xf9/0xad0 [ 749.444996][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 749.445002][ C3] net_rx_action+0x54f/0xda0 [ 749.445005][ C3] handle_softirqs+0x215/0x610 [ 749.445011][ C3] do_softirq+0xad/0xe0 [ 749.445013][ C3] __local_bh_enable_ip+0x101/0x120 [ 749.445016][ C3] virtnet_open+0x228/0xb40 [ 749.445019][ C3] __dev_open+0x224/0x670 [ 749.445021][ C3] __dev_change_flags+0x460/0x6c0 [ 749.445023][ C3] netif_change_flags+0x80/0x160 [ 749.445025][ C3] do_setlink.constprop.0+0x984/0x2640 [ 749.445030][ C3] rtnl_newlink+0x693/0xa60 [ 749.445033][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 749.445035][ C3] netlink_rcv_skb+0x121/0x340 [ 749.445041][ C3] netlink_unicast+0x4aa/0x780 [ 749.445043][ C3] netlink_sendmsg+0x71d/0xbe0 [ 749.445046][ C3] ____sys_sendmsg+0x3dd/0x890 [ 749.445051][ C3] ___sys_sendmsg+0xed/0x170 [ 749.445055][ C3] __sys_sendmsg+0x10b/0x1a0 [ 749.445058][ C3] do_syscall_64+0xc1/0x370 [ 749.445063][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445069][ C3] IN-SOFTIRQ-W at: [ 749.445071][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445074][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445078][ C3] _raw_spin_lock+0x33/0x40 [ 749.445081][ C3] virtnet_poll_tx+0x1da/0x6f0 [ 749.445084][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 749.445089][ C3] net_rx_action+0x54f/0xda0 [ 749.445093][ C3] handle_softirqs+0x215/0x610 [ 749.445096][ C3] do_softirq+0xad/0xe0 [ 749.445100][ C3] __local_bh_enable_ip+0x101/0x120 [ 749.445104][ C3] virtnet_napi_tx_enable+0x1b1/0x270 [ 749.445111][ C3] virtnet_open+0x27c/0xb40 [ 749.445114][ C3] __dev_open+0x224/0x670 [ 749.445117][ C3] __dev_change_flags+0x460/0x6c0 [ 749.445120][ C3] netif_change_flags+0x80/0x160 [ 749.445124][ C3] do_setlink.constprop.0+0x984/0x2640 [ 749.445128][ C3] rtnl_newlink+0x693/0xa60 [ 749.445131][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 749.445134][ C3] netlink_rcv_skb+0x121/0x340 [ 749.445138][ C3] netlink_unicast+0x4aa/0x780 [ 749.445141][ C3] netlink_sendmsg+0x71d/0xbe0 [ 749.445145][ C3] ____sys_sendmsg+0x3dd/0x890 [ 749.445150][ C3] ___sys_sendmsg+0xed/0x170 [ 749.445154][ C3] __sys_sendmsg+0x10b/0x1a0 [ 749.445159][ C3] do_syscall_64+0xc1/0x370 [ 749.445163][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445166][ C3] INITIAL USE at: [ 749.445169][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445173][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445177][ C3] _raw_spin_trylock+0x69/0x80 [ 749.445182][ C3] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 749.445186][ C3] virtnet_poll+0xf9/0xad0 [ 749.445189][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 749.445194][ C3] net_rx_action+0x54f/0xda0 [ 749.445198][ C3] handle_softirqs+0x215/0x610 [ 749.445203][ C3] do_softirq+0xad/0xe0 [ 749.445206][ C3] __local_bh_enable_ip+0x101/0x120 [ 749.445211][ C3] virtnet_open+0x228/0xb40 [ 749.445215][ C3] __dev_open+0x224/0x670 [ 749.445218][ C3] __dev_change_flags+0x460/0x6c0 [ 749.445222][ C3] netif_change_flags+0x80/0x160 [ 749.445226][ C3] do_setlink.constprop.0+0x984/0x2640 [ 749.445230][ C3] rtnl_newlink+0x693/0xa60 [ 749.445233][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 749.445236][ C3] netlink_rcv_skb+0x121/0x340 [ 749.445240][ C3] netlink_unicast+0x4aa/0x780 [ 749.445243][ C3] netlink_sendmsg+0x71d/0xbe0 [ 749.445248][ C3] ____sys_sendmsg+0x3dd/0x890 [ 749.445252][ C3] ___sys_sendmsg+0xed/0x170 [ 749.445256][ C3] __sys_sendmsg+0x10b/0x1a0 [ 749.445261][ C3] do_syscall_64+0xc1/0x370 [ 749.445265][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445269][ C3] } [ 749.445271][ C3] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 749.445279][ C3] ... acquired at: [ 749.445281][ C3] __lock_acquire+0x449/0x7e0 [ 749.445284][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445288][ C3] _raw_spin_lock+0x33/0x40 [ 749.445291][ C3] virtnet_poll_tx+0x1da/0x6f0 [ 749.445293][ C3] poll_napi+0xf8/0x250 [ 749.445298][ C3] netpoll_poll_dev+0x264/0x2f0 [ 749.445300][ C3] __netpoll_send_skb+0x6ba/0x8a0 [ 749.445303][ C3] netpoll_send_skb+0x2a/0x90 [ 749.445305][ C3] send_ext_msg_udp+0x422/0x570 [netconsole] [ 749.445315][ C3] write_ext_msg+0x1c6/0x220 [netconsole] [ 749.445319][ C3] console_emit_next_record+0x20a/0x430 [ 749.445325][ C3] console_flush_all+0x3b4/0x620 [ 749.445328][ C3] console_unlock+0xba/0x190 [ 749.445330][ C3] vprintk_emit+0x290/0x2d0 [ 749.445333][ C3] devkmsg_emit.constprop.0+0xab/0xe0 [ 749.445336][ C3] devkmsg_write+0x193/0x300 [ 749.445339][ C3] vfs_write+0xaae/0x12c0 [ 749.445344][ C3] ksys_write+0xf7/0x1d0 [ 749.445346][ C3] do_syscall_64+0xc1/0x370 [ 749.445348][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445350][ C3] [ 749.445351][ C3] -> (target_list_lock){....}-{3:3} { [ 749.445355][ C3] INITIAL USE at: [ 749.445357][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445359][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445362][ C3] _raw_spin_lock_irqsave+0x42/0x60 [ 749.445365][ C3] netconsole_netdev_event+0x78/0x63e [netconsole] [ 749.445368][ C3] notifier_call_chain+0xcc/0x150 [ 749.445373][ C3] netif_change_name+0x45a/0x920 [ 749.445375][ C3] do_setlink.constprop.0+0x1ca6/0x2640 [ 749.445377][ C3] rtnl_setlink+0x2ad/0x590 [ 749.445380][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 749.445382][ C3] netlink_rcv_skb+0x121/0x340 [ 749.445384][ C3] netlink_unicast+0x4aa/0x780 [ 749.445387][ C3] netlink_sendmsg+0x71d/0xbe0 [ 749.445389][ C3] __sys_sendto+0x24b/0x380 [ 749.445392][ C3] __x64_sys_sendto+0xe0/0x1b0 [ 749.445395][ C3] do_syscall_64+0xc1/0x370 [ 749.445397][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445399][ C3] } [ 749.445400][ C3] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 749.445405][ C3] ... acquired at: [ 749.445406][ C3] __lock_acquire+0x449/0x7e0 [ 749.445408][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445410][ C3] _raw_spin_lock_irqsave+0x42/0x60 [ 749.445413][ C3] write_ext_msg+0x8e/0x220 [netconsole] [ 749.445417][ C3] console_emit_next_record+0x20a/0x430 [ 749.445419][ C3] console_flush_all+0x3b4/0x620 [ 749.445422][ C3] console_unlock+0xba/0x190 [ 749.445424][ C3] vprintk_emit+0x290/0x2d0 [ 749.445427][ C3] devkmsg_emit.constprop.0+0xab/0xe0 [ 749.445430][ C3] devkmsg_write+0x193/0x300 [ 749.445432][ C3] vfs_write+0xaae/0x12c0 [ 749.445434][ C3] ksys_write+0xf7/0x1d0 [ 749.445436][ C3] do_syscall_64+0xc1/0x370 [ 749.445438][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 749.445440][ C3] [ 749.445441][ C3] -> (console_owner){-...}-{0:0} { [ 749.445444][ C3] IN-HARDIRQ-W at: [ 749.445446][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445448][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445450][ C3] console_lock_spinning_enable+0x99/0xb0 [ 749.445453][ C3] console_emit_next_record+0x1b2/0x430 [ 749.445455][ C3] console_flush_all+0x3b4/0x620 [ 749.445458][ C3] console_unlock+0xba/0x190 [ 749.445460][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 749.445463][ C3] irq_work_single+0x108/0x210 [ 749.445467][ C3] irq_work_run_list+0x6a/0x90 [ 749.445471][ C3] update_process_times+0x136/0x1a0 [ 749.445477][ C3] tick_nohz_handler+0x319/0x4e0 [ 749.445483][ C3] __run_hrtimer+0x158/0x370 [ 749.445487][ C3] __hrtimer_run_queues+0x194/0x260 [ 749.445491][ C3] hrtimer_interrupt+0x339/0x850 [ 749.445494][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 749.445501][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 749.445506][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 749.445510][ C3] pv_native_safe_halt+0xf/0x10 [ 749.445513][ C3] default_idle+0x9/0x10 [ 749.445518][ C3] default_idle_call+0x6d/0xa0 [ 749.445521][ C3] cpuidle_idle_call+0x23c/0x370 [ 749.445526][ C3] do_idle+0xe1/0x140 [ 749.445529][ C3] cpu_startup_entry+0x54/0x60 [ 749.445533][ C3] start_secondary+0x1fd/0x290 [ 749.445536][ C3] common_startup_64+0x13e/0x148 [ 749.445543][ C3] INITIAL USE at: [ 749.445547][ C3] } [ 749.445548][ C3] ... key at: [] console_owner_dep_map+0x0/0x60 [ 749.445557][ C3] ... acquired at: [ 749.445558][ C3] mark_lock+0x16c/0x2f0 [ 749.445561][ C3] mark_usage+0x11d/0x140 [ 749.445563][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445566][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445569][ C3] console_lock_spinning_enable+0x99/0xb0 [ 749.445573][ C3] console_emit_next_record+0x1b2/0x430 [ 749.445577][ C3] console_flush_all+0x3b4/0x620 [ 749.445580][ C3] console_unlock+0xba/0x190 [ 749.445584][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 749.445587][ C3] irq_work_single+0x108/0x210 [ 749.445592][ C3] irq_work_run_list+0x6a/0x90 [ 749.445595][ C3] update_process_times+0x136/0x1a0 [ 749.445600][ C3] tick_nohz_handler+0x319/0x4e0 [ 749.445605][ C3] __run_hrtimer+0x158/0x370 [ 749.445610][ C3] __hrtimer_run_queues+0x194/0x260 [ 749.445614][ C3] hrtimer_interrupt+0x339/0x850 [ 749.445618][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 749.445623][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 749.445627][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 749.445631][ C3] pv_native_safe_halt+0xf/0x10 [ 749.445635][ C3] default_idle+0x9/0x10 [ 749.445640][ C3] default_idle_call+0x6d/0xa0 [ 749.445644][ C3] cpuidle_idle_call+0x23c/0x370 [ 749.445648][ C3] do_idle+0xe1/0x140 [ 749.445652][ C3] cpu_startup_entry+0x54/0x60 [ 749.445655][ C3] start_secondary+0x1fd/0x290 [ 749.445659][ C3] common_startup_64+0x13e/0x148 [ 749.445663][ C3] [ 749.445665][ C3] [ 749.445665][ C3] stack backtrace: [ 749.445671][ C3] CPU: 3 UID: 0 PID: 0 Comm: swapper/3 Not tainted 6.17.0-rc2-virtme #1 PREEMPT(full) [ 749.445677][ C3] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 749.445681][ C3] Call Trace: [ 749.445684][ C3] [ 749.445691][ C3] dump_stack_lvl+0x82/0xc0 [ 749.445699][ C3] print_irq_inversion_bug.part.0+0x206/0x260 [ 749.445707][ C3] mark_lock_irq+0x248/0x400 [ 749.445719][ C3] mark_lock+0x16c/0x2f0 [ 749.445726][ C3] mark_usage+0x11d/0x140 [ 749.445731][ C3] __lock_acquire+0x20b/0x7e0 [ 749.445739][ C3] lock_acquire.part.0+0xb6/0x240 [ 749.445743][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 749.445749][ C3] ? rcu_is_watching+0x12/0xb0 [ 749.445756][ C3] ? lock_acquire+0x104/0x160 [ 749.445758][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 749.445762][ C3] console_lock_spinning_enable+0x99/0xb0 [ 749.445765][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 749.445768][ C3] console_emit_next_record+0x1b2/0x430 [ 749.445773][ C3] ? devkmsg_read+0x460/0x460 [ 749.445777][ C3] ? rcu_is_watching+0x12/0xb0 [ 749.445782][ C3] console_flush_all+0x3b4/0x620 [ 749.445786][ C3] ? console_emit_next_record+0x430/0x430 [ 749.445790][ C3] ? __lock_acquire+0x449/0x7e0 [ 749.445794][ C3] console_unlock+0xba/0x190 [ 749.445797][ C3] ? console_flush_all+0x620/0x620 [ 749.445800][ C3] ? rcu_is_watching+0x12/0xb0 [ 749.445804][ C3] ? irq_work_single+0x108/0x210 [ 749.445807][ C3] ? irq_work_single+0x108/0x210 [ 749.445811][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 749.445815][ C3] irq_work_single+0x108/0x210 [ 749.445819][ C3] irq_work_run_list+0x6a/0x90 [ 749.445822][ C3] ? irq_work_tick+0x9b/0x140 [ 749.445825][ C3] update_process_times+0x136/0x1a0 [ 749.445829][ C3] tick_nohz_handler+0x319/0x4e0 [ 749.445832][ C3] ? rcu_is_watching+0x12/0xb0 [ 749.445836][ C3] __run_hrtimer+0x158/0x370 [ 749.445840][ C3] ? tick_do_update_jiffies64.part.0+0x280/0x280 [ 749.445844][ C3] __hrtimer_run_queues+0x194/0x260 [ 749.445848][ C3] ? hrtimer_interrupt+0x12a/0x850 [ 749.445851][ C3] ? __run_hrtimer+0x370/0x370 [ 749.445854][ C3] ? kvm_clock_get_cycles+0x18/0x30 [ 749.445861][ C3] hrtimer_interrupt+0x339/0x850 [ 749.445864][ C3] ? lockdep_softirqs_on+0xbb/0x130 [ 749.445870][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 749.445873][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 749.445877][ C3] [ 749.445878][ C3] [ 749.445880][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 749.445883][ C3] RIP: 0010:pv_native_safe_halt+0xf/0x10 [ 749.445887][ C3] Code: 48 8b 3d 74 ab 05 02 e8 1f 00 00 00 48 2b 05 c8 54 86 00 c3 0f 1f 80 00 00 00 00 f3 0f 1e fa eb 07 0f 00 2d b3 1d 0c 00 fb f4 66 0f 1f 00 41 54 55 53 48 89 fb 48 83 ec 10 8b 17 83 e2 fe 41 [ 749.445891][ C3] RSP: 0018:ffffc90000157de8 EFLAGS: 00000206 [ 749.445894][ C3] RAX: 0000000000ab71c3 RBX: 1ffff9200002afc1 RCX: ffffffff92bd21c5 [ 749.445897][ C3] RDX: 0000000000000000 RSI: ffffffff933ea64b RDI: ffffffff92e57960 [ 749.445899][ C3] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006c76252 [ 749.445901][ C3] R10: ffff8880363b1293 R11: ffff8880363b6958 R12: 0000000000000000 [ 749.445903][ C3] R13: ffff888001ab45c0 R14: dffffc0000000000 R15: 0000000000000000 [ 749.445907][ C3] ? ct_kernel_exit.constprop.0+0x105/0x150 [ 749.445912][ C3] default_idle+0x9/0x10 [ 749.445916][ C3] default_idle_call+0x6d/0xa0 [ 749.445919][ C3] cpuidle_idle_call+0x23c/0x370 [ 749.445922][ C3] ? arch_cpu_idle_exit+0x40/0x40 [ 749.445925][ C3] ? tsc_verify_tsc_adjust+0x94/0x310 [ 749.445929][ C3] do_idle+0xe1/0x140 [ 749.445932][ C3] cpu_startup_entry+0x54/0x60 [ 749.445935][ C3] start_secondary+0x1fd/0x290 [ 749.445938][ C3] ? set_cpu_sibling_map+0x1f70/0x1f70 [ 749.445943][ C3] common_startup_64+0x13e/0x148 [ 749.445950][ C3]