[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <20180724074730.GH19722@shao2-debian>
Date: Tue, 24 Jul 2018 15:47:30 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Jia-Ju Bai <baijiaju1990@...il.com>
Cc: axboe@...nel.dk, linux-block@...r.kernel.org,
linux-kernel@...r.kernel.org, Jia-Ju Bai <baijiaju1990@...il.com>,
lkp@...org
Subject: [LKP] [block] 8448e82606: WARNING:suspicious_RCU_usage
FYI, we noticed the following commit (built with gcc-7):
commit: 8448e82606629efed4829e4a50874b62a6e90d6a ("[PATCH] block: ioprio: Replace GFP_ATOMIC with GFP_KERNEL in set_task_ioprio()")
url: https://github.com/0day-ci/linux/commits/Jia-Ju-Bai/block-ioprio-Replace-GFP_ATOMIC-with-GFP_KERNEL-in-set_task_ioprio/20180723-104919
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next
in testcase: trinity
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 host -smp 2 -m 1G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+------------------------------------------------------------------------------------+------------+------------+
| | e7a0c1f1ee | 8448e82606 |
+------------------------------------------------------------------------------------+------------+------------+
| boot_successes | 31 | 34 |
| boot_failures | 5 | 27 |
| invoked_oom-killer:gfp_mask=0x | 5 | 8 |
| Mem-Info | 5 | 8 |
| RIP:copy_user_generic_unrolled | 1 | |
| WARNING:suspicious_RCU_usage | 0 | 19 |
| include/linux/rcupdate.h:#Illegal_context_switch_in_RCU_read-side_critical_section | 0 | 19 |
| BUG:sleeping_function_called_from_invalid_context_at_block/blk-ioc.c | 0 | 19 |
| Out_of_memory:Kill_process | 0 | 1 |
| RIP:__put_user_4 | 0 | 1 |
| RIP:__clear_user | 0 | 2 |
+------------------------------------------------------------------------------------+------------+------------+
[ 205.610784] WARNING: suspicious RCU usage
[ 205.611955] 4.18.0-rc4-00088-g8448e82 #1 Not tainted
[ 205.613463] -----------------------------
[ 205.614655] include/linux/rcupdate.h:303 Illegal context switch in RCU read-side critical section!
[ 205.618099]
[ 205.618099] other info that might help us debug this:
[ 205.618099]
[ 205.620775]
[ 205.620775] rcu_scheduler_active = 2, debug_locks = 1
[ 205.622906] 1 lock held by trinity-c3/10529:
[ 205.624331] #0: 000000004b305fe0 (rcu_read_lock){....}, at: rcu_read_lock+0x0/0x31
[ 205.626804]
[ 205.626804] stack backtrace:
[ 205.628245] CPU: 0 PID: 10529 Comm: trinity-c3 Not tainted 4.18.0-rc4-00088-g8448e82 #1
[ 205.630789] Call Trace:
[ 205.631619] ___might_sleep+0x1c/0x1d1
[ 205.632876] get_task_io_context+0x2f/0x87
[ 205.634209] set_task_ioprio+0xb7/0xd2
[ 205.635384] __x64_sys_ioprio_set+0x7f/0x27f
[ 205.636811] ? do_syscall_64+0x16/0x176
[ 205.638081] do_syscall_64+0x165/0x176
[ 205.639348] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 205.640996] RIP: 0033:0x7f56bc95b229
[ 205.642068] 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 73 01 c3 48 8b 0d 3f 4c 2b 00 f7 d8 64 89 01 48
[ 205.647906] RSP: 002b:00007ffc377476f8 EFLAGS: 00000246 ORIG_RAX: 00000000000000fb
[ 205.650384] RAX: ffffffffffffffda RBX: 00000000000000fb RCX: 00007f56bc95b229
[ 205.652579] RDX: 0000000000007171 RSI: 0000000000000000 RDI: 0000000000000001
[ 205.654920] RBP: 00007ffc377477a0 R08: 0000000000000004 R09: 0000253c04282180
[ 205.657318] R10: 0000000012000060 R11: 0000000000000246 R12: 0000000000000002
[ 205.659657] R13: 00007f56bd01c058 R14: 00007f56bd038ad8 R15: 00007f56bd01c000
[ 205.662033] BUG: sleeping function called from invalid context at block/blk-ioc.c:324
[ 205.665181] in_atomic(): 1, irqs_disabled(): 0, pid: 10529, name: trinity-c3
[ 205.667489] 1 lock held by trinity-c3/10529:
[ 205.668939] #0: 000000004b305fe0 (rcu_read_lock){....}, at: rcu_read_lock+0x0/0x31
[ 205.671481] CPU: 0 PID: 10529 Comm: trinity-c3 Not tainted 4.18.0-rc4-00088-g8448e82 #1
[ 205.674186] Call Trace:
[ 205.675074] ___might_sleep+0x1b8/0x1d1
[ 205.676425] get_task_io_context+0x2f/0x87
[ 205.677819] set_task_ioprio+0xb7/0xd2
[ 205.679060] __x64_sys_ioprio_set+0x7f/0x27f
[ 205.680522] ? do_syscall_64+0x16/0x176
[ 205.681838] do_syscall_64+0x165/0x176
[ 205.683092] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 205.684745] RIP: 0033:0x7f56bc95b229
[ 205.685852] 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 73 01 c3 48 8b 0d 3f 4c 2b 00 f7 d8 64 89 01 48
[ 205.691723] RSP: 002b:00007ffc377476f8 EFLAGS: 00000246 ORIG_RAX: 00000000000000fb
[ 205.694239] RAX: ffffffffffffffda RBX: 00000000000000fb RCX: 00007f56bc95b229
[ 205.696578] RDX: 0000000000007171 RSI: 0000000000000000 RDI: 0000000000000001
[ 205.698856] RBP: 00007ffc377477a0 R08: 0000000000000004 R09: 0000253c04282180
[ 205.701148] R10: 0000000012000060 R11: 0000000000000246 R12: 0000000000000002
[ 205.703423] R13: 00007f56bd01c058 R14: 00007f56bd038ad8 R15: 00007f56bd01c000
[ 205.742618] [child1:10493] trace_fd was -1
[ 205.742633]
[ 205.761481] [main] trace_fd was -1
[ 205.761495]
[ 205.783383] [main] kernel became tainted! (512/0) Last seed was 4121142949
[ 205.783398]
[ 205.828372] trinity: Detected kernel tainting. Last seed was 4121142949
[ 205.828388]
[ 206.085299] [child3:10529] trace_fd was -1
[ 206.085316]
[ 206.106885] [main] exit_reason=7, but 2 children still running.
[ 206.106902]
[ 209.105912] [main] Bailing main loop because kernel became tainted..
[ 209.105936]
[ 209.156724] [main] trace_fd was -1
[ 209.156747]
[ 209.181460] [main] Ran 491475 syscalls. Successes: 156553 Failures: 335387
[ 209.181476]
Elapsed time: 210
#!/bin/bash
# To reproduce,
# 1) save job-script and this script (both are attached in 0day report email)
# 2) run this script with your compiled kernel and optional env $INSTALL_MOD_PATH
kernel=$1
initrds=(
/osimage/debian/debian-x86_64-2018-04-03.cgz
/lkp/lkp/lkp-x86_64.cgz
/osimage/deps/debian-x86_64-2018-04-03.cgz/run-ipconfig_2018-04-03.cgz
/osimage/deps/debian-x86_64-2018-04-03.cgz/lkp_2018-04-03.cgz
/osimage/deps/debian-x86_64-2018-04-03.cgz/rsync-rootfs_2018-04-03.cgz
/osimage/pkg/debian-x86_64-2018-04-03.cgz/trinity-x86_64-1b2d43cb_2018-06-12.cgz
)
HTTP_PREFIX=https://download.01.org/0day-ci/lkp-qemu
wget --timestamping "${initrds[@]/#/$HTTP_PREFIX}"
{
cat "${initrds[@]//*\//}"
[[ $INSTALL_MOD_PATH ]] && (
cd "$INSTALL_MOD_PATH"
find lib | cpio -o -H newc --quiet | gzip
)
echo job-script | cpio -o -H newc --quiet | gzip
} > initrd.img
kvm=(
qemu-system-x86_64
-enable-kvm
-cpu host
-kernel $kernel
-initrd initrd.img
-m 1024
-smp 2
-device e1000,netdev=net0
-netdev user,id=net0,hostfwd=tcp::23203-:22
-boot order=nc
-no-reboot
-watchdog i6300esb
-watchdog-action debug
-rtc base=localtime
-serial stdio
-display none
-monitor null
)
append=(
ip=::::vm-lkp-nex04-1G-4::dhcp
root=/dev/ram0
user=lkp
job=/job-script
ARCH=x86_64
kconfig=x86_64-randconfig-s3-07231123
branch=linux-devel/devel-catchup-201807231136
commit=8448e82606629efed4829e4a50874b62a6e90d6a
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-s3-07231123/gcc-7/8448e82606629efed4829e4a50874b62a6e90d6a/vmlinuz-4.18.0-rc4-00088-g8448e82
To reproduce:
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
View attachment "config-4.18.0-rc4-00088-g8448e82" of type "text/plain" (105381 bytes)
View attachment "job-script" of type "text/plain" (4090 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (20188 bytes)
Powered by blists - more mailing lists