[ 707.246071][ T68] sched: DL replenish lagged too much [ 707.246560][ C1] [ 707.246563][ C1] ======================================================== [ 707.246564][ C1] WARNING: possible irq lock inversion dependency detected [ 707.246567][ C1] 6.16.0-virtme #1 Not tainted [ 707.246569][ C1] -------------------------------------------------------- [ 707.246570][ C1] swapper/1/0 just changed the state of lock: [ 707.246572][ C1] ffffffffb367b540 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 707.246589][ C1] but this lock took another, HARDIRQ-unsafe lock in the past: [ 707.246591][ C1] (_xmit_ETHER#2){+.-.}-{3:3} [ 707.246595][ C1] [ 707.246595][ C1] [ 707.246595][ C1] and interrupts could create inverse lock ordering between them. [ 707.246595][ C1] [ 707.246596][ C1] [ 707.246596][ C1] other info that might help us debug this: [ 707.246597][ C1] Chain exists of: [ 707.246597][ C1] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 707.246597][ C1] [ 707.246603][ C1] Possible interrupt unsafe locking scenario: [ 707.246603][ C1] [ 707.246604][ C1] CPU0 CPU1 [ 707.246605][ C1] ---- ---- [ 707.246606][ C1] lock(_xmit_ETHER#2); [ 707.246609][ C1] local_irq_disable(); [ 707.246610][ C1] lock(console_owner); [ 707.246612][ C1] lock(target_list_lock); [ 707.246614][ C1] [ 707.246615][ C1] lock(console_owner); [ 707.246617][ C1] [ 707.246617][ C1] *** DEADLOCK *** [ 707.246617][ C1] [ 707.246617][ C1] 2 locks held by swapper/1/0: [ 707.246619][ C1] #0: ffffffffb375bba0 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x108/0x210 [ 707.246629][ C1] #1: ffffffffb375bc10 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x620 [ 707.246636][ C1] [ 707.246636][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 707.246643][ C1] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 707.246649][ C1] HARDIRQ-ON-W at: [ 707.246652][ C1] __lock_acquire+0x20b/0x7e0 [ 707.246658][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.246663][ C1] _raw_spin_trylock+0x69/0x80 [ 707.246670][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 707.246676][ C1] virtnet_poll+0xf9/0xad0 [ 707.246679][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 707.246684][ C1] net_rx_action+0x54f/0xda0 [ 707.246687][ C1] handle_softirqs+0x215/0x610 [ 707.246691][ C1] do_softirq+0xad/0xe0 [ 707.246694][ C1] __local_bh_enable_ip+0x101/0x120 [ 707.246697][ C1] virtnet_open+0x228/0xb40 [ 707.246699][ C1] __dev_open+0x224/0x680 [ 707.246702][ C1] __dev_change_flags+0x460/0x6c0 [ 707.246706][ C1] netif_change_flags+0x80/0x160 [ 707.246709][ C1] do_setlink.constprop.0+0x984/0x2640 [ 707.246714][ C1] rtnl_newlink+0x693/0xa60 [ 707.246717][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 707.246720][ C1] netlink_rcv_skb+0x121/0x340 [ 707.246723][ C1] netlink_unicast+0x4aa/0x780 [ 707.246727][ C1] netlink_sendmsg+0x71d/0xbe0 [ 707.246730][ C1] ____sys_sendmsg+0x3dd/0x890 [ 707.246734][ C1] ___sys_sendmsg+0xed/0x170 [ 707.246738][ C1] __sys_sendmsg+0x10b/0x1a0 [ 707.246741][ C1] do_syscall_64+0xc1/0x370 [ 707.246748][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.246755][ C1] IN-SOFTIRQ-W at: [ 707.246757][ C1] __lock_acquire+0x20b/0x7e0 [ 707.246760][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.246762][ C1] _raw_spin_lock+0x33/0x40 [ 707.246765][ C1] virtnet_poll_tx+0x1da/0x6f0 [ 707.246769][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 707.246772][ C1] net_rx_action+0x54f/0xda0 [ 707.246775][ C1] handle_softirqs+0x215/0x610 [ 707.246778][ C1] do_softirq+0xad/0xe0 [ 707.246780][ C1] __local_bh_enable_ip+0x101/0x120 [ 707.246783][ C1] virtnet_napi_tx_enable+0x1b1/0x270 [ 707.246786][ C1] virtnet_open+0x27c/0xb40 [ 707.246788][ C1] __dev_open+0x224/0x680 [ 707.246791][ C1] __dev_change_flags+0x460/0x6c0 [ 707.246794][ C1] netif_change_flags+0x80/0x160 [ 707.246797][ C1] do_setlink.constprop.0+0x984/0x2640 [ 707.246800][ C1] rtnl_newlink+0x693/0xa60 [ 707.246804][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 707.246807][ C1] netlink_rcv_skb+0x121/0x340 [ 707.246809][ C1] netlink_unicast+0x4aa/0x780 [ 707.246813][ C1] netlink_sendmsg+0x71d/0xbe0 [ 707.246819][ C1] ____sys_sendmsg+0x3dd/0x890 [ 707.246821][ C1] ___sys_sendmsg+0xed/0x170 [ 707.246825][ C1] __sys_sendmsg+0x10b/0x1a0 [ 707.246829][ C1] do_syscall_64+0xc1/0x370 [ 707.246832][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.246835][ C1] INITIAL USE at: [ 707.246837][ C1] __lock_acquire+0x20b/0x7e0 [ 707.246839][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.246842][ C1] _raw_spin_trylock+0x69/0x80 [ 707.246845][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 707.246848][ C1] virtnet_poll+0xf9/0xad0 [ 707.246850][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 707.246853][ C1] net_rx_action+0x54f/0xda0 [ 707.246856][ C1] handle_softirqs+0x215/0x610 [ 707.246859][ C1] do_softirq+0xad/0xe0 [ 707.246861][ C1] __local_bh_enable_ip+0x101/0x120 [ 707.246864][ C1] virtnet_open+0x228/0xb40 [ 707.246866][ C1] __dev_open+0x224/0x680 [ 707.246869][ C1] __dev_change_flags+0x460/0x6c0 [ 707.246872][ C1] netif_change_flags+0x80/0x160 [ 707.246876][ C1] do_setlink.constprop.0+0x984/0x2640 [ 707.246880][ C1] rtnl_newlink+0x693/0xa60 [ 707.246883][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 707.246886][ C1] netlink_rcv_skb+0x121/0x340 [ 707.246889][ C1] netlink_unicast+0x4aa/0x780 [ 707.246892][ C1] netlink_sendmsg+0x71d/0xbe0 [ 707.246895][ C1] ____sys_sendmsg+0x3dd/0x890 [ 707.246898][ C1] ___sys_sendmsg+0xed/0x170 [ 707.246901][ C1] __sys_sendmsg+0x10b/0x1a0 [ 707.246904][ C1] do_syscall_64+0xc1/0x370 [ 707.246906][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.246908][ C1] } [ 707.246909][ C1] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 707.246915][ C1] ... acquired at: [ 707.246916][ C1] __lock_acquire+0x449/0x7e0 [ 707.246918][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.246921][ C1] _raw_spin_lock+0x33/0x40 [ 707.246923][ C1] virtnet_poll_tx+0x1da/0x6f0 [ 707.246926][ C1] poll_napi+0xf8/0x250 [ 707.246931][ C1] netpoll_poll_dev+0x264/0x2f0 [ 707.246934][ C1] __netpoll_send_skb+0x6ba/0x8a0 [ 707.246936][ C1] netpoll_send_skb+0x2a/0x90 [ 707.246938][ C1] send_ext_msg_udp+0x422/0x570 [netconsole] [ 707.246947][ C1] write_ext_msg+0x1c6/0x220 [netconsole] [ 707.246951][ C1] console_emit_next_record+0x20a/0x430 [ 707.246954][ C1] console_flush_all+0x3b4/0x620 [ 707.246957][ C1] console_unlock+0xba/0x190 [ 707.246960][ C1] vprintk_emit+0x290/0x2d0 [ 707.246964][ C1] devkmsg_emit.constprop.0+0xab/0xe0 [ 707.246967][ C1] devkmsg_write+0x193/0x300 [ 707.246971][ C1] vfs_write+0xaae/0x1200 [ 707.246976][ C1] ksys_write+0xf7/0x1d0 [ 707.246980][ C1] do_syscall_64+0xc1/0x370 [ 707.246982][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.246985][ C1] [ 707.246987][ C1] -> (target_list_lock){....}-{3:3} { [ 707.246993][ C1] INITIAL USE at: [ 707.246996][ C1] __lock_acquire+0x20b/0x7e0 [ 707.247000][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.247004][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 707.247007][ C1] 0xffffffffc042e0c1 [ 707.247010][ C1] do_one_initcall+0x8c/0x1d0 [ 707.247015][ C1] do_init_module+0x27a/0x860 [ 707.247020][ C1] load_module+0x1f40/0x2dd0 [ 707.247023][ C1] init_module_from_file+0xe9/0x150 [ 707.247027][ C1] idempotent_init_module+0x331/0x610 [ 707.247030][ C1] __x64_sys_finit_module+0xca/0x150 [ 707.247034][ C1] do_syscall_64+0xc1/0x370 [ 707.247036][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.247038][ C1] } [ 707.247039][ C1] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 707.247045][ C1] ... acquired at: [ 707.247046][ C1] __lock_acquire+0x449/0x7e0 [ 707.247049][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.247051][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 707.247054][ C1] write_ext_msg+0x8e/0x220 [netconsole] [ 707.247058][ C1] console_emit_next_record+0x20a/0x430 [ 707.247062][ C1] console_flush_all+0x3b4/0x620 [ 707.247065][ C1] console_unlock+0xba/0x190 [ 707.247067][ C1] vprintk_emit+0x290/0x2d0 [ 707.247070][ C1] _printk+0xb6/0xe0 [ 707.247072][ C1] register_console+0x8dd/0xf30 [ 707.247075][ C1] 0xffffffffc042e5e7 [ 707.247077][ C1] do_one_initcall+0x8c/0x1d0 [ 707.247080][ C1] do_init_module+0x27a/0x860 [ 707.247083][ C1] load_module+0x1f40/0x2dd0 [ 707.247085][ C1] init_module_from_file+0xe9/0x150 [ 707.247088][ C1] idempotent_init_module+0x331/0x610 [ 707.247091][ C1] __x64_sys_finit_module+0xca/0x150 [ 707.247094][ C1] do_syscall_64+0xc1/0x370 [ 707.247097][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 707.247099][ C1] [ 707.247100][ C1] -> (console_owner){-...}-{0:0} { [ 707.247103][ C1] IN-HARDIRQ-W at: [ 707.247105][ C1] __lock_acquire+0x20b/0x7e0 [ 707.247108][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.247110][ C1] console_lock_spinning_enable+0x99/0xb0 [ 707.247114][ C1] console_emit_next_record+0x1b2/0x430 [ 707.247116][ C1] console_flush_all+0x3b4/0x620 [ 707.247119][ C1] console_unlock+0xba/0x190 [ 707.247122][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 707.247125][ C1] irq_work_single+0x108/0x210 [ 707.247129][ C1] irq_work_run_list+0x6a/0x90 [ 707.247132][ C1] update_process_times+0x136/0x1a0 [ 707.247136][ C1] tick_nohz_handler+0x319/0x4e0 [ 707.247141][ C1] __run_hrtimer+0x158/0x370 [ 707.247144][ C1] __hrtimer_run_queues+0x194/0x260 [ 707.247147][ C1] hrtimer_interrupt+0x339/0x850 [ 707.247150][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 707.247155][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 707.247159][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 707.247162][ C1] finish_task_switch.isra.0+0x24e/0x960 [ 707.247166][ C1] __schedule+0x88f/0x1b10 [ 707.247170][ C1] schedule_idle+0x61/0x90 [ 707.247172][ C1] do_idle+0x105/0x140 [ 707.247174][ C1] cpu_startup_entry+0x54/0x60 [ 707.247177][ C1] start_secondary+0x1fd/0x290 [ 707.247179][ C1] common_startup_64+0x13e/0x148 [ 707.247183][ C1] INITIAL USE at: [ 707.247185][ C1] } [ 707.247186][ C1] ... key at: [] console_owner_dep_map+0x0/0x60 [ 707.247190][ C1] ... acquired at: [ 707.247191][ C1] mark_lock+0x16c/0x2f0 [ 707.247194][ C1] mark_usage+0x11d/0x140 [ 707.247196][ C1] __lock_acquire+0x20b/0x7e0 [ 707.247198][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.247200][ C1] console_lock_spinning_enable+0x99/0xb0 [ 707.247203][ C1] console_emit_next_record+0x1b2/0x430 [ 707.247206][ C1] console_flush_all+0x3b4/0x620 [ 707.247209][ C1] console_unlock+0xba/0x190 [ 707.247212][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 707.247214][ C1] irq_work_single+0x108/0x210 [ 707.247217][ C1] irq_work_run_list+0x6a/0x90 [ 707.247220][ C1] update_process_times+0x136/0x1a0 [ 707.247223][ C1] tick_nohz_handler+0x319/0x4e0 [ 707.247226][ C1] __run_hrtimer+0x158/0x370 [ 707.247229][ C1] __hrtimer_run_queues+0x194/0x260 [ 707.247232][ C1] hrtimer_interrupt+0x339/0x850 [ 707.247235][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 707.247238][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 707.247241][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 707.247243][ C1] finish_task_switch.isra.0+0x24e/0x960 [ 707.247247][ C1] __schedule+0x88f/0x1b10 [ 707.247252][ C1] schedule_idle+0x61/0x90 [ 707.247255][ C1] do_idle+0x105/0x140 [ 707.247258][ C1] cpu_startup_entry+0x54/0x60 [ 707.247261][ C1] start_secondary+0x1fd/0x290 [ 707.247264][ C1] common_startup_64+0x13e/0x148 [ 707.247268][ C1] [ 707.247269][ C1] [ 707.247269][ C1] stack backtrace: [ 707.247273][ C1] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted 6.16.0-virtme #1 PREEMPT(full) [ 707.247279][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 707.247282][ C1] Call Trace: [ 707.247284][ C1] [ 707.247287][ C1] dump_stack_lvl+0x82/0xc0 [ 707.247293][ C1] print_irq_inversion_bug.part.0+0x206/0x260 [ 707.247298][ C1] mark_lock_irq+0x248/0x400 [ 707.247304][ C1] mark_lock+0x16c/0x2f0 [ 707.247307][ C1] mark_usage+0x11d/0x140 [ 707.247310][ C1] __lock_acquire+0x20b/0x7e0 [ 707.247315][ C1] lock_acquire.part.0+0xb6/0x240 [ 707.247318][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 707.247321][ C1] ? rcu_is_watching+0x12/0xb0 [ 707.247326][ C1] ? lock_acquire+0x104/0x160 [ 707.247328][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 707.247334][ C1] console_lock_spinning_enable+0x99/0xb0 [ 707.247340][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 707.247344][ C1] console_emit_next_record+0x1b2/0x430 [ 707.247350][ C1] ? devkmsg_read+0x460/0x460 [ 707.247356][ C1] ? rcu_is_watching+0x12/0xb0 [ 707.247365][ C1] console_flush_all+0x3b4/0x620 [ 707.247370][ C1] ? console_emit_next_record+0x430/0x430 [ 707.247373][ C1] ? __lock_acquire+0x449/0x7e0 [ 707.247378][ C1] console_unlock+0xba/0x190 [ 707.247382][ C1] ? console_flush_all+0x620/0x620 [ 707.247385][ C1] ? rcu_is_watching+0x12/0xb0 [ 707.247390][ C1] ? irq_work_single+0x108/0x210 [ 707.247394][ C1] ? irq_work_single+0x108/0x210 [ 707.247400][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 707.247406][ C1] irq_work_single+0x108/0x210 [ 707.247412][ C1] irq_work_run_list+0x6a/0x90 [ 707.247417][ C1] ? irq_work_tick+0x9b/0x140 [ 707.247421][ C1] update_process_times+0x136/0x1a0 [ 707.247425][ C1] tick_nohz_handler+0x319/0x4e0 [ 707.247429][ C1] ? rcu_is_watching+0x12/0xb0 [ 707.247433][ C1] __run_hrtimer+0x158/0x370 [ 707.247437][ C1] ? tick_do_update_jiffies64.part.0+0x280/0x280 [ 707.247441][ C1] __hrtimer_run_queues+0x194/0x260 [ 707.247446][ C1] ? hrtimer_interrupt+0x12a/0x850 [ 707.247450][ C1] ? __run_hrtimer+0x370/0x370 [ 707.247453][ C1] ? kvm_clock_get_cycles+0x18/0x30 [ 707.247459][ C1] hrtimer_interrupt+0x339/0x850 [ 707.247463][ C1] ? __common_interrupt+0xaa/0x1c0 [ 707.247470][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 707.247474][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 707.247477][ C1] [ 707.247479][ C1] [ 707.247480][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 707.247483][ C1] RIP: 0010:finish_task_switch.isra.0+0x24e/0x960 [ 707.247488][ C1] 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 00 b9 0f 02 e8 6b 9d 2e 00 fb 65 48 8b 1d 02 e3 13 04 <66> 90 48 83 7d d0 00 74 55 65 48 8b 1d f1 e2 13 04 48 8d bb 18 05 [ 707.247491][ C1] RSP: 0018:ffffc90000137cd0 EFLAGS: 00000202 [ 707.247494][ C1] RAX: 00000000011018fd RBX: ffff888001b28040 RCX: ffffffffb0bd097f [ 707.247497][ C1] RDX: 0000000000000000 RSI: ffffffffb31e9d66 RDI: ffffffffb2c58660 [ 707.247498][ C1] RBP: ffffc90000137d10 R08: 0000000000000001 R09: 0000000000000001 [ 707.247500][ C1] R10: ffffffffb401e0d7 R11: ffff8880362b6958 R12: ffff8880362b6958 [ 707.247502][ C1] R13: ffff888008a82300 R14: ffff8880362b74a8 R15: ffff8880362b6940 [ 707.247506][ C1] ? trace_irq_enable.constprop.0+0x2f/0x130 [ 707.247513][ C1] ? __switch_to+0x503/0xd90 [ 707.247518][ C1] __schedule+0x88f/0x1b10 [ 707.247524][ C1] ? io_schedule_timeout+0x150/0x150 [ 707.247528][ C1] ? trace_rcu_watching+0x11d/0x1b0 [ 707.247534][ C1] ? rcu_is_watching+0x12/0xb0 [ 707.247537][ C1] ? default_idle_call+0x97/0xa0 [ 707.247541][ C1] ? lockdep_hardirqs_on+0x7c/0x110 [ 707.247546][ C1] ? arch_cpu_idle_exit+0x40/0x40 [ 707.247551][ C1] schedule_idle+0x61/0x90 [ 707.247554][ C1] do_idle+0x105/0x140 [ 707.247557][ C1] cpu_startup_entry+0x54/0x60 [ 707.247560][ C1] start_secondary+0x1fd/0x290 [ 707.247564][ C1] ? set_cpu_sibling_map+0x1f70/0x1f70 [ 707.247569][ C1] common_startup_64+0x13e/0x148 [ 707.247576][ C1]