Greeting, FYI, we noticed the following commit (built with gcc-9): commit: d792962d3d4fdefcd21abcd238dddfe9481bf326 ("printk: move console printing to kthreads") https://git.kernel.org/cgit/linux/kernel/git/rt/linux-rt-devel.git linux-5.14.y-rt in testcase: boot on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace): +----------------------------------------------------------+------------+------------+ | | 8bab77c4bd | d792962d3d | +----------------------------------------------------------+------------+------------+ | boot_successes | 6 | 0 | | boot_failures | 0 | 6 | | WARNING:at_kernel/time/clocksource-wdtest.c:#wdtest_func | 0 | 6 | | EIP:wdtest_func | 0 | 6 | +----------------------------------------------------------+------------+------------+ If you fix the issue, kindly add following tag Reported-by: kernel test robot <oliver.sang(a)intel.com&gt; [ 37.052390][ T105] WARNING: CPU: 0 PID: 105 at kernel/time/clocksource-wdtest.c:163 wdtest_func (kernel/time/clocksource-wdtest.c:163 (discriminator 1)) [ 37.052404][ T105] Modules linked in: crc32c_intel aesni_intel crypto_simd input_leds led_class pcspkr qemu_fw_cfg [ 37.052421][ T105] CPU: 0 PID: 105 Comm: wdtest Not tainted 5.14.0-rc3-00020-gd792962d3d4f #1 8b633a590536ecd13269ffa750772a6565cf629f [ 37.052427][ T105] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014 [ 37.052430][ T105] EIP: wdtest_func (kernel/time/clocksource-wdtest.c:163 (discriminator 1)) [ 37.052435][ T105] Code: c4 73 1f c8 31 d2 b8 18 92 35 c8 83 e3 40 0f 94 c2 31 c9 c7 04 24 00 00 00 00 89 55 f4 e8 ed 65 03 00 85 db 8b 55 f4 58 75 02 <0f> 0b 31 c9 b8 00 92 35 c8 6a 00 e8 d5 65 03 00 b8 80 73 1f c8 e8 All code ======== 0: c4 (bad) 1: 73 1f jae 0x22 3: c8 31 d2 b8 enterq $0xd231,$0xb8 7: 18 92 35 c8 83 e3 sbb %dl,-0x1c7c37cb(%rdx) d: 40 0f 94 c2 sete %dl 11: 31 c9 xor %ecx,%ecx 13: c7 04 24 00 00 00 00 movl $0x0,(%rsp) 1a: 89 55 f4 mov %edx,-0xc(%rbp) 1d: e8 ed 65 03 00 callq 0x3660f 22: 85 db test %ebx,%ebx 24: 8b 55 f4 mov -0xc(%rbp),%edx 27: 58 pop %rax 28: 75 02 jne 0x2c 2a:* 0f 0b ud2 <-- trapping instruction 2c: 31 c9 xor %ecx,%ecx 2e: b8 00 92 35 c8 mov $0xc8359200,%eax 33: 6a 00 pushq $0x0 35: e8 d5 65 03 00 callq 0x3660f 3a: b8 80 73 1f c8 mov $0xc81f7380,%eax 3f: e8 .byte 0xe8 Code starting with the faulting instruction =========================================== 0: 0f 0b ud2 2: 31 c9 xor %ecx,%ecx 4: b8 00 92 35 c8 mov $0xc8359200,%eax 9: 6a 00 pushq $0x0 b: e8 d5 65 03 00 callq 0x365e5 10: b8 80 73 1f c8 mov $0xc81f7380,%eax 15: e8 .byte 0xe8 [ 37.052439][ T105] EAX: 00000000 EBX: 00000000 ECX: 00000000 EDX: 00000001 [ 37.052442][ T105] ESI: 00000005 EDI: 00000000 EBP: c418ff88 ESP: c418ff78 [ 37.052445][ T105] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010246 [ 37.052449][ T105] CR0: 80050033 CR2: 03daa000 CR3: 34803000 CR4: 000406d0 [ 37.052456][ T105] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000 [ 37.052458][ T105] DR6: fffe0ff0 DR7: 00000400 [ 37.052461][ T105] Call Trace: [ 37.052481][ T105] kthread (kernel/kthread.c:321) [ 37.052492][ T105] ? wdtest_ktime_read (kernel/time/clocksource-wdtest.c:106) [ 37.052500][ T105] ? set_kthread_struct (kernel/kthread.c:272) [ 37.052512][ T105] ret_from_fork (arch/x86/entry/entry_32.S:775) [ 37.052570][ T105] irq event stamp: 253 [ 37.052572][ T105] hardirqs last enabled at (255): vprintk_store (arch/x86/include/asm/irqflags.h:29 (discriminator 3) arch/x86/include/asm/irqflags.h:70 (discriminator 3) arch/x86/include/asm/irqflags.h:132 (discriminator 3) kernel/printk/printk.c:2154 (discriminator 3)) [ 37.052577][ T105] hardirqs last disabled at (256): vprintk_store (arch/x86/include/asm/preempt.h:27 (discriminator 3) kernel/printk/printk.c:1908 (discriminator 3) kernel/printk/printk.c:2057 (discriminator 3)) [ 37.052580][ T105] softirqs last enabled at (0): copy_process (kernel/fork.c:2006) [ 37.052586][ T105] softirqs last disabled at (0): 0x0 [ 37.052592][ T105] ---[ end trace daeb5df61cb95f4a ]--- [ 37.052599][ T105] clocksource: Checking clocksource wdtest-ktime synchronization from CPU 0 to CPUs 1. [ 37.052618][ T105] clocksource: CPUs 1 ahead of CPU 0 for clocksource wdtest-ktime. [ 37.052621][ T105] clocksource: CPU 0 check durations 13686ns - 13686ns for clocksource wdtest-ktime. [ 37.052630][ T105] clocksource_wdtest: --- Done with test. [ 37.596591][ T406] _warn_unseeded_randomness: 29 callbacks suppressed [ 37.596601][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 37.614173][ T510] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 37.614194][ T510] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 38.083005][ T263] [ 38.303649][ T263] mount: mount point /sys/kernel/debug does not exist [ 38.303668][ T263] [ 38.663469][ T406] _warn_unseeded_randomness: 13 callbacks suppressed [ 38.663479][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 38.665905][ T513] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 38.665923][ T513] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 39.686093][ T406] _warn_unseeded_randomness: 13 callbacks suppressed [ 39.686102][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 39.691153][ T516] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 39.691171][ T516] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 40.344544][ T261] install debs round one: dpkg -i --force-confdef --force-depends /opt/deb/gawk_1%3a4.1.4+dfsg-1_i386.deb [ 40.344561][ T261] [ 40.346875][ T261] Selecting previously unselected package gawk. [ 40.346892][ T261] [ 40.350671][ T261] (Reading database ... 16210 files and directories currently installed.) [ 40.350682][ T261] [ 40.353935][ T261] Preparing to unpack .../gawk_1%3a4.1.4+dfsg-1_i386.deb ... [ 40.353948][ T261] [ 40.355803][ T261] Unpacking gawk (1:4.1.4+dfsg-1) ... [ 40.355814][ T261] [ 40.357780][ T261] Setting up gawk (1:4.1.4+dfsg-1) ... [ 40.357792][ T261] [ 40.359827][ T261] mount debug /sys/kernel/debug -t debugfs [ 40.359837][ T261] [ 40.361298][ T261] none on / type rootfs (rw) [ 40.361308][ T261] [ 40.365686][ T261] sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime) [ 40.365700][ T261] [ 40.369392][ T261] proc on /proc type proc (rw,nosuid,nodev,noexec,relatime) [ 40.369405][ T261] [ 40.373579][ T261] devtmpfs on /dev type devtmpfs (rw,nosuid,size=1455760k,nr_inodes=163686,mode=755) [ 40.373592][ T261] [ 40.387629][ T261] securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime) [ 40.387646][ T261] [ 40.390075][ T261] tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev) [ 40.390088][ T261] [ 40.400550][ T261] devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000) [ 40.400565][ T261] [ 40.405066][ T261] tmpfs on /run type tmpfs (rw,nosuid,nodev,mode=755) [ 40.405081][ T261] [ 40.408919][ T261] tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k) [ 40.408932][ T261] [ 40.413348][ T261] tmpfs on /sys/fs/cgroup type tmpfs (ro,nosuid,nodev,noexec,mode=755) [ 40.413415][ T261] [ 40.749169][ T406] _warn_unseeded_randomness: 14 callbacks suppressed [ 40.749179][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 40.790247][ T519] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 40.790267][ T519] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 41.818088][ T406] _warn_unseeded_randomness: 13 callbacks suppressed [ 41.818098][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 41.827438][ T522] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 41.827456][ T522] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 42.862513][ T406] _warn_unseeded_randomness: 13 callbacks suppressed [ 42.862523][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 42.864776][ T525] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 42.864792][ T525] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 43.890265][ T406] _warn_unseeded_randomness: 14 callbacks suppressed [ 43.890275][ T406] random: get_random_u32 called from copy_process+0x271/0x1899 with crng_init=1 [ 43.895818][ T528] random: get_random_u32 called from arch_rnd+0x34/0x45 with crng_init=1 [ 43.895836][ T528] random: get_random_u32 called from randomize_stack_top+0x1c/0x37 with crng_init=1 [ 44.175104][ T261] cgroup on /sys/fs/cgroup/systemd type cgroup (rw,nosuid,nodev,noexec,relatime,xattr,release_agent=/lib/systemd/systemd-cgroups-agent,name=systemd) [ 44.175180][ T261] [ 44.184164][ T261] pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime) [ 44.184181][ T261] [ 44.191573][ T261] cgroup on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids) [ 44.191588][ T261] [ 44.196240][ T261] cgroup on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls) [ 44.196257][ T261] [ 44.213036][ T261] cgroup on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio) [ 44.213052][ T261] [ 44.221804][ T261] cgroup on /sys/fs/cgroup/cpu type cgroup (rw,nosuid,nodev,noexec,relatime,cpu) [ 44.221823][ T261] [ 44.235501][ T261] systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=28,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=28486) [ 44.235515][ T261] [ 44.242221][ T261] sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime) [ 44.242236][ T261] [ 44.247841][ T261] fusectl on /sys/fs/fuse/connections type fusectl (rw,relatime) [ 44.247855][ T261] [ 44.251314][ T261] tmp on /tmp type tmpfs (rw,relatime) [ 44.251331][ T261] [ 44.251974][ T261] nodev sysfs [ 44.251988][ T261] [ 44.259535][ T261] nodev tmpfs [ 44.259550][ T261] [ 44.260094][ T261] nodev bdev [ 44.260105][ T261] [ 44.261384][ T261] nodev proc [ 44.261399][ T261] To reproduce: # build kernel cd linux cp config-5.14.0-rc3-00020-gd792962d3d4f .config make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 olddefconfig prepare modules_prepare bzImage git clone https://github.com/intel/lkp-tests.git cd lkp-tests bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email # if come across any failure that blocks the test, # please remove ~/.lkp and /lkp dir to run from a clean state. --- 0DAY/LKP+ Test Infrastructure Open Source Technology Center https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation Thanks, Oliver Sang