[ 23.918061][ T277] ip (277) used greatest stack depth: 24648 bytes left [ 23.918079][ T277] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 23.918081][ T277] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 277, name: ip [ 23.918083][ T277] preempt_count: 2, expected: 0 [ 23.918084][ T277] RCU nest depth: 0, expected: 0 [ 23.918085][ T277] locks held by ip/277: 5, last CPU#2: [ 23.918087][ T277] #0: ffffffffa4e027b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 23.918099][ T277] #1: ffffffffa4f99cc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 23.918105][ T277] #2: ffffffffa4f99d38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 23.918109][ T277] #3: ffffffffa4e89660 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 23.918113][ T277] #4: ffffffffa4e89560 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 23.918117][ T277] irq event stamp: 20820 [ 23.918117][ T277] hardirqs last enabled at (20819): [] __down_trylock_console_sem+0x86/0xa0 [ 23.918120][ T277] hardirqs last disabled at (20820): [] console_emit_next_record+0x3f8/0x4f0 [ 23.918122][ T277] softirqs last enabled at (19274): [] netlink_release+0x17b/0xcf0 [ 23.918126][ T277] softirqs last disabled at (19272): [] netlink_release+0xd2/0xcf0 [ 23.918129][ T277] Preemption disabled at: [ 23.918129][ T277] [<0000000000000000>] 0x0 [ 23.918137][ T277] CPU: 2 UID: 0 PID: 277 Comm: ip Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 23.918140][ T277] Tainted: [W]=WARN [ 23.918141][ T277] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 23.918143][ T277] Call Trace: [ 23.918145][ T277] [ 23.918146][ T277] dump_stack_lvl+0x6f/0xa0 [ 23.918152][ T277] __might_resched.cold+0x1fe/0x2c1 [ 23.918157][ T277] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 23.918161][ T277] ? __kmalloc_noprof+0xdb/0x760 [ 23.918166][ T277] __kmalloc_noprof+0x443/0x760 [ 23.918168][ T277] ? alloc_buf.isra.0+0x4b/0x260 [ 23.918174][ T277] ? do_raw_spin_unlock+0x59/0x250 [ 23.918176][ T277] alloc_buf.isra.0+0x4b/0x260 [ 23.918179][ T277] put_chars+0x1e1/0x2f0 [ 23.918182][ T277] ? __send_to_port+0x420/0x420 [ 23.918184][ T277] ? printk_get_next_message+0x2fe/0x7d0 [ 23.918187][ T277] ? rcu_read_lock_any_held+0x3c/0x90 [ 23.918190][ T277] ? validate_chain+0x38b/0xc20 [ 23.918195][ T277] hvc_console_print+0x292/0x780 [ 23.918198][ T277] ? __lock_acquire+0x518/0xc20 [ 23.918199][ T277] ? __lock_acquire+0x518/0xc20 [ 23.918203][ T277] ? hvc_write+0x3a0/0x3a0 [ 23.918206][ T277] ? rcu_is_watching+0x16/0xd0 [ 23.918210][ T277] ? lock_acquire+0x13c/0x160 [ 23.918213][ T277] console_emit_next_record+0x252/0x4f0 [ 23.918217][ T277] ? devkmsg_read+0x4e0/0x4e0 [ 23.918222][ T277] ? rcu_is_watching+0x16/0xd0 [ 23.918224][ T277] ? lock_acquire+0x13c/0x160 [ 23.918228][ T277] console_flush_one_record+0x46f/0x710 [ 23.918232][ T277] ? console_emit_next_record+0x4f0/0x4f0 [ 23.918233][ T277] ? __lock_acquire+0x518/0xc20 [ 23.918239][ T277] console_unlock+0xee/0x1f0 [ 23.918241][ T277] ? console_flush_one_record+0x710/0x710 [ 23.918243][ T277] ? rcu_is_watching+0x16/0xd0 [ 23.918245][ T277] ? lock_acquire+0x60/0x160 [ 23.918252][ T277] ? __down_trylock_console_sem+0x5e/0xa0 [ 23.918254][ T277] ? vprintk_emit+0x320/0x3e0 [ 23.918259][ T277] vprintk_emit+0x37c/0x3e0 [ 23.918262][ T277] ? wake_up_klogd_work_func+0x90/0x90 [ 23.918266][ T277] ? __lock_acquire+0x518/0xc20 [ 23.918269][ T277] _printk+0xc7/0x100 [ 23.918273][ T277] ? snapshot_read.cold+0x21/0x21 [ 23.918276][ T277] ? do_raw_spin_lock+0x131/0x280 [ 23.918279][ T277] ? __rwlock_init+0x150/0x150 [ 23.918282][ T277] ? do_raw_spin_lock+0x131/0x280 [ 23.918285][ T277] do_exit.cold+0x82/0x9c [ 23.918289][ T277] ? exit_notify+0x890/0x890 [ 23.918291][ T277] ? __lock_release.isra.0+0x69/0x1a0 [ 23.918293][ T277] ? rcu_is_watching+0x16/0xd0 [ 23.918297][ T277] do_group_exit+0xb8/0x370 [ 23.918301][ T277] __x64_sys_exit_group+0x3c/0x50 [ 23.918303][ T277] x64_sys_call+0x1567/0x1570 [ 23.918306][ T277] do_syscall_64+0xff/0x530 [ 23.918309][ T277] ? exc_page_fault+0xee/0x100 [ 23.918312][ T277] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 23.918314][ T277] RIP: 0033:0x7ff81176b1b8 [ 23.918317][ T277] Code: Unable to access opcode bytes at 0x7ff81176b18e. [ 23.918318][ T277] RSP: 002b:00007ffce8817f48 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7 [ 23.918321][ T277] RAX: ffffffffffffffda RBX: 00007ff81189bf88 RCX: 00007ff81176b1b8 [ 23.918322][ T277] RDX: 00007ff8114b5fc8 RSI: fffffffffffffeb8 RDI: 0000000000000000 [ 23.918323][ T277] RBP: 00007ffce8817fa0 R08: 0000000000000000 R09: 0000000000000050 [ 23.918324][ T277] R10: 00007ffce8817d60 R11: 0000000000000246 R12: 0000000000000001 [ 23.918325][ T277] R13: 0000000000000000 R14: 00007ff81189a680 R15: 00007ff81189bfa0 [ 23.918332][ T277] [ 23.925391][ C0] clocksource: Watchdog remote CPU 2 read timed out [ 23.925417][ C0] [ 23.925418][ C0] ======================================================== [ 23.925419][ C0] WARNING: possible irq lock inversion dependency detected [ 23.925421][ C0] 7.2.0-virtme #1 Tainted: G W [ 23.925422][ C0] -------------------------------------------------------- [ 23.925423][ C0] swapper/0/0 just changed the state of lock: [ 23.925424][ C0] ffffffffa4e89660 (console_owner){..-.}-{0:0}, at: console_trylock_spinning+0xa4/0x1e0 [ 23.925433][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 23.925434][ C0] (fs_reclaim){+.+.}-{0:0} [ 23.925435][ C0] [ 23.925435][ C0] [ 23.925435][ C0] and interrupts could create inverse lock ordering between them. [ 23.925435][ C0] [ 23.925436][ C0] [ 23.925436][ C0] other info that might help us debug this: [ 23.925437][ C0] Possible interrupt unsafe locking scenario: [ 23.925437][ C0] [ 23.925437][ C0] CPU0 CPU1 [ 23.925438][ C0] ---- ---- [ 23.925438][ C0] lock(fs_reclaim); [ 23.925439][ C0] local_irq_disable(); [ 23.925440][ C0] lock(console_owner); [ 23.925441][ C0] lock(fs_reclaim); [ 23.925441][ C0] [ 23.925442][ C0] lock(console_owner); [ 23.925443][ C0] [ 23.925443][ C0] *** DEADLOCK *** [ 23.925443][ C0] [ 23.925443][ C0] locks held by swapper/0/0: 2, last CPU#0: [ 23.925444][ C0] #0: ffa0000000007c90 ((&watchdog_timer)){+.-.}-{0:0}, at: call_timer_fn+0x110/0x4d0 [ 23.925450][ C0] #1: ffffffffa4ffe8b8 (watchdog_lock){+.-.}-{3:3}, at: clocksource_watchdog+0x15/0x30 [ 23.925454][ C0] [ 23.925454][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 23.925459][ C0] -> (fs_reclaim){+.+.}-{0:0} { [ 23.925461][ C0] HARDIRQ-ON-W at: [ 23.925462][ C0] __lock_acquire+0x388/0xc20 [ 23.925464][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925466][ C0] fs_reclaim_acquire+0xd5/0x120 [ 23.925469][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 23.925471][ C0] kthread_create_worker_on_node+0xea/0x210 [ 23.925474][ C0] workqueue_init+0x2a/0x680 [ 23.925478][ C0] kernel_init_freeable+0x2fe/0x630 [ 23.925480][ C0] kernel_init+0x21/0x150 [ 23.925483][ C0] ret_from_fork+0x474/0x6b0 [ 23.925486][ C0] ret_from_fork_asm+0x11/0x20 [ 23.925487][ C0] SOFTIRQ-ON-W at: [ 23.925488][ C0] __lock_acquire+0x388/0xc20 [ 23.925490][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925491][ C0] fs_reclaim_acquire+0xd5/0x120 [ 23.925492][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 23.925493][ C0] kthread_create_worker_on_node+0xea/0x210 [ 23.925495][ C0] workqueue_init+0x2a/0x680 [ 23.925496][ C0] kernel_init_freeable+0x2fe/0x630 [ 23.925497][ C0] kernel_init+0x21/0x150 [ 23.925499][ C0] ret_from_fork+0x474/0x6b0 [ 23.925500][ C0] ret_from_fork_asm+0x11/0x20 [ 23.925501][ C0] INITIAL USE at: [ 23.925502][ C0] __lock_acquire+0x388/0xc20 [ 23.925503][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925504][ C0] fs_reclaim_acquire+0xd5/0x120 [ 23.925506][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 23.925507][ C0] kthread_create_worker_on_node+0xea/0x210 [ 23.925508][ C0] workqueue_init+0x2a/0x680 [ 23.925510][ C0] kernel_init_freeable+0x2fe/0x630 [ 23.925511][ C0] kernel_init+0x21/0x150 [ 23.925512][ C0] ret_from_fork+0x474/0x6b0 [ 23.925514][ C0] ret_from_fork_asm+0x11/0x20 [ 23.925515][ C0] } [ 23.925515][ C0] ... key at: [] __fs_reclaim_map+0x0/0xbe0 [ 23.925519][ C0] ... acquired at: [ 23.925520][ C0] __lock_acquire+0x518/0xc20 [ 23.925522][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925523][ C0] fs_reclaim_acquire+0xd5/0x120 [ 23.925524][ C0] __kmalloc_noprof+0xd3/0x760 [ 23.925525][ C0] alloc_buf.isra.0+0x4b/0x260 [ 23.925527][ C0] put_chars+0x1e1/0x2f0 [ 23.925528][ C0] hvc_console_print+0x292/0x780 [ 23.925530][ C0] console_emit_next_record+0x252/0x4f0 [ 23.925531][ C0] console_flush_one_record+0x46f/0x710 [ 23.925533][ C0] console_unlock+0xee/0x1f0 [ 23.925534][ C0] vprintk_emit+0x37c/0x3e0 [ 23.925535][ C0] _printk+0xc7/0x100 [ 23.925538][ C0] loop_init+0x12a/0x130 [ 23.925541][ C0] do_one_initcall+0x124/0x4f0 [ 23.925543][ C0] kernel_init_freeable+0x596/0x630 [ 23.925544][ C0] kernel_init+0x21/0x150 [ 23.925546][ C0] ret_from_fork+0x474/0x6b0 [ 23.925548][ C0] ret_from_fork_asm+0x11/0x20 [ 23.925549][ C0] [ 23.925549][ C0] -> (console_owner){..-.}-{0:0} { [ 23.925551][ C0] IN-SOFTIRQ-W at: [ 23.925552][ C0] __lock_acquire+0x388/0xc20 [ 23.925553][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925554][ C0] console_trylock_spinning+0xb5/0x1e0 [ 23.925555][ C0] vprintk_emit+0x320/0x3e0 [ 23.925556][ C0] _printk+0xc7/0x100 [ 23.925558][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 23.925560][ C0] call_timer_fn+0x160/0x4d0 [ 23.925562][ C0] __run_timers+0x68f/0xaa0 [ 23.925563][ C0] run_timer_softirq+0xf0/0x160 [ 23.925564][ C0] handle_softirqs+0x1d3/0x900 [ 23.925567][ C0] __irq_exit_rcu+0x145/0x1c0 [ 23.925569][ C0] irq_exit_rcu+0xe/0x30 [ 23.925571][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 23.925572][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 23.925574][ C0] pv_native_safe_halt+0xf/0x10 [ 23.925575][ C0] default_idle+0x9/0x10 [ 23.925577][ C0] default_idle_call+0x6e/0xb0 [ 23.925579][ C0] cpuidle_idle_call.constprop.0+0x237/0x410 [ 23.925581][ C0] do_idle+0xd8/0x190 [ 23.925583][ C0] cpu_startup_entry+0x53/0x70 [ 23.925585][ C0] rest_init+0x279/0x280 [ 23.925586][ C0] start_kernel+0x3af/0x3b0 [ 23.925588][ C0] x86_64_start_reservations+0x24/0x30 [ 23.925590][ C0] x86_64_start_kernel+0x12b/0x130 [ 23.925591][ C0] common_startup_64+0x13e/0x148 [ 23.925593][ C0] INITIAL USE at: [ 23.925594][ C0] } [ 23.925595][ C0] ... key at: [] console_owner_dep_map+0x0/0x60 [ 23.925597][ C0] ... acquired at: [ 23.925598][ C0] mark_lock+0x1d7/0xa00 [ 23.925599][ C0] mark_usage+0x42/0x170 [ 23.925600][ C0] __lock_acquire+0x388/0xc20 [ 23.925601][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925602][ C0] console_trylock_spinning+0xb5/0x1e0 [ 23.925604][ C0] vprintk_emit+0x320/0x3e0 [ 23.925605][ C0] _printk+0xc7/0x100 [ 23.925606][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 23.925608][ C0] call_timer_fn+0x160/0x4d0 [ 23.925609][ C0] __run_timers+0x68f/0xaa0 [ 23.925610][ C0] run_timer_softirq+0xf0/0x160 [ 23.925612][ C0] handle_softirqs+0x1d3/0x900 [ 23.925613][ C0] __irq_exit_rcu+0x145/0x1c0 [ 23.925615][ C0] irq_exit_rcu+0xe/0x30 [ 23.925617][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 23.925618][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 23.925619][ C0] pv_native_safe_halt+0xf/0x10 [ 23.925621][ C0] default_idle+0x9/0x10 [ 23.925622][ C0] default_idle_call+0x6e/0xb0 [ 23.925624][ C0] cpuidle_idle_call.constprop.0+0x237/0x410 [ 23.925625][ C0] do_idle+0xd8/0x190 [ 23.925627][ C0] cpu_startup_entry+0x53/0x70 [ 23.925629][ C0] rest_init+0x279/0x280 [ 23.925630][ C0] start_kernel+0x3af/0x3b0 [ 23.925631][ C0] x86_64_start_reservations+0x24/0x30 [ 23.925633][ C0] x86_64_start_kernel+0x12b/0x130 [ 23.925634][ C0] common_startup_64+0x13e/0x148 [ 23.925635][ C0] [ 23.925636][ C0] [ 23.925636][ C0] stack backtrace: [ 23.925638][ C0] CPU: 0 UID: 0 PID: 0 Comm: swapper/0 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 23.925641][ C0] Tainted: [W]=WARN [ 23.925641][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 23.925642][ C0] Call Trace: [ 23.925643][ C0] [ 23.925644][ C0] dump_stack_lvl+0x6f/0xa0 [ 23.925647][ C0] print_irq_inversion_bug.part.0.cold+0xe6/0x143 [ 23.925649][ C0] mark_lock_irq+0x989/0x9c0 [ 23.925651][ C0] ? add_lock_to_list+0x2c/0x1a0 [ 23.925655][ C0] mark_lock+0x1d7/0xa00 [ 23.925656][ C0] mark_usage+0x42/0x170 [ 23.925658][ C0] __lock_acquire+0x388/0xc20 [ 23.925660][ C0] lock_acquire.part.0+0xd4/0x280 [ 23.925661][ C0] ? console_trylock_spinning+0xa4/0x1e0 [ 23.925663][ C0] ? rcu_is_watching+0x16/0xd0 [ 23.925665][ C0] ? lock_acquire+0x13c/0x160 [ 23.925667][ C0] console_trylock_spinning+0xb5/0x1e0 [ 23.925668][ C0] ? console_trylock_spinning+0xa4/0x1e0 [ 23.925670][ C0] vprintk_emit+0x320/0x3e0 [ 23.925672][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 23.925674][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 23.925676][ C0] _printk+0xc7/0x100 [ 23.925678][ C0] ? snapshot_read.cold+0x21/0x21 [ 23.925680][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 23.925681][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 23.925683][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 23.925685][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 23.925686][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 23.925687][ C0] call_timer_fn+0x160/0x4d0 [ 23.925689][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 23.925691][ C0] ? debug_object_active_state+0x430/0x430 [ 23.925695][ C0] ? find_held_lock+0x2b/0x80 [ 23.925697][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 23.925698][ C0] ? rcu_is_watching+0x16/0xd0 [ 23.925701][ C0] __run_timers+0x68f/0xaa0 [ 23.925702][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 23.925704][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 23.925706][ C0] ? __lock_acquire+0x518/0xc20 [ 23.925708][ C0] ? __rwlock_init+0x150/0x150 [ 23.925710][ C0] run_timer_softirq+0xf0/0x160 [ 23.925712][ C0] ? __run_timers+0xaa0/0xaa0 [ 23.925714][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 23.925717][ C0] ? rcu_is_watching+0x16/0xd0 [ 23.925718][ C0] handle_softirqs+0x1d3/0x900 [ 23.925721][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 23.925722][ C0] ? _local_bh_enable+0xc0/0xc0 [ 23.925725][ C0] __irq_exit_rcu+0x145/0x1c0 [ 23.925727][ C0] irq_exit_rcu+0xe/0x30 [ 23.925729][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 23.925731][ C0] [ 23.925731][ C0] [ 23.925732][ C0] ? lockdep_hardirqs_on_prepare.part.0+0x9a/0x160 [ 23.925733][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 23.925735][ C0] RIP: 0010:pv_native_safe_halt+0xf/0x10 [ 23.925737][ C0] Code: 48 8b 3d 94 e2 f7 01 e8 1f 00 00 00 48 2b 05 58 a3 98 00 c3 0f 1f 80 00 00 00 00 f3 0f 1e fa eb 07 0f 00 2d 13 06 11 00 fb f4 0f 1f 40 d6 48 83 ec 20 8b 17 49 89 f8 83 e2 fe 41 89 d2 0f 01 [ 23.925740][ C0] RSP: 0018:ffffffffa4c07cf8 EFLAGS: 00000296 [ 23.925742][ C0] RAX: 0000000000086aaf RBX: ffffffffa4c1c600 RCX: ffffffffa1ced307 [ 23.925743][ C0] RDX: ffffffffa4c1c600 RSI: ffffffffa4a70974 RDI: ffffffffa448f560 [ 23.925744][ C0] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000 [ 23.925745][ C0] R10: 0000000000000000 R11: 0000000000000001 R12: 1ffffffff4980fa2 [ 23.925746][ C0] R13: 0000000000000000 R14: dffffc0000000000 R15: 0000000000014770 [ 23.925747][ C0] ? cpuidle_idle_call.constprop.0+0x237/0x410 [ 23.925750][ C0] ? lockdep_hardirqs_on+0x91/0x130 [ 23.925752][ C0] default_idle+0x9/0x10 [ 23.925754][ C0] default_idle_call+0x6e/0xb0 [ 23.925755][ C0] cpuidle_idle_call.constprop.0+0x237/0x410 [ 23.925758][ C0] ? arch_cpu_idle_exit+0x40/0x40 [ 23.925760][ C0] ? mark_tsc_async_resets+0x30/0x30 [ 23.925763][ C0] ? rcu_is_watching+0x16/0xd0 [ 23.925765][ C0] do_idle+0xd8/0x190 [ 23.925767][ C0] cpu_startup_entry+0x53/0x70 [ 23.925769][ C0] rest_init+0x279/0x280 [ 23.925771][ C0] ? __cpuidle_text_end+0x3b/0x3b [ 23.925774][ C0] ? rest_init+0x280/0x280 [ 23.925776][ C0] ? acpi_hw_set_mode+0x4a0/0x4a0 [ 23.925779][ C0] ? cpus_read_unlock+0x4f/0xc0 [ 23.925781][ C0] ? acpi_enable+0x1e4/0x330 [ 23.925784][ C0] start_kernel+0x3af/0x3b0 [ 23.925785][ C0] x86_64_start_reservations+0x24/0x30 [ 23.925787][ C0] x86_64_start_kernel+0x12b/0x130 [ 23.925789][ C0] common_startup_64+0x13e/0x148 [ 23.925792][ C0]