Re: rcu_preempt caused oom

[Paul E. McKenney]

On Wed, Dec 05, 2018 at 08:42:54AM +0000, He, Bo wrote:
> I double checked the .config, we don't enable CONFIG_NO_HZ_FULL .
> Our previous logs can dump all the task backtrace, and kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks) are all in "I" state not in "R" state, my understandings are if it's the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, the kthreads should be in R state.

Hmmm...  Well, the tasks could in theory be waiting on a blocking mutex.
But in practice the grace-period kthreads wait on events, so that makes
no sense.

Is it possible for you to dump out the grace-period kthread's stack,
for example, with sysreq-t?  (Steve might know a better way to do this.)

> I will do more experiments and keep you update once we have more findings:
> 1. set the kthread priority to SCHED_FIFO without CONFIG_RCU_BOOST and see if the issue can reproduce.

That sounds like a most excellent experiment!

> 2. check more ftrace to double confirm why there is no trace_rcu_quiescent_state_report and most of the trace_rcu_grace_period are in "AccWaitCB".

As noted earlier, to see something interesting, you will need to start
the ftrace before the grace period starts.  This would probably mean
having ftrace running before starting the test.  Starting the ftrace
after the hang commences is unlikely to produce useful information.

							Thanx, Paul

> -----Original Message-----
> From: Paul E. McKenney <paulmck@xxxxxxxxxxxxx> 
> Sent: Wednesday, December 5, 2018 3:50 AM
> To: He, Bo <bo.he@xxxxxxxxx>
> Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>; linux-kernel@xxxxxxxxxxxxxxx; josh@xxxxxxxxxxxxxxxx; mathieu.desnoyers@xxxxxxxxxxxx; jiangshanlai@xxxxxxxxx; Zhang, Jun <jun.zhang@xxxxxxxxx>; Xiao, Jin <jin.xiao@xxxxxxxxx>; Zhang, Yanmin <yanmin.zhang@xxxxxxxxx>; Bai, Jie A <jie.a.bai@xxxxxxxxx>
> Subject: Re: rcu_preempt caused oom
> 
> On Tue, Dec 04, 2018 at 07:50:04AM +0000, He, Bo wrote:
> > Hi, Paul:
> > the enclosed is the log trigger the 120s hung_task_panic without other debug patches, the hung task is blocked at __wait_rcu_gp, it means the rcu_cpu_stall can't detect the scenario:
> > echo 1 > /proc/sys/kernel/panic_on_rcu_stall
> > echo 7 > /sys/module/rcupdate/parameters/rcu_cpu_stall_timeout
> 
> Not necessarily.  If there is an RCU CPU stall warning, blocking within
> __wait_rcu_gp() is expected behavior.  It is possible that the problem is that although the grace period is completing as required, the callbacks are not being invoked in a timely fashion.  And that could happen if you had CONFIG_NO_HZ_FULL and a bunch of nohz_full CPUs, or, alternatively, callback offloading enabled.  But I don't see these in your previous emails.  Another possible cause is that the grace-period kthread is being delayed, so that the grace period never starts.  This seems unlikely, but it is the only thing thus far that matches the symptoms.
> 
> CONFIG_RCU_BOOST=y has the side-effect of causing RCU's kthreads to be run at SCHED_FIFO priority 1, and that would help in the case where RCU's grace-period kthread (the rcu_preempt, rcu_sched, and rcu_bh tasks, all of which execute in the rcu_gp_kthread() function) was being starved of CPU time.
> 
> Does that sound likely?
> 
> 							Thanx, Paul
> 
> > -----Original Message-----
> > From: Paul E. McKenney <paulmck@xxxxxxxxxxxxx>
> > Sent: Monday, December 3, 2018 9:57 PM
> > To: He, Bo <bo.he@xxxxxxxxx>
> > Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>; 
> > linux-kernel@xxxxxxxxxxxxxxx; josh@xxxxxxxxxxxxxxxx; 
> > mathieu.desnoyers@xxxxxxxxxxxx; jiangshanlai@xxxxxxxxx; Zhang, Jun 
> > <jun.zhang@xxxxxxxxx>; Xiao, Jin <jin.xiao@xxxxxxxxx>; Zhang, Yanmin 
> > <yanmin.zhang@xxxxxxxxx>
> > Subject: Re: rcu_preempt caused oom
> > 
> > On Mon, Dec 03, 2018 at 07:44:03AM +0000, He, Bo wrote:
> > > Thanks, we have run the test for the whole weekend and not reproduce the issue,  so we confirm the CONFIG_RCU_BOOST can fix the issue.
> > 
> > Very good, that is encouraging.  Perhaps I should think about making CONFIG_RCU_BOOST=y the default for CONFIG_PREEMPT in mainline, at least for architectures for which rt_mutexes are implemented.
> > 
> > > We have enabled the rcupdate.rcu_cpu_stall_timeout=7 and also set panic on rcu stall and will see if we can see the panic, will keep you posed with the test results.
> > > echo 1 > /proc/sys/kernel/panic_on_rcu_stall
> > 
> > Looking forward to seeing what is going on!  Of course, to reproduce, you will need to again build with CONFIG_RCU_BOOST=n.
> > 
> > 							Thanx, Paul
> > 
> > > -----Original Message-----
> > > From: Paul E. McKenney <paulmck@xxxxxxxxxxxxx>
> > > Sent: Saturday, December 1, 2018 12:49 AM
> > > To: He, Bo <bo.he@xxxxxxxxx>
> > > Cc: Steven Rostedt <rostedt@xxxxxxxxxxx>; 
> > > linux-kernel@xxxxxxxxxxxxxxx; josh@xxxxxxxxxxxxxxxx; 
> > > mathieu.desnoyers@xxxxxxxxxxxx; jiangshanlai@xxxxxxxxx; Zhang, Jun 
> > > <jun.zhang@xxxxxxxxx>; Xiao, Jin <jin.xiao@xxxxxxxxx>; Zhang, Yanmin 
> > > <yanmin.zhang@xxxxxxxxx>
> > > Subject: Re: rcu_preempt caused oom
> > > 
> > > On Fri, Nov 30, 2018 at 03:18:58PM +0000, He, Bo wrote:
> > > > Here is the kernel cmdline:
> > > 
> > > Thank you!
> > > 
> > > > Kernel command line: androidboot.acpio_idx=0
> > > > androidboot.bootloader=efiwrapper-02_03-userdebug_kernelflinger-06
> > > > _0
> > > > 3- userdebug androidboot.diskbus=00.0 
> > > > androidboot.verifiedbootstate=green
> > > > androidboot.bootreason=power-on 
> > > > androidboot.serialno=R1J56L6006a7bb
> > > > g_ffs.iSerialNumber=R1J56L6006a7bb no_timer_check noxsaves 
> > > > reboot_panic=p,w i915.hpd_sense_invert=0x7 mem=2G nokaslr nopti 
> > > > ftrace_dump_on_oops trace_buf_size=1024K intel_iommu=off gpt
> > > > loglevel=4 androidboot.hardware=gordon_peak 
> > > > firmware_class.path=/vendor/firmware relative_sleep_states=1
> > > > enforcing=0 androidboot.selinux=permissive cpu_init_udelay=10 
> > > > androidboot.android_dt_dir=/sys/bus/platform/devices/ANDR0001:00/p
> > > > ro pe rties/android/ pstore.backend=ramoops 
> > > > memmap=0x1400000$0x50000000
> > > > ramoops.mem_address=0x50000000 ramoops.mem_size=0x1400000
> > > > ramoops.record_size=0x4000 ramoops.console_size=0x1000000
> > > > ramoops.ftrace_size=0x10000 ramoops.dump_oops=1 vga=current
> > > > i915.modeset=1 drm.atomic=1 i915.nuclear_pageflip=1 
> > > > drm.vblankoffdelay=
> > > 
> > > And no sign of any suppression of RCU CPU stall warnings.  Hmmm...
> > > It does take more than 21 seconds to OOM?  Or do things happen faster than that?  If they do happen faster than that, then on approach would be to add something like this to the kernel command line:
> > > 
> > > 	rcupdate.rcu_cpu_stall_timeout=7
> > > 
> > > This would set the stall timeout to seven seconds.  Note that timeouts less than three seconds are silently interpreted as three seconds.
> > > 
> > > 							Thanx, Paul
> > > 
> > > > -----Original Message-----
> > > > From: Steven Rostedt <rostedt@xxxxxxxxxxx>
> > > > Sent: Friday, November 30, 2018 11:17 PM
> > > > To: Paul E. McKenney <paulmck@xxxxxxxxxxxxx>
> > > > Cc: He, Bo <bo.he@xxxxxxxxx>; linux-kernel@xxxxxxxxxxxxxxx; 
> > > > josh@xxxxxxxxxxxxxxxx; mathieu.desnoyers@xxxxxxxxxxxx; 
> > > > jiangshanlai@xxxxxxxxx; Zhang, Jun <jun.zhang@xxxxxxxxx>; Xiao, 
> > > > Jin <jin.xiao@xxxxxxxxx>; Zhang, Yanmin <yanmin.zhang@xxxxxxxxx>
> > > > Subject: Re: rcu_preempt caused oom
> > > > 
> > > > On Fri, 30 Nov 2018 06:43:17 -0800 "Paul E. McKenney" 
> > > > <paulmck@xxxxxxxxxxxxx> wrote:
> > > > 
> > > > > Could you please send me your list of kernel boot parameters?  
> > > > > They usually appear near the start of your console output.
> > > > 
> > > > Or just: cat /proc/cmdline
> > > > 
> > > > -- Steve
> > > > 
> > > 
> > 
> 
>