[ 550.160442][ T2344] netdevsim netdevsim347 eni347np1: renamed from eth1 [ 550.276899][ T2345] netdevsim netdevsim607 eni607np1: renamed from eth0 [ 552.226447][ T2314] printk: legacy console [netcon_ext0] enabled [ 552.226825][ T2314] netconsole: netconsole: local port 6665 [ 552.227124][ T2314] netconsole: netconsole: local IPv4 address 192.0.2.1 [ 552.227451][ T2314] netconsole: netconsole: interface name 'eni347np1' [ 552.228650][ T2314] netconsole: netconsole: local ethernet address '00:00:00:00:00:00' [ 552.229048][ T2314] netconsole: netconsole: remote port 6666 [ 552.229375][ T2314] netconsole: netconsole: remote IPv4 address 192.0.2.2 [ 552.229694][ T2314] netconsole: netconsole: remote ethernet address b6:90:6f:22:db:94 [ 552.237010][ T2314] netconsole: network logging started [ 554.652961][ T2314] printk: legacy console [netcon_ext0] disabled [ 560.499553][ T37] sched: DL replenish lagged too much [ 560.500028][ C2] [ 560.500030][ C2] ======================================================== [ 560.500032][ C2] WARNING: possible irq lock inversion dependency detected [ 560.500034][ C2] 6.16.0-virtme #1 Not tainted [ 560.500037][ C2] -------------------------------------------------------- [ 560.500038][ C2] kworker/2:0/28 just changed the state of lock: [ 560.500040][ C2] ffffffff8e677de0 (console_owner){-...}-{0:0}, at: console_lock_spinning_enable+0x7d/0xb0 [ 560.500058][ C2] but this lock took another, HARDIRQ-unsafe lock in the past: [ 560.500060][ C2] (_xmit_ETHER#2){+.-.}-{3:3} [ 560.500063][ C2] [ 560.500063][ C2] [ 560.500063][ C2] and interrupts could create inverse lock ordering between them. [ 560.500063][ C2] [ 560.500065][ C2] [ 560.500065][ C2] other info that might help us debug this: [ 560.500066][ C2] Chain exists of: [ 560.500066][ C2] console_owner --> target_list_lock --> _xmit_ETHER#2 [ 560.500066][ C2] [ 560.500072][ C2] Possible interrupt unsafe locking scenario: [ 560.500072][ C2] [ 560.500073][ C2] CPU0 CPU1 [ 560.500074][ C2] ---- ---- [ 560.500075][ C2] lock(_xmit_ETHER#2); [ 560.500078][ C2] local_irq_disable(); [ 560.500079][ C2] lock(console_owner); [ 560.500080][ C2] lock(target_list_lock); [ 560.500083][ C2] [ 560.500083][ C2] lock(console_owner); [ 560.500085][ C2] [ 560.500085][ C2] *** DEADLOCK *** [ 560.500085][ C2] [ 560.500086][ C2] 2 locks held by kworker/2:0/28: [ 560.500088][ C2] #0: ffffffff8e758440 (console_lock){+.+.}-{0:0}, at: irq_work_single+0x108/0x210 [ 560.500098][ C2] #1: ffffffff8e7584b0 (console_srcu){....}-{0:0}, at: console_flush_all+0x12f/0x620 [ 560.500105][ C2] [ 560.500105][ C2] the shortest dependencies between 2nd lock and 1st lock: [ 560.500112][ C2] -> (_xmit_ETHER#2){+.-.}-{3:3} { [ 560.500116][ C2] HARDIRQ-ON-W at: [ 560.500119][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500124][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500127][ C2] _raw_spin_trylock+0x69/0x80 [ 560.500135][ C2] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 560.500141][ C2] virtnet_poll+0xf9/0xad0 [ 560.500144][ C2] __napi_poll.constprop.0+0x9f/0x460 [ 560.500151][ C2] net_rx_action+0x54f/0xda0 [ 560.500154][ C2] handle_softirqs+0x215/0x610 [ 560.500160][ C2] do_softirq+0xad/0xe0 [ 560.500162][ C2] __local_bh_enable_ip+0x101/0x120 [ 560.500165][ C2] virtnet_open+0x228/0xb40 [ 560.500167][ C2] __dev_open+0x224/0x670 [ 560.500169][ C2] __dev_change_flags+0x460/0x6c0 [ 560.500172][ C2] netif_change_flags+0x80/0x160 [ 560.500174][ C2] do_setlink.constprop.0+0x984/0x2640 [ 560.500179][ C2] rtnl_newlink+0x693/0xa60 [ 560.500181][ C2] rtnetlink_rcv_msg+0x709/0xc00 [ 560.500183][ C2] netlink_rcv_skb+0x121/0x340 [ 560.500187][ C2] netlink_unicast+0x4aa/0x780 [ 560.500190][ C2] netlink_sendmsg+0x71d/0xbe0 [ 560.500192][ C2] ____sys_sendmsg+0x3dd/0x890 [ 560.500197][ C2] ___sys_sendmsg+0xed/0x170 [ 560.500200][ C2] __sys_sendmsg+0x10b/0x1a0 [ 560.500203][ C2] do_syscall_64+0xc1/0x370 [ 560.500208][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500211][ C2] IN-SOFTIRQ-W at: [ 560.500213][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500215][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500217][ C2] _raw_spin_lock+0x33/0x40 [ 560.500221][ C2] virtnet_poll_tx+0x1da/0x6f0 [ 560.500223][ C2] __napi_poll.constprop.0+0x9f/0x460 [ 560.500226][ C2] net_rx_action+0x54f/0xda0 [ 560.500229][ C2] handle_softirqs+0x215/0x610 [ 560.500232][ C2] do_softirq+0xad/0xe0 [ 560.500234][ C2] __local_bh_enable_ip+0x101/0x120 [ 560.500237][ C2] virtnet_napi_tx_enable+0x1b1/0x270 [ 560.500243][ C2] virtnet_open+0x27c/0xb40 [ 560.500245][ C2] __dev_open+0x224/0x670 [ 560.500247][ C2] __dev_change_flags+0x460/0x6c0 [ 560.500249][ C2] netif_change_flags+0x80/0x160 [ 560.500251][ C2] do_setlink.constprop.0+0x984/0x2640 [ 560.500253][ C2] rtnl_newlink+0x693/0xa60 [ 560.500255][ C2] rtnetlink_rcv_msg+0x709/0xc00 [ 560.500258][ C2] netlink_rcv_skb+0x121/0x340 [ 560.500260][ C2] netlink_unicast+0x4aa/0x780 [ 560.500262][ C2] netlink_sendmsg+0x71d/0xbe0 [ 560.500264][ C2] ____sys_sendmsg+0x3dd/0x890 [ 560.500267][ C2] ___sys_sendmsg+0xed/0x170 [ 560.500270][ C2] __sys_sendmsg+0x10b/0x1a0 [ 560.500273][ C2] do_syscall_64+0xc1/0x370 [ 560.500276][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500278][ C2] INITIAL USE at: [ 560.500280][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500282][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500285][ C2] _raw_spin_trylock+0x69/0x80 [ 560.500288][ C2] virtnet_poll_cleantx.isra.0+0x1fe/0x500 [ 560.500290][ C2] virtnet_poll+0xf9/0xad0 [ 560.500292][ C2] __napi_poll.constprop.0+0x9f/0x460 [ 560.500296][ C2] net_rx_action+0x54f/0xda0 [ 560.500298][ C2] handle_softirqs+0x215/0x610 [ 560.500301][ C2] do_softirq+0xad/0xe0 [ 560.500303][ C2] __local_bh_enable_ip+0x101/0x120 [ 560.500306][ C2] virtnet_open+0x228/0xb40 [ 560.500308][ C2] __dev_open+0x224/0x670 [ 560.500310][ C2] __dev_change_flags+0x460/0x6c0 [ 560.500312][ C2] netif_change_flags+0x80/0x160 [ 560.500314][ C2] do_setlink.constprop.0+0x984/0x2640 [ 560.500316][ C2] rtnl_newlink+0x693/0xa60 [ 560.500318][ C2] rtnetlink_rcv_msg+0x709/0xc00 [ 560.500321][ C2] netlink_rcv_skb+0x121/0x340 [ 560.500323][ C2] netlink_unicast+0x4aa/0x780 [ 560.500325][ C2] netlink_sendmsg+0x71d/0xbe0 [ 560.500327][ C2] ____sys_sendmsg+0x3dd/0x890 [ 560.500330][ C2] ___sys_sendmsg+0xed/0x170 [ 560.500333][ C2] __sys_sendmsg+0x10b/0x1a0 [ 560.500336][ C2] do_syscall_64+0xc1/0x370 [ 560.500338][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500340][ C2] } [ 560.500341][ C2] ... key at: [] netdev_xmit_lock_key+0x10/0x3c0 [ 560.500347][ C2] ... acquired at: [ 560.500348][ C2] __lock_acquire+0x449/0x7e0 [ 560.500350][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500352][ C2] _raw_spin_lock+0x33/0x40 [ 560.500355][ C2] virtnet_poll_tx+0x1da/0x6f0 [ 560.500357][ C2] poll_napi+0xf8/0x250 [ 560.500361][ C2] netpoll_poll_dev+0x264/0x2f0 [ 560.500363][ C2] __netpoll_send_skb+0x6ba/0x8a0 [ 560.500365][ C2] netpoll_send_skb+0x2a/0x90 [ 560.500367][ C2] send_ext_msg_udp+0x422/0x570 [netconsole] [ 560.500376][ C2] write_ext_msg+0x1c6/0x220 [netconsole] [ 560.500380][ C2] console_emit_next_record+0x20a/0x430 [ 560.500384][ C2] console_flush_all+0x3b4/0x620 [ 560.500386][ C2] console_unlock+0xba/0x190 [ 560.500389][ C2] vprintk_emit+0x290/0x2d0 [ 560.500391][ C2] _printk+0xb6/0xe0 [ 560.500394][ C2] enabled_store+0x23b/0x850 [netconsole] [ 560.500397][ C2] configfs_write_iter+0x2c7/0x490 [ 560.500404][ C2] vfs_write+0xaae/0x1200 [ 560.500408][ C2] ksys_write+0xf7/0x1d0 [ 560.500411][ C2] do_syscall_64+0xc1/0x370 [ 560.500413][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500415][ C2] [ 560.500416][ C2] -> (target_list_lock){....}-{3:3} { [ 560.500420][ C2] INITIAL USE at: [ 560.500422][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500424][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500426][ C2] _raw_spin_lock_irqsave+0x42/0x60 [ 560.500429][ C2] netconsole_netdev_event+0x78/0x63e [netconsole] [ 560.500433][ C2] notifier_call_chain+0xcc/0x150 [ 560.500438][ C2] netif_change_name+0x45a/0x920 [ 560.500440][ C2] do_setlink.constprop.0+0x1ca6/0x2640 [ 560.500442][ C2] rtnl_setlink+0x2ad/0x590 [ 560.500444][ C2] rtnetlink_rcv_msg+0x709/0xc00 [ 560.500447][ C2] netlink_rcv_skb+0x121/0x340 [ 560.500449][ C2] netlink_unicast+0x4aa/0x780 [ 560.500451][ C2] netlink_sendmsg+0x71d/0xbe0 [ 560.500453][ C2] __sys_sendto+0x24b/0x380 [ 560.500456][ C2] __x64_sys_sendto+0xe0/0x1b0 [ 560.500459][ C2] do_syscall_64+0xc1/0x370 [ 560.500462][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500464][ C2] } [ 560.500465][ C2] ... key at: [] target_list_lock+0x18/0x60 [netconsole] [ 560.500469][ C2] ... acquired at: [ 560.500470][ C2] __lock_acquire+0x449/0x7e0 [ 560.500472][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500474][ C2] _raw_spin_lock_irqsave+0x42/0x60 [ 560.500477][ C2] write_msg+0x9a/0x280 [netconsole] [ 560.500481][ C2] console_emit_next_record+0x20a/0x430 [ 560.500484][ C2] console_flush_all+0x3b4/0x620 [ 560.500486][ C2] console_unlock+0xba/0x190 [ 560.500489][ C2] vprintk_emit+0x290/0x2d0 [ 560.500491][ C2] devkmsg_emit.constprop.0+0xab/0xe0 [ 560.500494][ C2] devkmsg_write+0x193/0x300 [ 560.500497][ C2] vfs_write+0xaae/0x1200 [ 560.500499][ C2] ksys_write+0xf7/0x1d0 [ 560.500501][ C2] do_syscall_64+0xc1/0x370 [ 560.500503][ C2] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 560.500505][ C2] [ 560.500506][ C2] -> (console_owner){-...}-{0:0} { [ 560.500510][ C2] IN-HARDIRQ-W at: [ 560.500511][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500514][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500516][ C2] console_lock_spinning_enable+0x99/0xb0 [ 560.500519][ C2] console_emit_next_record+0x1b2/0x430 [ 560.500522][ C2] console_flush_all+0x3b4/0x620 [ 560.500525][ C2] console_unlock+0xba/0x190 [ 560.500527][ C2] wake_up_klogd_work_func+0x5b/0x80 [ 560.500530][ C2] irq_work_single+0x108/0x210 [ 560.500533][ C2] irq_work_run_list+0x6a/0x90 [ 560.500536][ C2] update_process_times+0x136/0x1a0 [ 560.500542][ C2] tick_nohz_handler+0x319/0x4e0 [ 560.500547][ C2] __run_hrtimer+0x158/0x370 [ 560.500550][ C2] __hrtimer_run_queues+0x194/0x260 [ 560.500553][ C2] hrtimer_interrupt+0x339/0x850 [ 560.500556][ C2] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 560.500561][ C2] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 560.500565][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 560.500567][ C2] _raw_spin_unlock_irq+0x2e/0x50 [ 560.500570][ C2] process_one_work+0x731/0x1650 [ 560.500574][ C2] worker_thread+0x591/0xcf0 [ 560.500577][ C2] kthread+0x37b/0x5f0 [ 560.500581][ C2] ret_from_fork+0x240/0x320 [ 560.500586][ C2] ret_from_fork_asm+0x11/0x20 [ 560.500591][ C2] INITIAL USE at: [ 560.500593][ C2] } [ 560.500593][ C2] ... key at: [] console_owner_dep_map+0x0/0x60 [ 560.500599][ C2] ... acquired at: [ 560.500600][ C2] mark_lock+0x16c/0x2f0 [ 560.500602][ C2] mark_usage+0x11d/0x140 [ 560.500604][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500606][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500608][ C2] console_lock_spinning_enable+0x99/0xb0 [ 560.500611][ C2] console_emit_next_record+0x1b2/0x430 [ 560.500613][ C2] console_flush_all+0x3b4/0x620 [ 560.500616][ C2] console_unlock+0xba/0x190 [ 560.500618][ C2] wake_up_klogd_work_func+0x5b/0x80 [ 560.500621][ C2] irq_work_single+0x108/0x210 [ 560.500624][ C2] irq_work_run_list+0x6a/0x90 [ 560.500626][ C2] update_process_times+0x136/0x1a0 [ 560.500629][ C2] tick_nohz_handler+0x319/0x4e0 [ 560.500632][ C2] __run_hrtimer+0x158/0x370 [ 560.500635][ C2] __hrtimer_run_queues+0x194/0x260 [ 560.500638][ C2] hrtimer_interrupt+0x339/0x850 [ 560.500640][ C2] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 560.500643][ C2] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 560.500646][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 560.500648][ C2] _raw_spin_unlock_irq+0x2e/0x50 [ 560.500651][ C2] process_one_work+0x731/0x1650 [ 560.500654][ C2] worker_thread+0x591/0xcf0 [ 560.500657][ C2] kthread+0x37b/0x5f0 [ 560.500659][ C2] ret_from_fork+0x240/0x320 [ 560.500662][ C2] ret_from_fork_asm+0x11/0x20 [ 560.500664][ C2] [ 560.500665][ C2] [ 560.500665][ C2] stack backtrace: [ 560.500668][ C2] CPU: 2 UID: 0 PID: 28 Comm: kworker/2:0 Not tainted 6.16.0-virtme #1 PREEMPT(full) [ 560.500672][ C2] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 560.500675][ C2] Workqueue: pm pm_runtime_work [ 560.500682][ C2] Call Trace: [ 560.500685][ C2] [ 560.500689][ C2] dump_stack_lvl+0x82/0xc0 [ 560.500695][ C2] print_irq_inversion_bug.part.0+0x206/0x260 [ 560.500699][ C2] mark_lock_irq+0x248/0x400 [ 560.500706][ C2] mark_lock+0x16c/0x2f0 [ 560.500709][ C2] mark_usage+0x11d/0x140 [ 560.500712][ C2] __lock_acquire+0x20b/0x7e0 [ 560.500716][ C2] lock_acquire.part.0+0xb6/0x240 [ 560.500719][ C2] ? console_lock_spinning_enable+0x7d/0xb0 [ 560.500723][ C2] ? rcu_is_watching+0x12/0xb0 [ 560.500729][ C2] ? lock_acquire+0x104/0x160 [ 560.500732][ C2] ? console_lock_spinning_enable+0x7d/0xb0 [ 560.500736][ C2] console_lock_spinning_enable+0x99/0xb0 [ 560.500739][ C2] ? console_lock_spinning_enable+0x7d/0xb0 [ 560.500742][ C2] console_emit_next_record+0x1b2/0x430 [ 560.500746][ C2] ? devkmsg_read+0x460/0x460 [ 560.500750][ C2] ? rcu_is_watching+0x12/0xb0 [ 560.500756][ C2] console_flush_all+0x3b4/0x620 [ 560.500760][ C2] ? console_emit_next_record+0x430/0x430 [ 560.500763][ C2] ? __lock_acquire+0x449/0x7e0 [ 560.500768][ C2] console_unlock+0xba/0x190 [ 560.500771][ C2] ? console_flush_all+0x620/0x620 [ 560.500774][ C2] ? rcu_is_watching+0x12/0xb0 [ 560.500778][ C2] ? irq_work_single+0x108/0x210 [ 560.500781][ C2] ? irq_work_single+0x108/0x210 [ 560.500786][ C2] wake_up_klogd_work_func+0x5b/0x80 [ 560.500789][ C2] irq_work_single+0x108/0x210 [ 560.500793][ C2] irq_work_run_list+0x6a/0x90 [ 560.500796][ C2] ? irq_work_tick+0x9b/0x140 [ 560.500799][ C2] update_process_times+0x136/0x1a0 [ 560.500803][ C2] tick_nohz_handler+0x319/0x4e0 [ 560.500806][ C2] ? rcu_is_watching+0x12/0xb0 [ 560.500810][ C2] __run_hrtimer+0x158/0x370 [ 560.500814][ C2] ? tick_do_update_jiffies64.part.0+0x280/0x280 [ 560.500818][ C2] __hrtimer_run_queues+0x194/0x260 [ 560.500822][ C2] ? hrtimer_interrupt+0x12a/0x850 [ 560.500826][ C2] ? __run_hrtimer+0x370/0x370 [ 560.500829][ C2] ? kvm_clock_get_cycles+0x18/0x30 [ 560.500837][ C2] hrtimer_interrupt+0x339/0x850 [ 560.500841][ C2] ? __common_interrupt+0xaa/0x1c0 [ 560.500849][ C2] __sysvec_apic_timer_interrupt+0xc6/0x150 [ 560.500852][ C2] sysvec_apic_timer_interrupt+0xa3/0xc0 [ 560.500856][ C2] [ 560.500857][ C2] [ 560.500859][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 560.500861][ C2] RIP: 0010:_raw_spin_unlock_irq+0x2e/0x50 [ 560.500865][ C2] Code: 0f 1f 44 00 00 55 48 8b 74 24 08 48 89 fd 48 83 c7 18 e8 85 da f9 fd 48 89 ef e8 ad 29 fa fd e8 58 df 1d fe fb bf 01 00 00 00 fd 5d ee fd 65 8b 05 76 7c 03 02 85 c0 74 02 5d c3 e8 bb 76 aa [ 560.500868][ C2] RSP: 0018:ffffc900001ffc88 EFLAGS: 00000202 [ 560.500871][ C2] RAX: 0000000000008443 RBX: ffffffff8f01d264 RCX: ffffffff8bbcd1ff [ 560.500873][ C2] RDX: 0000000000000000 RSI: ffffffff8e1ea6cb RDI: 0000000000000001 [ 560.500875][ C2] RBP: ffff888036335880 R08: 0000000000000001 R09: 0000000000000001 [ 560.500877][ C2] R10: ffffffff8f01c217 R11: ffffffff9096b760 R12: ffff8880058e0a58 [ 560.500879][ C2] R13: ffff888001c60040 R14: ffff888001965540 R15: 0000000000000000 [ 560.500882][ C2] ? trace_irq_enable.constprop.0+0x2f/0x130 [ 560.500890][ C2] ? _raw_spin_unlock_irq+0x28/0x50 [ 560.500893][ C2] process_one_work+0x731/0x1650 [ 560.500899][ C2] ? pwq_dec_nr_in_flight+0x550/0x550 [ 560.500905][ C2] ? assign_work+0x168/0x240 [ 560.500909][ C2] worker_thread+0x591/0xcf0 [ 560.500915][ C2] ? rescuer_thread+0xd10/0xd10 [ 560.500918][ C2] kthread+0x37b/0x5f0 [ 560.500922][ C2] ? kthread_is_per_cpu+0xc0/0xc0 [ 560.500925][ C2] ? ret_from_fork+0x1b/0x320 [ 560.500927][ C2] ? __lock_release+0x5d/0x170 [ 560.500930][ C2] ? rcu_is_watching+0x12/0xb0 [ 560.500934][ C2] ? kthread_is_per_cpu+0xc0/0xc0 [ 560.500938][ C2] ret_from_fork+0x240/0x320 [ 560.500940][ C2] ? kthread_is_per_cpu+0xc0/0xc0 [ 560.500944][ C2] ret_from_fork_asm+0x11/0x20 [ 560.500950][ C2]