lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<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

Powered by Openwall GNU/*/Linux Powered by OpenVZ