cpu_clock confusion (was: printk time confusion?)

cpu_clock confusion (was: printk time confusion?)

[Johannes Berg]

[-- Attachment #1: Type: text/plain, Size: 1506 bytes --]

Hi,

> > Not sure whether the lockdep patches or something else is causing this
> > as I haven't checked w/o the patches yet, but I seem to be having some
> > confusion of printk timestamps:
> 
> Tried reverting the patches ?

That didn't help, so it's not the lockdep patches causing it. I'm still
seeing printk timestamps like this:

[    2.764009 (3/3)]
[    4.272241 (2/2)]
[    4.272322 (2/2)]
[    4.272375 (2/2)]
[    2.948002 (3/3)]

As you can see, I added printk_cpu and smp_processor_id() to the printk
timestamp output and thus it is obvious that the different times come
from different CPUs.

I have to admit that I do not understand the cpu_clock() implementation,
but I can only point out that the bug seems to be there since our
sched_clock() uses the timebase which is certainly synchronized. For the
fun of it, here's another output, with get_tb() thrown in:

[   15.285317 (0/0,1734086151)]
[   13.563845 (3/3,1757040324)]
[   13.700157 (3/3,1773150788)]
[   15.181275 (1/1,1829646200)]
[   15.181343 (1/1,1829648488)]
[   16.987944 (0/0,1829664311)]
[   16.988485 (0/0,1829682407)]
[   12.047482 (2/2,1829690681)]

As expected, the timebase is perfectly fine, it's monotonously
increasing over all the processors, but cpu_clock() doesn't seem to
notice. Not sure what to make of it. It seems just using the timebase
(in form of sched_clock()) ought to be perfectly fine and even have less
overhead than all this cpu_clock() business.

johannes

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 828 bytes --]

Re: cpu_clock confusion (was: printk time confusion?)

[Ingo Molnar]

* Johannes Berg <johannes@sipsolutions.net> wrote:

> Hi,
> 
> > > Not sure whether the lockdep patches or something else is causing this
> > > as I haven't checked w/o the patches yet, but I seem to be having some
> > > confusion of printk timestamps:
> > 
> > Tried reverting the patches ?
> 
> That didn't help, so it's not the lockdep patches causing it. I'm still
> seeing printk timestamps like this:
> 
> [    2.764009 (3/3)]
> [    4.272241 (2/2)]
> [    4.272322 (2/2)]
> [    4.272375 (2/2)]
> [    2.948002 (3/3)]
> 
> As you can see, I added printk_cpu and smp_processor_id() to the 
> printk timestamp output and thus it is obvious that the different 
> times come from different CPUs.

the fixes are queued for v2.6.26. You can pick them up from 
sched-devel/latest as well:

  http://people.redhat.com/mingo/sched-devel.git/README

	Ingo

Re: cpu_clock confusion (was: printk time confusion?)

[Johannes Berg]

[-- Attachment #1: Type: text/plain, Size: 714 bytes --]


> > [    2.764009 (3/3)]
> > [    4.272241 (2/2)]
> > [    4.272322 (2/2)]
> > [    4.272375 (2/2)]
> > [    2.948002 (3/3)]
> > 
> > As you can see, I added printk_cpu and smp_processor_id() to the 
> > printk timestamp output and thus it is obvious that the different 
> > times come from different CPUs.
> 
> the fixes are queued for v2.6.26. You can pick them up from 
> sched-devel/latest as well:
> 
>   http://people.redhat.com/mingo/sched-devel.git/README

Hmm. Why is that whole cpu_clock stuff in place anyway? powerpc has
perfectly synchronised time across processors with dirt cheap access to
it as well, so why build all this code that only messes it up on top of
it?

johannes

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 828 bytes --]

Re: cpu_clock confusion

[David Miller]

From: Johannes Berg <johannes@sipsolutions.net>
Date: Thu, 24 Apr 2008 11:21:52 +0200

> Hmm. Why is that whole cpu_clock stuff in place anyway? powerpc has
> perfectly synchronised time across processors with dirt cheap access to
> it as well, so why build all this code that only messes it up on top of
> it?

Same on sparc64.  These changes add more bugs than they fix.

Re: cpu_clock confusion

[Johannes Berg]

[-- Attachment #1: Type: text/plain, Size: 790 bytes --]

On Thu, 2008-04-24 at 02:24 -0700, David Miller wrote:
> From: Johannes Berg <johannes@sipsolutions.net>
> Date: Thu, 24 Apr 2008 11:21:52 +0200
> 
> > Hmm. Why is that whole cpu_clock stuff in place anyway? powerpc has
> > perfectly synchronised time across processors with dirt cheap access to
> > it as well, so why build all this code that only messes it up on top of
> > it?
> 
> Same on sparc64.  These changes add more bugs than they fix.

I tend to think all this clock business should be done local to those
arches that aren't capable of providing cheap, useful synchronised and
accurate clocks themselves. Or be a lib that they can link in if needed.
As it stands, it seems to me that it all just penalises those
architectures that have decent clocks.

johannes

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 828 bytes --]

Re: cpu_clock confusion

[Gabriel Paubert]

On Thu, Apr 24, 2008 at 11:27:37AM +0200, Johannes Berg wrote:
> On Thu, 2008-04-24 at 02:24 -0700, David Miller wrote:
> > From: Johannes Berg <johannes@sipsolutions.net>
> > Date: Thu, 24 Apr 2008 11:21:52 +0200
> > 
> > > Hmm. Why is that whole cpu_clock stuff in place anyway? powerpc has
> > > perfectly synchronised time across processors with dirt cheap access to
> > > it as well, so why build all this code that only messes it up on top of
> > > it?
> > 
> > Same on sparc64.  These changes add more bugs than they fix.
> 
> I tend to think all this clock business should be done local to those
> arches that aren't capable of providing cheap, useful synchronised and
> accurate clocks themselves. Or be a lib that they can link in if needed.
> As it stands, it seems to me that it all just penalises those
> architectures that have decent clocks.

100% agreed. 

	Gabriel