Re: [tip:sched/urgent] sched: Fix cross-cpu clock sync on remotewakeups

From: Peter Zijlstra
Date: Wed Jun 01 2011 - 08:43:35 EST


On Wed, 2011-06-01 at 09:05 +0200, Borislav Petkov wrote:
> On Tue, May 31, 2011 at 03:11:56PM +0200, Peter Zijlstra wrote:
> > Well, I don't have a modern AMD system to verify on, but the only
> > explanation is sched_clock weirdness (different code from the GTOD tsc
> > stuff). I could not reproduce on an Intel Westmere machine, but could on
> > a Core2.
> >
> > The sched_clock_cpu stuff basically takes a GTOD timestamp every tick
> > and uses sched_clock() (tsc + cyc2ns) to provide delta increments, when
> > TSCs are synced every cpu should return the same value and the patch is
> > a nop.
> >
> > If they aren't synced the per-cpu sched_clock_cpu() values can drift up
> > to about 2 jiffies (when the ticks drift about 1 and the slower of the
> > two has a stuck tsc while the faster of the two does progress at the
> > normal rate). In that case doing a clock update cross-cpu will ensure
> > time monotonicity between those two cpus.
>
> Hmm, could it be that the sched_clock_tick() could be seeing different
> TSC values due to propagation delays of IPIs and TSCs? Or, it could be
> also that some TSCs don't start at the same moment after powerup but
> still run synchronized though?
>
> How can we trace this, do you do trace_printk() in the scheduler? I'm
> asking because I remember reading somewhere that tracing the scheduler
> is not that trivial like say a driver :). I could do that on a couple of
> machines I have here and see what happens.

trace_printk() can go pretty much anywhere, you want to start with
something like the below and go from there, either up into
arch/x86/kernel/tsc.c:native_sched_clock() or down into the scheduler
and instrument rq->clock (although you most likely already get most of
that through the sched_clock_cpu() trace_printk).

Also, it might be good to check on the sched_clock_stable logic in
general and on your platform in particular, if that's set we forgo all
the fancy bits and return sched_clock() directly.

---
kernel/sched_clock.c | 10 ++++++++++
1 files changed, 10 insertions(+), 0 deletions(-)

diff --git a/kernel/sched_clock.c b/kernel/sched_clock.c
index 9d8af0b..873f50f 100644
--- a/kernel/sched_clock.c
+++ b/kernel/sched_clock.c
@@ -167,6 +167,9 @@ static u64 sched_clock_local(struct sched_clock_data *scd)
if (cmpxchg64(&scd->clock, old_clock, clock) != old_clock)
goto again;

+ trace_printk("now: %llu, gtod: %llu, delta: %llu, old_clock: %llu, clock: %llu\n",
+ now, scd->tick_gtod, delta, old_clock, clock);
+
return clock;
}

@@ -203,6 +206,9 @@ static u64 sched_clock_remote(struct sched_clock_data *scd)
if (cmpxchg64(ptr, old_val, val) != old_val)
goto again;

+ trace_printk("this: %llu, remote: %llu, clock: %llu\n",
+ thid_clock, remote_clock, val);
+
return val;
}

@@ -231,6 +237,8 @@ u64 sched_clock_cpu(int cpu)
else
clock = sched_clock_local(scd);

+ trace_printk("clock: %llu\n", clock);
+
return clock;
}

@@ -251,6 +259,8 @@ void sched_clock_tick(void)
now_gtod = ktime_to_ns(ktime_get());
now = sched_clock();

+ trace_printk("gtod: %llu, now: %llu\n", now_gtod, now);
+
scd->tick_raw = now;
scd->tick_gtod = now_gtod;
sched_clock_local(scd);

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/