lkml.org 
[lkml]   [2008]   [Apr]   [4]   [last100]   RSS Feed
Views: [wrap][no wrap]   [headers]  [forward] 
 
Messages in this thread
/
Subjectcpu_clock confusion (was: printk time confusion?)
From
Date
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
[unhandled content-type:application/pgp-signature]
\
 
 \ /
  Last update: 2008-04-04 16:31    [W:0.062 / U:0.808 seconds]
©2003-2020 Jasper Spaans|hosted at Digital Ocean and TransIP|Read the blog|Advertise on this site