[ 588.985850][ C1] sched: DL replenish lagged too much [ 588.986906][ C1] [ 588.986915][ C1] ======================================================== [ 588.986920][ C1] WARNING: possible irq lock inversion dependency detected [ 588.986924][ C1] 6.16.0-virtme #1 Not tainted [ 588.986926][ C1] -------------------------------------------------------- [ 588.986928][ C1] bash/190 just changed the state of lock: [ 588.986931][ C1] ffffffffb6477de0 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 588.986965][ C1] but this lock took another, HARDIRQ-unsafe lock in the past: [ 588.986967][ C1] (_xmit_ETHER#2){+.-.}-{3:3} [ 588.986971][ C1] [ 588.986971][ C1] [ 588.986971][ C1] and interrupts could create inverse lock ordering between them. [ 588.986971][ C1] [ 588.986973][ C1] [ 588.986973][ C1] other info that might help us debug this: [ 588.986975][ C1] Chain exists of: [ 588.986975][ C1] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 588.986975][ C1] [ 588.986983][ C1] Possible interrupt unsafe locking scenario: [ 588.986983][ C1] [ 588.986986][ C1] CPU0 CPU1 [ 588.986988][ C1] ---- ---- [ 588.986989][ C1] lock(_xmit_ETHER#2); [ 588.986992][ C1] local_irq_disable(); [ 588.986994][ C1] lock(console_owner); [ 588.986997][ C1] lock(target_list_lock); [ 588.987000][ C1] [ 588.987002][ C1] lock(console_owner); [ 588.987004][ C1] [ 588.987004][ C1] *** DEADLOCK *** [ 588.987004][ C1] [ 588.987006][ C1] 2 locks held by bash/190: [ 588.987008][ C1] #0: ffffffffb6558440 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x108/0x210 [ 588.987025][ C1] #1: ffffffffb65584b0 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x620 [ 588.987035][ C1] [ 588.987035][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 588.987048][ C1] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 588.987054][ C1] HARDIRQ-ON-W at: [ 588.987057][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987067][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987071][ C1] _raw_spin_trylock+0x69/0x80 [ 588.987080][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 588.987088][ C1] virtnet_poll+0xf9/0xad0 [ 588.987094][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 588.987105][ C1] net_rx_action+0x54f/0xda0 [ 588.987109][ C1] handle_softirqs+0x215/0x610 [ 588.987118][ C1] do_softirq+0xad/0xe0 [ 588.987122][ C1] __local_bh_enable_ip+0x101/0x120 [ 588.987126][ C1] virtnet_open+0x228/0xb40 [ 588.987130][ C1] __dev_open+0x224/0x670 [ 588.987136][ C1] __dev_change_flags+0x460/0x6c0 [ 588.987140][ C1] netif_change_flags+0x80/0x160 [ 588.987146][ C1] do_setlink.constprop.0+0x984/0x2640 [ 588.987152][ C1] rtnl_newlink+0x693/0xa60 [ 588.987155][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 588.987158][ C1] netlink_rcv_skb+0x121/0x340 [ 588.987164][ C1] netlink_unicast+0x4aa/0x780 [ 588.987166][ C1] netlink_sendmsg+0x71d/0xbe0 [ 588.987169][ C1] ____sys_sendmsg+0x3dd/0x890 [ 588.987177][ C1] ___sys_sendmsg+0xed/0x170 [ 588.987183][ C1] __sys_sendmsg+0x10b/0x1a0 [ 588.987186][ C1] do_syscall_64+0xc1/0x370 [ 588.987193][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987198][ C1] IN-SOFTIRQ-W at: [ 588.987200][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987204][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987208][ C1] _raw_spin_lock+0x33/0x40 [ 588.987212][ C1] virtnet_poll_tx+0x1da/0x6f0 [ 588.987215][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 588.987219][ C1] net_rx_action+0x54f/0xda0 [ 588.987222][ C1] handle_softirqs+0x215/0x610 [ 588.987226][ C1] do_softirq+0xad/0xe0 [ 588.987229][ C1] __local_bh_enable_ip+0x101/0x120 [ 588.987232][ C1] virtnet_napi_tx_enable+0x1b1/0x270 [ 588.987240][ C1] virtnet_open+0x27c/0xb40 [ 588.987243][ C1] __dev_open+0x224/0x670 [ 588.987248][ C1] __dev_change_flags+0x460/0x6c0 [ 588.987252][ C1] netif_change_flags+0x80/0x160 [ 588.987257][ C1] do_setlink.constprop.0+0x984/0x2640 [ 588.987260][ C1] rtnl_newlink+0x693/0xa60 [ 588.987264][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 588.987267][ C1] netlink_rcv_skb+0x121/0x340 [ 588.987270][ C1] netlink_unicast+0x4aa/0x780 [ 588.987274][ C1] netlink_sendmsg+0x71d/0xbe0 [ 588.987278][ C1] ____sys_sendmsg+0x3dd/0x890 [ 588.987283][ C1] ___sys_sendmsg+0xed/0x170 [ 588.987287][ C1] __sys_sendmsg+0x10b/0x1a0 [ 588.987291][ C1] do_syscall_64+0xc1/0x370 [ 588.987294][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987298][ C1] INITIAL USE at: [ 588.987300][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987304][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987308][ C1] _raw_spin_trylock+0x69/0x80 [ 588.987312][ C1] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 588.987316][ C1] virtnet_poll+0xf9/0xad0 [ 588.987319][ C1] __napi_poll.constprop.0+0x9f/0x460 [ 588.987324][ C1] net_rx_action+0x54f/0xda0 [ 588.987328][ C1] handle_softirqs+0x215/0x610 [ 588.987332][ C1] do_softirq+0xad/0xe0 [ 588.987335][ C1] __local_bh_enable_ip+0x101/0x120 [ 588.987339][ C1] virtnet_open+0x228/0xb40 [ 588.987343][ C1] __dev_open+0x224/0x670 [ 588.987347][ C1] __dev_change_flags+0x460/0x6c0 [ 588.987352][ C1] netif_change_flags+0x80/0x160 [ 588.987357][ C1] do_setlink.constprop.0+0x984/0x2640 [ 588.987360][ C1] rtnl_newlink+0x693/0xa60 [ 588.987363][ C1] rtnetlink_rcv_msg+0x709/0xc00 [ 588.987366][ C1] netlink_rcv_skb+0x121/0x340 [ 588.987369][ C1] netlink_unicast+0x4aa/0x780 [ 588.987372][ C1] netlink_sendmsg+0x71d/0xbe0 [ 588.987374][ C1] ____sys_sendmsg+0x3dd/0x890 [ 588.987377][ C1] ___sys_sendmsg+0xed/0x170 [ 588.987381][ C1] __sys_sendmsg+0x10b/0x1a0 [ 588.987384][ C1] do_syscall_64+0xc1/0x370 [ 588.987387][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987390][ C1] } [ 588.987392][ C1] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 588.987412][ C1] ... acquired at: [ 588.987416][ C1] __lock_acquire+0x449/0x7e0 [ 588.987419][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987422][ C1] _raw_spin_lock+0x33/0x40 [ 588.987427][ C1] virtnet_poll_tx+0x1da/0x6f0 [ 588.987430][ C1] poll_napi+0xf8/0x250 [ 588.987436][ C1] netpoll_poll_dev+0x264/0x2f0 [ 588.987440][ C1] __netpoll_send_skb+0x6ba/0x8a0 [ 588.987444][ C1] netpoll_send_skb+0x2a/0x90 [ 588.987447][ C1] send_ext_msg_udp+0x422/0x570 [netconsole] [ 588.987462][ C1] write_ext_msg+0x1c6/0x220 [netconsole] [ 588.987469][ C1] console_emit_next_record+0x20a/0x430 [ 588.987473][ C1] console_flush_all+0x3b4/0x620 [ 588.987476][ C1] console_unlock+0xba/0x190 [ 588.987479][ C1] vprintk_emit+0x290/0x2d0 [ 588.987484][ C1] devkmsg_emit.constprop.0+0xab/0xe0 [ 588.987488][ C1] devkmsg_write+0x193/0x300 [ 588.987492][ C1] vfs_write+0xaae/0x1200 [ 588.987501][ C1] ksys_write+0xf7/0x1d0 [ 588.987504][ C1] do_syscall_64+0xc1/0x370 [ 588.987508][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987511][ C1] [ 588.987512][ C1] -> (target_list_lock){....}-{3:3} { [ 588.987518][ C1] INITIAL USE at: [ 588.987521][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987525][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987528][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 588.987533][ C1] 0xffffffffc042e0c1 [ 588.987537][ C1] do_one_initcall+0x8c/0x1d0 [ 588.987547][ C1] do_init_module+0x27a/0x860 [ 588.987558][ C1] load_module+0x1f40/0x2dd0 [ 588.987562][ C1] init_module_from_file+0xe9/0x150 [ 588.987566][ C1] idempotent_init_module+0x331/0x610 [ 588.987570][ C1] __x64_sys_finit_module+0xca/0x150 [ 588.987575][ C1] do_syscall_64+0xc1/0x370 [ 588.987579][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987583][ C1] } [ 588.987584][ C1] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 588.987594][ C1] ... acquired at: [ 588.987596][ C1] __lock_acquire+0x449/0x7e0 [ 588.987600][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987603][ C1] _raw_spin_lock_irqsave+0x42/0x60 [ 588.987607][ C1] write_ext_msg+0x8e/0x220 [netconsole] [ 588.987614][ C1] console_emit_next_record+0x20a/0x430 [ 588.987618][ C1] console_flush_all+0x3b4/0x620 [ 588.987623][ C1] console_unlock+0xba/0x190 [ 588.987627][ C1] vprintk_emit+0x290/0x2d0 [ 588.987631][ C1] _printk+0xb6/0xe0 [ 588.987635][ C1] register_console+0x8dd/0xf30 [ 588.987639][ C1] 0xffffffffc042e5e7 [ 588.987643][ C1] do_one_initcall+0x8c/0x1d0 [ 588.987647][ C1] do_init_module+0x27a/0x860 [ 588.987652][ C1] load_module+0x1f40/0x2dd0 [ 588.987655][ C1] init_module_from_file+0xe9/0x150 [ 588.987659][ C1] idempotent_init_module+0x331/0x610 [ 588.987664][ C1] __x64_sys_finit_module+0xca/0x150 [ 588.987667][ C1] do_syscall_64+0xc1/0x370 [ 588.987671][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987673][ C1] [ 588.987674][ C1] -> (console_owner){-...}-{0:0} { [ 588.987679][ C1] IN-HARDIRQ-W at: [ 588.987681][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987685][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987688][ C1] console_lock_spinning_enable+0x99/0xb0 [ 588.987692][ C1] console_emit_next_record+0x1b2/0x430 [ 588.987696][ C1] console_flush_all+0x3b4/0x620 [ 588.987699][ C1] console_unlock+0xba/0x190 [ 588.987703][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 588.987707][ C1] irq_work_single+0x108/0x210 [ 588.987712][ C1] irq_work_run_list+0x6a/0x90 [ 588.987716][ C1] update_process_times+0x136/0x1a0 [ 588.987721][ C1] tick_nohz_handler+0x319/0x4e0 [ 588.987728][ C1] __run_hrtimer+0x158/0x370 [ 588.987732][ C1] __hrtimer_run_queues+0x194/0x260 [ 588.987737][ C1] hrtimer_interrupt+0x339/0x850 [ 588.987741][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 588.987750][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 588.987756][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 588.987761][ C1] lock_is_held_type+0x102/0x140 [ 588.987764][ C1] __might_resched+0x47c/0x5a0 [ 588.987771][ C1] __might_fault+0x64/0x170 [ 588.987777][ C1] core_sys_select+0x5c4/0x6f0 [ 588.987782][ C1] do_pselect.constprop.0+0x116/0x1e0 [ 588.987785][ C1] __x64_sys_pselect6+0x10a/0x1c0 [ 588.987788][ C1] do_syscall_64+0xc1/0x370 [ 588.987791][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987794][ C1] INITIAL USE at: [ 588.987796][ C1] } [ 588.987797][ C1] ... key at: [] console_owner_dep_map+0x0/0x60 [ 588.987818][ C1] ... acquired at: [ 588.987819][ C1] mark_lock+0x16c/0x2f0 [ 588.987822][ C1] mark_usage+0x11d/0x140 [ 588.987826][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987828][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987831][ C1] console_lock_spinning_enable+0x99/0xb0 [ 588.987835][ C1] console_emit_next_record+0x1b2/0x430 [ 588.987839][ C1] console_flush_all+0x3b4/0x620 [ 588.987842][ C1] console_unlock+0xba/0x190 [ 588.987846][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 588.987850][ C1] irq_work_single+0x108/0x210 [ 588.987854][ C1] irq_work_run_list+0x6a/0x90 [ 588.987857][ C1] update_process_times+0x136/0x1a0 [ 588.987861][ C1] tick_nohz_handler+0x319/0x4e0 [ 588.987865][ C1] __run_hrtimer+0x158/0x370 [ 588.987869][ C1] __hrtimer_run_queues+0x194/0x260 [ 588.987872][ C1] hrtimer_interrupt+0x339/0x850 [ 588.987876][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 588.987880][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 588.987884][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 588.987886][ C1] lock_is_held_type+0x102/0x140 [ 588.987890][ C1] __might_resched+0x47c/0x5a0 [ 588.987893][ C1] __might_fault+0x64/0x170 [ 588.987896][ C1] core_sys_select+0x5c4/0x6f0 [ 588.987898][ C1] do_pselect.constprop.0+0x116/0x1e0 [ 588.987902][ C1] __x64_sys_pselect6+0x10a/0x1c0 [ 588.987905][ C1] do_syscall_64+0xc1/0x370 [ 588.987909][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.987912][ C1] [ 588.987913][ C1] [ 588.987913][ C1] stack backtrace: [ 588.987923][ C1] CPU: 1 UID: 0 PID: 190 Comm: bash Not tainted 6.16.0-virtme #1 PREEMPT(full) [ 588.987928][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 588.987938][ C1] Call Trace: [ 588.987944][ C1] [ 588.987947][ C1] dump_stack_lvl+0x82/0xc0 [ 588.987955][ C1] print_irq_inversion_bug.part.0+0x206/0x260 [ 588.987962][ C1] mark_lock_irq+0x248/0x400 [ 588.987971][ C1] mark_lock+0x16c/0x2f0 [ 588.987976][ C1] mark_usage+0x11d/0x140 [ 588.987980][ C1] __lock_acquire+0x20b/0x7e0 [ 588.987986][ C1] lock_acquire.part.0+0xb6/0x240 [ 588.987990][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 588.987995][ C1] ? rcu_is_watching+0x12/0xb0 [ 588.988007][ C1] ? lock_acquire+0x104/0x160 [ 588.988010][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 588.988016][ C1] console_lock_spinning_enable+0x99/0xb0 [ 588.988021][ C1] ? console_lock_spinning_enable+0x7d/0xb0 [ 588.988025][ C1] console_emit_next_record+0x1b2/0x430 [ 588.988031][ C1] ? devkmsg_read+0x460/0x460 [ 588.988036][ C1] ? rcu_is_watching+0x12/0xb0 [ 588.988043][ C1] console_flush_all+0x3b4/0x620 [ 588.988049][ C1] ? console_emit_next_record+0x430/0x430 [ 588.988053][ C1] ? __lock_acquire+0x449/0x7e0 [ 588.988059][ C1] console_unlock+0xba/0x190 [ 588.988063][ C1] ? console_flush_all+0x620/0x620 [ 588.988067][ C1] ? rcu_is_watching+0x12/0xb0 [ 588.988072][ C1] ? irq_work_single+0x108/0x210 [ 588.988076][ C1] ? irq_work_single+0x108/0x210 [ 588.988082][ C1] wake_up_klogd_work_func+0x5b/0x80 [ 588.988087][ C1] irq_work_single+0x108/0x210 [ 588.988093][ C1] irq_work_run_list+0x6a/0x90 [ 588.988097][ C1] ? irq_work_tick+0x9b/0x140 [ 588.988101][ C1] update_process_times+0x136/0x1a0 [ 588.988106][ C1] tick_nohz_handler+0x319/0x4e0 [ 588.988110][ C1] ? rcu_is_watching+0x12/0xb0 [ 588.988115][ C1] __run_hrtimer+0x158/0x370 [ 588.988120][ C1] ? tick_do_update_jiffies64.part.0+0x280/0x280 [ 588.988126][ C1] __hrtimer_run_queues+0x194/0x260 [ 588.988131][ C1] ? hrtimer_interrupt+0x12a/0x850 [ 588.988136][ C1] ? __run_hrtimer+0x370/0x370 [ 588.988140][ C1] ? kvm_clock_get_cycles+0x18/0x30 [ 588.988152][ C1] hrtimer_interrupt+0x339/0x850 [ 588.988161][ C1] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 588.988166][ C1] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 588.988171][ C1] [ 588.988172][ C1] [ 588.988177][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 588.988182][ C1] RIP: 0010:lock_is_held_type+0x102/0x140 [ 588.988189][ C1] Code: 00 00 b8 ff ff ff ff 65 0f c1 05 f9 f6 05 02 83 f8 01 75 29 9c 58 f6 c4 02 75 3f 48 f7 04 24 00 02 00 00 74 01 fb 48 83 c4 08 <44> 89 e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 45 31 ed eb b9 90 0f 0b [ 588.988193][ C1] RSP: 0018:ffffc900009d7b28 EFLAGS: 00000286 [ 588.988203][ C1] RAX: 0000000000000046 RBX: 0000000000000000 RCX: 0000000000000001 [ 588.988206][ C1] RDX: 0000000000000000 RSI: ffffffffb5fd2fd9 RDI: ffffffffb5a57960 [ 588.988209][ C1] RBP: ffffffffb656f8c0 R08: 0000000000000104 R09: ffff888004bd16c0 [ 588.988212][ C1] R10: ffffc900009d7bc0 R11: 0000000000000041 R12: ffff88800c2bc5c0 [ 588.988215][ C1] R13: 0000000000000000 R14: 00000000ffffffff R15: ffffc900009d7c90 [ 588.988225][ C1] __might_resched+0x47c/0x5a0 [ 588.988230][ C1] __might_fault+0x64/0x170 [ 588.988234][ C1] core_sys_select+0x5c4/0x6f0 [ 588.988241][ C1] ? poll_select_set_timeout+0xe0/0xe0 [ 588.988250][ C1] ? find_held_lock+0x2b/0x80 [ 588.988261][ C1] ? __might_fault+0x117/0x170 [ 588.988265][ C1] ? __lock_release+0x5d/0x170 [ 588.988271][ C1] ? __might_fault+0x117/0x170 [ 588.988276][ C1] ? _copy_from_user+0x53/0x90 [ 588.988282][ C1] ? _copy_from_user+0x53/0x90 [ 588.988286][ C1] ? get_timespec64+0x73/0x150 [ 588.988291][ C1] ? __set_current_blocked+0xf0/0xf0 [ 588.988299][ C1] ? trace_rseq_update+0xce/0x130 [ 588.988312][ C1] do_pselect.constprop.0+0x116/0x1e0 [ 588.988316][ C1] ? __rseq_handle_notify_resume+0x2b8/0x420 [ 588.988323][ C1] ? kern_select+0x1e0/0x1e0 [ 588.988328][ C1] ? ksys_read+0xf7/0x1d0 [ 588.988334][ C1] ? vfs_write+0x1200/0x1200 [ 588.988339][ C1] __x64_sys_pselect6+0x10a/0x1c0 [ 588.988344][ C1] ? do_syscall_64+0x85/0x370 [ 588.988347][ C1] ? lockdep_hardirqs_on+0x7c/0x110 [ 588.988352][ C1] do_syscall_64+0xc1/0x370 [ 588.988356][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 588.988360][ C1] RIP: 0033:0x7fd388670c04 [ 588.988365][ C1] Code: 30 4c 89 4c 24 40 48 c7 44 24 48 08 00 00 00 64 8b 04 25 18 00 00 00 4c 8d 4c 24 40 85 c0 75 36 4c 89 f2 b8 0e 01 00 00 0f 05 <48> 3d 00 f0 ff ff 0f 87 80 00 00 00 48 8b 54 24 58 64 48 2b 14 25 [ 588.988369][ C1] RSP: 002b:00007ffd943442c0 EFLAGS: 00000246 ORIG_RAX: 000000000000010e [ 588.988373][ C1] RAX: ffffffffffffffda RBX: 00007ffd943443b0 RCX: 00007fd388670c04 [ 588.988376][ C1] RDX: 0000000000000000 RSI: 00007ffd94344440 RDI: 0000000000000001 [ 588.988378][ C1] RBP: 0000000000000001 R08: 00007ffd943442f0 R09: 00007ffd94344300 [ 588.988380][ C1] R10: 00007ffd943443c0 R11: 0000000000000246 R12: 00007ffd94344440 [ 588.988383][ C1] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000 [ 588.988391][ C1]