[ 497.039385][ T3294] sched: DL replenish lagged too much [ 497.039709][ C3] [ 497.039711][ C3] ======================================================== [ 497.039712][ C3] WARNING: possible irq lock inversion dependency detected [ 497.039714][ C3] 6.17.0-rc3-virtme #1 Not tainted [ 497.039716][ C3] -------------------------------------------------------- [ 497.039717][ C3] swapper/3/0 just changed the state of lock: [ 497.039719][ C3] ffffffffb5077e80 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 497.039731][ C3] but this lock took another, HARDIRQ-unsafe lock in the past: [ 497.039733][ C3] (_xmit_ETHER#2){+.-.}-{3:3} [ 497.039736][ C3] [ 497.039736][ C3] [ 497.039736][ C3] and interrupts could create inverse lock ordering between them. [ 497.039736][ C3] [ 497.039737][ C3] [ 497.039737][ C3] other info that might help us debug this: [ 497.039738][ C3] Chain exists of: [ 497.039738][ C3] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 497.039738][ C3] [ 497.039743][ C3] Possible interrupt unsafe locking scenario: [ 497.039743][ C3] [ 497.039744][ C3] CPU0 CPU1 [ 497.039745][ C3] ---- ---- [ 497.039746][ C3] lock(_xmit_ETHER#2); [ 497.039748][ C3] local_irq_disable(); [ 497.039749][ C3] lock(console_owner); [ 497.039751][ C3] lock(target_list_lock); [ 497.039753][ C3] [ 497.039754][ C3] lock(console_owner); [ 497.039755][ C3] [ 497.039755][ C3] *** DEADLOCK *** [ 497.039755][ C3] [ 497.039756][ C3] 2 locks held by swapper/3/0: [ 497.039758][ C3] #0: ffffffffb51584e0 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x108/0x210 [ 497.039766][ C3] #1: ffffffffb5158550 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x620 [ 497.039772][ C3] [ 497.039772][ C3] the shortest dependencies between 2nd lock and 1st lock: [ 497.039779][ C3] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 497.039782][ C3] HARDIRQ-ON-W at: [ 497.039784][ C3] __lock_acquire+0x20b/0x7e0 [ 497.039788][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.039791][ C3] _raw_spin_trylock+0x69/0x80 [ 497.039797][ C3] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 497.039801][ C3] virtnet_poll+0xf9/0xad0 [ 497.039803][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 497.039806][ C3] net_rx_action+0x54f/0xda0 [ 497.039808][ C3] handle_softirqs+0x215/0x610 [ 497.039812][ C3] do_softirq+0xad/0xe0 [ 497.039815][ C3] __local_bh_enable_ip+0x101/0x120 [ 497.039817][ C3] virtnet_open+0x228/0xb40 [ 497.039819][ C3] __dev_open+0x224/0x670 [ 497.039822][ C3] __dev_change_flags+0x460/0x6c0 [ 497.039824][ C3] netif_change_flags+0x80/0x160 [ 497.039826][ C3] do_setlink.constprop.0+0x984/0x2640 [ 497.039830][ C3] rtnl_newlink+0x693/0xa60 [ 497.039832][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 497.039834][ C3] netlink_rcv_skb+0x121/0x340 [ 497.039838][ C3] netlink_unicast+0x4aa/0x780 [ 497.039841][ C3] netlink_sendmsg+0x71d/0xbe0 [ 497.039844][ C3] ____sys_sendmsg+0x3dd/0x890 [ 497.039848][ C3] ___sys_sendmsg+0xed/0x170 [ 497.039851][ C3] __sys_sendmsg+0x10b/0x1a0 [ 497.039854][ C3] do_syscall_64+0xc1/0x370 [ 497.039858][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.039861][ C3] IN-SOFTIRQ-W at: [ 497.039862][ C3] __lock_acquire+0x20b/0x7e0 [ 497.039865][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.039867][ C3] _raw_spin_lock+0x33/0x40 [ 497.039870][ C3] virtnet_poll_tx+0x1da/0x6f0 [ 497.039872][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 497.039874][ C3] net_rx_action+0x54f/0xda0 [ 497.039876][ C3] handle_softirqs+0x215/0x610 [ 497.039879][ C3] do_softirq+0xad/0xe0 [ 497.039881][ C3] __local_bh_enable_ip+0x101/0x120 [ 497.039884][ C3] virtnet_napi_tx_enable+0x1b1/0x270 [ 497.039886][ C3] virtnet_open+0x27c/0xb40 [ 497.039888][ C3] __dev_open+0x224/0x670 [ 497.039890][ C3] __dev_change_flags+0x460/0x6c0 [ 497.039892][ C3] netif_change_flags+0x80/0x160 [ 497.039894][ C3] do_setlink.constprop.0+0x984/0x2640 [ 497.039896][ C3] rtnl_newlink+0x693/0xa60 [ 497.039898][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 497.039901][ C3] netlink_rcv_skb+0x121/0x340 [ 497.039903][ C3] netlink_unicast+0x4aa/0x780 [ 497.039905][ C3] netlink_sendmsg+0x71d/0xbe0 [ 497.039907][ C3] ____sys_sendmsg+0x3dd/0x890 [ 497.039910][ C3] ___sys_sendmsg+0xed/0x170 [ 497.039913][ C3] __sys_sendmsg+0x10b/0x1a0 [ 497.039916][ C3] do_syscall_64+0xc1/0x370 [ 497.039918][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.039921][ C3] INITIAL USE at: [ 497.039922][ C3] __lock_acquire+0x20b/0x7e0 [ 497.039924][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.039926][ C3] _raw_spin_trylock+0x69/0x80 [ 497.039929][ C3] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 497.039931][ C3] virtnet_poll+0xf9/0xad0 [ 497.039934][ C3] __napi_poll.constprop.0+0x9f/0x460 [ 497.039936][ C3] net_rx_action+0x54f/0xda0 [ 497.039937][ C3] handle_softirqs+0x215/0x610 [ 497.039940][ C3] do_softirq+0xad/0xe0 [ 497.039942][ C3] __local_bh_enable_ip+0x101/0x120 [ 497.039945][ C3] virtnet_open+0x228/0xb40 [ 497.039947][ C3] __dev_open+0x224/0x670 [ 497.039949][ C3] __dev_change_flags+0x460/0x6c0 [ 497.039950][ C3] netif_change_flags+0x80/0x160 [ 497.039953][ C3] do_setlink.constprop.0+0x984/0x2640 [ 497.039955][ C3] rtnl_newlink+0x693/0xa60 [ 497.039957][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 497.039959][ C3] netlink_rcv_skb+0x121/0x340 [ 497.039962][ C3] netlink_unicast+0x4aa/0x780 [ 497.039964][ C3] netlink_sendmsg+0x71d/0xbe0 [ 497.039967][ C3] ____sys_sendmsg+0x3dd/0x890 [ 497.039969][ C3] ___sys_sendmsg+0xed/0x170 [ 497.039972][ C3] __sys_sendmsg+0x10b/0x1a0 [ 497.039975][ C3] do_syscall_64+0xc1/0x370 [ 497.039977][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.039980][ C3] } [ 497.039980][ C3] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 497.039986][ C3] ... acquired at: [ 497.039986][ C3] __lock_acquire+0x449/0x7e0 [ 497.039989][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.039991][ C3] _raw_spin_lock+0x33/0x40 [ 497.039994][ C3] virtnet_poll_tx+0x1da/0x6f0 [ 497.039996][ C3] poll_napi+0xf8/0x250 [ 497.039999][ C3] netpoll_poll_dev+0x264/0x2f0 [ 497.040001][ C3] __netpoll_send_skb+0x6ba/0x8a0 [ 497.040004][ C3] netpoll_send_skb+0x2a/0x90 [ 497.040006][ C3] send_ext_msg_udp+0x422/0x570 [netconsole] [ 497.040012][ C3] write_ext_msg+0x1c6/0x220 [netconsole] [ 497.040016][ C3] console_emit_next_record+0x20a/0x430 [ 497.040019][ C3] console_flush_all+0x3b4/0x620 [ 497.040022][ C3] console_unlock+0xba/0x190 [ 497.040024][ C3] vprintk_emit+0x290/0x2d0 [ 497.040027][ C3] devkmsg_emit.constprop.0+0xab/0xe0 [ 497.040029][ C3] devkmsg_write+0x193/0x300 [ 497.040032][ C3] vfs_write+0xaae/0x12c0 [ 497.040035][ C3] ksys_write+0xf7/0x1d0 [ 497.040037][ C3] do_syscall_64+0xc1/0x370 [ 497.040040][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.040042][ C3] [ 497.040043][ C3] -> (target_list_lock){....}-{3:3} { [ 497.040046][ C3] INITIAL USE at: [ 497.040048][ C3] __lock_acquire+0x20b/0x7e0 [ 497.040050][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.040052][ C3] _raw_spin_lock_irqsave+0x42/0x60 [ 497.040056][ C3] netconsole_netdev_event+0x78/0x63e [netconsole] [ 497.040059][ C3] notifier_call_chain+0xcc/0x150 [ 497.040063][ C3] netif_change_name+0x45a/0x920 [ 497.040065][ C3] do_setlink.constprop.0+0x1ca6/0x2640 [ 497.040067][ C3] rtnl_setlink+0x2ad/0x590 [ 497.040069][ C3] rtnetlink_rcv_msg+0x709/0xc00 [ 497.040072][ C3] netlink_rcv_skb+0x121/0x340 [ 497.040074][ C3] netlink_unicast+0x4aa/0x780 [ 497.040077][ C3] netlink_sendmsg+0x71d/0xbe0 [ 497.040079][ C3] __sys_sendto+0x24b/0x380 [ 497.040082][ C3] __x64_sys_sendto+0xe0/0x1b0 [ 497.040085][ C3] do_syscall_64+0xc1/0x370 [ 497.040087][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.040089][ C3] } [ 497.040090][ C3] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 497.040095][ C3] ... acquired at: [ 497.040096][ C3] __lock_acquire+0x449/0x7e0 [ 497.040098][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.040100][ C3] _raw_spin_lock_irqsave+0x42/0x60 [ 497.040103][ C3] write_ext_msg+0x8e/0x220 [netconsole] [ 497.040107][ C3] console_emit_next_record+0x20a/0x430 [ 497.040110][ C3] console_flush_all+0x3b4/0x620 [ 497.040112][ C3] console_unlock+0xba/0x190 [ 497.040114][ C3] vprintk_emit+0x290/0x2d0 [ 497.040117][ C3] _printk+0xb6/0xe0 [ 497.040119][ C3] register_console+0x8dd/0xf30 [ 497.040122][ C3] enabled_store+0x623/0x850 [netconsole] [ 497.040126][ C3] configfs_write_iter+0x2c7/0x490 [ 497.040132][ C3] vfs_write+0xaae/0x12c0 [ 497.040134][ C3] ksys_write+0xf7/0x1d0 [ 497.040136][ C3] do_syscall_64+0xc1/0x370 [ 497.040138][ C3] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 497.040140][ C3] [ 497.040141][ C3] -> (console_owner){-...}-{0:0} { [ 497.040144][ C3] IN-HARDIRQ-W at: [ 497.040145][ C3] __lock_acquire+0x20b/0x7e0 [ 497.040148][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.040150][ C3] console_lock_spinning_enable+0x99/0xb0 [ 497.040153][ C3] console_emit_next_record+0x1b2/0x430 [ 497.040155][ C3] console_flush_all+0x3b4/0x620 [ 497.040158][ C3] console_unlock+0xba/0x190 [ 497.040160][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 497.040163][ C3] irq_work_single+0x108/0x210 [ 497.040166][ C3] irq_work_run_list+0x6a/0x90 [ 497.040169][ C3] update_process_times+0x136/0x1a0 [ 497.040173][ C3] tick_nohz_handler+0x319/0x4e0 [ 497.040176][ C3] __run_hrtimer+0x158/0x370 [ 497.040179][ C3] __hrtimer_run_queues+0x194/0x260 [ 497.040182][ C3] hrtimer_interrupt+0x339/0x850 [ 497.040185][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 497.040189][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 497.040192][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 497.040195][ C3] finish_task_switch.isra.0+0x24e/0x960 [ 497.040199][ C3] __schedule+0x888/0x1b10 [ 497.040202][ C3] schedule_idle+0x61/0x90 [ 497.040205][ C3] do_idle+0x105/0x140 [ 497.040208][ C3] cpu_startup_entry+0x54/0x60 [ 497.040211][ C3] start_secondary+0x1fd/0x290 [ 497.040213][ C3] common_startup_64+0x13e/0x148 [ 497.040218][ C3] INITIAL USE at: [ 497.040219][ C3] } [ 497.040220][ C3] ... key at: [] console_owner_dep_map+0x0/0x60 [ 497.040226][ C3] ... acquired at: [ 497.040227][ C3] mark_lock+0x16c/0x2f0 [ 497.040229][ C3] mark_usage+0x11d/0x140 [ 497.040231][ C3] __lock_acquire+0x20b/0x7e0 [ 497.040233][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.040235][ C3] console_lock_spinning_enable+0x99/0xb0 [ 497.040238][ C3] console_emit_next_record+0x1b2/0x430 [ 497.040240][ C3] console_flush_all+0x3b4/0x620 [ 497.040243][ C3] console_unlock+0xba/0x190 [ 497.040245][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 497.040248][ C3] irq_work_single+0x108/0x210 [ 497.040251][ C3] irq_work_run_list+0x6a/0x90 [ 497.040253][ C3] update_process_times+0x136/0x1a0 [ 497.040256][ C3] tick_nohz_handler+0x319/0x4e0 [ 497.040259][ C3] __run_hrtimer+0x158/0x370 [ 497.040262][ C3] __hrtimer_run_queues+0x194/0x260 [ 497.040265][ C3] hrtimer_interrupt+0x339/0x850 [ 497.040268][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 497.040271][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 497.040274][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 497.040276][ C3] finish_task_switch.isra.0+0x24e/0x960 [ 497.040279][ C3] __schedule+0x888/0x1b10 [ 497.040281][ C3] schedule_idle+0x61/0x90 [ 497.040284][ C3] do_idle+0x105/0x140 [ 497.040285][ C3] cpu_startup_entry+0x54/0x60 [ 497.040287][ C3] start_secondary+0x1fd/0x290 [ 497.040290][ C3] common_startup_64+0x13e/0x148 [ 497.040292][ C3] [ 497.040293][ C3] [ 497.040293][ C3] stack backtrace: [ 497.040296][ C3] CPU: 3 UID: 0 PID: 0 Comm: swapper/3 Not tainted 6.17.0-rc3-virtme #1 PREEMPT(full) [ 497.040300][ C3] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 497.040302][ C3] Call Trace: [ 497.040303][ C3] [ 497.040305][ C3] dump_stack_lvl+0x82/0xc0 [ 497.040310][ C3] print_irq_inversion_bug.part.0+0x206/0x260 [ 497.040314][ C3] mark_lock_irq+0x248/0x400 [ 497.040321][ C3] mark_lock+0x16c/0x2f0 [ 497.040324][ C3] mark_usage+0x11d/0x140 [ 497.040327][ C3] __lock_acquire+0x20b/0x7e0 [ 497.040332][ C3] lock_acquire.part.0+0xb6/0x240 [ 497.040334][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 497.040338][ C3] ? rcu_is_watching+0x12/0xb0 [ 497.040344][ C3] ? lock_acquire+0x104/0x160 [ 497.040346][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 497.040350][ C3] console_lock_spinning_enable+0x99/0xb0 [ 497.040353][ C3] ? console_lock_spinning_enable+0x7d/0xb0 [ 497.040356][ C3] console_emit_next_record+0x1b2/0x430 [ 497.040360][ C3] ? devkmsg_read+0x460/0x460 [ 497.040364][ C3] ? rcu_is_watching+0x12/0xb0 [ 497.040369][ C3] console_flush_all+0x3b4/0x620 [ 497.040373][ C3] ? console_emit_next_record+0x430/0x430 [ 497.040376][ C3] ? __lock_acquire+0x449/0x7e0 [ 497.040381][ C3] console_unlock+0xba/0x190 [ 497.040384][ C3] ? console_flush_all+0x620/0x620 [ 497.040387][ C3] ? rcu_is_watching+0x12/0xb0 [ 497.040391][ C3] ? irq_work_single+0x108/0x210 [ 497.040394][ C3] ? irq_work_single+0x108/0x210 [ 497.040398][ C3] wake_up_klogd_work_func+0x5b/0x80 [ 497.040402][ C3] irq_work_single+0x108/0x210 [ 497.040405][ C3] irq_work_run_list+0x6a/0x90 [ 497.040408][ C3] ? irq_work_tick+0x9b/0x140 [ 497.040412][ C3] update_process_times+0x136/0x1a0 [ 497.040416][ C3] tick_nohz_handler+0x319/0x4e0 [ 497.040419][ C3] ? rcu_is_watching+0x12/0xb0 [ 497.040423][ C3] __run_hrtimer+0x158/0x370 [ 497.040426][ C3] ? tick_do_update_jiffies64.part.0+0x280/0x280 [ 497.040430][ C3] __hrtimer_run_queues+0x194/0x260 [ 497.040434][ C3] ? hrtimer_interrupt+0x12a/0x850 [ 497.040438][ C3] ? __run_hrtimer+0x370/0x370 [ 497.040441][ C3] ? kvm_clock_get_cycles+0x18/0x30 [ 497.040448][ C3] hrtimer_interrupt+0x339/0x850 [ 497.040455][ C3] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 497.040459][ C3] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 497.040463][ C3] [ 497.040464][ C3] [ 497.040465][ C3] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 497.040468][ C3] RIP: 0010:finish_task_switch.isra.0+0x24e/0x960 [ 497.040472][ C3] Code: 4c 8b 23 4c 89 ff 48 c7 03 00 00 00 00 ff d2 4d 85 e4 75 bd 4c 89 ff e8 c0 5f 11 02 e8 db ae 2e 00 fb 65 48 8b 1d 72 7f 14 04 <66> 90 48 83 7d d0 00 74 55 65 48 8b 1d 61 7f 14 04 48 8d bb 18 05 [ 497.040474][ C3] RSP: 0018:ffffc90000157cd0 EFLAGS: 00000202 [ 497.040477][ C3] RAX: 0000000000794c73 RBX: ffff888001ab45c0 RCX: ffffffffb25cce7f [ 497.040479][ C3] RDX: 0000000000000000 RSI: ffffffffb4beb6fc RDI: ffffffffb4657ae0 [ 497.040481][ C3] RBP: ffffc90000157d10 R08: 0000000000000001 R09: 0000000000000001 [ 497.040483][ C3] R10: ffffffffb5a1d717 R11: ffff8880363b6958 R12: ffff8880363b6958 [ 497.040484][ C3] R13: ffff8880144e2300 R14: ffff8880363b74a8 R15: ffff8880363b6940 [ 497.040488][ C3] ? trace_irq_enable.constprop.0+0x2f/0x130 [ 497.040494][ C3] ? __switch_to+0x503/0xd90 [ 497.040498][ C3] __schedule+0x888/0x1b10 [ 497.040503][ C3] ? io_schedule_timeout+0x150/0x150 [ 497.040506][ C3] ? trace_rcu_watching+0x11d/0x1b0 [ 497.040510][ C3] ? rcu_is_watching+0x12/0xb0 [ 497.040514][ C3] ? default_idle_call+0x97/0xa0 [ 497.040516][ C3] ? lockdep_hardirqs_on+0x7c/0x110 [ 497.040521][ C3] ? arch_cpu_idle_exit+0x40/0x40 [ 497.040523][ C3] ? trace_irq_enable.constprop.0+0x2f/0x130 [ 497.040527][ C3] schedule_idle+0x61/0x90 [ 497.040531][ C3] do_idle+0x105/0x140 [ 497.040534][ C3] cpu_startup_entry+0x54/0x60 [ 497.040536][ C3] start_secondary+0x1fd/0x290 [ 497.040540][ C3] ? set_cpu_sibling_map+0x1f70/0x1f70 [ 497.040544][ C3] common_startup_64+0x13e/0x148 [ 497.040551][ C3]