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-tip-commits" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html