Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: d5883a5113ffde433efec9b54e4402c9534ccb19 ("io_uring: store io_identity in io_uring_task")
https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git io_uring-5.10-next
in testcase: trinity
version: trinity-static-x86_64-x86_64-1c734c75-1_2020-01-06
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-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 8G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-----------------------------------------------------------------+------------+------------+
| | 6ffbd564b7 | d5883a5113 |
+-----------------------------------------------------------------+------------+------------+
| boot_successes | 15 | 3 |
| boot_failures | 1 | 25 |
| BUG:kernel_hang_in_boot_stage | 1 | |
| BUG:using__this_cpu_read()in_preemptible | 0 | 25 |
| WARNING:suspicious_RCU_usage | 0 | 25 |
| include/linux/cgroup.h:#suspicious_rcu_dereference_check()usage | 0 | 25 |
+-----------------------------------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>
[ 53.088161] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c7/672
[ 53.094406] caller is lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 53.097470] CPU: 1 PID: 672 Comm: trinity-c7 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 53.100945] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 53.104483] Call Trace:
[ 53.106598] dump_stack+0x8d/0xb5
[ 53.108962] check_preemption_disabled+0xc3/0xe0
[ 53.111557] lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 53.114258] trace_hardirqs_on+0x40/0x100
[ 53.116734] __bad_area_nosemaphore+0x63/0x180
[ 53.119060] ? up_read+0x17/0x220
[ 53.121277] exc_page_fault+0x5d/0x260
[ 53.123632] ? asm_exc_page_fault+0x8/0x30
[ 53.125971] asm_exc_page_fault+0x1e/0x30
[ 53.128308] RIP: 0033:0x4003b0
[ 53.130322] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 53.137668] RSP: 002b:00007ffc032269f8 EFLAGS: 00010212
[ 53.140626] RAX: 00007fc8dbb1e064 RBX: 000000000000000b RCX: 0a30303030303478
[ 53.143909] RDX: 0000000000000075 RSI: 0000000000000000 RDI: 00007fc8dbb1e06f
[ 53.147362] RBP: 00007fc8dbb1e064 R08: 0000000000000001 R09: 0000000000000008
[ 53.150654] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000b
[ 53.153924] R13: 00007fc8dbb18058 R14: 0000000000000000 R15: 0000000000000000
[ 53.157313] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c7/672
[ 53.188012] random: fast init done
[ 53.190954] caller is lockdep_hardirqs_on+0x38/0x120
[ 53.193937] CPU: 1 PID: 672 Comm: trinity-c7 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 53.197443] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 53.201120] Call Trace:
[ 53.203349] dump_stack+0x8d/0xb5
[ 53.205901] check_preemption_disabled+0xc3/0xe0
[ 53.208816] ? __bad_area_nosemaphore+0x63/0x180
[ 53.211441] lockdep_hardirqs_on+0x38/0x120
[ 53.213905] __bad_area_nosemaphore+0x63/0x180
[ 53.216681] ? up_read+0x17/0x220
[ 53.219122] exc_page_fault+0x5d/0x260
[ 53.221513] ? asm_exc_page_fault+0x8/0x30
[ 53.224084] asm_exc_page_fault+0x1e/0x30
[ 53.226713] RIP: 0033:0x4003b0
[ 53.228951] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 53.236945] RSP: 002b:00007ffc032269f8 EFLAGS: 00010212
[ 53.240274] RAX: 00007fc8dbb1e064 RBX: 000000000000000b RCX: 0a30303030303478
[ 53.243926] RDX: 0000000000000075 RSI: 0000000000000000 RDI: 00007fc8dbb1e06f
[ 53.247563] RBP: 00007fc8dbb1e064 R08: 0000000000000001 R09: 0000000000000008
[ 53.251355] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000b
[ 53.255057] R13: 00007fc8dbb18058 R14: 0000000000000000 R15: 0000000000000000
[ 53.952791] VFS: Warning: trinity-c6 using old stat() call. Recompile your binary.
[ 54.171475] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
[ 54.196981] VFS: Warning: trinity-c0 using old stat() call. Recompile your binary.
[ 54.911962] warning: process `trinity-c1' used the obsolete bdflush system call
[ 54.920646] Fix your initscripts?
[ 55.264038] VFS: Warning: trinity-c3 using old stat() call. Recompile your binary.
[ 55.478928] random: crng init done
[ 55.513466] scsi_nl_rcv_msg: discarding partial skb
[ 55.552739] Unable to find swap-space signature
[ 56.237353] VFS: Warning: trinity-c4 using old stat() call. Recompile your binary.
[ 56.619817] futex_wake_op: trinity-c6 tries to shift op by -1; fix this program
[ 56.801954] NET: Registered protocol family 36
[ 57.720175] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c6/710
[ 57.725837] caller is lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 57.729103] CPU: 1 PID: 710 Comm: trinity-c6 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 57.737156] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 57.741064] Call Trace:
[ 57.743602] dump_stack+0x8d/0xb5
[ 57.746239] check_preemption_disabled+0xc3/0xe0
[ 57.749241] lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 57.752170] trace_hardirqs_on+0x40/0x100
[ 57.754899] __bad_area_nosemaphore+0x63/0x180
[ 57.757853] ? up_read+0x17/0x220
[ 57.760522] exc_page_fault+0x5d/0x260
[ 57.763248] ? asm_exc_page_fault+0x8/0x30
[ 57.770001] asm_exc_page_fault+0x1e/0x30
[ 57.772723] RIP: 0033:0x4003b0
[ 57.775024] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 57.782964] RSP: 002b:00007ffc032269f8 EFLAGS: 00010212
[ 57.785945] RAX: 00007fc8dbb25064 RBX: 000000000000000b RCX: 0a30303030303478
[ 57.789405] RDX: 0000000000000075 RSI: 0000000000000000 RDI: 00007fc8dbb2506f
[ 57.793101] RBP: 00007fc8dbb25064 R08: 0000000000000001 R09: 0000000000000008
[ 57.796785] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000b
[ 57.800410] R13: 00007fc8dbb1f058 R14: 00000000000002a6 R15: 0000000000000008
[ 57.808676] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c6/710
[ 57.812544] caller is lockdep_hardirqs_on+0x38/0x120
[ 57.815829] CPU: 1 PID: 710 Comm: trinity-c6 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 57.819766] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 57.823721] Call Trace:
[ 57.826298] dump_stack+0x8d/0xb5
[ 57.828955] check_preemption_disabled+0xc3/0xe0
[ 57.831922] ? __bad_area_nosemaphore+0x63/0x180
[ 57.834905] lockdep_hardirqs_on+0x38/0x120
[ 57.837755] __bad_area_nosemaphore+0x63/0x180
[ 57.840399] ? up_read+0x17/0x220
[ 57.842900] exc_page_fault+0x5d/0x260
[ 57.845455] ? asm_exc_page_fault+0x8/0x30
[ 57.848252] asm_exc_page_fault+0x1e/0x30
[ 57.851043] RIP: 0033:0x4003b0
[ 57.853404] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 <00> 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 57.861944] RSP: 002b:00007ffc032269f8 EFLAGS: 00010212
[ 57.864996] RAX: 00007fc8dbb25064 RBX: 000000000000000b RCX: 0a30303030303478
[ 57.868674] RDX: 0000000000000075 RSI: 0000000000000000 RDI: 00007fc8dbb2506f
[ 57.872387] RBP: 00007fc8dbb25064 R08: 0000000000000001 R09: 0000000000000008
[ 57.876154] R10: 0000000000000000 R11: 0000000000000000 R12: 000000000000000b
[ 57.879900] R13: 00007fc8dbb1f058 R14: 00000000000002a6 R15: 0000000000000008
[ 58.836817] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c2/660
[ 58.841943] caller is lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 58.845502] CPU: 0 PID: 660 Comm: trinity-c2 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 58.849414] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 58.853254] Call Trace:
[ 58.855946] dump_stack+0x8d/0xb5
[ 58.858719] check_preemption_disabled+0xc3/0xe0
[ 58.861840] lockdep_hardirqs_on_prepare+0x2f/0x1c0
[ 58.865091] trace_hardirqs_on+0x40/0x100
[ 58.868054] __bad_area_nosemaphore+0x63/0x180
[ 58.871058] exc_page_fault+0x5d/0x260
[ 58.873863] ? asm_exc_page_fault+0x8/0x30
[ 58.876544] asm_exc_page_fault+0x1e/0x30
[ 58.879296] RIP: 0033:0x4134c1
[ 58.881861] Code: 00 85 d2 75 54 e8 af 05 00 00 e9 2a ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 83 c5 02 44 39 ed 0f 87 74 fd ff ff e8 6f 01 00 00 <66> 41 89 04 24 e9 de fb ff ff 0f 1f 44 00 00 41 8d 45 ff c6 04 03
[ 58.890245] RSP: 002b:00007ffc03226ad0 EFLAGS: 00010206
[ 58.893762] RAX: 0000000000000071 RBX: 0000000000000000 RCX: 0000000000000000
[ 58.897628] RDX: 00000000285d5467 RSI: 00007ffc03226a8c RDI: 0000000001094c60
[ 58.901340] RBP: 0000000000000002 R08: 0000000001094ca4 R09: 0000000001094d20
[ 58.905189] R10: ffffffffffffffff R11: 0000000000000287 R12: 0000000000000000
[ 58.908887] R13: 0000000000001000 R14: 0000000055555556 R15: 0000000000000000
[ 58.912797] BUG: using __this_cpu_read() in preemptible [00000000] code: trinity-c2/660
[ 58.916783] caller is lockdep_hardirqs_on+0x38/0x120
[ 58.920180] CPU: 0 PID: 660 Comm: trinity-c2 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 58.924262] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 58.928247] Call Trace:
[ 58.930783] dump_stack+0x8d/0xb5
[ 58.933521] check_preemption_disabled+0xc3/0xe0
[ 58.936567] ? __bad_area_nosemaphore+0x63/0x180
[ 58.939671] lockdep_hardirqs_on+0x38/0x120
[ 58.942471] __bad_area_nosemaphore+0x63/0x180
[ 58.945531] exc_page_fault+0x5d/0x260
[ 58.948204] ? asm_exc_page_fault+0x8/0x30
[ 58.950982] asm_exc_page_fault+0x1e/0x30
[ 58.953757] RIP: 0033:0x4134c1
[ 58.956438] Code: 00 85 d2 75 54 e8 af 05 00 00 e9 2a ff ff ff 66 2e 0f 1f 84 00 00 00 00 00 83 c5 02 44 39 ed 0f 87 74 fd ff ff e8 6f 01 00 00 <66> 41 89 04 24 e9 de fb ff ff 0f 1f 44 00 00 41 8d 45 ff c6 04 03
[ 58.964615] RSP: 002b:00007ffc03226ad0 EFLAGS: 00010206
[ 58.967977] RAX: 0000000000000071 RBX: 0000000000000000 RCX: 0000000000000000
[ 58.971552] RDX: 00000000285d5467 RSI: 00007ffc03226a8c RDI: 0000000001094c60
[ 58.975218] RBP: 0000000000000002 R08: 0000000001094ca4 R09: 0000000001094d20
[ 58.978843] R10: ffffffffffffffff R11: 0000000000000287 R12: 0000000000000000
[ 58.982182] R13: 0000000000001000 R14: 0000000055555556 R15: 0000000000000000
[ 59.064181]
[ 59.072668] =============================
[ 59.083414] WARNING: suspicious RCU usage
[ 59.096302] 5.9.0-02606-gd5883a5113ffde #1 Not tainted
[ 59.109297] -----------------------------
[ 59.114391] include/linux/cgroup.h:494 suspicious rcu_dereference_check() usage!
[ 59.120423]
[ 59.120423] other info that might help us debug this:
[ 59.120423]
[ 59.131496]
[ 59.131496] rcu_scheduler_active = 2, debug_locks = 1
[ 59.141142] no locks held by trinity-c5/757.
[ 59.146572]
[ 59.146572] stack backtrace:
[ 59.154114] CPU: 1 PID: 757 Comm: trinity-c5 Not tainted 5.9.0-02606-gd5883a5113ffde #1
[ 59.158382] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 59.162381] Call Trace:
[ 59.165123] dump_stack+0x8d/0xb5
[ 59.168036] io_init_identity+0xeb/0x100
[ 59.170852] io_uring_alloc_task_context+0xa1/0xc0
[ 59.173832] io_uring_add_task_file+0x6d/0x80
[ 59.176511] io_uring_create+0x654/0x9e0
[ 59.179247] io_uring_setup+0x57/0xa0
[ 59.182179] do_syscall_64+0x33/0x40
[ 59.184815] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[ 59.187747] RIP: 0033:0x463519
[ 59.190228] Code: 00 f3 c3 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 40 00 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24 08 0f 05 <48> 3d 01 f0 ff ff 0f 83 db 59 00 00 c3 66 2e 0f 1f 84 00 00 00 00
[ 59.198321] RSP: 002b:00007ffc03226938 EFLAGS: 00000246 ORIG_RAX: 00000000000001a9
[ 59.202158] RAX: ffffffffffffffda RBX: 00000000000001a9 RCX: 0000000000463519
[ 59.205873] RDX: 0000000000000800 RSI: 00007fc8dacf0000 RDI: 000000000000008b
[ 59.209615] RBP: 00007fc8dbb26000 R08: 00000000420f0db7 R09: 00f82028447cfd92
[ 59.213114] R10: ffffaa34c80b8d94 R11: 0000000000000246 R12: 0000000000000002
[ 59.216818] R13: 00007fc8dbb26058 R14: 0000000002c87850 R15: 00007fc8dbb26000
Kboot worker: lkp-worker29
Elapsed time: 60
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu SandyBridge
-kernel $kernel
-initrd initrd-vm-snb-75.cgz
-m 8192
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::32032-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-snb-75::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-rhel-7.6-kselftests
branch=block/io_uring-5.10-next
commit=d5883a5113ffde433efec9b54e4402c9534ccb19
BOOT_IMAGE=/pkg/linux/x86_64-rhel-7.6-kselftests/gcc-9/d5883a5113ffde433efec9b54e4402c9534ccb19/vmlinuz-5.9.0-02606-gd5883a5113ffde
max_uptime=3600
RESULT_ROOT=/result/trinity/300s/vm-snb/yocto-x86_64-minimal-20190520.cgz/x86_64-rhel-7.6-kselftests/gcc-9/d5883a5113ffde433efec9b54e4402c9534ccb19/3
result_service=tmpfs
selinux=0
debug
apic=debug
sysrq_always_enabled
rcupdate.rcu_cpu_stall_timeout=100
net.ifnames=0
printk.devkmsg=on
panic=-1
softlockup_panic=1
nmi_watchdog=panic
oops=panic
load_ramdisk=2
prompt_ramdisk=0
drbd.minor_count=8
systemd.log_level=err
ignore_loglevel
console=tty0
earlyprintk=ttyS0,115200
console=ttyS0,115200
vga=normal
rw
rcuperf.shutdown=0
watchdog_thresh=60
)
"${kvm[@]}" -append "${append[*]}"
To reproduce:
# build kernel
cd linux
cp config-5.9.0-02606-gd5883a5113ffde .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 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,
Rong Chen
On 10/18/20 2:52 AM, kernel test robot wrote:
> Greeting,
>
> FYI, we noticed the following commit (built with gcc-9):
>
> commit: d5883a5113ffde433efec9b54e4402c9534ccb19 ("io_uring: store io_identity in io_uring_task")
> https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git io_uring-5.10-next
This one should already be fixed.
--
Jens Axboe