[ 650.578932][ T1391] sched: DL replenish lagged too much [ 650.579776][ C1] [ 650.579780][ C1] ======================================================== [ 650.579781][ C1] WARNING: possible irq lock inversion dependency detected [ 650.579784][ C1] 6.16.0-virtme #1 Not tainted [ 650.579787][ C1] -------------------------------------------------------- [ 650.579788][ C1] swapper/1/0 just changed the state of lock: [ 650.579790][ C1] ffffffffb4e80280 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 650.579809][ C1] but this lock took another, HARDIRQ-unsafe lock in the past: [ 650.579811][ C1] (_xmit_ETHER#2){+.-.}-{3:3} [ 650.579815][ C1] [ 650.579815][ C1] [ 650.579815][ C1] and interrupts could create inverse lock ordering between them. [ 650.579815][ C1] [ 650.579816][ C1] [ 650.579816][ C1] other info that might help us debug this: [ 650.579817][ C1] Chain exists of: [ 650.579817][ C1] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 650.579817][ C1] [ 650.579822][ C1] Possible interrupt unsafe locking scenario: [ 650.579822][ C1] [ 650.579823][ C1] CPU0 CPU1 [ 650.579824][ C1] ---- ---- [ 650.579825][ C1] lock(_xmit_ETHER#2); [ 650.579827][ C1] local_irq_disable(); [ 650.579828][ C1] lock(console_owner); [ 650.579830][ C1] lock(target_list_lock); [ 650.579832][ C1] [ 650.579832][ C1] lock(console_owner); [ 650.579834][ C1] [ 650.579834][ C1] *** DEADLOCK *** [ 650.579834][ C1] [ 650.579835][ C1] 2 locks held by swapper/1/0: [ 650.579836][ C1] #0: ffffffffb4f608e0 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x10b/0x220 [ 650.579844][ C1] #1: ffffffffb4f60950 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x630 [ 650.579850][ C1] [ 650.579850][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 650.579857][ C1] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 650.579861][ C1] HARDIRQ-ON-W at: [ 650.579863][ C1] __lock_acquire+0x20b/0x7e0 [ 650.579867][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.579869][ C1] _raw_spin_trylock+0x6d/0x80 [ 650.579875][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 650.579880][ C1] virtnet_poll+0xf9/0xad0 [ 650.579883][ C1] __napi_poll.constprop.0+0xa2/0x470 [ 650.579888][ C1] net_rx_action+0x54f/0xda0 [ 650.579892][ C1] handle_softirqs+0x21b/0x620 [ 650.579896][ C1] do_softirq+0xb1/0xe0 [ 650.579898][ C1] __local_bh_enable_ip+0x105/0x130 [ 650.579901][ C1] virtnet_open+0x228/0xb40 [ 650.579904][ C1] __dev_open+0x22e/0x680 [ 650.579906][ C1] __dev_change_flags+0x467/0x6c0 [ 650.579908][ C1] netif_change_flags+0x80/0x160 [ 650.579910][ C1] do_setlink.constprop.0+0x98a/0x2650 [ 650.579914][ C1] rtnl_newlink+0x69a/0xa60 [ 650.579916][ C1] rtnetlink_rcv_msg+0x713/0xc00 [ 650.579918][ C1] netlink_rcv_skb+0x121/0x350 [ 650.579922][ C1] netlink_unicast+0x4b6/0x790 [ 650.579925][ C1] netlink_sendmsg+0x721/0xbe0 [ 650.579927][ C1] ____sys_sendmsg+0x7ad/0xa10 [ 650.579930][ C1] ___sys_sendmsg+0xed/0x170 [ 650.579933][ C1] __sys_sendmsg+0x10b/0x1a0 [ 650.579936][ C1] do_syscall_64+0xc1/0x380 [ 650.579940][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.579943][ C1] IN-SOFTIRQ-W at: [ 650.579945][ C1] __lock_acquire+0x20b/0x7e0 [ 650.579947][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.579949][ C1] _raw_spin_lock+0x33/0x40 [ 650.579951][ C1] virtnet_poll_tx+0x1da/0x700 [ 650.579954][ C1] __napi_poll.constprop.0+0xa2/0x470 [ 650.579957][ C1] net_rx_action+0x54f/0xda0 [ 650.579960][ C1] handle_softirqs+0x21b/0x620 [ 650.579962][ C1] do_softirq+0xb1/0xe0 [ 650.579964][ C1] __local_bh_enable_ip+0x105/0x130 [ 650.579967][ C1] virtnet_napi_tx_enable+0x1b5/0x270 [ 650.579970][ C1] virtnet_open+0x27c/0xb40 [ 650.579972][ C1] __dev_open+0x22e/0x680 [ 650.579974][ C1] __dev_change_flags+0x467/0x6c0 [ 650.579976][ C1] netif_change_flags+0x80/0x160 [ 650.579978][ C1] do_setlink.constprop.0+0x98a/0x2650 [ 650.579981][ C1] rtnl_newlink+0x69a/0xa60 [ 650.579983][ C1] rtnetlink_rcv_msg+0x713/0xc00 [ 650.579985][ C1] netlink_rcv_skb+0x121/0x350 [ 650.579988][ C1] netlink_unicast+0x4b6/0x790 [ 650.579990][ C1] netlink_sendmsg+0x721/0xbe0 [ 650.579993][ C1] ____sys_sendmsg+0x7ad/0xa10 [ 650.579995][ C1] ___sys_sendmsg+0xed/0x170 [ 650.579997][ C1] __sys_sendmsg+0x10b/0x1a0 [ 650.580000][ C1] do_syscall_64+0xc1/0x380 [ 650.580003][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.580005][ C1] INITIAL USE at: [ 650.580006][ C1] __lock_acquire+0x20b/0x7e0 [ 650.580008][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580010][ C1] _raw_spin_trylock+0x6d/0x80 [ 650.580013][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 650.580015][ C1] virtnet_poll+0xf9/0xad0 [ 650.580018][ C1] __napi_poll.constprop.0+0xa2/0x470 [ 650.580021][ C1] net_rx_action+0x54f/0xda0 [ 650.580023][ C1] handle_softirqs+0x21b/0x620 [ 650.580026][ C1] do_softirq+0xb1/0xe0 [ 650.580028][ C1] __local_bh_enable_ip+0x105/0x130 [ 650.580030][ C1] virtnet_open+0x228/0xb40 [ 650.580032][ C1] __dev_open+0x22e/0x680 [ 650.580034][ C1] __dev_change_flags+0x467/0x6c0 [ 650.580036][ C1] netif_change_flags+0x80/0x160 [ 650.580038][ C1] do_setlink.constprop.0+0x98a/0x2650 [ 650.580040][ C1] rtnl_newlink+0x69a/0xa60 [ 650.580043][ C1] rtnetlink_rcv_msg+0x713/0xc00 [ 650.580045][ C1] netlink_rcv_skb+0x121/0x350 [ 650.580048][ C1] netlink_unicast+0x4b6/0x790 [ 650.580050][ C1] netlink_sendmsg+0x721/0xbe0 [ 650.580052][ C1] ____sys_sendmsg+0x7ad/0xa10 [ 650.580055][ C1] ___sys_sendmsg+0xed/0x170 [ 650.580057][ C1] __sys_sendmsg+0x10b/0x1a0 [ 650.580060][ C1] do_syscall_64+0xc1/0x380 [ 650.580063][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.580066][ C1] } [ 650.580067][ C1] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 650.580074][ C1] ... acquired at: [ 650.580075][ C1] __lock_acquire+0x44d/0x7e0 [ 650.580078][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580081][ C1] _raw_spin_lock+0x33/0x40 [ 650.580084][ C1] virtnet_poll_tx+0x1da/0x700 [ 650.580088][ C1] poll_napi+0xfb/0x260 [ 650.580093][ C1] netpoll_poll_dev+0x26b/0x2f0 [ 650.580096][ C1] __netpoll_send_skb+0x6be/0x8b0 [ 650.580100][ C1] netpoll_send_skb+0x2a/0xa0 [ 650.580104][ C1] send_ext_msg_udp+0x422/0x570 [netconsole] [ 650.580116][ C1] write_ext_msg+0x1c6/0x230 [netconsole] [ 650.580125][ C1] console_emit_next_record+0x20c/0x430 [ 650.580129][ C1] console_flush_all+0x3b4/0x630 [ 650.580134][ C1] console_unlock+0xba/0x1a0 [ 650.580137][ C1] vprintk_emit+0x294/0x2d0 [ 650.580140][ C1] devkmsg_emit.constprop.0+0xab/0xe0 [ 650.580143][ C1] devkmsg_write+0x193/0x300 [ 650.580146][ C1] vfs_write+0xab8/0x1210 [ 650.580149][ C1] ksys_write+0xf7/0x1d0 [ 650.580151][ C1] do_syscall_64+0xc1/0x380 [ 650.580154][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.580156][ C1] [ 650.580157][ C1] -> (target_list_lock){....}-{3:3} { [ 650.580160][ C1] INITIAL USE at: [ 650.580162][ C1] __lock_acquire+0x20b/0x7e0 [ 650.580164][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580166][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 650.580168][ C1] netconsole_netdev_event+0x78/0x646 [netconsole] [ 650.580173][ C1] notifier_call_chain+0xd0/0x150 [ 650.580177][ C1] netif_change_name+0x45e/0x920 [ 650.580180][ C1] do_setlink.constprop.0+0x1cbe/0x2650 [ 650.580183][ C1] rtnl_setlink+0x2ad/0x590 [ 650.580185][ C1] rtnetlink_rcv_msg+0x713/0xc00 [ 650.580187][ C1] netlink_rcv_skb+0x121/0x350 [ 650.580190][ C1] netlink_unicast+0x4b6/0x790 [ 650.580192][ C1] netlink_sendmsg+0x721/0xbe0 [ 650.580195][ C1] __sys_sendto+0x3b8/0x440 [ 650.580197][ C1] __x64_sys_sendto+0xe0/0x1c0 [ 650.580200][ C1] do_syscall_64+0xc1/0x380 [ 650.580203][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.580205][ C1] } [ 650.580206][ C1] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 650.580211][ C1] ... acquired at: [ 650.580212][ C1] __lock_acquire+0x44d/0x7e0 [ 650.580214][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580216][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 650.580218][ C1] write_msg+0x9a/0x280 [netconsole] [ 650.580223][ C1] console_emit_next_record+0x20c/0x430 [ 650.580226][ C1] console_flush_all+0x3b4/0x630 [ 650.580228][ C1] console_unlock+0xba/0x1a0 [ 650.580231][ C1] vprintk_emit+0x294/0x2d0 [ 650.580233][ C1] devkmsg_emit.constprop.0+0xab/0xe0 [ 650.580236][ C1] devkmsg_write+0x193/0x300 [ 650.580239][ C1] vfs_write+0xab8/0x1210 [ 650.580241][ C1] ksys_write+0xf7/0x1d0 [ 650.580243][ C1] do_syscall_64+0xc1/0x380 [ 650.580245][ C1] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 650.580247][ C1] [ 650.580248][ C1] -> (console_owner){-...}-{0:0} { [ 650.580251][ C1] IN-HARDIRQ-W at: [ 650.580252][ C1] __lock_acquire+0x20b/0x7e0 [ 650.580254][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580256][ C1] console_lock_spinning_enable+0x99/0xb0 [ 650.580259][ C1] console_emit_next_record+0x1b2/0x430 [ 650.580262][ C1] console_flush_all+0x3b4/0x630 [ 650.580264][ C1] console_unlock+0xba/0x1a0 [ 650.580267][ C1] wake_up_klogd_work_func+0x5f/0x90 [ 650.580270][ C1] irq_work_single+0x10b/0x220 [ 650.580272][ C1] irq_work_run_list+0x6a/0xa0 [ 650.580274][ C1] update_process_times+0x136/0x1a0 [ 650.580277][ C1] tick_nohz_handler+0x31d/0x4f0 [ 650.580281][ C1] __run_hrtimer+0x15b/0x370 [ 650.580283][ C1] __hrtimer_run_queues+0x194/0x260 [ 650.580285][ C1] hrtimer_interrupt+0x339/0x850 [ 650.580287][ C1] __sysvec_apic_timer_interrupt+0xcd/0x150 [ 650.580291][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 650.580294][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 650.580298][ C1] pv_native_safe_halt+0xf/0x20 [ 650.580302][ C1] default_idle+0x9/0x10 [ 650.580305][ C1] default_idle_call+0x6d/0xb0 [ 650.580309][ C1] cpuidle_idle_call+0x240/0x370 [ 650.580314][ C1] do_idle+0xe1/0x140 [ 650.580318][ C1] cpu_startup_entry+0x54/0x60 [ 650.580322][ C1] start_secondary+0x213/0x2a0 [ 650.580328][ C1] common_startup_64+0x13e/0x148 [ 650.580332][ C1] INITIAL USE at: [ 650.580333][ C1] } [ 650.580334][ C1] ... key at: [] console_owner_dep_map+0x0/0x60 [ 650.580339][ C1] ... acquired at: [ 650.580339][ C1] mark_lock+0x174/0x2f0 [ 650.580343][ C1] mark_usage+0x129/0x150 [ 650.580345][ C1] __lock_acquire+0x20b/0x7e0 [ 650.580347][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580349][ C1] console_lock_spinning_enable+0x99/0xb0 [ 650.580351][ C1] console_emit_next_record+0x1b2/0x430 [ 650.580354][ C1] console_flush_all+0x3b4/0x630 [ 650.580357][ C1] console_unlock+0xba/0x1a0 [ 650.580360][ C1] wake_up_klogd_work_func+0x5f/0x90 [ 650.580364][ C1] irq_work_single+0x10b/0x220 [ 650.580367][ C1] irq_work_run_list+0x6a/0xa0 [ 650.580370][ C1] update_process_times+0x136/0x1a0 [ 650.580373][ C1] tick_nohz_handler+0x31d/0x4f0 [ 650.580377][ C1] __run_hrtimer+0x15b/0x370 [ 650.580380][ C1] __hrtimer_run_queues+0x194/0x260 [ 650.580383][ C1] hrtimer_interrupt+0x339/0x850 [ 650.580387][ C1] __sysvec_apic_timer_interrupt+0xcd/0x150 [ 650.580389][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 650.580392][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 650.580394][ C1] pv_native_safe_halt+0xf/0x20 [ 650.580397][ C1] default_idle+0x9/0x10 [ 650.580400][ C1] default_idle_call+0x6d/0xb0 [ 650.580403][ C1] cpuidle_idle_call+0x240/0x370 [ 650.580405][ C1] do_idle+0xe1/0x140 [ 650.580408][ C1] cpu_startup_entry+0x54/0x60 [ 650.580411][ C1] start_secondary+0x213/0x2a0 [ 650.580414][ C1] common_startup_64+0x13e/0x148 [ 650.580417][ C1] [ 650.580417][ C1] [ 650.580417][ C1] stack backtrace: [ 650.580421][ C1] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Not tainted 6.16.0-virtme #1 PREEMPT(full) [ 650.580425][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 650.580427][ C1] Call Trace: [ 650.580430][ C1] [ 650.580432][ C1] dump_stack_lvl+0x82/0xd0 [ 650.580438][ C1] print_irq_inversion_bug.part.0+0x206/0x260 [ 650.580443][ C1] mark_lock_irq+0x248/0x400 [ 650.580451][ C1] mark_lock+0x174/0x2f0 [ 650.580455][ C1] mark_usage+0x129/0x150 [ 650.580457][ C1] __lock_acquire+0x20b/0x7e0 [ 650.580462][ C1] lock_acquire.part.0+0xb6/0x240 [ 650.580464][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 650.580468][ C1] ? rcu_is_watching+0x12/0xc0 [ 650.580472][ C1] ? lock_acquire+0x10c/0x170 [ 650.580474][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 650.580478][ C1] console_lock_spinning_enable+0x99/0xb0 [ 650.580481][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 650.580484][ C1] console_emit_next_record+0x1b2/0x430 [ 650.580488][ C1] ? __pfx_console_emit_next_record+0x10/0x10 [ 650.580493][ C1] ? rcu_is_watching+0x12/0xc0 [ 650.580497][ C1] console_flush_all+0x3b4/0x630 [ 650.580502][ C1] ? __pfx_console_flush_all+0x10/0x10 [ 650.580505][ C1] ? __lock_acquire+0x44d/0x7e0 [ 650.580510][ C1] console_unlock+0xba/0x1a0 [ 650.580513][ C1] ? __pfx_console_unlock+0x10/0x10 [ 650.580517][ C1] ? rcu_is_watching+0x12/0xc0 [ 650.580519][ C1] ? irq_work_single+0x10b/0x220 [ 650.580522][ C1] ? irq_work_single+0x10b/0x220 [ 650.580526][ C1] wake_up_klogd_work_func+0x5f/0x90 [ 650.580529][ C1] irq_work_single+0x10b/0x220 [ 650.580533][ C1] irq_work_run_list+0x6a/0xa0 [ 650.580535][ C1] ? irq_work_tick+0x9b/0x140 [ 650.580537][ C1] update_process_times+0x136/0x1a0 [ 650.580540][ C1] tick_nohz_handler+0x31d/0x4f0 [ 650.580543][ C1] ? rcu_is_watching+0x12/0xc0 [ 650.580547][ C1] __run_hrtimer+0x15b/0x370 [ 650.580549][ C1] ? __pfx_tick_nohz_handler+0x10/0x10 [ 650.580553][ C1] __hrtimer_run_queues+0x194/0x260 [ 650.580556][ C1] ? hrtimer_interrupt+0x12a/0x850 [ 650.580560][ C1] ? __pfx___hrtimer_run_queues+0x10/0x10 [ 650.580562][ C1] ? kvm_clock_get_cycles+0x18/0x30 [ 650.580570][ C1] hrtimer_interrupt+0x339/0x850 [ 650.580573][ C1] ? __common_interrupt+0xad/0x1d0 [ 650.580581][ C1] __sysvec_apic_timer_interrupt+0xcd/0x150 [ 650.580584][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 650.580587][ C1] [ 650.580588][ C1] [ 650.580590][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 650.580593][ C1] RIP: 0010:pv_native_safe_halt+0xf/0x20 [ 650.580596][ C1] Code: 34 a8 00 e9 c3 6a 02 00 0f 1f 00 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 d1 1b 00 fb f4 cc cc cc cc 66 2e 0f 1f 84 00 00 00 00 00 66 90 90 90 90 90 90 [ 650.580599][ C1] RSP: 0018:ffffc90000137de8 EFLAGS: 00000246 [ 650.580602][ C1] RAX: 000000000104822d RBX: 1ffff92000026fc1 RCX: ffffffffb40d83f9 [ 650.580604][ C1] RDX: 0000000000000000 RSI: ffffffffb4b0e27c RDI: ffffffffb4459c60 [ 650.580606][ C1] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffed1006016252 [ 650.580607][ C1] R10: ffff8880300b1293 R11: ffff8880300b6958 R12: 0000000000000000 [ 650.580609][ C1] R13: ffff888001ba8040 R14: dffffc0000000000 R15: 0000000000000000 [ 650.580613][ C1] ? ct_kernel_exit.constprop.0+0x109/0x160 [ 650.580618][ C1] default_idle+0x9/0x10 [ 650.580621][ C1] default_idle_call+0x6d/0xb0 [ 650.580624][ C1] cpuidle_idle_call+0x240/0x370 [ 650.580628][ C1] ? __pfx_cpuidle_idle_call+0x10/0x10 [ 650.580633][ C1] ? tsc_verify_tsc_adjust+0x98/0x310 [ 650.580637][ C1] do_idle+0xe1/0x140 [ 650.580641][ C1] cpu_startup_entry+0x54/0x60 [ 650.580645][ C1] start_secondary+0x213/0x2a0 [ 650.580649][ C1] ? __pfx_start_secondary+0x10/0x10 [ 650.580654][ C1] common_startup_64+0x13e/0x148 [ 650.580661][ C1]