Re: [patch 61/66] timers: Convert to hotplug state machine

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

Hi Richard,

On 11/07/16 13:29, Anna-Maria Gleixner wrote:
> From: Richard Cochran <rcochran-hfZtesqFncYOwBW4kG4KsQ@public.gmane.org>
> 
> When tearing down, call timers_dead_cpu before notify_dead.
> There is a hidden dependency between:
>
> - timers
> - Block multiqueue
> - rcutree
>
> If timers_dead_cpu() comes later than blk_mq_queue_reinit_notify()
> that latter function causes a RCU stall.

After this change is applied I am seeing RCU stalls during suspend
on Tegra. I guess I am hitting the case mentioned above? How should
this be avoided?

[    5.321824] PM: Syncing filesystems ... done.
[    5.349746] Freezing user space processes ... (elapsed 0.001 seconds) done.
[    5.358122] Double checking all user space processes after OOM killer disable... (elapsed 0.000 seconds) 
[    5.367817] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[    5.376746] Suspending console(s) (use no_console_suspend to debug)
[    5.427213] PM: suspend of devices complete after 42.812 msecs
[    5.429909] PM: late suspend of devices complete after 2.680 msecs
[    5.431968] PM: noirq suspend of devices complete after 2.049 msecs
[    5.431973] Disabling non-boot CPUs ...
[    5.432861] CPU1: shutdown
[    5.467806] CPU2: shutdown
[    5.506925] IRQ17 no longer affine to CPU3
[    5.507294] CPU3: shutdown
[   26.509992] INFO: rcu_sched detected stalls on CPUs/tasks:
[   26.510005]  3-O.N: (0 ticks this GP) idle=e13/140000000000000/0 softirq=86/86 fqs=0 
[   26.510016]  (detected by 0, t=4202 jiffies, g=-225, c=-226, q=23)
[   26.510020] Task dump for CPU 3:
[   26.510033] swapper/3       R running      0     0      1 0x00000000
[   26.510063] [<c0b79fac>] (__schedule) from [<c033b808>] (tegra_cpu_die+0x30/0x48)
[   26.510080] [<c033b808>] (tegra_cpu_die) from [<c030dd4c>] (arch_cpu_idle_dead+0x44/0x88)
[   26.510094] [<c030dd4c>] (arch_cpu_idle_dead) from [<c03794bc>] (cpu_startup_entry+0x1c0/0x220)
[   26.510106] [<c03794bc>] (cpu_startup_entry) from [<80301c2c>] (0x80301c2c)
[   26.510116] rcu_sched kthread starved for 4202 jiffies! g4294967071 c4294967070 f0x0 RCU_GP_WAIT_FQS(3) ->state=0x1
[   26.510128] rcu_sched       S c0b79fac     0     7      2 0x00000000
[   26.510139] [<c0b79fac>] (__schedule) from [<c0b7a434>] (schedule+0x38/0x9c)
[   26.510152] [<c0b7a434>] (schedule) from [<c0b7cf3c>] (schedule_timeout+0x158/0x21c)
[   26.510166] [<c0b7cf3c>] (schedule_timeout) from [<c03922e0>] (rcu_gp_kthread+0x414/0x99c)
[   26.510179] [<c03922e0>] (rcu_gp_kthread) from [<c035cdb8>] (kthread+0xd8/0xf4)
[   26.510191] [<c035cdb8>] (kthread) from [<c0307fb8>] (ret_from_fork+0x14/0x3c)
[   26.531238] Enabling non-boot CPUs ...
[   26.546568] CPU1 is up
[   26.566858] CPU2 is up
[   26.587169] CPU3 is up
[   26.588470] PM: noirq resume of devices complete after 1.290 msecs
[   26.591329] PM: early resume of devices complete after 2.574 msecs
[   26.696785] PM: resume of devices complete after 105.439 msecs
[   26.876814] Restarting tasks ... done.

Interestingly I am only seeing the above when using the ARM
multi_v7_defconfig kernel configuration and not with the tegra_defconfig.
One key difference between these is that the multi_v7_defconfig does not
have CONFIG_PREEMPT enabled. Initial testing shows enabling CONFIG_PREEMPT
for multi_v7_defconfig makes the problem go away.

Cheers
Jon

Re: [patch 61/66] timers: Convert to hotplug state machine

[rcochran-hfZtesqFncYOwBW4kG4KsQ]

On Mon, Jul 25, 2016 at 03:56:48PM +0100, Jon Hunter wrote:
> > There is a hidden dependency between:
> >
> > - timers
> > - Block multiqueue
> > - rcutree
> >
> > If timers_dead_cpu() comes later than blk_mq_queue_reinit_notify()
> > that latter function causes a RCU stall.
> 
> After this change is applied I am seeing RCU stalls during suspend
> on Tegra. I guess I am hitting the case mentioned above? How should
> this be avoided?

The problem that I had found was a hidden dependency.  When I
initially placed the timers callback into the new HP state list, that
caused a stall because the dependency was broken.  The old code worked
by luck, based on the order of the notifier registrations.  The new
code makes the old implicit ordering explicit, so it should work just
as well as before (famous last words).

> Interestingly I am only seeing the above when using the ARM
> multi_v7_defconfig kernel configuration and not with the tegra_defconfig.
> One key difference between these is that the multi_v7_defconfig does not
> have CONFIG_PREEMPT enabled. Initial testing shows enabling CONFIG_PREEMPT
> for multi_v7_defconfig makes the problem go away.

Just to be sure, this problem didn't exist before the HP rework, that
is, suspend worked fine with and without CONFIG_PREEMPT, right?

I see if I can find a tegra system to test with...

Thanks,
Richard

Re: [patch 61/66] timers: Convert to hotplug state machine

[rcochran-hfZtesqFncYOwBW4kG4KsQ]

On Mon, Jul 25, 2016 at 05:35:43PM +0200, rcochran-hfZtesqFncYOwBW4kG4KsQ@public.gmane.org wrote:
> I see if I can find a tegra system to test with...

I tried the tip:smp/hotplug branch under kvm x86_64, and I didn't see
any problems with suspend or hibernate, even with CONFIG_PREEMPT_NONE.
I'll see if I can get my hands on a tegra system tomorrow.  Until
then, two questions:

1. The issue appears with suspend (echo mem > /sys/power/state), as
   opposed to hibernate, right?

2. CONFIG_PREEMPT_NONE is good, but CONFIG_PREEMPT is bad, right?

Thanks,
Richard

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

On 25/07/16 16:35, rcochran@linutronix.de wrote:
> On Mon, Jul 25, 2016 at 03:56:48PM +0100, Jon Hunter wrote:
>>> There is a hidden dependency between:
>>>
>>> - timers
>>> - Block multiqueue
>>> - rcutree
>>>
>>> If timers_dead_cpu() comes later than blk_mq_queue_reinit_notify()
>>> that latter function causes a RCU stall.
>>
>> After this change is applied I am seeing RCU stalls during suspend
>> on Tegra. I guess I am hitting the case mentioned above? How should
>> this be avoided?
> 
> The problem that I had found was a hidden dependency.  When I
> initially placed the timers callback into the new HP state list, that
> caused a stall because the dependency was broken.  The old code worked
> by luck, based on the order of the notifier registrations.  The new
> code makes the old implicit ordering explicit, so it should work just
> as well as before (famous last words).

I see.

>> Interestingly I am only seeing the above when using the ARM
>> multi_v7_defconfig kernel configuration and not with the tegra_defconfig.
>> One key difference between these is that the multi_v7_defconfig does not
>> have CONFIG_PREEMPT enabled. Initial testing shows enabling CONFIG_PREEMPT
>> for multi_v7_defconfig makes the problem go away.
> 
> Just to be sure, this problem didn't exist before the HP rework, that
> is, suspend worked fine with and without CONFIG_PREEMPT, right?

Correct. I test suspend on Tegra with both multi_v7_defconfig
(CONFIG_PREEMPT disabled) and tegra_defconfig (CONFIG_PREEMPT enabled).
Looking at the git history for these configs I don't see any changes in
this regard since they were added (unless some underlying Kconfig files
have changed).

> I see if I can find a tegra system to test with...

Thanks. I have not tried another ARM based device, but I would be
curious if another ARM device sees this or not.

Cheers
Jon

-- 
nvpublic

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

On 25/07/16 21:46, rcochran-hfZtesqFncYOwBW4kG4KsQ@public.gmane.org wrote:
> On Mon, Jul 25, 2016 at 05:35:43PM +0200, rcochran-hfZtesqFncYOwBW4kG4KsQ@public.gmane.org wrote:
>> I see if I can find a tegra system to test with...
> 
> I tried the tip:smp/hotplug branch under kvm x86_64, and I didn't see
> any problems with suspend or hibernate, even with CONFIG_PREEMPT_NONE.
> I'll see if I can get my hands on a tegra system tomorrow.  Until
> then, two questions:
> 
> 1. The issue appears with suspend (echo mem > /sys/power/state), as
>    opposed to hibernate, right?

Yes. I have been using rtcwake to test suspend with the following
arguments ...

# rtcwake -d rtc1 -m mem -s 3

> 2. CONFIG_PREEMPT_NONE is good, but CONFIG_PREEMPT is bad, right?

The other way around.

Cheers
Jon

-- 
nvpublic

Re: [patch 61/66] timers: Convert to hotplug state machine

[Thomas Gleixner]

Jon,

On Tue, 26 Jul 2016, Jon Hunter wrote:
> On 25/07/16 16:35, rcochran@linutronix.de wrote:
> > Just to be sure, this problem didn't exist before the HP rework, that
> > is, suspend worked fine with and without CONFIG_PREEMPT, right?
> 
> Correct. I test suspend on Tegra with both multi_v7_defconfig
> (CONFIG_PREEMPT disabled) and tegra_defconfig (CONFIG_PREEMPT enabled).
> Looking at the git history for these configs I don't see any changes in
> this regard since they were added (unless some underlying Kconfig files
> have changed).

Is that fully reproducible, i.e on every suspend?

Can you please check whether this issue happens with just cpu offline as
well? I.e. set a cpu (or all non-boot cpus) offline, wait long enough that the
stall detector can trigger, set the cpu(s) online again and repeat.

Thanks

	tglx

Re: [patch 61/66] timers: Convert to hotplug state machine

[rcochran-hfZtesqFncYOwBW4kG4KsQ]

Jon,

On Tue, Jul 26, 2016 at 10:20:58AM +0100, Jon Hunter wrote:
> Thanks. I have not tried another ARM based device, but I would be
> curious if another ARM device sees this or not.

I do see this stall on socfpga and on zynq, but in both cases the
suspend mechanism is flakey in other ways, too.  At least I can
reproduce the stall sometimes.

In your other mail you wrote that you test it like this:

   rtcwake -d rtc1 -m mem -s 3

But the stall appears only after 20 seconds.  So the resume event
after three seconds (-s 3) is getting lost, right?

Thanks,
Richard

Re: [patch 61/66] timers: Convert to hotplug state machine

[rcochran-hfZtesqFncYOwBW4kG4KsQ]

Jon,

On Mon, Jul 25, 2016 at 03:56:48PM +0100, Jon Hunter wrote:
> > When tearing down, call timers_dead_cpu before notify_dead.
> > There is a hidden dependency between:
> >
> > - timers
> > - Block multiqueue
> > - rcutree
> >
> > If timers_dead_cpu() comes later than blk_mq_queue_reinit_notify()
> > that latter function causes a RCU stall.
> 
> After this change is applied I am seeing RCU stalls during suspend
> on Tegra. I guess I am hitting the case mentioned above? How should
> this be avoided?

Contrary to the commit message, this callback ended up in the wrong
place within the sequence.  (It was correct in an earlier version, but
the series has been through many changes.)

Can you try this patch to see if it avoids the stall, please?

Thanks,
Richard
---

diff --git a/include/linux/cpuhotplug.h b/include/linux/cpuhotplug.h
index 6d405db..242bf53 100644
--- a/include/linux/cpuhotplug.h
+++ b/include/linux/cpuhotplug.h
@@ -20,9 +20,9 @@ enum cpuhp_state {
 	CPUHP_PROFILE_PREPARE,
 	CPUHP_X2APIC_PREPARE,
 	CPUHP_SMPCFD_PREPARE,
-	CPUHP_TIMERS_DEAD,
 	CPUHP_RCUTREE_PREP,
 	CPUHP_NOTIFY_PREPARE,
+	CPUHP_TIMERS_DEAD,
 	CPUHP_BRINGUP_CPU,
 	CPUHP_AP_IDLE_DEAD,
 	CPUHP_AP_OFFLINE,
diff --git a/kernel/cpu.c b/kernel/cpu.c
index 67f4943..8d65510 100644
--- a/kernel/cpu.c
+++ b/kernel/cpu.c
@@ -1208,11 +1208,6 @@ static struct cpuhp_step cpuhp_bp_states[] = {
 		.startup = smpcfd_prepare_cpu,
 		.teardown = smpcfd_dead_cpu,
 	},
-	[CPUHP_TIMERS_DEAD] = {
-		.name = "timers dead",
-		.startup = NULL,
-		.teardown = timers_dead_cpu,
-	},
 	[CPUHP_RCUTREE_PREP] = {
 		.name = "RCU-tree prepare",
 		.startup = rcutree_prepare_cpu,
@@ -1229,6 +1224,11 @@ static struct cpuhp_step cpuhp_bp_states[] = {
 		.skip_onerr		= true,
 		.cant_stop		= true,
 	},
+	[CPUHP_TIMERS_DEAD] = {
+		.name = "timers dead",
+		.startup = NULL,
+		.teardown = timers_dead_cpu,
+	},
 	/* Kicks the plugged cpu into life */
 	[CPUHP_BRINGUP_CPU] = {
 		.name			= "cpu:bringup",

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

Hi Richard,

On 26/07/16 16:42, rcochran-hfZtesqFncYOwBW4kG4KsQ@public.gmane.org wrote:
> Jon,
> 
> On Mon, Jul 25, 2016 at 03:56:48PM +0100, Jon Hunter wrote:
>>> When tearing down, call timers_dead_cpu before notify_dead.
>>> There is a hidden dependency between:
>>>
>>> - timers
>>> - Block multiqueue
>>> - rcutree
>>>
>>> If timers_dead_cpu() comes later than blk_mq_queue_reinit_notify()
>>> that latter function causes a RCU stall.
>>
>> After this change is applied I am seeing RCU stalls during suspend
>> on Tegra. I guess I am hitting the case mentioned above? How should
>> this be avoided?
> 
> Contrary to the commit message, this callback ended up in the wrong
> place within the sequence.  (It was correct in an earlier version, but
> the series has been through many changes.)
> 
> Can you try this patch to see if it avoids the stall, please?

I have included the patch and I am no longer seeing any RCU stalls and
so this does look like it fixed it.

Thanks!
Jon

-- 
nvpublic

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

Hi Thomas,

On 26/07/16 15:15, Thomas Gleixner wrote:
> Jon,
> 
> On Tue, 26 Jul 2016, Jon Hunter wrote:
>> On 25/07/16 16:35, rcochran@linutronix.de wrote:
>>> Just to be sure, this problem didn't exist before the HP rework, that
>>> is, suspend worked fine with and without CONFIG_PREEMPT, right?
>>
>> Correct. I test suspend on Tegra with both multi_v7_defconfig
>> (CONFIG_PREEMPT disabled) and tegra_defconfig (CONFIG_PREEMPT enabled).
>> Looking at the git history for these configs I don't see any changes in
>> this regard since they were added (unless some underlying Kconfig files
>> have changed).
> 
> Is that fully reproducible, i.e on every suspend?

No not every suspend. I run 10 suspend cycles on each Tegra board (5
boards total) and typically between 3 and 5 boards would see the stall
in the 10 suspend cycles. So it does appear to be timing sensitive.

> Can you please check whether this issue happens with just cpu offline as
> well? I.e. set a cpu (or all non-boot cpus) offline, wait long enough that the
> stall detector can trigger, set the cpu(s) online again and repeat.

I can, but it appears like Richard's patch has fixed this. I am happy to
do more testing if necessary.

Cheers
Jon

-- 
nvpublic

Re: [patch 61/66] timers: Convert to hotplug state machine

[Jon Hunter]

Hi Richard,

On 26/07/16 15:40, rcochran@linutronix.de wrote:
> Jon,
> 
> On Tue, Jul 26, 2016 at 10:20:58AM +0100, Jon Hunter wrote:
>> Thanks. I have not tried another ARM based device, but I would be
>> curious if another ARM device sees this or not.
> 
> I do see this stall on socfpga and on zynq, but in both cases the
> suspend mechanism is flakey in other ways, too.  At least I can
> reproduce the stall sometimes.
> 
> In your other mail you wrote that you test it like this:
> 
>    rtcwake -d rtc1 -m mem -s 3
> 
> But the stall appears only after 20 seconds.  So the resume event
> after three seconds (-s 3) is getting lost, right?

I don't think so. I noticed that when the stall occurs, I don't see the
board attempt to transition to the Tegra LP1 power state in suspend and
appears to wake up straight away. So I think the wake-up is seen, but
the stall prevents it from transitioning all the way to LP1.

Cheers
Jon

-- 
nvpublic