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>] [day] [month] [year] [list]
Date:   Sat, 28 Mar 2020 21:19:56 +0800
From:   kernel test robot <rong.a.chen@...el.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     LKML <linux-kernel@...r.kernel.org>, lkp@...ts.01.org
Subject: [tracing] ff895103a8:
 BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h

FYI, we noticed the following commit (built with gcc-7):

commit: ff895103a84abc85a5f43ecabc7f67cf36e1348f ("tracing: Save off entry when peeking at next entry")
https://git.kernel.org/cgit/linux/kernel/git/rostedt/linux-trace.git ftrace/core

in testcase: rcuperf
with following parameters:

	runtime: 300s
	perf_type: srcud



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):


+----------------------------------------------------------------+------------+------------+
|                                                                | 8c77f0ba41 | ff895103a8 |
+----------------------------------------------------------------+------------+------------+
| boot_successes                                                 | 4          | 4          |
| boot_failures                                                  | 0          | 4          |
| BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h | 0          | 4          |
+----------------------------------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <rong.a.chen@...el.com>


[   19.755781] BUG: sleeping function called from invalid context at mm/slab.h:565
[   19.757001] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 597, name: rcu_perf_writer
[   19.758163] no locks held by rcu_perf_writer/597.
[   19.758798] CPU: 1 PID: 597 Comm: rcu_perf_writer Tainted: G                T 5.6.0-rc4-00008-gff895103a84ab #2
[   19.760123] Call Trace:
[   19.760473]  ? dump_stack+0x6b/0xa1
[   19.760955]  ? ___might_sleep+0x146/0x170
[   19.761507]  ? __kmalloc+0x73/0x300
[   19.762010]  ? trace_find_next_entry+0x5c/0x120
[   19.762626]  ? trace_find_next_entry+0x5c/0x120
[   19.763243]  ? trace_print_lat_context+0x29/0x3b0
[   19.763885]  ? find_next_bit+0x29/0x40
[   19.764398]  ? __find_next_entry+0x10d/0x170
[   19.764979]  ? print_trace_line+0x475/0x570
[   19.765551]  ? ftrace_dump+0x173/0x250
[   19.766027]  ? rcu_perf_writer+0x345/0x480 [rcuperf]
[   19.766457]  ? kthread+0xf7/0x100
[   19.766747]  ? rcu_perf_wait_shutdown+0x60/0x60 [rcuperf]
[   19.767208]  ? kthread_stop+0x210/0x210
[   19.767542]  ? ret_from_fork+0x1e/0x28
[   19.767883] rb_produ-167     1.... 1976130us : ring_buffer_producer_thread: Starting ring buffer hammer
[   19.768684] rb_produ-167     0.... 11977103us : ring_buffer_producer_thread: End ring buffer hammer
[   19.769457] rb_produ-167     0.... 12023757us : ring_buffer_producer_thread: Running Consumer at nice: 19
[   19.770282] rb_produ-167     0.... 12023758us : ring_buffer_producer_thread: Running Producer at nice: 19
[   19.771094] rb_produ-167     0.... 12023758us : ring_buffer_producer_thread: WARNING!!! This test is running at lowest priority.
[   19.772075] rb_produ-167     0.... 12023758us : ring_buffer_producer_thread: Time:     10000957 (usecs)
[   19.772874] rb_produ-167     0.... 12023759us : ring_buffer_producer_thread: Overruns: 34670819
[   19.773620] rb_produ-167     0.... 12023759us : ring_buffer_producer_thread: Read:     7743031  (by events)
[   19.774451] rb_produ-167     0.... 12023760us : ring_buffer_producer_thread: Entries:  0
[   19.775140] rb_produ-167     0.... 12023760us : ring_buffer_producer_thread: Total:    42413850
[   19.775878] rb_produ-167     0.... 12023760us : ring_buffer_producer_thread: Missed:   0
[   19.776576] rb_produ-167     0.... 12023760us : ring_buffer_producer_thread: Hit:      42413850
[   19.777313] rb_produ-167     0.... 12023760us : ring_buffer_producer_thread: Entries per millisec: 4241
[   19.778118] rb_produ-167     0.... 12023761us : ring_buffer_producer_thread: 235 ns per entry
[   19.778849] rb_produ-167     0.... 12023761us : ring_buffer_producer_thread: Sleeping for 10 secs
[   19.779600] ---------------------------------
[   19.791139] random: fast init done
[   19.791524] srcud-perf: Test complete

Elapsed time: 60

qemu-img create -f qcow2 disk-vm-snb-i386-37-0 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-1 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-2 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-3 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-4 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-5 256G
qemu-img create -f qcow2 disk-vm-snb-i386-37-6 256G

kvm=(
	qemu-system-i386
	-enable-kvm
	-cpu SandyBridge
	-kernel $kernel
	-initrd initrd-vm-snb-i386-37.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
	-drive file=disk-vm-snb-i386-37-0,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-1,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-2,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-3,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-4,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-5,media=disk,if=virtio
	-drive file=disk-vm-snb-i386-37-6,media=disk,if=virtio
	-serial stdio
	-display none
	-monitor null
)

append=(
	ip=::::vm-snb-i386-37::dhcp
	root=/dev/ram0
	user=lkp
	job=/job-script
	ARCH=i386
	kconfig=i386-randconfig-b003-20200324
	branch=linux-devel/devel-hourly-2020032506
	commit=ff895103a84abc85a5f43ecabc7f67cf36e1348f
	BOOT_IMAGE=/pkg/linux/i386-randconfig-b003-20200324/gcc-7/ff895103a84abc85a5f43ecabc7f67cf36e1348f/vmlinuz-5.6.0-rc4-00008-gff895103a84ab
	max_uptime=1500
	RESULT_ROOT=/result/rcuperf/srcud-300s/vm-snb-i386/yocto-i386-minimal-20190520.cgz/i386-randconfig-b003-20200324/gcc-7/ff895103a84abc85a5f43ecabc7f67cf36e1348f/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


To reproduce:

        # build kernel
	cd linux
	cp config-5.6.0-rc4-00008-gff895103a84ab .config
	make HOSTCC=gcc-7 CC=gcc-7 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,
Rong Chen


View attachment "config-5.6.0-rc4-00008-gff895103a84ab" of type "text/plain" (132989 bytes)

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

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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ