From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752166AbdLDRRM (ORCPT ); Mon, 4 Dec 2017 12:17:12 -0500 Received: from mx0b-001b2d01.pphosted.com ([148.163.158.5]:48070 "EHLO mx0a-001b2d01.pphosted.com" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1751246AbdLDRRK (ORCPT ); Mon, 4 Dec 2017 12:17:10 -0500 Date: Mon, 4 Dec 2017 09:16:48 -0800 From: "Paul E. McKenney" To: Frederic Weisbecker Cc: linux-kernel@vger.kernel.org, xiaolong.ye@intel.com, tglx@linutronix.de, cmetcalf@mellanox.com, cl@linux.com, torvalds@linux-foundation.org, lcapitulino@redhat.com, efault@gmx.de, peterz@infradead.org, riel@redhat.com, kernellwp@gmail.com, mingo@kernel.org, john.stultz@linaro.org Subject: Re: [PATCH] sched/isolation: Make NO_HZ_FULL select CPU_ISOLATION Reply-To: paulmck@linux.vnet.ibm.com References: <20171130202046.GA27138@linux.vnet.ibm.com> <20171202192419.GN7829@linux.vnet.ibm.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.21 (2010-09-15) X-TM-AS-GCONF: 00 x-cbid: 17120417-0052-0000-0000-0000028C54C6 X-IBM-SpamModules-Scores: X-IBM-SpamModules-Versions: BY=3.00008152; HX=3.00000241; KW=3.00000007; PH=3.00000004; SC=3.00000243; SDB=6.00955379; UDB=6.00482850; IPR=6.00735416; BA=6.00005727; NDR=6.00000001; ZLA=6.00000005; ZF=6.00000009; ZB=6.00000000; ZP=6.00000000; ZH=6.00000000; ZU=6.00000002; MB=3.00018342; XFM=3.00000015; UTC=2017-12-04 17:16:50 X-IBM-AV-DETECTION: SAVI=unused REMOTE=unused XFE=unused x-cbparentid: 17120417-0053-0000-0000-000052D08494 Message-Id: <20171204171648.GU7829@linux.vnet.ibm.com> X-Proofpoint-Virus-Version: vendor=fsecure engine=2.50.10432:,, definitions=2017-12-04_05:,, signatures=0 X-Proofpoint-Spam-Details: rule=outbound_notspam policy=outbound score=0 priorityscore=1501 malwarescore=0 suspectscore=0 phishscore=0 bulkscore=0 spamscore=0 clxscore=1015 lowpriorityscore=0 impostorscore=0 adultscore=0 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.0.1-1709140000 definitions=main-1712040249 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Mon, Dec 04, 2017 at 04:53:15PM +0100, Frederic Weisbecker wrote: > 2017-12-02 20:24 UTC+01:00, Paul E. McKenney : > > On Sat, Dec 02, 2017 at 02:59:12PM +0100, Frederic Weisbecker wrote: > >> 2017-11-30 21:20 UTC+01:00, Paul E. McKenney > >> : > >> > Commit 5c4991e24c69 ("sched/isolation: Split out new > >> > CONFIG_CPU_ISOLATION=y config from CONFIG_NO_HZ_FULL") can result in > >> > RCU > >> > CPU stall warnings when running rcutorture with CONFIG_NO_HZ_FULL_ALL=y > >> > and CONFIG_CPU_ISOLATION=n. These warnings are caused by RCU's > >> > grace-period kthreads sleeping for a few jiffies, but never being > >> > awakened: > >> > > >> > [ 116.353432] rcu_preempt kthread starved for 9974 jiffies! > >> > g4294967208 > >> > +c4294967207 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x402 ->cpu=0 > >> > [ 116.355517] rcu_preempt I 7464 8 2 0x80000000 > >> > [ 116.356543] Call Trace: > >> > [ 116.357008] __schedule+0x493/0x620 > >> > [ 116.357682] schedule+0x24/0x40 > >> > [ 116.358291] schedule_timeout+0x330/0x3b0 > >> > [ 116.359024] ? preempt_count_sub+0xea/0x140 > >> > [ 116.359806] ? collect_expired_timers+0xb0/0xb0 > >> > [ 116.360660] rcu_gp_kthread+0x6bf/0xef0 > >> > > >> > This commit therefore makes NO_HZ_FULL select CPU_ISOLATION, which > >> > prevents this behavior and seems like it was the original intention in > >> > any case. > >> > >> Although CONFIG_NO_HZ should indeed select CONFIG_CPU_ISOLATION, I'm > >> surprised about this stall. I'm even more surprised that setting > >> CONFIG_CPU_ISOLATION=y is enough to fix the issue because > >> CONFIG_NO_HZ_FULL_ALL shortcuts CONFIG_CPU_ISOLATION entirely (which > >> is not good, but work in progress...). > > > > Yes, and after applying this patch, I get failures a few commits > > later, which appears to be due to other changes that break > > CONFIG_NO_HZ_FULL_ALL=y. So I have another patch staged that removes > > CONFIG_NO_HZ_FULL_ALL, on the grounds that no one else has complained, > > so rcutorture is likely to be the only user, and I don't see the point > > of having a Kconfig option for only one user. > > I would prefer to keep it. It's useful for automated boot testing > based on configs such as 0-day or -tip test machines. But I'm likely > to migrate it to isolcpus implementation. Maybe something along the > lines of CONFIG_CPU_ISOLATION_ALL. How about instead allowing something like "nohz_full=1-" specify that all CPUs other than CPU 0 should be nohz_full CPUs? That would shrink the code by eliminating CONFIG_NO_HZ_FULL_ALL while still allowing easy automation of that particular scenario. (Right now, the boot code complains about "nohz_full=1-", which means that whatever is generating the boot parameters needs to know how many CPUs there really are, which as you say can be a pain.) > >> Did you have any nohz_full= or isolcpus= boot options? > > > > Replacing CONFIG_NO_HZ_FULL_ALL=y with nohz_full=1-7 works, that > > is CONFIG_NO_HZ_FULL=y, CONFIG_NO_HZ_FULL_ALL=n, and nohz_full=1-7 > > on an eight-CPU test. > > > > But it is relatively easy to test. Running the rcutorture TREE04 > > scenario on a four-socket x86 gets me RCU CPU stall warnings within > > a few minutes more than half the time. ;-) > > Indeed I managed to trigger something. If it's the same thing I should > be able to track down the root cause. > > [ 123.907557] ??? Writer stall state RTWS_STUTTER(8) g160 c160 f0x0 > ->state 0x1 cpu 2 > [ 123.915184] rcu_torture_wri S 0 111 2 0x80080000 > [ 123.920673] Call Trace: > [ 123.923096] ? __schedule+0x2bf/0xbb0 > [ 123.926715] ? _raw_spin_unlock_irqrestore+0x59/0x70 > [ 123.931657] schedule+0x3c/0x90 > [ 123.934777] schedule_timeout+0x1e1/0x560 It might well be the same thing, as this schedule_timeout() does look familiar. I have some diagnostic patches in -rcu, please see below for the overall effect. Thanx, Paul > [ 123.938785] ? __next_timer_interrupt+0xd0/0xd0 > [ 123.943276] stutter_wait+0xc5/0xe0 > [ 123.946738] rcu_torture_writer+0x1ae/0x730 > [ 123.950912] ? rcu_torture_pipe_update+0xf0/0xf0 > [ 123.955491] kthread+0x15f/0x1a0 > [ 123.958702] ? kthread_unpark+0x60/0x60 > [ 123.962523] ret_from_fork+0x24/0x30 > [ 123.966091] rcu_preempt: wait state: 1 ->state: 0x402 > [ 123.971112] rcu_sched: wait state: 1 ->state: 0x402 > [ 123.975953] rcu_bh: wait state: 1 ->state: 0x402 ------------------------------------------------------------------------ diff --git a/kernel/time/timer.c b/kernel/time/timer.c index ffebcf878fba..23af27461d8c 100644 --- a/kernel/time/timer.c +++ b/kernel/time/timer.c @@ -1755,8 +1755,13 @@ static void process_timeout(struct timer_list *t) */ signed long __sched schedule_timeout(signed long timeout) { + struct timer_base *base; struct process_timer timer; unsigned long expire; + unsigned long flags; + unsigned long i; + unsigned int idx, idx_now; + unsigned long j; switch (timeout) { @@ -1793,6 +1798,17 @@ signed long __sched schedule_timeout(signed long timeout) timer_setup_on_stack(&timer.timer, process_timeout, 0); __mod_timer(&timer.timer, expire, 0); schedule(); + j = jiffies; + if (timeout < 5 && time_after(j, expire + 8 * HZ) && timer_pending(&timer.timer)) { + base = lock_timer_base(&timer.timer, &flags); + idx = timer_get_idx(&timer.timer); + idx_now = calc_wheel_index(j, base->clk); + raw_spin_unlock_irqrestore(&base->lock, flags); + pr_info("%s: Waylayed timer base->clk: %#lx jiffies: %#lx base->next_expiry: %#lx timer->flags: %#x timer->expires %#lx idx: %x idx_now: %x base->pending_map ", __func__, base->clk, j, base->next_expiry, timer.timer.flags, timer.timer.expires, idx, idx_now); + for (i = 0; i < WHEEL_SIZE / sizeof(base->pending_map[0]) / 8; i++) + pr_cont("%016lx", base->pending_map[i]); + pr_cont("\n"); + } del_singleshot_timer_sync(&timer.timer); /* Remove the timer from the object tracker */