System instability are seen during resume from hibernation when system
is under heavy CPU load. This is due to the lack of update of sched
clock data, and the scheduler would then think that heavy CPU hog
tasks need more time in CPU, causing the system to freeze
during the unfreezing of tasks. For example, threaded irqs,
and kernel processes servicing network interface may be delayed
for several tens of seconds, causing the system to be unreachable.
Situation like this can be reported by using lockup detectors
such as workqueue lockup detectors:
[root@ip-172-31-67-114 ec2-user]# echo disk > /sys/power/state
Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
kernel:BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 57s!
Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 57s!
Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 57s!
Message from syslogd@ip-172-31-67-114 at May 7 18:29:06 ...
kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 403s!
The fix for this situation is to mark the sched clock as unstable
as early as possible in the resume path, leaving it unstable
for the duration of the resume process. This will force the
scheduler to attempt to align the sched clock across CPUs using
the delta with time of day, updating sched clock data. In a post
hibernation event, we can then mark the sched clock as stable
again, avoiding unnecessary syncs with time of day on systems
in which TSC is reliable.
Cc: Thomas Gleixner <[email protected]>
Cc: Ingo Molnar <[email protected]>
Cc: "H. Peter Anvin" <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Cc: Dou Liyang <[email protected]>
Cc: Len Brown <[email protected]>
Cc: "Rafael J. Wysocki" <[email protected]>
Cc: Eduardo Valentin <[email protected]>
Cc: "[email protected]" <[email protected]>
Cc: Rajvi Jingar <[email protected]>
Cc: Pavel Tatashin <[email protected]>
Cc: Philippe Ombredanne <[email protected]>
Cc: Kate Stewart <[email protected]>
Cc: Greg Kroah-Hartman <[email protected]>
Cc: [email protected]
Cc: [email protected]
Cc: [email protected]
Signed-off-by: Eduardo Valentin <[email protected]>
---
Hey,
No changes from first attempt, no pressure on resending. The RESEND
tag is just because I missed linux-pm in the first attempt.
BR,
arch/x86/kernel/tsc.c | 29 +++++++++++++++++++++++++++++
include/linux/sched/clock.h | 5 +++++
kernel/sched/clock.c | 4 ++--
3 files changed, 36 insertions(+), 2 deletions(-)
diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
index 8ea117f8142e..f197c9742fef 100644
--- a/arch/x86/kernel/tsc.c
+++ b/arch/x86/kernel/tsc.c
@@ -13,6 +13,7 @@
#include <linux/percpu.h>
#include <linux/timex.h>
#include <linux/static_key.h>
+#include <linux/suspend.h>
#include <asm/hpet.h>
#include <asm/timer.h>
@@ -1377,3 +1378,31 @@ unsigned long calibrate_delay_is_known(void)
return 0;
}
#endif
+
+static int tsc_pm_notifier(struct notifier_block *notifier,
+ unsigned long pm_event, void *unused)
+{
+ switch (pm_event) {
+ case PM_HIBERNATION_PREPARE:
+ clear_sched_clock_stable();
+ break;
+ case PM_POST_HIBERNATION:
+ /* Set back to the default */
+ if (!check_tsc_unstable())
+ set_sched_clock_stable();
+ break;
+ }
+
+ return 0;
+};
+
+static struct notifier_block tsc_pm_notifier_block = {
+ .notifier_call = tsc_pm_notifier,
+};
+
+static int tsc_setup_pm_notifier(void)
+{
+ return register_pm_notifier(&tsc_pm_notifier_block);
+}
+
+subsys_initcall(tsc_setup_pm_notifier);
diff --git a/include/linux/sched/clock.h b/include/linux/sched/clock.h
index 867d588314e0..902654ac5f7e 100644
--- a/include/linux/sched/clock.h
+++ b/include/linux/sched/clock.h
@@ -32,6 +32,10 @@ static inline void clear_sched_clock_stable(void)
{
}
+static inline void set_sched_clock_stable(void)
+{
+}
+
static inline void sched_clock_idle_sleep_event(void)
{
}
@@ -51,6 +55,7 @@ static inline u64 local_clock(void)
}
#else
extern int sched_clock_stable(void);
+extern void set_sched_clock_stable(void);
extern void clear_sched_clock_stable(void);
/*
diff --git a/kernel/sched/clock.c b/kernel/sched/clock.c
index e086babe6c61..8453440e236c 100644
--- a/kernel/sched/clock.c
+++ b/kernel/sched/clock.c
@@ -131,7 +131,7 @@ static void __scd_stamp(struct sched_clock_data *scd)
scd->tick_raw = sched_clock();
}
-static void __set_sched_clock_stable(void)
+void set_sched_clock_stable(void)
{
struct sched_clock_data *scd;
@@ -228,7 +228,7 @@ static int __init sched_clock_init_late(void)
smp_mb(); /* matches {set,clear}_sched_clock_stable() */
if (__sched_clock_stable_early)
- __set_sched_clock_stable();
+ set_sched_clock_stable();
return 0;
}
--
2.18.0
On Thu, Jul 26, 2018 at 5:56 PM, Eduardo Valentin <[email protected]> wrote:
> System instability are seen during resume from hibernation when system
> is under heavy CPU load. This is due to the lack of update of sched
> clock data,
Isn't that the actual bug?
> and the scheduler would then think that heavy CPU hog
> tasks need more time in CPU, causing the system to freeze
> during the unfreezing of tasks. For example, threaded irqs,
> and kernel processes servicing network interface may be delayed
> for several tens of seconds, causing the system to be unreachable.
>
> Situation like this can be reported by using lockup detectors
> such as workqueue lockup detectors:
>
> [root@ip-172-31-67-114 ec2-user]# echo disk > /sys/power/state
>
> Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> kernel:BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 57s!
>
> Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 57s!
>
> Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 57s!
>
> Message from syslogd@ip-172-31-67-114 at May 7 18:29:06 ...
> kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 403s!
>
> The fix for this situation is to mark the sched clock as unstable
> as early as possible in the resume path, leaving it unstable
> for the duration of the resume process.
I would rather call it a workaround.
> This will force the
> scheduler to attempt to align the sched clock across CPUs using
> the delta with time of day, updating sched clock data. In a post
> hibernation event, we can then mark the sched clock as stable
> again, avoiding unnecessary syncs with time of day on systems
> in which TSC is reliable.
>
> Cc: Thomas Gleixner <[email protected]>
> Cc: Ingo Molnar <[email protected]>
> Cc: "H. Peter Anvin" <[email protected]>
> Cc: Peter Zijlstra <[email protected]>
> Cc: Dou Liyang <[email protected]>
> Cc: Len Brown <[email protected]>
> Cc: "Rafael J. Wysocki" <[email protected]>
> Cc: Eduardo Valentin <[email protected]>
> Cc: "[email protected]" <[email protected]>
> Cc: Rajvi Jingar <[email protected]>
> Cc: Pavel Tatashin <[email protected]>
> Cc: Philippe Ombredanne <[email protected]>
> Cc: Kate Stewart <[email protected]>
> Cc: Greg Kroah-Hartman <[email protected]>
> Cc: [email protected]
> Cc: [email protected]
> Cc: [email protected]
> Signed-off-by: Eduardo Valentin <[email protected]>
> ---
>
> Hey,
>
> No changes from first attempt, no pressure on resending. The RESEND
> tag is just because I missed linux-pm in the first attempt.
>
> BR,
>
> arch/x86/kernel/tsc.c | 29 +++++++++++++++++++++++++++++
> include/linux/sched/clock.h | 5 +++++
> kernel/sched/clock.c | 4 ++--
> 3 files changed, 36 insertions(+), 2 deletions(-)
>
> diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
> index 8ea117f8142e..f197c9742fef 100644
> --- a/arch/x86/kernel/tsc.c
> +++ b/arch/x86/kernel/tsc.c
> @@ -13,6 +13,7 @@
> #include <linux/percpu.h>
> #include <linux/timex.h>
> #include <linux/static_key.h>
> +#include <linux/suspend.h>
>
> #include <asm/hpet.h>
> #include <asm/timer.h>
> @@ -1377,3 +1378,31 @@ unsigned long calibrate_delay_is_known(void)
> return 0;
> }
> #endif
> +
> +static int tsc_pm_notifier(struct notifier_block *notifier,
> + unsigned long pm_event, void *unused)
> +{
> + switch (pm_event) {
> + case PM_HIBERNATION_PREPARE:
> + clear_sched_clock_stable();
> + break;
This is too early IMO. This happens before hibernation starts, even
before the image is created.
> + case PM_POST_HIBERNATION:
> + /* Set back to the default */
> + if (!check_tsc_unstable())
> + set_sched_clock_stable();
> + break;
> + }
> +
> + return 0;
> +};
If anything like this is the way to go, which honestly I doubt, I
would prefer it to be done in hibernate() in the !in_suspend case.
But why does it only affect hibernation? Do we do something extra for
system-wide suspend/resume that is not done for hibernation?
On Thu, Jul 26, 2018 at 08:56:56AM -0700, Eduardo Valentin wrote:
> System instability are seen during resume from hibernation when system
> is under heavy CPU load. This is due to the lack of update of sched
> clock data
Which would suggest you're already running with unstable sched clock.
Otherwise nobody would care about the scd stuff.
What kind of machine are you running? What does:
dmesg | grep -i tsc
say?
> The fix for this situation is to mark the sched clock as unstable
> as early as possible in the resume path, leaving it unstable
> for the duration of the resume process. This will force the
> scheduler to attempt to align the sched clock across CPUs using
> the delta with time of day, updating sched clock data. In a post
> hibernation event, we can then mark the sched clock as stable
> again, avoiding unnecessary syncs with time of day on systems
> in which TSC is reliable.
None of this makes any sense. Either you were already unstable and it
should already have worked and them marking it stable is an outright
bug, or your sched clock was stable but then your initial diagnosis of
lack of scd updates is complete garbage.
Hey Peter,
On Mon, Jul 30, 2018 at 10:53:54AM +0200, Peter Zijlstra wrote:
> On Thu, Jul 26, 2018 at 08:56:56AM -0700, Eduardo Valentin wrote:
> > System instability are seen during resume from hibernation when system
> > is under heavy CPU load. This is due to the lack of update of sched
> > clock data
>
> Which would suggest you're already running with unstable sched clock.
> Otherwise nobody would care about the scd stuff.
Yes.
>
> What kind of machine are you running? What does:
>
> dmesg | grep -i tsc
>
> say?
Here:
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.004005] tsc: Detected 3000.000 MHz processor
[ 0.066796] TSC deadline timer enabled
[ 3.904269] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2b3e459bf4c, max_idle_ns: 440795289890 ns
>
> > The fix for this situation is to mark the sched clock as unstable
> > as early as possible in the resume path, leaving it unstable
> > for the duration of the resume process. This will force the
> > scheduler to attempt to align the sched clock across CPUs using
> > the delta with time of day, updating sched clock data. In a post
> > hibernation event, we can then mark the sched clock as stable
> > again, avoiding unnecessary syncs with time of day on systems
> > in which TSC is reliable.
>
> None of this makes any sense. Either you were already unstable and it
> should already have worked and them marking it stable is an outright
> bug, or your sched clock was stable but then your initial diagnosis of
> lack of scd updates is complete garbage.
>
I see, or it is just a workaround for the underling issue. I, for sure, see no
lockups anymore after forcing the scd updates. The other thing which are not
super clear is that this happens during the unfreezing of tasks. If I get a
set of cpu hog tasks while unfreezing, I see the system throwing worqueue lockup
detectors in hibernation restore.
>
--
All the best,
Eduardo Valentin
On Mon, Jul 30, 2018 at 09:15:48AM +0200, Rafael J. Wysocki wrote:
> On Thu, Jul 26, 2018 at 5:56 PM, Eduardo Valentin <[email protected]> wrote:
> > System instability are seen during resume from hibernation when system
> > is under heavy CPU load. This is due to the lack of update of sched
> > clock data,
>
> Isn't that the actual bug?
>
> > and the scheduler would then think that heavy CPU hog
> > tasks need more time in CPU, causing the system to freeze
> > during the unfreezing of tasks. For example, threaded irqs,
> > and kernel processes servicing network interface may be delayed
> > for several tens of seconds, causing the system to be unreachable.
> >
> > Situation like this can be reported by using lockup detectors
> > such as workqueue lockup detectors:
> >
> > [root@ip-172-31-67-114 ec2-user]# echo disk > /sys/power/state
> >
> > Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> > kernel:BUG: workqueue lockup - pool cpus=0 node=0 flags=0x0 nice=0 stuck for 57s!
> >
> > Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> > kernel:BUG: workqueue lockup - pool cpus=1 node=0 flags=0x0 nice=0 stuck for 57s!
> >
> > Message from syslogd@ip-172-31-67-114 at May 7 18:23:21 ...
> > kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 57s!
> >
> > Message from syslogd@ip-172-31-67-114 at May 7 18:29:06 ...
> > kernel:BUG: workqueue lockup - pool cpus=3 node=0 flags=0x1 nice=0 stuck for 403s!
> >
> > The fix for this situation is to mark the sched clock as unstable
> > as early as possible in the resume path, leaving it unstable
> > for the duration of the resume process.
>
> I would rather call it a workaround.
ok.
>
> > This will force the
> > scheduler to attempt to align the sched clock across CPUs using
> > the delta with time of day, updating sched clock data. In a post
> > hibernation event, we can then mark the sched clock as stable
> > again, avoiding unnecessary syncs with time of day on systems
> > in which TSC is reliable.
> >
> > Cc: Thomas Gleixner <[email protected]>
> > Cc: Ingo Molnar <[email protected]>
> > Cc: "H. Peter Anvin" <[email protected]>
> > Cc: Peter Zijlstra <[email protected]>
> > Cc: Dou Liyang <[email protected]>
> > Cc: Len Brown <[email protected]>
> > Cc: "Rafael J. Wysocki" <[email protected]>
> > Cc: Eduardo Valentin <[email protected]>
> > Cc: "[email protected]" <[email protected]>
> > Cc: Rajvi Jingar <[email protected]>
> > Cc: Pavel Tatashin <[email protected]>
> > Cc: Philippe Ombredanne <[email protected]>
> > Cc: Kate Stewart <[email protected]>
> > Cc: Greg Kroah-Hartman <[email protected]>
> > Cc: [email protected]
> > Cc: [email protected]
> > Cc: [email protected]
> > Signed-off-by: Eduardo Valentin <[email protected]>
> > ---
> >
> > Hey,
> >
> > No changes from first attempt, no pressure on resending. The RESEND
> > tag is just because I missed linux-pm in the first attempt.
> >
> > BR,
> >
> > arch/x86/kernel/tsc.c | 29 +++++++++++++++++++++++++++++
> > include/linux/sched/clock.h | 5 +++++
> > kernel/sched/clock.c | 4 ++--
> > 3 files changed, 36 insertions(+), 2 deletions(-)
> >
> > diff --git a/arch/x86/kernel/tsc.c b/arch/x86/kernel/tsc.c
> > index 8ea117f8142e..f197c9742fef 100644
> > --- a/arch/x86/kernel/tsc.c
> > +++ b/arch/x86/kernel/tsc.c
> > @@ -13,6 +13,7 @@
> > #include <linux/percpu.h>
> > #include <linux/timex.h>
> > #include <linux/static_key.h>
> > +#include <linux/suspend.h>
> >
> > #include <asm/hpet.h>
> > #include <asm/timer.h>
> > @@ -1377,3 +1378,31 @@ unsigned long calibrate_delay_is_known(void)
> > return 0;
> > }
> > #endif
> > +
> > +static int tsc_pm_notifier(struct notifier_block *notifier,
> > + unsigned long pm_event, void *unused)
> > +{
> > + switch (pm_event) {
> > + case PM_HIBERNATION_PREPARE:
> > + clear_sched_clock_stable();
> > + break;
>
> This is too early IMO. This happens before hibernation starts, even
> before the image is created.
Yeah, I think, as long as it is marked, it should be fine.
>
> > + case PM_POST_HIBERNATION:
> > + /* Set back to the default */
> > + if (!check_tsc_unstable())
> > + set_sched_clock_stable();
> > + break;
> > + }
> > +
> > + return 0;
> > +};
>
> If anything like this is the way to go, which honestly I doubt, I
> would prefer it to be done in hibernate() in the !in_suspend case.
>
The problem is more in the unfreeze of tasks..
> But why does it only affect hibernation? Do we do something extra for
> system-wide suspend/resume that is not done for hibernation?
I don't think we do anything special in hibernation per si.
Only thing is the unfreezing of tasks seams to get confused when
CPU hog tasks are present.
>
--
All the best,
Eduardo Valentin
On Mon, 30 Jul 2018, Eduardo Valentin wrote:
> On Mon, Jul 30, 2018 at 10:53:54AM +0200, Peter Zijlstra wrote:
> > On Thu, Jul 26, 2018 at 08:56:56AM -0700, Eduardo Valentin wrote:
> > > System instability are seen during resume from hibernation when system
> > > is under heavy CPU load. This is due to the lack of update of sched
> > > clock data
> >
> > Which would suggest you're already running with unstable sched clock.
> > Otherwise nobody would care about the scd stuff.
>
> Yes.
I doubt that...
> >
> > What kind of machine are you running? What does:
> >
> > dmesg | grep -i tsc
> >
> > say?
>
> Here:
> [ 0.000000] tsc: Fast TSC calibration using PIT
> [ 0.004005] tsc: Detected 3000.000 MHz processor
> [ 0.066796] TSC deadline timer enabled
> [ 3.904269] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2b3e459bf4c, max_idle_ns: 440795289890 ns
>
... because if the sched clock would be unstable then you'd have something
like 'TSC unstable' in dmesg, which you obviously do not.
'sched_clock: Marking unstable' is the other message which would be
emitted.
> > > The fix for this situation is to mark the sched clock as unstable
> > > as early as possible in the resume path, leaving it unstable
> > > for the duration of the resume process. This will force the
> > > scheduler to attempt to align the sched clock across CPUs using
> > > the delta with time of day, updating sched clock data. In a post
> > > hibernation event, we can then mark the sched clock as stable
> > > again, avoiding unnecessary syncs with time of day on systems
> > > in which TSC is reliable.
> >
> > None of this makes any sense. Either you were already unstable and it
> > should already have worked and them marking it stable is an outright
> > bug, or your sched clock was stable but then your initial diagnosis of
> > lack of scd updates is complete garbage.
> >
>
> I see, or it is just a workaround for the underling issue. I, for sure, see no
> lockups anymore after forcing the scd updates. The other thing which are not
> super clear is that this happens during the unfreezing of tasks. If I get a
> set of cpu hog tasks while unfreezing, I see the system throwing worqueue lockup
> detectors in hibernation restore.
Yes, it pretty much papers over something else. Can you please provide a
full dmesg from boot to failure case?
Another question: Does the system recover after issuing the lockup messages
or is it hosed completely?
Thanks,
tglx