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  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Date:   Sun, 18 Oct 2020 16:52:51 +0800
From:   kernel test robot <rong.a.chen@...el.com>
To:     Jens Axboe <axboe@...nel.dk>
Cc:     LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org,
        lkp@...el.com
Subject: [io_uring] d5883a5113: BUG:using__this_cpu_read()in_preemptible

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 <rong.a.chen@...el.com>


[   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


View attachment "config-5.9.0-02606-gd5883a5113ffde" of type "text/plain" (210231 bytes)

View attachment "job-script" of type "text/plain" (4300 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (15728 bytes)

Powered by blists - more mailing lists