virtme: waiting for virtiofsd to start virtme: use 'microvm' QEMU architecture [ 1.100574][ T1] PPP generic driver version 2.4.2 [ 1.100600][ T1] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 1.100602][ T1] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 1, name: swapper/0 [ 1.100604][ T1] preempt_count: 1, expected: 0 [ 1.100604][ T1] RCU nest depth: 0, expected: 0 [ 1.100605][ T1] locks held by swapper/0/1: 4, last CPU#3: [ 1.100607][ T1] #0: ffffffffb4f99dc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 1.100619][ T1] #1: ffffffffb4f99e38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 1.100624][ T1] #2: ffffffffb4e89760 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 1.100628][ T1] #3: ffffffffb4e89660 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 1.100632][ T1] irq event stamp: 352790 [ 1.100633][ T1] hardirqs last enabled at (352789): [] __down_trylock_console_sem+0x86/0xa0 [ 1.100636][ T1] hardirqs last disabled at (352790): [] console_emit_next_record+0x3f8/0x4f0 [ 1.100638][ T1] softirqs last enabled at (352630): [] handle_softirqs+0x67c/0x900 [ 1.100641][ T1] softirqs last disabled at (352621): [] __irq_exit_rcu+0x145/0x1c0 [ 1.100643][ T1] Preemption disabled at: [ 1.100644][ T1] [] vprintk_emit+0x31b/0x3e0 [ 1.100649][ T1] CPU: 3 UID: 0 PID: 1 Comm: swapper/0 Not tainted 7.2.0-virtme #1 PREEMPT(full) [ 1.100651][ T1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 1.100653][ T1] Call Trace: [ 1.100655][ T1] [ 1.100658][ T1] dump_stack_lvl+0x6f/0xa0 [ 1.100663][ T1] ? vprintk_emit+0x31b/0x3e0 [ 1.100666][ T1] __might_resched.cold+0x1fe/0x2c1 [ 1.100670][ T1] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 1.100674][ T1] ? __kmalloc_noprof+0xdb/0x760 [ 1.100679][ T1] __kmalloc_noprof+0x443/0x760 [ 1.100682][ T1] ? alloc_buf.isra.0+0x4b/0x260 [ 1.100688][ T1] ? do_raw_spin_unlock+0x59/0x250 [ 1.100691][ T1] alloc_buf.isra.0+0x4b/0x260 [ 1.100694][ T1] put_chars+0x1e1/0x2f0 [ 1.100696][ T1] ? printk_get_next_message+0x2fe/0x7d0 [ 1.100699][ T1] ? __send_to_port+0x420/0x420 [ 1.100701][ T1] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 1.100705][ T1] ? validate_chain+0x38b/0xc20 [ 1.100711][ T1] hvc_console_print+0x292/0x780 [ 1.100717][ T1] ? hvc_write+0x3a0/0x3a0 [ 1.100720][ T1] ? rcu_is_watching+0x16/0xd0 [ 1.100722][ T1] ? lock_acquire+0x13c/0x160 [ 1.100726][ T1] console_emit_next_record+0x252/0x4f0 [ 1.100730][ T1] ? devkmsg_read+0x4e0/0x4e0 [ 1.100734][ T1] ? rcu_is_watching+0x16/0xd0 [ 1.100736][ T1] ? lock_acquire+0x13c/0x160 [ 1.100740][ T1] console_flush_one_record+0x46f/0x710 [ 1.100744][ T1] ? console_emit_next_record+0x4f0/0x4f0 [ 1.100746][ T1] ? __lock_acquire+0x518/0xc20 [ 1.100751][ T1] console_unlock+0xee/0x1f0 [ 1.100754][ T1] ? console_flush_one_record+0x710/0x710 [ 1.100756][ T1] ? rcu_is_watching+0x16/0xd0 [ 1.100758][ T1] ? lock_acquire+0xa0/0x160 [ 1.100761][ T1] ? __down_trylock_console_sem+0x5e/0xa0 [ 1.100763][ T1] ? vprintk_emit+0x320/0x3e0 [ 1.100766][ T1] vprintk_emit+0x37c/0x3e0 [ 1.100770][ T1] ? wake_up_klogd_work_func+0x90/0x90 [ 1.100775][ T1] ? vxlan_init_module+0x80/0x80 [ 1.100779][ T1] _printk+0xc7/0x100 [ 1.100782][ T1] ? snapshot_read.cold+0x21/0x21 [ 1.100784][ T1] ? add_chain_block+0x1e0/0x5b0 [ 1.100786][ T1] ? _raw_spin_unlock_irqrestore+0x40/0x80 [ 1.100791][ T1] ? add_device_randomness+0xbb/0x100 [ 1.100793][ T1] ? random_write_iter+0x20/0x20 [ 1.100796][ T1] ? phy_module_init+0x20/0x20 [ 1.100798][ T1] ? do_one_initcall+0x113/0x4f0 [ 1.100801][ T1] ppp_init+0x16/0x100 [ 1.100802][ T1] do_one_initcall+0x124/0x4f0 [ 1.100805][ T1] ? trace_event_raw_event_initcall_level+0x280/0x280 [ 1.100806][ T1] ? parameq+0x110/0x110 [ 1.100812][ T1] ? kernel_init_freeable+0x3f1/0x630 [ 1.100815][ T1] ? rcu_is_watching+0x16/0xd0 [ 1.100819][ T1] kernel_init_freeable+0x596/0x630 [ 1.100822][ T1] ? rest_init+0x280/0x280 [ 1.100825][ T1] kernel_init+0x21/0x150 [ 1.100826][ T1] ? rest_init+0x280/0x280 [ 1.100827][ T1] ret_from_fork+0x474/0x6b0 [ 1.100831][ T1] ? arch_exit_to_user_mode_prepare.isra.0+0x120/0x120 [ 1.100834][ T1] ? __switch_to+0x5a3/0xe00 [ 1.100838][ T1] ? rest_init+0x280/0x280 [ 1.100840][ T1] ret_from_fork_asm+0x11/0x20 [ 1.100847][ T1] [ 1.117764][ T1] NET: Registered PF_PPPOX protocol family [ 1.118660][ T1] i8042: PNP: No PS/2 controller found. [ 1.127403][ T1] rtc_cmos PNP0B00:00: registered as rtc0 [ 1.127819][ T1] rtc_cmos PNP0B00:00: setting system clock to 2026-08-28T08:29:00 UTC (1787905740) [ 1.128725][ T1] rtc_cmos PNP0B00:00: alarms up to one day, 242 bytes nvram [ 1.131485][ T1] device-mapper: ioctl: 4.50.0-ioctl (2025-04-28) initialised: dm-devel@lists.linux.dev [ 1.137733][ T1] ipip: IPv4 and MPLS over IPv4 tunneling driver [ 1.140698][ T1] gre: GRE over IPv4 demultiplexer driver [ 1.140877][ T1] ip_gre: GRE over IPv4 tunneling driver [ 1.149233][ T1] Initializing XFRM netlink socket [ 1.149827][ T1] NET: Registered PF_INET6 protocol family [ 1.156177][ T1] Segment Routing with IPv6 [ 1.156595][ T1] In-situ OAM (IOAM) with IPv6 [ 1.156922][ T1] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver [ 1.163859][ T1] ip6_gre: GRE over IPv6 tunneling driver [ 1.167317][ T1] NET: Registered PF_PACKET protocol family [ 1.167630][ T1] 9pnet: Installing 9P2000 support [ 1.168023][ T1] Key type dns_resolver registered [ 1.168834][ T1] NET: Registered PF_VSOCK protocol family [ 1.173254][ T1] IPI shorthand broadcast: enabled [ 1.279102][ T1] sched_clock: Marking stable (1245001267, 33376895)->(1381840073, -103461911) [ 1.281482][ T1] registered taskstats version 1 [ 1.283546][ T1] Loading compiled-in X.509 certificates [ 1.383218][ T1] Demotion targets for Node 0: null [ 1.383536][ T1] kmemleak: Kernel memory leak detector initialized (mem pool available: 11962) [ 1.383842][ T1] page_owner is disabled [ 1.392959][ T1] PM: Magic number: 6:889:473 [ 1.395235][ T1] ALSA device list: [ 1.395866][ T1] No soundcards found. [ 1.397018][ T1] md: Skipping autodetection of RAID arrays. (raid=autodetect will force) [ 1.399725][ T1] VFS: Mounted root (virtiofs filesystem) readonly on device 0:24. [ 1.400470][ T1] devtmpfs: mounted [ 1.400780][ T1] VFS: Pivoted into new rootfs [ 1.413890][ T71] kwatchdog (71) used greatest stack depth: 29688 bytes left [ 1.428988][ T1] Freeing unused kernel image (initmem) memory: 2576K [ 1.429230][ T1] Write protecting the kernel read-only data: 63488k [ 1.429910][ T1] Freeing unused kernel image (text/rodata gap) memory: 864K [ 1.430522][ T1] Freeing unused kernel image (rodata/data gap) memory: 1116K [ 1.430790][ T1] Run /usr/lib/python3.14/site-packages/virtme/guest/bin/virtme-ng-init as init process [ 1.431104][ T1] with arguments: [ 1.431282][ T1] /usr/lib/python3.14/site-packages/virtme/guest/bin/virtme-ng-init [ 1.431584][ T1] with environment: [ 1.431709][ T1] HOME=/ [ 1.431830][ T1] TERM=dumb [ 1.431996][ T1] virtme_hostname=vmksft-drv-hw-dbg,debug-threads=on [ 1.432194][ T1] nr_open=2147483584 [ 1.432364][ T1] virtme_link_mods=/srv/vmksft/testing/wt-22/.virtme_mods/lib/modules/0.0.0 [ 1.432695][ T1] virtme_rw_overlay0=/etc [ 1.432850][ T1] virtme_rw_overlay1=/lib [ 1.433006][ T1] virtme_rw_overlay2=/home [ 1.433218][ T1] virtme_rw_overlay3=/opt [ 1.433369][ T1] virtme_rw_overlay4=/srv [ 1.436035][ T1] virtme_rw_overlay5=/usr [ 1.436196][ T1] virtme_rw_overlay6=/var [ 1.436356][ T1] virtme_rw_overlay7=/tmp [ 1.436807][ T1] virtme_console=ttyS0 [ 1.436999][ T1] virtme_chdir=srv/vmksft/testing/wt-22 [ 1.453595][ T1] virtme-ng-init: mount devtmpfs -> /dev: EBUSY: Device or resource busy [ 1.455098][ T1] virtme-ng-init: Setting hostname to vmksft-drv-hw-dbg,debug-threads=on... [ 1.464299][ T1] overlayfs: failed to set xattr on upper [ 1.464560][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.464861][ T1] overlayfs: ...falling back to uuid=null. [ 1.467097][ T1] overlayfs: failed to set xattr on upper [ 1.467298][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.467619][ T1] overlayfs: ...falling back to uuid=null. [ 1.469450][ T1] overlayfs: failed to set xattr on upper [ 1.469650][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.469888][ T1] overlayfs: ...falling back to uuid=null. [ 1.471717][ T1] overlayfs: failed to set xattr on upper [ 1.471926][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.472161][ T1] overlayfs: ...falling back to uuid=null. [ 1.473974][ T1] overlayfs: failed to set xattr on upper [ 1.474172][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.474664][ T1] overlayfs: ...falling back to uuid=null. [ 1.476256][ T1] overlayfs: failed to set xattr on upper [ 1.476457][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.476700][ T1] overlayfs: ...falling back to uuid=null. [ 1.478480][ T1] overlayfs: failed to set xattr on upper [ 1.478688][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.478929][ T1] overlayfs: ...falling back to uuid=null. [ 1.481108][ T1] overlayfs: failed to set xattr on upper [ 1.481310][ T1] overlayfs: ...falling back to redirect_dir=nofollow. [ 1.481565][ T1] overlayfs: ...falling back to uuid=null. [ 1.492484][ T1] virtme-ng-init: running systemd-tmpfiles [ 3.478837][ T72] systemd-tmpfile (72) used greatest stack depth: 25104 bytes left [ 3.478854][ T72] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 3.478856][ T72] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 72, name: systemd-tmpfile [ 3.478858][ T72] preempt_count: 2, expected: 0 [ 3.478859][ T72] RCU nest depth: 0, expected: 0 [ 3.478860][ T72] locks held by systemd-tmpfile/72: 5, last CPU#1: [ 3.478862][ T72] #0: ffffffffb4e027b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 3.478873][ T72] #1: ffffffffb4f99dc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 3.478878][ T72] #2: ffffffffb4f99e38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 3.478882][ T72] #3: ffffffffb4e89760 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 3.478885][ T72] #4: ffffffffb4e89660 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 3.478889][ T72] irq event stamp: 2305788 [ 3.478890][ T72] hardirqs last enabled at (2305787): [] __down_trylock_console_sem+0x86/0xa0 [ 3.478892][ T72] hardirqs last disabled at (2305788): [] console_emit_next_record+0x3f8/0x4f0 [ 3.478894][ T72] softirqs last enabled at (2304892): [] handle_softirqs+0x67c/0x900 [ 3.478897][ T72] softirqs last disabled at (2304783): [] __irq_exit_rcu+0x145/0x1c0 [ 3.478899][ T72] Preemption disabled at: [ 3.478900][ T72] [<0000000000000000>] 0x0 [ 3.478906][ T72] CPU: 1 UID: 0 PID: 72 Comm: systemd-tmpfile Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 3.478910][ T72] Tainted: [W]=WARN [ 3.478911][ T72] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 3.478912][ T72] Call Trace: [ 3.478914][ T72] [ 3.478915][ T72] dump_stack_lvl+0x6f/0xa0 [ 3.478921][ T72] __might_resched.cold+0x1fe/0x2c1 [ 3.478926][ T72] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 3.478930][ T72] ? __kmalloc_noprof+0xdb/0x760 [ 3.478935][ T72] __kmalloc_noprof+0x443/0x760 [ 3.478937][ T72] ? alloc_buf.isra.0+0x4b/0x260 [ 3.478944][ T72] ? do_raw_spin_unlock+0x59/0x250 [ 3.478946][ T72] alloc_buf.isra.0+0x4b/0x260 [ 3.478950][ T72] put_chars+0x1e1/0x2f0 [ 3.478953][ T72] ? __send_to_port+0x420/0x420 [ 3.478955][ T72] ? printk_get_next_message+0x2fe/0x7d0 [ 3.478958][ T72] ? rcu_read_lock_any_held+0x3c/0x90 [ 3.478961][ T72] ? validate_chain+0x38b/0xc20 [ 3.478965][ T72] hvc_console_print+0x292/0x780 [ 3.478968][ T72] ? __lock_acquire+0x518/0xc20 [ 3.478970][ T72] ? __lock_acquire+0x518/0xc20 [ 3.478974][ T72] ? hvc_write+0x3a0/0x3a0 [ 3.478977][ T72] ? rcu_is_watching+0x16/0xd0 [ 3.478981][ T72] ? lock_acquire+0x13c/0x160 [ 3.478985][ T72] console_emit_next_record+0x252/0x4f0 [ 3.478988][ T72] ? devkmsg_read+0x4e0/0x4e0 [ 3.478992][ T72] ? rcu_is_watching+0x16/0xd0 [ 3.478995][ T72] ? lock_acquire+0x13c/0x160 [ 3.478998][ T72] console_flush_one_record+0x46f/0x710 [ 3.479002][ T72] ? console_emit_next_record+0x4f0/0x4f0 [ 3.479004][ T72] ? __lock_acquire+0x518/0xc20 [ 3.479009][ T72] console_unlock+0xee/0x1f0 [ 3.479012][ T72] ? console_flush_one_record+0x710/0x710 [ 3.479013][ T72] ? rcu_is_watching+0x16/0xd0 [ 3.479016][ T72] ? lock_acquire+0xa0/0x160 [ 3.479019][ T72] ? __down_trylock_console_sem+0x5e/0xa0 [ 3.479021][ T72] ? vprintk_emit+0x320/0x3e0 [ 3.479024][ T72] vprintk_emit+0x37c/0x3e0 [ 3.479027][ T72] ? wake_up_klogd_work_func+0x90/0x90 [ 3.479031][ T72] ? __lock_acquire+0x518/0xc20 [ 3.479033][ T1] virtme-ng-init: Failed to read '/usr/lib/tmpfiles.d/audit.conf': Permission denied [ 3.479033][ T1] Failed to create directory or subvolume "/var/spool/at/spool": Permission denied [ 3.479033][ T1] Failed to create file /var/spool/at/.SEQ: Permission denied [ 3.479033][ T1] Failed to opendir() '/proc/self/fd/6': Permission denied [ 3.479034][ T72] _printk+0xc7/0x100 [ 3.479038][ T72] ? snapshot_read.cold+0x21/0x21 [ 3.479040][ T72] ? do_raw_spin_lock+0x131/0x280 [ 3.479043][ T72] ? __rwlock_init+0x150/0x150 [ 3.479046][ T72] ? do_raw_spin_lock+0x131/0x280 [ 3.479049][ T72] do_exit.cold+0x82/0x9c [ 3.479053][ T72] ? exit_notify+0x890/0x890 [ 3.479054][ T72] ? __lock_release.isra.0+0x69/0x1a0 [ 3.479056][ T72] ? rcu_is_watching+0x16/0xd0 [ 3.479060][ T72] do_group_exit+0xb8/0x370 [ 3.479063][ T72] __x64_sys_exit_group+0x3c/0x50 [ 3.479065][ T72] x64_sys_call+0x1567/0x1570 [ 3.479067][ T72] do_syscall_64+0xff/0x530 [ 3.479070][ T72] ? exc_page_fault+0xee/0x100 [ 3.479074][ T72] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 3.479076][ T72] RIP: 0033:0x7f6c9a34a1b8 [ 3.479078][ T72] Code: Unable to access opcode bytes at 0x7f6c9a34a18e. [ 3.479079][ T72] RSP: 002b:00007ffe298a23b8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7 [ 3.479082][ T72] RAX: ffffffffffffffda RBX: 00007f6c9a47af88 RCX: 00007f6c9a34a1b8 [ 3.479083][ T72] RDX: 00007f6c99ba84c8 RSI: fffffffffffffe90 RDI: 0000000000000049 [ 3.479084][ T72] RBP: 00007ffe298a2410 R08: 0000000000000000 R09: 0000000000001000 [ 3.479085][ T72] R10: 00007ffe298a21d0 R11: 0000000000000246 R12: 0000000000000001 [ 3.479085][ T72] R13: 0000000000000049 R14: 00007f6c9a479680 R15: 00007f6c9a47afa0 [ 3.479092][ T72] [ 3.495939][ T1] virtme-ng-init: basic initialization done [ 3.506684][ T75] virtme-ng-init (75) used greatest stack depth: 24864 bytes left [ 3.547534][ T77] ip (77) used greatest stack depth: 23784 bytes left [ 3.556862][ T74] virtme-ng-init: Starting systemd-udevd version 259.8-1.fc44 [ 3.557227][ T74] virtme-ng-init: triggering udev coldplug [ 5.626169][ T85] virtio_net virtio2 enp0s1: renamed from eth0 [ 5.626224][ T85] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 5.626226][ T85] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 85, name: (udev-worker) [ 5.626228][ T85] preempt_count: 1, expected: 0 [ 5.626229][ T85] RCU nest depth: 0, expected: 0 [ 5.626230][ T85] locks held by (udev-worker)/85: 5, last CPU#2: [ 5.626232][ T85] #0: ffffffffb5712c80 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_setlink+0x29d/0x920 [ 5.626244][ T85] #1: ffffffffb4f99dc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 5.626251][ T85] #2: ffffffffb4f99e38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 5.626255][ T85] #3: ffffffffb4e89760 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 5.626259][ T85] #4: ffffffffb4e89660 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 5.626263][ T85] irq event stamp: 223398 [ 5.626264][ T85] hardirqs last enabled at (223397): [] __down_trylock_console_sem+0x86/0xa0 [ 5.626266][ T85] hardirqs last disabled at (223398): [] console_emit_next_record+0x3f8/0x4f0 [ 5.626268][ T85] softirqs last enabled at (223392): [] netif_change_name+0x216/0x8c0 [ 5.626271][ T85] softirqs last disabled at (223390): [] netif_change_name+0x1ad/0x8c0 [ 5.626273][ T85] Preemption disabled at: [ 5.626274][ T85] [] vprintk_emit+0x31b/0x3e0 [ 5.626279][ T85] CPU: 2 UID: 0 PID: 85 Comm: (udev-worker) Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 5.626283][ T85] Tainted: [W]=WARN [ 5.626284][ T85] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 5.626285][ T85] Call Trace: [ 5.626287][ T85] [ 5.626289][ T85] dump_stack_lvl+0x6f/0xa0 [ 5.626294][ T85] ? vprintk_emit+0x31b/0x3e0 [ 5.626297][ T85] __might_resched.cold+0x1fe/0x2c1 [ 5.626302][ T85] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 5.626306][ T85] ? __kmalloc_noprof+0xdb/0x760 [ 5.626311][ T85] __kmalloc_noprof+0x443/0x760 [ 5.626314][ T85] ? alloc_buf.isra.0+0x4b/0x260 [ 5.626320][ T85] ? do_raw_spin_unlock+0x59/0x250 [ 5.626323][ T85] alloc_buf.isra.0+0x4b/0x260 [ 5.626327][ T85] put_chars+0x1e1/0x2f0 [ 5.626330][ T85] ? __send_to_port+0x420/0x420 [ 5.626334][ T85] ? validate_chain+0x34a/0xc20 [ 5.626339][ T85] hvc_console_print+0x292/0x780 [ 5.626343][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626348][ T85] ? hvc_write+0x3a0/0x3a0 [ 5.626352][ T85] ? rcu_is_watching+0x16/0xd0 [ 5.626359][ T85] console_emit_next_record+0x252/0x4f0 [ 5.626362][ T85] ? devkmsg_read+0x4e0/0x4e0 [ 5.626367][ T85] ? rcu_is_watching+0x16/0xd0 [ 5.626369][ T85] ? lock_acquire+0x13c/0x160 [ 5.626374][ T85] console_flush_one_record+0x46f/0x710 [ 5.626380][ T85] ? console_emit_next_record+0x4f0/0x4f0 [ 5.626382][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626388][ T85] console_unlock+0xee/0x1f0 [ 5.626391][ T85] ? console_flush_one_record+0x710/0x710 [ 5.626393][ T85] ? rcu_is_watching+0x16/0xd0 [ 5.626395][ T85] ? lock_acquire+0xa0/0x160 [ 5.626399][ T85] ? __down_trylock_console_sem+0x5e/0xa0 [ 5.626401][ T85] ? vprintk_emit+0x320/0x3e0 [ 5.626404][ T85] vprintk_emit+0x37c/0x3e0 [ 5.626408][ T85] ? wake_up_klogd_work_func+0x90/0x90 [ 5.626410][ T85] ? write_profile+0xf0/0xf0 [ 5.626413][ T85] ? unwind_get_return_address+0x67/0xd0 [ 5.626419][ T85] dev_vprintk_emit+0x27f/0x2c0 [ 5.626424][ T85] ? device_rename.cold+0xa/0xa [ 5.626428][ T85] ? filter_irq_stacks+0xd0/0xd0 [ 5.626434][ T85] dev_printk_emit+0xb9/0xee [ 5.626436][ T85] ? dev_vprintk_emit+0x2c0/0x2c0 [ 5.626440][ T85] ? check_prev_add+0x316/0xe90 [ 5.626446][ T85] __netdev_printk+0x160/0x1d0 [ 5.626452][ T85] netdev_info+0xe2/0x116 [ 5.626454][ T85] ? netdev_notice+0x120/0x120 [ 5.626457][ T85] ? find_held_lock+0x2b/0x80 [ 5.626460][ T85] ? __lock_release.isra.0+0x69/0x1a0 [ 5.626463][ T85] ? mark_held_locks+0x40/0x70 [ 5.626467][ T85] ? do_setlink.isra.0+0x1f7d/0x2a60 [ 5.626470][ T85] netif_change_name.cold+0x4f/0x89 [ 5.626472][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626474][ T85] ? add_chain_block+0x1e7/0x5b0 [ 5.626476][ T85] ? static_obj+0x52/0x90 [ 5.626479][ T85] ? netdev_adjacent_rename_links+0x470/0x470 [ 5.626481][ T85] ? lock_acquire.part.0+0xd4/0x280 [ 5.626483][ T85] ? find_held_lock+0x2b/0x80 [ 5.626486][ T85] ? __asan_memset+0x27/0x50 [ 5.626491][ T85] do_setlink.isra.0+0x1f7d/0x2a60 [ 5.626494][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626497][ T85] ? rtnl_link_get_size+0x350/0x350 [ 5.626498][ T85] ? mark_usage+0x61/0x170 [ 5.626500][ T85] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 5.626503][ T85] ? rcu_read_lock_any_held+0x3c/0x90 [ 5.626505][ T85] ? validate_chain+0x38b/0xc20 [ 5.626510][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626514][ T85] ? lock_acquire.part.0+0xd4/0x280 [ 5.626516][ T85] ? osq_unlock+0x91/0x310 [ 5.626518][ T85] ? rtnl_setlink+0x29d/0x920 [ 5.626520][ T85] ? osq_lock+0x580/0x580 [ 5.626524][ T85] ? rcu_is_watching+0x16/0xd0 [ 5.626526][ T85] ? trace_contention_end+0xb3/0x180 [ 5.626530][ T85] ? __mutex_lock+0x9a3/0x1ea0 [ 5.626533][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626535][ T85] ? rtnl_setlink+0x29d/0x920 [ 5.626539][ T85] ? ww_mutex_lock+0x160/0x160 [ 5.626546][ T85] ? nla_get_range_signed+0x3d0/0x3d0 [ 5.626552][ T85] ? mark_usage+0x61/0x170 [ 5.626556][ T85] ? cap_capable+0x1d7/0x3d0 [ 5.626563][ T85] rtnl_setlink+0x527/0x920 [ 5.626566][ T85] ? __rtnl_newlink+0xa50/0xa50 [ 5.626568][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626591][ T85] ? lock_acquire.part.0+0xd4/0x280 [ 5.626593][ T85] ? find_held_lock+0x2b/0x80 [ 5.626595][ T85] ? __lock_release.isra.0+0x69/0x1a0 [ 5.626597][ T85] ? mark_usage+0x61/0x170 [ 5.626600][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626604][ T85] ? lock_acquire.part.0+0xd4/0x280 [ 5.626606][ T85] ? find_held_lock+0x2b/0x80 [ 5.626608][ T85] ? __rtnl_newlink+0xa50/0xa50 [ 5.626610][ T85] ? __lock_release.isra.0+0x69/0x1a0 [ 5.626614][ T85] ? __rtnl_newlink+0xa50/0xa50 [ 5.626616][ T85] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 5.626620][ T85] ? rtnl_link_fill+0x900/0x900 [ 5.626622][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626626][ T85] ? lock_acquire.part.0+0xd4/0x280 [ 5.626628][ T85] ? find_held_lock+0x2b/0x80 [ 5.626631][ T85] netlink_rcv_skb+0x14e/0x3a0 [ 5.626635][ T85] ? rtnl_link_fill+0x900/0x900 [ 5.626638][ T85] ? netlink_ack+0xcd0/0xcd0 [ 5.626645][ T85] ? netlink_deliver_tap+0xc5/0x330 [ 5.626647][ T85] ? netlink_deliver_tap+0x13c/0x330 [ 5.626652][ T85] netlink_unicast+0x486/0x750 [ 5.626656][ T85] ? netlink_attachskb+0x810/0x810 [ 5.626658][ T85] ? __lock_acquire+0x518/0xc20 [ 5.626661][ T85] ? do_raw_spin_unlock+0x21/0x250 [ 5.626665][ T85] netlink_sendmsg+0x735/0xc60 [ 5.626669][ T85] ? netlink_unicast+0x750/0x750 [ 5.626673][ T85] ? __might_fault+0x97/0x140 [ 5.626677][ T85] ? __might_fault+0x97/0x140 [ 5.626681][ T85] __sys_sendto+0x2aa/0x400 [ 5.626684][ T85] ? __ia32_sys_getpeername+0xd0/0xd0 [ 5.626695][ T85] ? exc_page_fault+0x87/0x100 [ 5.626701][ T85] __x64_sys_sendto+0xe4/0x1f0 [ 5.626703][ T85] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 5.626706][ T85] ? lockdep_hardirqs_on+0x91/0x130 [ 5.626708][ T85] ? do_syscall_64+0xa6/0x530 [ 5.626710][ T85] do_syscall_64+0xff/0x530 [ 5.626712][ T85] ? exc_page_fault+0xee/0x100 [ 5.626715][ T85] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 5.626717][ T85] RIP: 0033:0x7f4af8bfd54e [ 5.626721][ T85] Code: 4d 89 d8 e8 b4 bd 00 00 4c 8b 5d f8 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 74 11 c9 c3 0f 1f 80 00 00 00 00 48 8b 45 10 0f 05 c3 83 e2 39 83 fa 08 75 e7 e8 03 ff ff ff 0f 1f 00 f3 0f 1e fa [ 5.626722][ T85] RSP: 002b:00007ffc4d8b0410 EFLAGS: 00000202 ORIG_RAX: 000000000000002c [ 5.626725][ T85] RAX: ffffffffffffffda RBX: 000055ffe2083f50 RCX: 00007f4af8bfd54e [ 5.626726][ T85] RDX: 000000000000002c RSI: 000055ffe21e9a30 RDI: 000000000000001a [ 5.626727][ T85] RBP: 00007ffc4d8b0420 R08: 00007ffc4d8b0470 R09: 0000000000000080 [ 5.626728][ T85] R10: 0000000000000000 R11: 0000000000000202 R12: 000055ffe21ed970 [ 5.626729][ T85] R13: 00007ffc4d8b0554 R14: 0000000000000000 R15: 0000000000000000 [ 5.626736][ T85] [ 5.683346][ T89] virtio_net virtio3 enp0s2: renamed from eth1 [ 5.702501][ T74] virtme-ng-init: waiting for udev to settle [ 6.350206][ T74] virtme-ng-init: udev is done [ 6.353016][ T1] virtme-ng-init: initialization done [ 9.909511][ C0] clocksource: Watchdog remote CPU 2 read timed out [ 9.909553][ C0] [ 9.909555][ C0] ======================================================== [ 9.909556][ C0] WARNING: possible irq lock inversion dependency detected [ 9.909558][ C0] 7.2.0-virtme #1 Tainted: G W [ 9.909559][ C0] -------------------------------------------------------- [ 9.909560][ C0] env/149 just changed the state of lock: [ 9.909561][ C0] ffffffffb4e89760 (console_owner){..-.}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 9.909578][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 9.909579][ C0] (fs_reclaim){+.+.}-{0:0} [ 9.909581][ C0] [ 9.909581][ C0] [ 9.909581][ C0] and interrupts could create inverse lock ordering between them. [ 9.909581][ C0] [ 9.909582][ C0] [ 9.909582][ C0] other info that might help us debug this: [ 9.909582][ C0] Possible interrupt unsafe locking scenario: [ 9.909582][ C0] [ 9.909583][ C0] CPU0 CPU1 [ 9.909584][ C0] ---- ---- [ 9.909584][ C0] lock(fs_reclaim); [ 9.909585][ C0] local_irq_disable(); [ 9.909586][ C0] lock(console_owner); [ 9.909587][ C0] lock(fs_reclaim); [ 9.909588][ C0] [ 9.909588][ C0] lock(console_owner); [ 9.909589][ C0] [ 9.909589][ C0] *** DEADLOCK *** [ 9.909589][ C0] [ 9.909589][ C0] locks held by env/149: 8, last CPU#0: [ 9.909590][ C0] #0: ff110000053b20a0 (&tty->ldisc_sem){++++}-{0:0}, at: tty_ldisc_ref_wait+0x28/0x80 [ 9.909596][ C0] #1: ff110000053b2128 (&tty->atomic_write_lock){+.+.}-{4:4}, at: iterate_tty_write+0x9f/0x590 [ 9.909600][ C0] #2: ff110000053b22c8 (&tty->termios_rwsem){++++}-{4:4}, at: n_tty_write+0x1ad/0x8f0 [ 9.909604][ C0] #3: ffa000000009b370 (&ldata->output_lock){+.+.}-{4:4}, at: n_tty_write+0x372/0x8f0 [ 9.909607][ C0] #4: ffa0000000007c90 ((&watchdog_timer)){+.-.}-{0:0}, at: call_timer_fn+0x110/0x4d0 [ 9.909612][ C0] #5: ffffffffb4ffe9f8 (watchdog_lock){+.-.}-{3:3}, at: clocksource_watchdog+0x15/0x30 [ 9.909615][ C0] #6: ffffffffb4f99dc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 9.909619][ C0] #7: ffffffffb4f99e38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 9.909622][ C0] [ 9.909622][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 9.909626][ C0] -> (fs_reclaim){+.+.}-{0:0} { [ 9.909629][ C0] HARDIRQ-ON-W at: [ 9.909630][ C0] __lock_acquire+0x388/0xc20 [ 9.909633][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909634][ C0] fs_reclaim_acquire+0xd5/0x120 [ 9.909637][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 9.909640][ C0] kthread_create_worker_on_node+0xea/0x210 [ 9.909643][ C0] workqueue_init+0x2a/0x680 [ 9.909646][ C0] kernel_init_freeable+0x2fe/0x630 [ 9.909649][ C0] kernel_init+0x21/0x150 [ 9.909652][ C0] ret_from_fork+0x474/0x6b0 [ 9.909655][ C0] ret_from_fork_asm+0x11/0x20 [ 9.909658][ C0] SOFTIRQ-ON-W at: [ 9.909659][ C0] __lock_acquire+0x388/0xc20 [ 9.909660][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909661][ C0] fs_reclaim_acquire+0xd5/0x120 [ 9.909663][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 9.909664][ C0] kthread_create_worker_on_node+0xea/0x210 [ 9.909665][ C0] workqueue_init+0x2a/0x680 [ 9.909667][ C0] kernel_init_freeable+0x2fe/0x630 [ 9.909668][ C0] kernel_init+0x21/0x150 [ 9.909669][ C0] ret_from_fork+0x474/0x6b0 [ 9.909670][ C0] ret_from_fork_asm+0x11/0x20 [ 9.909671][ C0] INITIAL USE at: [ 9.909672][ C0] __lock_acquire+0x388/0xc20 [ 9.909673][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909674][ C0] fs_reclaim_acquire+0xd5/0x120 [ 9.909676][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 9.909677][ C0] kthread_create_worker_on_node+0xea/0x210 [ 9.909679][ C0] workqueue_init+0x2a/0x680 [ 9.909680][ C0] kernel_init_freeable+0x2fe/0x630 [ 9.909681][ C0] kernel_init+0x21/0x150 [ 9.909682][ C0] ret_from_fork+0x474/0x6b0 [ 9.909683][ C0] ret_from_fork_asm+0x11/0x20 [ 9.909684][ C0] } [ 9.909685][ C0] ... key at: [] __fs_reclaim_map+0x0/0xbe0 [ 9.909689][ C0] ... acquired at: [ 9.909690][ C0] __lock_acquire+0x518/0xc20 [ 9.909691][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909692][ C0] fs_reclaim_acquire+0xd5/0x120 [ 9.909694][ C0] __kmalloc_noprof+0xd3/0x760 [ 9.909695][ C0] alloc_buf.isra.0+0x4b/0x260 [ 9.909698][ C0] put_chars+0x1e1/0x2f0 [ 9.909700][ C0] hvc_console_print+0x292/0x780 [ 9.909702][ C0] console_emit_next_record+0x252/0x4f0 [ 9.909704][ C0] console_flush_one_record+0x46f/0x710 [ 9.909705][ C0] console_unlock+0xee/0x1f0 [ 9.909707][ C0] vprintk_emit+0x37c/0x3e0 [ 9.909708][ C0] _printk+0xc7/0x100 [ 9.909711][ C0] ppp_init+0x16/0x100 [ 9.909714][ C0] do_one_initcall+0x124/0x4f0 [ 9.909715][ C0] kernel_init_freeable+0x596/0x630 [ 9.909716][ C0] kernel_init+0x21/0x150 [ 9.909717][ C0] ret_from_fork+0x474/0x6b0 [ 9.909718][ C0] ret_from_fork_asm+0x11/0x20 [ 9.909719][ C0] [ 9.909720][ C0] -> (console_owner){..-.}-{0:0} { [ 9.909722][ C0] IN-SOFTIRQ-W at: [ 9.909722][ C0] __lock_acquire+0x388/0xc20 [ 9.909724][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909725][ C0] console_lock_spinning_enable+0x5c/0x60 [ 9.909727][ C0] console_emit_next_record+0x1f4/0x4f0 [ 9.909728][ C0] console_flush_one_record+0x46f/0x710 [ 9.909730][ C0] console_unlock+0xee/0x1f0 [ 9.909731][ C0] vprintk_emit+0x37c/0x3e0 [ 9.909732][ C0] _printk+0xc7/0x100 [ 9.909734][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 9.909736][ C0] call_timer_fn+0x160/0x4d0 [ 9.909737][ C0] __run_timers+0x68f/0xaa0 [ 9.909739][ C0] run_timer_softirq+0xf0/0x160 [ 9.909740][ C0] handle_softirqs+0x1d3/0x900 [ 9.909743][ C0] __irq_exit_rcu+0x145/0x1c0 [ 9.909744][ C0] irq_exit_rcu+0xe/0x30 [ 9.909745][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 9.909748][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 9.909750][ C0] _raw_spin_unlock_irqrestore+0x36/0x80 [ 9.909752][ C0] uart_write_room+0x29f/0x810 [ 9.909753][ C0] n_tty_write+0x37a/0x8f0 [ 9.909754][ C0] iterate_tty_write+0x291/0x590 [ 9.909756][ C0] file_tty_write.isra.0+0x1bd/0x290 [ 9.909757][ C0] new_sync_write+0x33e/0x760 [ 9.909759][ C0] vfs_write+0x6a2/0xbd0 [ 9.909761][ C0] ksys_write+0x116/0x250 [ 9.909762][ C0] do_syscall_64+0xff/0x530 [ 9.909763][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 9.909764][ C0] INITIAL USE at: [ 9.909765][ C0] } [ 9.909766][ C0] ... key at: [] console_owner_dep_map+0x0/0x60 [ 9.909769][ C0] ... acquired at: [ 9.909769][ C0] mark_lock+0x1d7/0xa00 [ 9.909770][ C0] mark_usage+0x42/0x170 [ 9.909771][ C0] __lock_acquire+0x388/0xc20 [ 9.909773][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909774][ C0] console_lock_spinning_enable+0x5c/0x60 [ 9.909775][ C0] console_emit_next_record+0x1f4/0x4f0 [ 9.909777][ C0] console_flush_one_record+0x46f/0x710 [ 9.909778][ C0] console_unlock+0xee/0x1f0 [ 9.909780][ C0] vprintk_emit+0x37c/0x3e0 [ 9.909781][ C0] _printk+0xc7/0x100 [ 9.909783][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 9.909784][ C0] call_timer_fn+0x160/0x4d0 [ 9.909785][ C0] __run_timers+0x68f/0xaa0 [ 9.909786][ C0] run_timer_softirq+0xf0/0x160 [ 9.909788][ C0] handle_softirqs+0x1d3/0x900 [ 9.909789][ C0] __irq_exit_rcu+0x145/0x1c0 [ 9.909790][ C0] irq_exit_rcu+0xe/0x30 [ 9.909791][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 9.909793][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 9.909794][ C0] _raw_spin_unlock_irqrestore+0x36/0x80 [ 9.909795][ C0] uart_write_room+0x29f/0x810 [ 9.909796][ C0] n_tty_write+0x37a/0x8f0 [ 9.909798][ C0] iterate_tty_write+0x291/0x590 [ 9.909799][ C0] file_tty_write.isra.0+0x1bd/0x290 [ 9.909801][ C0] new_sync_write+0x33e/0x760 [ 9.909801][ C0] vfs_write+0x6a2/0xbd0 [ 9.909802][ C0] ksys_write+0x116/0x250 [ 9.909803][ C0] do_syscall_64+0xff/0x530 [ 9.909805][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 9.909806][ C0] [ 9.909806][ C0] [ 9.909806][ C0] stack backtrace: [ 9.909809][ C0] CPU: 0 UID: 0 PID: 149 Comm: env Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 9.909812][ C0] Tainted: [W]=WARN [ 9.909813][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 9.909814][ C0] Call Trace: [ 9.909816][ C0] [ 9.909817][ C0] dump_stack_lvl+0x6f/0xa0 [ 9.909821][ C0] print_irq_inversion_bug.part.0.cold+0xe6/0x143 [ 9.909823][ C0] mark_lock_irq+0x989/0x9c0 [ 9.909824][ C0] ? add_lock_to_list+0x2c/0x1a0 [ 9.909827][ C0] mark_lock+0x1d7/0xa00 [ 9.909829][ C0] mark_usage+0x42/0x170 [ 9.909830][ C0] __lock_acquire+0x388/0xc20 [ 9.909833][ C0] lock_acquire.part.0+0xd4/0x280 [ 9.909834][ C0] ? console_lock_spinning_enable+0x40/0x60 [ 9.909836][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909839][ C0] ? lock_acquire+0x13c/0x160 [ 9.909841][ C0] console_lock_spinning_enable+0x5c/0x60 [ 9.909843][ C0] ? console_lock_spinning_enable+0x40/0x60 [ 9.909844][ C0] console_emit_next_record+0x1f4/0x4f0 [ 9.909846][ C0] ? devkmsg_read+0x4e0/0x4e0 [ 9.909848][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909850][ C0] ? lock_acquire+0x13c/0x160 [ 9.909852][ C0] console_flush_one_record+0x46f/0x710 [ 9.909854][ C0] ? console_emit_next_record+0x4f0/0x4f0 [ 9.909856][ C0] ? __lock_acquire+0x518/0xc20 [ 9.909858][ C0] console_unlock+0xee/0x1f0 [ 9.909860][ C0] ? console_flush_one_record+0x710/0x710 [ 9.909862][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909863][ C0] ? lock_acquire+0xa0/0x160 [ 9.909865][ C0] ? __down_trylock_console_sem+0x5e/0xa0 [ 9.909867][ C0] ? vprintk_emit+0x320/0x3e0 [ 9.909869][ C0] vprintk_emit+0x37c/0x3e0 [ 9.909871][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 9.909873][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 9.909875][ C0] _printk+0xc7/0x100 [ 9.909877][ C0] ? snapshot_read.cold+0x21/0x21 [ 9.909878][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 9.909880][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.909882][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 9.909884][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.909886][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.909887][ C0] call_timer_fn+0x160/0x4d0 [ 9.909889][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 9.909891][ C0] ? debug_object_active_state+0x430/0x430 [ 9.909894][ C0] ? find_held_lock+0x2b/0x80 [ 9.909896][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.909898][ C0] ? mark_held_locks+0x40/0x70 [ 9.909900][ C0] __run_timers+0x68f/0xaa0 [ 9.909901][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.909903][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 9.909905][ C0] ? __lock_acquire+0x518/0xc20 [ 9.909908][ C0] ? __rwlock_init+0x150/0x150 [ 9.909910][ C0] run_timer_softirq+0xf0/0x160 [ 9.909912][ C0] ? __run_timers+0xaa0/0xaa0 [ 9.909914][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909916][ C0] handle_softirqs+0x1d3/0x900 [ 9.909917][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.909919][ C0] ? _local_bh_enable+0xc0/0xc0 [ 9.909921][ C0] __irq_exit_rcu+0x145/0x1c0 [ 9.909922][ C0] irq_exit_rcu+0xe/0x30 [ 9.909924][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 9.909926][ C0] [ 9.909926][ C0] [ 9.909927][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 9.909929][ C0] RIP: 0010:_raw_spin_unlock_irqrestore+0x36/0x80 [ 9.909931][ C0] Code: f5 53 48 8b 74 24 10 48 89 fb 48 83 c7 18 e8 81 6b a3 fd 48 89 df e8 89 c1 a3 fd f7 c5 00 02 00 00 75 1f 9c 58 f6 c4 02 75 2f 01 00 00 00 e8 10 8b 95 fd 65 48 83 3d af ab 63 02 00 74 12 5b [ 9.909933][ C0] RSP: 0018:ffa00000007d7ae0 EFLAGS: 00000246 [ 9.909935][ C0] RAX: 0000000000000086 RBX: ffffffffb7e16ba0 RCX: ffffffffb3b22483 [ 9.909936][ C0] RDX: ff1100000d020040 RSI: ffffffffb44ad54f RDI: ffffffffb3e913e0 [ 9.909937][ C0] RBP: 0000000000000286 R08: 0000000000000000 R09: 0000000000000000 [ 9.909938][ C0] R10: 0000000000000000 R11: 0000000000000001 R12: ffffffffb7e16cc0 [ 9.909939][ C0] R13: 0000000000000ef7 R14: ffffffffb7e16cf8 R15: 0000000000000286 [ 9.909940][ C0] ? _raw_spin_unlock_irqrestore+0x53/0x80 [ 9.909943][ C0] uart_write_room+0x29f/0x810 [ 9.909945][ C0] n_tty_write+0x37a/0x8f0 [ 9.909947][ C0] ? n_tty_receive_signal_char+0x110/0x110 [ 9.909949][ C0] ? _mutex_trylock_nest_lock+0x235/0x390 [ 9.909951][ C0] ? add_wait_queue_priority_exclusive+0x1b0/0x1b0 [ 9.909953][ C0] ? tty_ldisc_ref_wait+0x28/0x80 [ 9.909955][ C0] iterate_tty_write+0x291/0x590 [ 9.909957][ C0] ? tty_ldisc_ref_wait+0x28/0x80 [ 9.909959][ C0] file_tty_write.isra.0+0x1bd/0x290 [ 9.909960][ C0] ? redirected_tty_write+0xd0/0xd0 [ 9.909962][ C0] new_sync_write+0x33e/0x760 [ 9.909964][ C0] ? new_sync_read+0x750/0x750 [ 9.909965][ C0] ? fsnotify+0x3610/0x3610 [ 9.909969][ C0] vfs_write+0x6a2/0xbd0 [ 9.909971][ C0] ksys_write+0x116/0x250 [ 9.909972][ C0] ? __ia32_sys_read+0xc0/0xc0 [ 9.909974][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909976][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.909978][ C0] do_syscall_64+0xff/0x530 [ 9.909979][ C0] ? exc_page_fault+0xee/0x100 [ 9.909981][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 9.909982][ C0] RIP: 0033:0x7feefc3db54e [ 9.909985][ C0] Code: 4d 89 d8 e8 b4 bd 00 00 4c 8b 5d f8 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 74 11 c9 c3 0f 1f 80 00 00 00 00 48 8b 45 10 0f 05 c3 83 e2 39 83 fa 08 75 e7 e8 03 ff ff ff 0f 1f 00 f3 0f 1e fa [ 9.909985][ C0] RSP: 002b:00007ffce86e4870 EFLAGS: 00000202 ORIG_RAX: 0000000000000001 [ 9.909987][ C0] RAX: ffffffffffffffda RBX: 00007feefc55c580 RCX: 00007feefc3db54e [ 9.909988][ C0] RDX: 0000000000000008 RSI: 00005653b6a77170 RDI: 0000000000000001 [ 9.909989][ C0] RBP: 00007ffce86e4880 R08: 0000000000000000 R09: 0000000000000000 [ 9.909989][ C0] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000008 [ 9.909990][ C0] R13: 0000000000000008 R14: 00005653b6a77170 R15: 0000000000000001 [ 9.909992][ C0] [ 9.909996][ C0] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 9.909998][ C0] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 149, name: env [ 9.909999][ C0] preempt_count: 103, expected: 0 [ 9.910000][ C0] RCU nest depth: 0, expected: 0 [ 9.910001][ C0] INFO: lockdep is turned off. [ 9.910001][ C0] irq event stamp: 5513 [ 9.910002][ C0] hardirqs last enabled at (5512): [] __down_trylock_console_sem+0x86/0xa0 [ 9.910004][ C0] hardirqs last disabled at (5513): [] console_emit_next_record+0x3f8/0x4f0 [ 9.910006][ C0] softirqs last enabled at (4532): [] handle_softirqs+0x67c/0x900 [ 9.910007][ C0] softirqs last disabled at (5499): [] __irq_exit_rcu+0x145/0x1c0 [ 9.910009][ C0] Preemption disabled at: [ 9.910010][ C0] [<0000000000000000>] 0x0 [ 9.910012][ C0] CPU: 0 UID: 0 PID: 149 Comm: env Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 9.910014][ C0] Tainted: [W]=WARN [ 9.910014][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 9.910015][ C0] Call Trace: [ 9.910016][ C0] [ 9.910016][ C0] dump_stack_lvl+0x6f/0xa0 [ 9.910018][ C0] __might_resched.cold+0x1fe/0x2c1 [ 9.910021][ C0] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 9.910024][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910026][ C0] __kmalloc_noprof+0x443/0x760 [ 9.910028][ C0] ? __rwlock_init+0x150/0x150 [ 9.910029][ C0] ? alloc_buf.isra.0+0x4b/0x260 [ 9.910032][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 9.910033][ C0] alloc_buf.isra.0+0x4b/0x260 [ 9.910036][ C0] put_chars+0x1e1/0x2f0 [ 9.910038][ C0] ? __send_to_port+0x420/0x420 [ 9.910041][ C0] hvc_console_print+0x292/0x780 [ 9.910043][ C0] ? mark_usage+0x42/0x170 [ 9.910044][ C0] ? __lock_acquire+0x388/0xc20 [ 9.910046][ C0] ? hvc_write+0x3a0/0x3a0 [ 9.910048][ C0] ? lock_acquire.part.0+0xd4/0x280 [ 9.910050][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910051][ C0] ? lock_acquire+0x13c/0x160 [ 9.910053][ C0] console_emit_next_record+0x252/0x4f0 [ 9.910055][ C0] ? devkmsg_read+0x4e0/0x4e0 [ 9.910057][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910059][ C0] ? lock_acquire+0x13c/0x160 [ 9.910061][ C0] console_flush_one_record+0x46f/0x710 [ 9.910063][ C0] ? console_emit_next_record+0x4f0/0x4f0 [ 9.910065][ C0] ? __lock_acquire+0x518/0xc20 [ 9.910067][ C0] console_unlock+0xee/0x1f0 [ 9.910069][ C0] ? console_flush_one_record+0x710/0x710 [ 9.910070][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910072][ C0] ? lock_acquire+0xa0/0x160 [ 9.910074][ C0] ? __down_trylock_console_sem+0x5e/0xa0 [ 9.910075][ C0] ? vprintk_emit+0x320/0x3e0 [ 9.910077][ C0] vprintk_emit+0x37c/0x3e0 [ 9.910080][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 9.910082][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 9.910084][ C0] _printk+0xc7/0x100 [ 9.910085][ C0] ? snapshot_read.cold+0x21/0x21 [ 9.910087][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 9.910088][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.910091][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 9.910092][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.910094][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.910095][ C0] call_timer_fn+0x160/0x4d0 [ 9.910097][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 9.910099][ C0] ? debug_object_active_state+0x430/0x430 [ 9.910100][ C0] ? find_held_lock+0x2b/0x80 [ 9.910102][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.910103][ C0] ? mark_held_locks+0x40/0x70 [ 9.910105][ C0] __run_timers+0x68f/0xaa0 [ 9.910107][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 9.910109][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 9.910110][ C0] ? __lock_acquire+0x518/0xc20 [ 9.910113][ C0] ? __rwlock_init+0x150/0x150 [ 9.910115][ C0] run_timer_softirq+0xf0/0x160 [ 9.910117][ C0] ? __run_timers+0xaa0/0xaa0 [ 9.910119][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910121][ C0] handle_softirqs+0x1d3/0x900 [ 9.910122][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 9.910124][ C0] ? _local_bh_enable+0xc0/0xc0 [ 9.910126][ C0] __irq_exit_rcu+0x145/0x1c0 [ 9.910127][ C0] irq_exit_rcu+0xe/0x30 [ 9.910129][ C0] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 9.910131][ C0] [ 9.910131][ C0] [ 9.910132][ C0] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 9.910133][ C0] RIP: 0010:_raw_spin_unlock_irqrestore+0x36/0x80 [ 9.910135][ C0] Code: f5 53 48 8b 74 24 10 48 89 fb 48 83 c7 18 e8 81 6b a3 fd 48 89 df e8 89 c1 a3 fd f7 c5 00 02 00 00 75 1f 9c 58 f6 c4 02 75 2f 01 00 00 00 e8 10 8b 95 fd 65 48 83 3d af ab 63 02 00 74 12 5b [ 9.910136][ C0] RSP: 0018:ffa00000007d7ae0 EFLAGS: 00000246 [ 9.910137][ C0] RAX: 0000000000000086 RBX: ffffffffb7e16ba0 RCX: ffffffffb3b22483 [ 9.910138][ C0] RDX: ff1100000d020040 RSI: ffffffffb44ad54f RDI: ffffffffb3e913e0 [ 9.910139][ C0] RBP: 0000000000000286 R08: 0000000000000000 R09: 0000000000000000 [ 9.910139][ C0] R10: 0000000000000000 R11: 0000000000000001 R12: ffffffffb7e16cc0 [ 9.910140][ C0] R13: 0000000000000ef7 R14: ffffffffb7e16cf8 R15: 0000000000000286 [ 9.910141][ C0] ? _raw_spin_unlock_irqrestore+0x53/0x80 [ 9.910144][ C0] uart_write_room+0x29f/0x810 [ 9.910146][ C0] n_tty_write+0x37a/0x8f0 [ 9.910148][ C0] ? n_tty_receive_signal_char+0x110/0x110 [ 9.910150][ C0] ? _mutex_trylock_nest_lock+0x235/0x390 [ 9.910151][ C0] ? add_wait_queue_priority_exclusive+0x1b0/0x1b0 [ 9.910153][ C0] ? tty_ldisc_ref_wait+0x28/0x80 [ 9.910155][ C0] iterate_tty_write+0x291/0x590 [ 9.910157][ C0] ? tty_ldisc_ref_wait+0x28/0x80 [ 9.910158][ C0] file_tty_write.isra.0+0x1bd/0x290 [ 9.910160][ C0] ? redirected_tty_write+0xd0/0xd0 [ 9.910161][ C0] new_sync_write+0x33e/0x760 [ 9.910163][ C0] ? new_sync_read+0x750/0x750 [ 9.910164][ C0] ? fsnotify+0x3610/0x3610 [ 9.910167][ C0] vfs_write+0x6a2/0xbd0 [ 9.910169][ C0] ksys_write+0x116/0x250 [ 9.910170][ C0] ? __ia32_sys_read+0xc0/0xc0 [ 9.910172][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910173][ C0] ? rcu_is_watching+0x16/0xd0 [ 9.910175][ C0] do_syscall_64+0xff/0x530 [ 9.910177][ C0] ? exc_page_fault+0xee/0x100 [ 9.910178][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 9.910180][ C0] RIP: 0033:0x7feefc3db54e [ 9.910181][ C0] Code: 4d 89 d8 e8 b4 bd 00 00 4c 8b 5d f8 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 74 11 c9 c3 0f 1f 80 00 00 00 00 48 8b 45 10 0f 05 c3 83 e2 39 83 fa 08 75 e7 e8 03 ff ff ff 0f 1f 00 f3 0f 1e fa [ 9.910181][ C0] RSP: 002b:00007ffce86e4870 EFLAGS: 00000202 ORIG_RAX: 0000000000000001 [ 9.910183][ C0] RAX: ffffffffffffffda RBX: 00007feefc55c580 RCX: 00007feefc3db54e [ 9.910183][ C0] RDX: 0000000000000008 RSI: 00005653b6a77170 RDI: 0000000000000001 [ 9.910184][ C0] RBP: 00007ffce86e4880 R08: 0000000000000000 R09: 0000000000000000 [ 9.910185][ C0] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000008 [ 9.910185][ C0] R13: 0000000000000008 R14: 00005653b6a77170 R15: 0000000000000001 [ 9.910187][ C0]