[PATCH 0/3] sched_clock updates

[PATCH 0/3] sched_clock updates

[Steven Rostedt]

Working with ftrace on linux-tip, I found a few problems with the sched_clock
code that is suppose to help an unstable TSC keep accurate time. The
problem I was seeing was on a box with a stable TSC. The time would
jump around a lot. One would think that code to help unstable TSC keep
time would not be a problem with a stable TSC.

The main change was the patch that handled the dynamic ticks. That was
the culprit of bein off by several jiffies.

With these patches applied, ftrace is quite a bit better with respect to time.
But there is still jumps that happen that do not happen with sched_clock.

I'm suspecting that the problems that still exist have more to do with
time updates or a drift between the TSC and the clock used for GTOD.

Anyway, enjoy,

-- Steve

[PATCH 1/3] sched_clock: record from last tick

[Steven Rostedt]

[-- Attachment #1: sched-clock-tick-jiffies.patch --]
[-- Type: text/plain, Size: 2626 bytes --]

The sched_clock code tries to keep within the gtod time by one tick (jiffy).
The current code mistakenly keeps track of the delta jiffies between
updates of the clock, where the the delta is used to compare with the
number of jiffies that have past since an update of the gtod. The gtod is
updated at each schedule tick not each sched_clock update. After one
jiffy passes the clock is updated fine. But the delta is taken from the
last update so if the next update happens before the next tick the delta
jiffies used will be incorrect.

This patch changes the code to check the delta of jiffies between ticks
and not updates to match the comparison of the updates with the gtod.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/sched_clock.c |    9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

Index: linux-tip.git/kernel/sched_clock.c
===================================================================
--- linux-tip.git.orig/kernel/sched_clock.c	2008-07-06 01:24:43.000000000 -0400
+++ linux-tip.git/kernel/sched_clock.c	2008-07-06 22:35:35.000000000 -0400
@@ -40,7 +40,7 @@ struct sched_clock_data {
 	 */
 	raw_spinlock_t		lock;
 
-	unsigned long		prev_jiffies;
+	unsigned long		tick_jiffies;
 	u64			prev_raw;
 	u64			tick_raw;
 	u64			tick_gtod;
@@ -71,7 +71,7 @@ void sched_clock_init(void)
 		struct sched_clock_data *scd = cpu_sdc(cpu);
 
 		scd->lock = (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
-		scd->prev_jiffies = now_jiffies;
+		scd->tick_jiffies = now_jiffies;
 		scd->prev_raw = 0;
 		scd->tick_raw = 0;
 		scd->tick_gtod = ktime_now;
@@ -90,7 +90,7 @@ void sched_clock_init(void)
 static void __update_sched_clock(struct sched_clock_data *scd, u64 now)
 {
 	unsigned long now_jiffies = jiffies;
-	long delta_jiffies = now_jiffies - scd->prev_jiffies;
+	long delta_jiffies = now_jiffies - scd->tick_jiffies;
 	u64 clock = scd->clock;
 	u64 min_clock, max_clock;
 	s64 delta = now - scd->prev_raw;
@@ -119,7 +119,6 @@ static void __update_sched_clock(struct 
 		clock = min_clock;
 
 	scd->prev_raw = now;
-	scd->prev_jiffies = now_jiffies;
 	scd->clock = clock;
 }
 
@@ -179,6 +178,7 @@ u64 sched_clock_cpu(int cpu)
 void sched_clock_tick(void)
 {
 	struct sched_clock_data *scd = this_scd();
+	unsigned long now_jiffies = jiffies;
 	u64 now, now_gtod;
 
 	if (unlikely(!sched_clock_running))
@@ -196,6 +196,7 @@ void sched_clock_tick(void)
 	 * already observe 1 new jiffy; adding a new tick_gtod to that would
 	 * increase the clock 2 jiffies.
 	 */
+	scd->tick_jiffies = now_jiffies;
 	scd->tick_raw = now;
 	scd->tick_gtod = now_gtod;
 	__raw_spin_unlock(&scd->lock);

-- 

[PATCH 2/3] sched_clock: widen the max and min time

[Steven Rostedt]

[-- Attachment #1: sched_clock-bigger-max-min-buffer.patch --]
[-- Type: text/plain, Size: 1749 bytes --]

With keeping the max and min sched time within one jiffy of the gtod clock
was too tight. Just before a schedule tick the max could easily be hit, as
well as just after a schedule_tick the min could be hit. This caused the
clock to jump around by a jiffy.

This patch widens the minimum to
   last gtod + (delta_jiffies ? delta_jiffies - 1 : 0) * TICK_NSECS

and the maximum to
    last gtod + (2 + delta_jiffies) * TICK_NSECS

This keeps the minum to gtod or if one jiffy less than delta jiffies
and the maxim 2 jiffies ahead of gtod. This may cause unstable TSCs to be
a bit more sporadic, but it helps keep a clock with a stable TSC working well.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 kernel/sched_clock.c |   11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)

Index: linux-tip.git/kernel/sched_clock.c
===================================================================
--- linux-tip.git.orig/kernel/sched_clock.c	2008-07-06 22:35:35.000000000 -0400
+++ linux-tip.git/kernel/sched_clock.c	2008-07-06 22:33:49.000000000 -0400
@@ -96,14 +96,21 @@ static void __update_sched_clock(struct 
 	s64 delta = now - scd->prev_raw;
 
 	WARN_ON_ONCE(!irqs_disabled());
-	min_clock = scd->tick_gtod + delta_jiffies * TICK_NSEC;
+
+	min_clock = scd->tick_gtod +
+		(delta_jiffies ? delta_jiffies - 1 : 0) * TICK_NSEC;
 
 	if (unlikely(delta < 0)) {
 		clock++;
 		goto out;
 	}
 
-	max_clock = min_clock + TICK_NSEC;
+	/*
+	 * The clock must stay within a jiffie of the gtod.
+	 * But since we may be at the start of a jiffy or the end of one
+	 * we add another jiffy buffer.
+	 */
+	max_clock = scd->tick_gtod + (2 + delta_jiffies) * TICK_NSEC;
 
 	if (unlikely(clock + delta > max_clock)) {
 		if (clock < max_clock)

-- 

[PATCH 3/3] sched_clock: stop maximum check on NO HZ

[Steven Rostedt]

[-- Attachment #1: sched-clock-no-max-from-idle.patch --]
[-- Type: text/plain, Size: 5080 bytes --]

Working with ftrace I would get large jumps of 11 millisecs or more with
the clock tracer. This killed the latencing timings of ftrace and also
caused the irqoff self tests to fail.

What was happening is with NO_HZ the idle would stop the jiffy counter and
before the jiffy counter was updated the sched_clock would have a bad
delta jiffies to compare with the gtod with the maximum.

The jiffies would stop and the last sched_tick would record the last gtod.
On wakeup, the sched clock update would compare the gtod + delta jiffies
(which would be zero) and compare it to the TSC. The TSC would have
correctly (with a stable TSC) moved forward several jiffies. But because the
jiffies has not been updated yet the clock would be prevented from moving
forward because it would appear that the TSC jumped too far ahead.

The clock would then virtually stop, until the jiffies are updated. Then
the next sched clock update would see that the clock was very much behind
since the delta jiffies is now correct. This would then jump the clock
forward by several jiffies.

This caused ftrace to report several milliseconds of interrupts off
latency at every resume from NO_HZ idle.

This patch adds hooks into the nohz code to disable the checking of the
maximum clock update when nohz is in effect. It resumes the max check
when nohz has updated the jiffies again.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
---
 include/linux/sched.h    |   17 ++++++++++++++++-
 kernel/sched_clock.c     |   39 ++++++++++++++++++++++++++++++++++++++-
 kernel/time/tick-sched.c |    2 ++
 3 files changed, 56 insertions(+), 2 deletions(-)

Index: linux-tip.git/kernel/sched_clock.c
===================================================================
--- linux-tip.git.orig/kernel/sched_clock.c	2008-07-06 23:29:43.000000000 -0400
+++ linux-tip.git/kernel/sched_clock.c	2008-07-07 13:14:42.000000000 -0400
@@ -45,6 +45,9 @@ struct sched_clock_data {
 	u64			tick_raw;
 	u64			tick_gtod;
 	u64			clock;
+#ifdef CONFIG_NO_HZ
+	int			check_max;
+#endif
 };
 
 static DEFINE_PER_CPU_SHARED_ALIGNED(struct sched_clock_data, sched_clock_data);
@@ -76,11 +79,45 @@ void sched_clock_init(void)
 		scd->tick_raw = 0;
 		scd->tick_gtod = ktime_now;
 		scd->clock = ktime_now;
+#ifdef CONFIG_NO_HZ
+		scd->check_max = 1;
+#endif
 	}
 
 	sched_clock_running = 1;
 }
 
+#ifdef CONFIG_NO_HZ
+/*
+ * The dynamic ticks makes the delta jiffies inaccurate. This
+ * prevents us from checking the maximum time update.
+ * Disable the maximum check during stopped ticks.
+ */
+void sched_clock_tick_stop(int cpu)
+{
+	struct sched_clock_data *scd = cpu_sdc(cpu);
+
+	scd->check_max = 0;
+}
+
+void sched_clock_tick_start(int cpu)
+{
+	struct sched_clock_data *scd = cpu_sdc(cpu);
+
+	scd->check_max = 1;
+}
+
+static int check_max(struct sched_clock_data *scd)
+{
+	return scd->check_max;
+}
+#else
+static int check_max(struct sched_clock_data *scd)
+{
+	return 1;
+}
+#endif /* CONFIG_NO_HZ */
+
 /*
  * update the percpu scd from the raw @now value
  *
@@ -112,7 +149,7 @@ static void __update_sched_clock(struct 
 	 */
 	max_clock = scd->tick_gtod + (2 + delta_jiffies) * TICK_NSEC;
 
-	if (unlikely(clock + delta > max_clock)) {
+	if (unlikely(clock + delta > max_clock) && check_max(scd)) {
 		if (clock < max_clock)
 			clock = max_clock;
 		else
Index: linux-tip.git/include/linux/sched.h
===================================================================
--- linux-tip.git.orig/include/linux/sched.h	2008-07-06 23:02:53.000000000 -0400
+++ linux-tip.git/include/linux/sched.h	2008-07-06 23:38:33.000000000 -0400
@@ -1575,13 +1575,28 @@ static inline void sched_clock_idle_slee
 static inline void sched_clock_idle_wakeup_event(u64 delta_ns)
 {
 }
-#else
+
+#ifdef CONFIG_NO_HZ
+static inline void sched_clock_tick_stop(int cpu)
+{
+}
+
+static inline void sched_clock_tick_start(int cpu)
+{
+}
+#endif
+
+#else /* CONFIG_HAVE_UNSTABLE_SCHED_CLOCK */
 extern void sched_clock_init(void);
 extern u64 sched_clock_cpu(int cpu);
 extern void sched_clock_tick(void);
 extern void sched_clock_idle_sleep_event(void);
 extern void sched_clock_idle_wakeup_event(u64 delta_ns);
+#ifdef CONFIG_NO_HZ
+extern void sched_clock_tick_stop(int cpu);
+extern void sched_clock_tick_start(int cpu);
 #endif
+#endif /* CONFIG_HAVE_UNSTABLE_SCHED_CLOCK */
 
 /*
  * For kernel-internal use: high-speed (but slightly incorrect) per-cpu
Index: linux-tip.git/kernel/time/tick-sched.c
===================================================================
--- linux-tip.git.orig/kernel/time/tick-sched.c	2008-07-06 23:02:53.000000000 -0400
+++ linux-tip.git/kernel/time/tick-sched.c	2008-07-07 10:51:21.000000000 -0400
@@ -276,6 +276,7 @@ void tick_nohz_stop_sched_tick(void)
 			ts->tick_stopped = 1;
 			ts->idle_jiffies = last_jiffies;
 			rcu_enter_nohz();
+			sched_clock_tick_stop(cpu);
 		}
 
 		/*
@@ -375,6 +376,7 @@ void tick_nohz_restart_sched_tick(void)
 	select_nohz_load_balancer(0);
 	now = ktime_get();
 	tick_do_update_jiffies64(now);
+	sched_clock_tick_start(cpu);
 	cpu_clear(cpu, nohz_cpu_mask);
 
 	/*

-- 

Re: [PATCH 3/3] sched_clock: stop maximum check on NO HZ

[Peter Zijlstra]

On Mon, 2008-07-07 at 14:16 -0400, Steven Rostedt wrote:
> plain text document attachment (sched-clock-no-max-from-idle.patch)
> Working with ftrace I would get large jumps of 11 millisecs or more with
> the clock tracer. This killed the latencing timings of ftrace and also
> caused the irqoff self tests to fail.
> 
> What was happening is with NO_HZ the idle would stop the jiffy counter and
> before the jiffy counter was updated the sched_clock would have a bad
> delta jiffies to compare with the gtod with the maximum.
> 
> The jiffies would stop and the last sched_tick would record the last gtod.
> On wakeup, the sched clock update would compare the gtod + delta jiffies
> (which would be zero) and compare it to the TSC. The TSC would have
> correctly (with a stable TSC) moved forward several jiffies. But because the
> jiffies has not been updated yet the clock would be prevented from moving
> forward because it would appear that the TSC jumped too far ahead.
> 
> The clock would then virtually stop, until the jiffies are updated. Then
> the next sched clock update would see that the clock was very much behind
> since the delta jiffies is now correct. This would then jump the clock
> forward by several jiffies.
> 
> This caused ftrace to report several milliseconds of interrupts off
> latency at every resume from NO_HZ idle.
> 
> This patch adds hooks into the nohz code to disable the checking of the
> maximum clock update when nohz is in effect. It resumes the max check
> when nohz has updated the jiffies again.

IIRC we have code to move jiffies forward over no_hz periods too. So
could this be an ordering issue, in that we should update the jiffies
before we do this bit?

Wouldn't be the first time ftrace causes ordering issues..

/me goes look for where that jiffie stuff was done again.

> Signed-off-by: Steven Rostedt <srostedt@redhat.com>
> ---
>  include/linux/sched.h    |   17 ++++++++++++++++-
>  kernel/sched_clock.c     |   39 ++++++++++++++++++++++++++++++++++++++-
>  kernel/time/tick-sched.c |    2 ++
>  3 files changed, 56 insertions(+), 2 deletions(-)
> 
> Index: linux-tip.git/kernel/sched_clock.c
> ===================================================================
> --- linux-tip.git.orig/kernel/sched_clock.c	2008-07-06 23:29:43.000000000 -0400
> +++ linux-tip.git/kernel/sched_clock.c	2008-07-07 13:14:42.000000000 -0400
> @@ -45,6 +45,9 @@ struct sched_clock_data {
>  	u64			tick_raw;
>  	u64			tick_gtod;
>  	u64			clock;
> +#ifdef CONFIG_NO_HZ
> +	int			check_max;
> +#endif
>  };
>  
>  static DEFINE_PER_CPU_SHARED_ALIGNED(struct sched_clock_data, sched_clock_data);
> @@ -76,11 +79,45 @@ void sched_clock_init(void)
>  		scd->tick_raw = 0;
>  		scd->tick_gtod = ktime_now;
>  		scd->clock = ktime_now;
> +#ifdef CONFIG_NO_HZ
> +		scd->check_max = 1;
> +#endif
>  	}
>  
>  	sched_clock_running = 1;
>  }
>  
> +#ifdef CONFIG_NO_HZ
> +/*
> + * The dynamic ticks makes the delta jiffies inaccurate. This
> + * prevents us from checking the maximum time update.
> + * Disable the maximum check during stopped ticks.
> + */
> +void sched_clock_tick_stop(int cpu)
> +{
> +	struct sched_clock_data *scd = cpu_sdc(cpu);
> +
> +	scd->check_max = 0;
> +}
> +
> +void sched_clock_tick_start(int cpu)
> +{
> +	struct sched_clock_data *scd = cpu_sdc(cpu);
> +
> +	scd->check_max = 1;
> +}
> +
> +static int check_max(struct sched_clock_data *scd)
> +{
> +	return scd->check_max;
> +}
> +#else
> +static int check_max(struct sched_clock_data *scd)
> +{
> +	return 1;
> +}
> +#endif /* CONFIG_NO_HZ */
> +
>  /*
>   * update the percpu scd from the raw @now value
>   *
> @@ -112,7 +149,7 @@ static void __update_sched_clock(struct 
>  	 */
>  	max_clock = scd->tick_gtod + (2 + delta_jiffies) * TICK_NSEC;
>  
> -	if (unlikely(clock + delta > max_clock)) {
> +	if (unlikely(clock + delta > max_clock) && check_max(scd)) {
>  		if (clock < max_clock)
>  			clock = max_clock;
>  		else
> Index: linux-tip.git/include/linux/sched.h
> ===================================================================
> --- linux-tip.git.orig/include/linux/sched.h	2008-07-06 23:02:53.000000000 -0400
> +++ linux-tip.git/include/linux/sched.h	2008-07-06 23:38:33.000000000 -0400
> @@ -1575,13 +1575,28 @@ static inline void sched_clock_idle_slee
>  static inline void sched_clock_idle_wakeup_event(u64 delta_ns)
>  {
>  }
> -#else
> +
> +#ifdef CONFIG_NO_HZ
> +static inline void sched_clock_tick_stop(int cpu)
> +{
> +}
> +
> +static inline void sched_clock_tick_start(int cpu)
> +{
> +}
> +#endif
> +
> +#else /* CONFIG_HAVE_UNSTABLE_SCHED_CLOCK */
>  extern void sched_clock_init(void);
>  extern u64 sched_clock_cpu(int cpu);
>  extern void sched_clock_tick(void);
>  extern void sched_clock_idle_sleep_event(void);
>  extern void sched_clock_idle_wakeup_event(u64 delta_ns);
> +#ifdef CONFIG_NO_HZ
> +extern void sched_clock_tick_stop(int cpu);
> +extern void sched_clock_tick_start(int cpu);
>  #endif
> +#endif /* CONFIG_HAVE_UNSTABLE_SCHED_CLOCK */
>  
>  /*
>   * For kernel-internal use: high-speed (but slightly incorrect) per-cpu
> Index: linux-tip.git/kernel/time/tick-sched.c
> ===================================================================
> --- linux-tip.git.orig/kernel/time/tick-sched.c	2008-07-06 23:02:53.000000000 -0400
> +++ linux-tip.git/kernel/time/tick-sched.c	2008-07-07 10:51:21.000000000 -0400
> @@ -276,6 +276,7 @@ void tick_nohz_stop_sched_tick(void)
>  			ts->tick_stopped = 1;
>  			ts->idle_jiffies = last_jiffies;
>  			rcu_enter_nohz();
> +			sched_clock_tick_stop(cpu);
>  		}
>  
>  		/*
> @@ -375,6 +376,7 @@ void tick_nohz_restart_sched_tick(void)
>  	select_nohz_load_balancer(0);
>  	now = ktime_get();
>  	tick_do_update_jiffies64(now);
> +	sched_clock_tick_start(cpu);
>  	cpu_clear(cpu, nohz_cpu_mask);
>  
>  	/*
> 

Re: [PATCH 3/3] sched_clock: stop maximum check on NO HZ

[Steven Rostedt]

On Wed, 16 Jul 2008, Peter Zijlstra wrote:

>
> On Mon, 2008-07-07 at 14:16 -0400, Steven Rostedt wrote:
> > plain text document attachment (sched-clock-no-max-from-idle.patch)
> > Working with ftrace I would get large jumps of 11 millisecs or more with
> > the clock tracer. This killed the latencing timings of ftrace and also
> > caused the irqoff self tests to fail.
> >
> > What was happening is with NO_HZ the idle would stop the jiffy counter and
> > before the jiffy counter was updated the sched_clock would have a bad
> > delta jiffies to compare with the gtod with the maximum.
> >
> > The jiffies would stop and the last sched_tick would record the last gtod.
> > On wakeup, the sched clock update would compare the gtod + delta jiffies
> > (which would be zero) and compare it to the TSC. The TSC would have
> > correctly (with a stable TSC) moved forward several jiffies. But because the
> > jiffies has not been updated yet the clock would be prevented from moving
> > forward because it would appear that the TSC jumped too far ahead.
> >
> > The clock would then virtually stop, until the jiffies are updated. Then
> > the next sched clock update would see that the clock was very much behind
> > since the delta jiffies is now correct. This would then jump the clock
> > forward by several jiffies.
> >
> > This caused ftrace to report several milliseconds of interrupts off
> > latency at every resume from NO_HZ idle.
> >
> > This patch adds hooks into the nohz code to disable the checking of the
> > maximum clock update when nohz is in effect. It resumes the max check
> > when nohz has updated the jiffies again.
>
> IIRC we have code to move jiffies forward over no_hz periods too. So
> could this be an ordering issue, in that we should update the jiffies
> before we do this bit?
>
> Wouldn't be the first time ftrace causes ordering issues..
>
> /me goes look for where that jiffie stuff was done again.

The problem is that ftrace calls this code at every function, and even
when function_trace is not on, the irqsoff tracer will call it from
assembly. In-other-words, ftrace will use it before you even have a chance
to update the jiffies.

-- Steve