2022-07-25 08:27:48

by kernel test robot

[permalink] [raw]
Subject: [printk] 6e72f137fd: WARNING:at_kernel/rcu/tasks.h:#rcu_tasks_verify_self_tests



Greeting,

FYI, we noticed the following commit (built with clang-15):

commit: 6e72f137fdd27b79014ed848d16f03e6d239f2a2 ("printk: Bring back the RT bits.")
https://git.kernel.org/cgit/linux/kernel/git/rt/linux-rt-devel.git linux-5.19.y-rt-rebase

in testcase: boot

on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------------------+------------+------------+
| | 29202da893 | 6e72f137fd |
+------------------------------------------------------------+------------+------------+
| WARNING:at_kernel/rcu/tasks.h:#rcu_tasks_verify_self_tests | 0 | 29 |
| RIP:rcu_tasks_verify_self_tests | 0 | 29 |
+------------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 27.647276][ T1] ------------[ cut here ]------------
[ 27.647279][ T1] WARNING: CPU: 0 PID: 1 at kernel/rcu/tasks.h:1751 rcu_tasks_verify_self_tests (update.c:?)
[ 33.067924][ T1] Modules linked in:
[ 33.068393][ T1] CPU: 0 PID: 1 Comm: swapper Not tainted 5.19.0-rc7-00020-g6e72f137fdd2 #1
[ 33.069378][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.0-debian-1.16.0-4 04/01/2014
[ 33.070541][ T1] RIP: 0010:rcu_tasks_verify_self_tests (update.c:?)
[ 33.071289][ T1] Code: 48 c7 c7 40 6e e6 82 e8 5f a7 5c 01 41 bc ff ff ff ff 45 31 ed 49 83 ff 03 0f 85 72 ff ff ff eb 08 31 c0 41 f6 c5 01 75 07 90 <0f> 0b 90 44 89 e0 5b 41 5c 41 5d 41 5e 41 5f 5d 31 c9 31 ff 31 f6
All code
========
0: 48 c7 c7 40 6e e6 82 mov $0xffffffff82e66e40,%rdi
7: e8 5f a7 5c 01 callq 0x15ca76b
c: 41 bc ff ff ff ff mov $0xffffffff,%r12d
12: 45 31 ed xor %r13d,%r13d
15: 49 83 ff 03 cmp $0x3,%r15
19: 0f 85 72 ff ff ff jne 0xffffffffffffff91
1f: eb 08 jmp 0x29
21: 31 c0 xor %eax,%eax
23: 41 f6 c5 01 test $0x1,%r13b
27: 75 07 jne 0x30
29: 90 nop
2a:* 0f 0b ud2 <-- trapping instruction
2c: 90 nop
2d: 44 89 e0 mov %r12d,%eax
30: 5b pop %rbx
31: 41 5c pop %r12
33: 41 5d pop %r13
35: 41 5e pop %r14
37: 41 5f pop %r15
39: 5d pop %rbp
3a: 31 c9 xor %ecx,%ecx
3c: 31 ff xor %edi,%edi
3e: 31 f6 xor %esi,%esi

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 90 nop
3: 44 89 e0 mov %r12d,%eax
6: 5b pop %rbx
7: 41 5c pop %r12
9: 41 5d pop %r13
b: 41 5e pop %r14
d: 41 5f pop %r15
f: 5d pop %rbp
10: 31 c9 xor %ecx,%ecx
12: 31 ff xor %edi,%edi
14: 31 f6 xor %esi,%esi
[ 33.073563][ T1] RSP: 0018:ffffc9000001fcd8 EFLAGS: 00010246
[ 33.074245][ T1] RAX: 0000000000000000 RBX: ffffffff83abf550 RCX: 0000000000000000
[ 33.075150][ T1] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffffffff83abf538
[ 33.076037][ T1] RBP: ffffffff83abf558 R08: 0000000000000000 R09: 0000000000000000
[ 33.076940][ T1] R10: 0000000000000000 R11: 0000000000000000 R12: 00000000ffffffff
[ 33.077853][ T1] R13: 0000000000000000 R14: dffffc0000000000 R15: 0000000000000004
[ 33.078765][ T1] FS: 0000000000000000(0000) GS:ffffffff834a7000(0000) knlGS:0000000000000000
[ 33.079757][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 33.080510][ T1] CR2: 00007f3be6c0c3f8 CR3: 0000000003436000 CR4: 00000000000006b0
[ 33.081426][ T1] Call Trace:
[ 33.081813][ T1] <TASK>
[ 33.082156][ T1] ? rcu_barrier_tasks_trace (update.c:?)
[ 33.082774][ T1] do_one_initcall (??:?)
[ 33.083315][ T1] ? rcu_barrier_tasks_trace (update.c:?)
[ 33.083973][ T1] do_initcall_level (main.c:?)
[ 33.084555][ T1] do_initcalls (main.c:?)
[ 33.085071][ T1] kernel_init_freeable (main.c:?)
[ 33.085650][ T1] ? rest_init (main.c:?)
[ 33.086155][ T1] kernel_init (main.c:?)
[ 33.086646][ T1] ? rest_init (main.c:?)
[ 33.087148][ T1] ret_from_fork (??:?)
[ 33.087667][ T1] </TASK>
[ 33.088031][ T1] irq event stamp: 1004249
[ 33.088546][ T1] hardirqs last enabled at (1004257): __up_console_sem (printk.c:?)
[ 33.089635][ T1] hardirqs last disabled at (1004264): __up_console_sem (printk.c:?)
[ 33.090721][ T1] softirqs last enabled at (1003820): __do_softirq (??:?)
[ 33.091807][ T1] softirqs last disabled at (1003811): irq_exit_rcu (??:?)
[ 33.092871][ T1] ---[ end trace 0000000000000000 ]---
[ 33.093909][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.094018][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.094390][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.094448][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.099418][ T1] random: get_random_bytes called from key_alloc+0x640/0xc80 with crng_init=0
[ 33.099531][ T1] random: get_random_bytes called from key_alloc+0x640/0xc80 with crng_init=0
[ 33.099718][ T1] random: get_random_bytes called from key_alloc+0x640/0xc80 with crng_init=0
[ 33.099822][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.100034][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.106418][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.107373][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.112298][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.112703][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.112749][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.119141][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.119231][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.119309][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.119356][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.125525][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.125976][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.132017][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.132071][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.132467][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.135632][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.135871][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.136243][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.136294][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.136678][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.136706][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.136899][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.137087][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.137499][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.137918][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.147747][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.147983][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.150315][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.150361][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.150410][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.150951][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.155449][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.155482][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.155507][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.155535][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.155881][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.156109][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.156302][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.156730][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.156782][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.157150][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.157346][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.157532][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.157598][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.157961][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.169202][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.169420][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.169448][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.175762][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.175935][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176069][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176203][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176337][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176469][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176618][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176753][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.176886][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177018][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177151][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177275][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177424][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177588][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.177961][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.178055][ T2] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.178390][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.178578][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.178895][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.179108][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.179299][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0
[ 33.179358][ T1] random: get_random_u32 called from new_slab+0x1ce/0x3c0 with crng_init=0


To reproduce:

# build kernel
cd linux
cp config-5.19.0-rc7-00020-g6e72f137fdd2 .config
make HOSTCC=clang-15 CC=clang-15 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=clang-15 CC=clang-15 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz 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.



--
0-DAY CI Kernel Test Service
https://01.org/lkp



Attachments:
(No filename) (13.00 kB)
config-5.19.0-rc7-00020-g6e72f137fdd2 (136.72 kB)
job-script (4.76 kB)
dmesg.xz (57.19 kB)
Download all attachments