Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: c055908abe0d7f6a5bd4f602d0c825ae20daefc8 ("[RFC PATCH 33/39] blktrace: add blkext tracer")
url: https://github.com/0day-ci/linux/commits/Chaitanya-Kulkarni/blktrace-add-block-trace-extension-support/20210225-151637
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
in testcase: trinity
version: trinity-static-i386-x86_64-f93256fb_2019-08-28
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------------------------------+------------+------------+
| | 503e031aef | c055908abe |
+-------------------------------------------------------------------------+------------+------------+
| WARNING:at_kernel/trace/trace.c:#create_trace_option_files | 0 | 5 |
| EIP:create_trace_option_files | 0 | 5 |
+-------------------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>
[ 20.216017] WARNING: CPU: 0 PID: 1 at kernel/trace/trace.c:8370 create_trace_option_files (kbuild/src/consumer/kernel/trace/trace.c:8370 (discriminator 1))
[ 20.218480] Modules linked in:
[ 20.219395] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.11.0-09341-gc055908abe0d #1
[ 20.221182] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 20.224540] EIP: create_trace_option_files (kbuild/src/consumer/kernel/trace/trace.c:8370 (discriminator 1))
[ 20.225816] Code: d5 01 83 15 2c b7 08 d5 00 83 c0 01 39 c8 0f 84 c7 00 00 00 8b 14 c7 39 72 44 75 df 83 05 10 b7 08 d5 01 83 15 14 b7 08 d5 00 <0f> 0b 83 05 18 b7 08 d5 01 83 15 1c b7 08 d5 00 83 05 20 b7 08 d5
All code
========
0: d5 (bad)
1: 01 83 15 2c b7 08 add %eax,0x8b72c15(%rbx)
7: d5 (bad)
8: 00 83 c0 01 39 c8 add %al,-0x37c6fe40(%rbx)
e: 0f 84 c7 00 00 00 je 0xdb
14: 8b 14 c7 mov (%rdi,%rax,8),%edx
17: 39 72 44 cmp %esi,0x44(%rdx)
1a: 75 df jne 0xfffffffffffffffb
1c: 83 05 10 b7 08 d5 01 addl $0x1,-0x2af748f0(%rip) # 0xffffffffd508b733
23: 83 15 14 b7 08 d5 00 adcl $0x0,-0x2af748ec(%rip) # 0xffffffffd508b73e
2a:* 0f 0b ud2 <-- trapping instruction
2c: 83 05 18 b7 08 d5 01 addl $0x1,-0x2af748e8(%rip) # 0xffffffffd508b74b
33: 83 15 1c b7 08 d5 00 adcl $0x0,-0x2af748e4(%rip) # 0xffffffffd508b756
3a: 83 .byte 0x83
3b: 05 20 b7 08 d5 add $0xd508b720,%eax
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: 83 05 18 b7 08 d5 01 addl $0x1,-0x2af748e8(%rip) # 0xffffffffd508b721
9: 83 15 1c b7 08 d5 00 adcl $0x0,-0x2af748e4(%rip) # 0xffffffffd508b72c
10: 83 .byte 0x83
11: 05 20 b7 08 d5 add $0xd508b720,%eax
[ 20.231135] EAX: 00000008 EBX: d3c49fc0 ECX: 00000009 EDX: d43fd620
[ 20.232662] ESI: d3c49f9c EDI: c1f63698 EBP: c1c73f0c ESP: c1c73ef0
[ 20.234528] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 EFLAGS: 00010246
[ 20.236313] CR0: 80050033 CR2: 00000000 CR3: 14949000 CR4: 000006d0
[ 20.238351] Call Trace:
[ 20.239241] register_tracer (kbuild/src/consumer/kernel/trace/trace.c:5908 kbuild/src/consumer/kernel/trace/trace.c:2107)
[ 20.240372] ? init_graph_trace (kbuild/src/consumer/kernel/trace/blktrace.c:2526)
[ 20.241493] init_blk_tracer (kbuild/src/consumer/kernel/trace/blktrace.c:2545)
[ 20.242804] do_one_initcall (kbuild/src/consumer/init/main.c:1223)
[ 20.243862] ? rcu_read_lock_sched_held (kbuild/src/consumer/include/linux/lockdep.h:278 kbuild/src/consumer/kernel/rcu/update.c:125)
[ 20.245103] ? trace_initcall_level (kbuild/src/consumer/include/trace/events/initcall.h:10 (discriminator 67))
[ 20.246611] kernel_init_freeable (kbuild/src/consumer/init/main.c:1295 kbuild/src/consumer/init/main.c:1312 kbuild/src/consumer/init/main.c:1332 kbuild/src/consumer/init/main.c:1533)
[ 20.247834] ? rest_init (kbuild/src/consumer/init/main.c:1418)
[ 20.248901] kernel_init (kbuild/src/consumer/init/main.c:1423)
[ 20.249850] ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_32.S:856)
[ 20.251381] irq event stamp: 4343293
[ 20.252533] hardirqs last enabled at (4343301): console_unlock (kbuild/src/consumer/kernel/printk/printk.c:2605 (discriminator 1))
[ 20.255052] hardirqs last disabled at (4343310): console_unlock (kbuild/src/consumer/kernel/printk/printk.c:2520 (discriminator 1))
[ 20.257109] softirqs last enabled at (4342794): __do_softirq (kbuild/src/consumer/arch/x86/include/asm/preempt.h:27 kbuild/src/consumer/kernel/softirq.c:371)
[ 20.259404] softirqs last disabled at (4342789): call_on_stack (kbuild/src/consumer/arch/x86/kernel/irq_32.c:59)
[ 20.261358] ---[ end trace bc5f5cafed183c31 ]---
[ 20.269773] Initialise system trusted keyrings
[ 20.271532] Key type blacklist registered
[ 20.286648] workingset: timestamp_bits=14 max_order=20 bucket_order=6
[ 20.434198] zbud: loaded
[ 20.453926] DLM installed
[ 20.490173] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 20.819671] FS-Cache: Netfs 'nfs' registered for caching
[ 21.012308] NFS: Registering the id_resolver key type
[ 21.013624] Key type id_resolver registered
[ 21.014716] Key type id_legacy registered
[ 21.016704] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 21.018638] Installing knfsd (copyright (C) 1996 [email protected]).
[ 21.031359] utf8_selftest: All 154 tests passed
[ 21.362307] _warn_unseeded_randomness: 252 callbacks suppressed
[ 21.362324] random: get_random_u32 called from allocate_slab+0x13e/0x5a0 with crng_init=0
[ 21.365896] random: get_random_u32 called from copy_process+0x243/0x1900 with crng_init=0
[ 21.372082] random: get_random_u32 called from allocate_slab+0x13e/0x5a0 with crng_init=0
[ 22.826228] FS-Cache: Netfs 'cifs' registered for caching
[ 22.827594] _warn_unseeded_randomness: 1 callbacks suppressed
[ 22.827600] random: get_random_u32 called from __kmem_cache_create+0x26/0x3e0 with crng_init=0
[ 22.827622] random: get_random_u32 called from cache_random_seq_create+0x7c/0x140 with crng_init=0
[ 22.827831] random: get_random_u32 called from allocate_slab+0x13e/0x5a0 with crng_init=0
[ 22.840557] Key type cifs.spnego registered
[ 22.842144] Key type cifs.idmap registered
[ 22.844204] ntfs: driver 2.1.32 [Flags: R/W DEBUG].
[ 22.849844] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 22.863659] romfs: ROMFS MTD (C) 2007 Red Hat, Inc.
[ 22.866664] QNX4 filesystem 0.2.3 registered.
[ 22.868611] qnx6: QNX6 filesystem 1.0.0 registered.
[ 22.875183] fuse: init (API version 7.33)
[ 22.882906] orangefs_debugfs_init: called with debug mask: :none: :0:
[ 22.885270] orangefs_init: module version upstream loaded
[ 22.888998] JFS: nTxBlock = 8192, nTxLock = 65536
[ 23.267140] SGI XFS with ACLs, security attributes, realtime, scrub, repair, quota, fatal assert, debug enabled
[ 23.390479] 9p: Installing v9fs 9p2000 file system support
[ 23.392589] FS-Cache: Netfs '9p' registered for caching
[ 23.396857] NILFS version 2 loaded
[ 23.398093] befs: version: 0.9.3
[ 23.408701] ocfs2: Registered cluster interface o2cb
[ 23.410932] ocfs2: Registered cluster interface user
[ 23.730184] OCFS2 User DLM kernel interface loaded
[ 24.058434] _warn_unseeded_randomness: 236 callbacks suppressed
[ 24.058447] random: get_random_u32 called from __kmem_cache_create+0x26/0x3e0 with crng_init=0
[ 24.058479] random: get_random_u32 called from cache_random_seq_create+0x7c/0x140 with crng_init=0
[ 24.058652] random: get_random_u32 called from allocate_slab+0x13e/0x5a0 with crng_init=0
[ 24.073256] gfs2: GFS2 installed
[ 24.097912] FS-Cache: Netfs 'ceph' registered for caching
[ 24.099396] ceph: loaded (mds proto 32)
[ 24.105556] Smack: Registering netfilter hooks
[ 24.107358] integrity: Platform Keyring initialized
[ 24.108531] Allocating IMA blacklist keyring.
[ 24.403512] NET: Registered protocol family 38
[ 24.405457] xor: measuring software checksum speed
[ 24.408022] pIII_sse : 7748 MB/sec
[ 24.410377] prefetch64-sse : 9042 MB/sec
[ 24.411478] xor: using function: prefetch64-sse (9042 MB/sec)
[ 24.412923] async_tx: api initialized (async)
[ 24.414256] Key type asymmetric registered
[ 24.415613] Asymmetric key parser 'x509' registered
[ 24.416969] Asymmetric key parser 'pkcs8' registered
[ 24.418337] Key type pkcs7_test registered
[ 24.419419] Asymmetric key parser 'tpm_parser' registered
[ 24.420996] bounce: pool size: 64 pages
[ 24.423333] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 235)
[ 24.425884] io scheduler mq-deadline registered
[ 24.427055] io scheduler kyber registered
[ 24.429756] io scheduler bfq registered
[ 24.833213] String selftests succeeded
[ 24.834768] test_printf: loaded.
[ 24.835938] test_printf: crng possibly not yet initialized. plain 'p' buffer contains "(ptrval)"
[ 24.836004] test_printf: crng possibly not yet initialized. plain 'p' buffer contains "(ptrval)"
[ 24.839089] test_printf: crng possibly not yet initialized. plain 'p' buffer contains "(ptrval)"
[ 24.849973] test_printf: all 388 tests passed
[ 24.852954] test_bitmap: loaded.
[ 24.854346] test_bitmap: parselist: 14: input is '0-2047:128/256' OK, Time: 2067
[ 24.860960] test_bitmap: all 1679 tests passed
[ 24.862251] test_strscpy: loaded.
[ 24.863216] test_strscpy: all 32 tests passed
[ 24.870583] test_stackinit: u8_zero ok
[ 24.871767] test_stackinit: u16_zero ok
[ 24.872830] test_stackinit: u32_zero ok
[ 24.873980] test_stackinit: u64_zero ok
[ 24.874903] test_stackinit: char_array_zero ok
[ 24.875902] test_stackinit: small_hole_zero ok
[ 24.876904] test_stackinit: big_hole_zero ok
[ 24.878022] test_stackinit: trailing_hole_zero ok
[ 24.879097] test_stackinit: packed_zero ok
[ 24.880030] test_stackinit: small_hole_dynamic_partial ok
[ 24.881209] test_stackinit: big_hole_dynamic_partial ok
[ 24.882487] test_stackinit: trailing_hole_dynamic_partial ok
[ 24.883687] test_stackinit: packed_dynamic_partial ok
[ 24.884812] test_stackinit: small_hole_static_partial ok
[ 24.886164] test_stackinit: big_hole_static_partial ok
[ 24.887342] test_stackinit: trailing_hole_static_partial ok
[ 24.888571] test_stackinit: packed_static_partial ok
[ 24.889676] test_stackinit: small_hole_static_all FAIL (uninit bytes: 3)
[ 24.891127] test_stackinit: big_hole_static_all FAIL (uninit bytes: 61)
[ 24.892513] test_stackinit: trailing_hole_static_all FAIL (uninit bytes: 3)
[ 24.894015] test_stackinit: packed_static_all ok
[ 24.895117] test_stackinit: small_hole_dynamic_all FAIL (uninit bytes: 3)
To reproduce:
# build kernel
cd linux
cp config-5.11.0-09341-gc055908abe0d .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
Thanks,
Oliver Sang
On Sat, 27 Feb 2021 19:44:40 +0800
kernel test robot <[email protected]> wrote:
> [ 20.216017] WARNING: CPU: 0 PID: 1 at kernel/trace/trace.c:8370 create_trace_option_files (kbuild/src/consumer/kernel/trace/trace.c:8370 (discriminator 1))
> [ 20.218480] Modules linked in:
> [ 20.219395] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 5.11.0-09341-gc055908abe0d #1
> [ 20.221182] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [ 20.224540] EIP: create_trace_option_files (kbuild/src/consumer/kernel/trace/trace.c:8370 (discriminator 1))
> [ 20.225816] Code: d5 01 83 15 2c b7 08 d5 00 83 c0 01 39 c8 0f 84 c7 00 00 00 8b 14 c7 39 72 44 75 df 83 05 10 b7 08 d5 01 83 15 14 b7 08 d5 00 <0f> 0b 83 05 18 b7 08 d5 01 83 15 1c b7 08 d5 00 83 05 20 b7 08 d5
Looks to be from this:
> +static struct tracer blk_tracer_ext __read_mostly = {
> + .name = "blkext",
> + .init = blk_tracer_init,
> + .reset = blk_tracer_reset,
> + .start = blk_tracer_start,
> + .stop = blk_tracer_stop,
> + .print_header = blk_tracer_print_header,
> + .print_line = blk_tracer_print_line_ext,
> + .flags = &blk_tracer_flags,
^^^
As blk_tracer already registers those flags, when it gets registered as
a tracer, and flag names can not be duplicated.
I could fix the infrastructure to detect the same set of flags being
registered by two different tracers, but in the mean time, it may still
work to use the blk_trace_flags from blk_tracer, and keep .flags NULL
here.
-- Steve
> + .set_flag = blk_tracer_set_flag,
> +};
> +