bpf.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
From: Masami Hiramatsu <mhiramat@kernel.org>
To: kernel test robot <rong.a.chen@intel.com>
Cc: Steven Rostedt <rostedt@goodmis.org>,
	linux-kernel@vger.kernel.org, Ingo Molnar <mingo@kernel.org>,
	Andrew Morton <akpm@linux-foundation.org>,
	Peter Zijlstra <peterz@infradead.org>,
	Masami Hiramatsu <mhiramat@kernel.org>,
	Alexei Starovoitov <alexei.starovoitov@gmail.com>,
	Peter Wu <peter@lekensteyn.nl>, Jonathan Corbet <corbet@lwn.net>,
	Tom Zanussi <zanussi@kernel.org>,
	Shuah Khan <shuahkhan@gmail.com>, bpf <bpf@vger.kernel.org>,
	lkp@lists.01.org
Subject: Re: [tracing] cd8f62b481: BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h
Date: Wed, 1 Apr 2020 23:07:00 +0900	[thread overview]
Message-ID: <20200401230700.d9ddb42b3459dca98144b55c@kernel.org> (raw)
In-Reply-To: <20200326091256.GR11705@shao2-debian>

Hi Steve,

On Thu, 26 Mar 2020 17:12:56 +0800
kernel test robot <rong.a.chen@intel.com> wrote:

> FYI, we noticed the following commit (built with gcc-7):
> 
> commit: cd8f62b481530fafbeacee0d3283b60bcf42d854 ("[PATCH 02/12 v2] tracing: Save off entry when peeking at next entry")
> url: https://github.com/0day-ci/linux/commits/Steven-Rostedt/ring-buffer-tracing-Remove-disabling-of-ring-buffer-while-reading-trace-file/20200320-073240
> 

Hmm, this seems that we can not call kmalloc() in ftrace_dump().
Maybe we can fix it by
- Use GFP_ATOMIC.
 or
- Do not use iter->temp if it is NULL. (it is safe since ftrace_dump() stops tracing)

What would you think?

Thank you,

> 
> in testcase: rcuperf
> with following parameters:
> 
> 	runtime: 300s
> 	perf_type: rcu
> 
> 
> 
> 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):
> 
> 
> +----------------------------------------------------------------+------------+------------+
> |                                                                | 2e2bf17ca0 | cd8f62b481 |
> +----------------------------------------------------------------+------------+------------+
> | boot_successes                                                 | 13         | 0          |
> | boot_failures                                                  | 0          | 8          |
> | BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h | 0          | 8          |
> +----------------------------------------------------------------+------------+------------+
> 
> 
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <rong.a.chen@intel.com>
> 
> 
> [   16.821280] BUG: sleeping function called from invalid context at mm/slab.h:565
> [   16.822211] in_atomic(): 0, irqs_disabled(): 1, non_block: 0, pid: 158, name: rcu_perf_writer
> [   16.823164] no locks held by rcu_perf_writer/158.
> [   16.823650] CPU: 0 PID: 158 Comm: rcu_perf_writer Not tainted 5.6.0-rc6-00081-gcd8f62b481530f #1
> [   16.824856] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
> [   16.826220] Call Trace:
> [   16.826667]  dump_stack+0x16/0x18
> [   16.827265]  ___might_sleep+0x104/0x118
> [   16.827947]  __might_sleep+0x69/0x70
> [   16.828600]  ? __fs_reclaim_release+0x17/0x19
> [   16.829374]  slab_pre_alloc_hook+0x34/0x6e
> [   16.830107]  __kmalloc+0x48/0xe8
> [   16.830710]  ? rb_reader_unlock+0x2b/0x3c
> [   16.831205]  ? trace_find_next_entry+0x84/0x133
> [   16.831723]  trace_find_next_entry+0x84/0x133
> [   16.832217]  trace_print_lat_context+0x4b/0x437
> [   16.832730]  ? rb_event_length+0x56/0x67
> [   16.833186]  ? ring_buffer_event_length+0x34/0x79
> [   16.833728]  ? __find_next_entry+0xd3/0x1c2
> [   16.834190]  print_trace_line+0x69d/0x767
> [   16.834666]  ftrace_dump+0x285/0x437
> [   16.835055]  rcu_perf_writer+0x25f/0x34e
> [   16.835476]  kthread+0xdf/0xe1
> [   16.835823]  ? rcu_perf_reader+0x9c/0x9c
> [   16.836264]  ? kthread_create_worker_on_cpu+0x1c/0x1c
> [   16.836834]  ret_from_fork+0x2e/0x38
> [   16.837270] rb_produ-160     0.... 6528532us : ring_buffer_producer: Starting ring buffer hammer
> [   16.838318] rb_produ-160     0.... 16529141us : ring_buffer_producer: End ring buffer hammer
> [   16.839349] rb_produ-160     0.... 16558157us : ring_buffer_producer: Running Consumer at nice: 19
> [   16.840382] rb_produ-160     0.... 16558162us : ring_buffer_producer: Running Producer at nice: 19
> [   16.841401] rb_produ-160     0.... 16558163us : ring_buffer_producer: WARNING!!! This test is running at lowest priority.
> [   16.854781] rb_produ-160     0.... 16558164us : ring_buffer_producer: Time:     10000604 (usecs)
> [   16.857354] rb_produ-160     0.... 16558165us : ring_buffer_producer: Overruns: 6117960
> [   16.858322] rb_produ-160     0.... 16558166us : ring_buffer_producer: Read:     4356190  (by events)
> [   16.859404] rb_produ-160     0.... 16558167us : ring_buffer_producer: Entries:  44650
> [   16.860329] rb_produ-160     0.... 16558167us : ring_buffer_producer: Total:    10518800
> [   16.861226] rb_produ-160     0.... 16558168us : ring_buffer_producer: Missed:   0
> [   16.862124] rb_produ-160     0.... 16558169us : ring_buffer_producer: Hit:      10518800
> [   16.863087] rb_produ-160     0.... 16558170us : ring_buffer_producer: Entries per millisec: 1051
> [   16.864123] rb_produ-160     0.... 16558171us : ring_buffer_producer: 951 ns per entry
> [   16.865074] rb_produ-160     0.... 16558172us : ring_buffer_producer_thread: Sleeping for 10 secs
> [   16.866105] ---------------------------------
> [   16.866725] rcu-perf: Test complete
> [   16.878198] random: fast init done
> 
> Elapsed time: 60
> 
> qemu-img create -f qcow2 disk-vm-snb-i386-9-0 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-1 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-2 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-3 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-4 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-5 256G
> qemu-img create -f qcow2 disk-vm-snb-i386-9-6 256G
> 
> kvm=(
> 	qemu-system-i386
> 	-enable-kvm
> 	-cpu SandyBridge
> 	-kernel $kernel
> 	-initrd initrd-vm-snb-i386-9.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-9-0,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-1,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-2,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-3,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-4,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-5,media=disk,if=virtio
> 	-drive file=disk-vm-snb-i386-9-6,media=disk,if=virtio
> 	-serial stdio
> 	-display none
> 	-monitor null
> )
> 
> append=(
> 	ip=::::vm-snb-i386-9::dhcp
> 	root=/dev/ram0
> 	user=lkp
> 	job=/job-script
> 	ARCH=i386
> 	kconfig=i386-randconfig-g003-20200324
> 	branch=linux-devel/devel-hourly-2020032505
> 	commit=cd8f62b481530fafbeacee0d3283b60bcf42d854
> 	BOOT_IMAGE=/pkg/linux/i386-randconfig-g003-20200324/gcc-7/cd8f62b481530fafbeacee0d3283b60bcf42d854/vmlinuz-5.6.0-rc6-00081-gcd8f62b481530f
> 	max_uptime=1500
> 	RESULT_ROOT=/result/rcuperf/rcu-300s/vm-snb-i386/yocto-i386-minimal-20190520.cgz/i386-randconfig-g003-20200324/gcc-7/cd8f62b481530fafbeacee0d3283b60bcf42d854/3
> 	result_service=tmpfs
> 	selinux=0
> 	debug
> 	apic=debug
> 	sysrq_always_enabled
> 	rcupdate.rcu_cpu_stall_timeout=100
> 	net.ifnames=0
> 
> 
> To reproduce:
> 
>         # build kernel
> 	cd linux
> 	cp config-5.6.0-rc6-00081-gcd8f62b481530f .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
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

  parent reply	other threads:[~2020-04-01 14:07 UTC|newest]

Thread overview: 27+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2020-03-19 23:22 [PATCH 00/12 v2] ring-buffer/tracing: Remove disabling of ring buffer while reading trace file Steven Rostedt
2020-03-19 23:22 ` [PATCH 01/12 v2] selftest/ftrace: Fix function trigger test to handle trace not disabling the tracer Steven Rostedt
2020-03-19 23:22 ` [PATCH 02/12 v2] tracing: Save off entry when peeking at next entry Steven Rostedt
2020-03-20  2:57   ` Masami Hiramatsu
     [not found]   ` <20200326091256.GR11705@shao2-debian>
2020-04-01 14:07     ` Masami Hiramatsu [this message]
2020-04-01 14:21       ` [tracing] cd8f62b481: BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h Steven Rostedt
2020-04-01 15:04         ` Steven Rostedt
2020-04-02  7:19           ` Masami Hiramatsu
2020-04-02 18:14             ` Steven Rostedt
2020-04-03  6:47               ` Masami Hiramatsu
2020-04-03 13:16                 ` Steven Rostedt
2020-03-19 23:22 ` [PATCH 03/12 v2] ring-buffer: Have ring_buffer_empty() not depend on tracing stopped Steven Rostedt
2020-03-19 23:22 ` [PATCH 04/12 v2] ring-buffer: Rename ring_buffer_read() to read_buffer_iter_advance() Steven Rostedt
2020-03-19 23:22 ` [PATCH 05/12 v2] ring-buffer: Add page_stamp to iterator for synchronization Steven Rostedt
2020-03-19 23:22 ` [PATCH 06/12 v2] ring-buffer: Have rb_iter_head_event() handle concurrent writer Steven Rostedt
2020-03-19 23:22 ` [PATCH 07/12 v2] ring-buffer: Do not die if rb_iter_peek() fails more than thrice Steven Rostedt
2020-03-19 23:22 ` [PATCH 08/12 v2] ring-buffer: Optimize rb_iter_head_event() Steven Rostedt
2020-03-19 23:22 ` [PATCH 09/12 v2] ring-buffer: Do not disable recording when there is an iterator Steven Rostedt
2020-03-19 23:22 ` [PATCH 10/12 v2] tracing: Do not disable tracing when reading the trace file Steven Rostedt
2020-03-19 23:22 ` [PATCH 11/12 v2] ring-buffer/tracing: Have iterator acknowledge dropped events Steven Rostedt
2020-03-19 23:22 ` [PATCH 12/12 v2] tracing: Have the document reflect that the trace file keeps tracing enabled Steven Rostedt
2020-03-21 19:13 ` [PATCH 00/12 v2] ring-buffer/tracing: Remove disabling of ring buffer while reading trace file David Laight
2020-03-22 18:07   ` Steven Rostedt
2020-03-27  1:46   ` Steven Rostedt
2020-03-27 10:07     ` David Laight
2020-03-27 14:30       ` Steven Rostedt
2020-03-27 14:56         ` David Laight

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20200401230700.d9ddb42b3459dca98144b55c@kernel.org \
    --to=mhiramat@kernel.org \
    --cc=akpm@linux-foundation.org \
    --cc=alexei.starovoitov@gmail.com \
    --cc=bpf@vger.kernel.org \
    --cc=corbet@lwn.net \
    --cc=linux-kernel@vger.kernel.org \
    --cc=lkp@lists.01.org \
    --cc=mingo@kernel.org \
    --cc=peter@lekensteyn.nl \
    --cc=peterz@infradead.org \
    --cc=rong.a.chen@intel.com \
    --cc=rostedt@goodmis.org \
    --cc=shuahkhan@gmail.com \
    --cc=zanussi@kernel.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).