* CONFIG_PRINTK_TIME and initial value for jiffies?
@ 2006-05-15 20:41 Clem Taylor
2006-05-15 21:11 ` Sergei Shtylyov
0 siblings, 1 reply; 6+ messages in thread
From: Clem Taylor @ 2006-05-15 20:41 UTC (permalink / raw)
To: linux-mips
I just switched to 2.6.16.16 from 2.6.14 on a Au1550. I enabled
CONFIG_PRINTK_TIME, and for some reason jiffies doesn't start out near
zero like it does on x86. The first printk() always seems to have a
time of 4284667.296000.
jiffies_64 and wall_jiffies gets initialized to INITIAL_JIFFIES, but
I'm not sure where jiffies is initialized. INITIAL_JIFFIES is -300*HZ
(with some weird casting)
The first line on the 2.6.16.16 Au1550 box is:
[4294667.296000] Linux version 2.6.16.16 (ctaylor@gort) (gcc version
4.1.0) #4 Mon May 15 13:06:37 EDT 2006
The first line on a 2.6.16 x86_64 box is:
[ 0.000000] Bootdata ok (command line is ro root=/dev/md0)
[ 0.000000] Linux version 2.6.16 (ctaylor@klaatu) (gcc version
4.1.0 20060420 (Red Hat 4.1.0-9)) #3 SMP PREEMPT Sat Apr 29 03:36:06
EDT 2006
Shouldn't the first printk() have a time at or very near zero?
--Clem
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: CONFIG_PRINTK_TIME and initial value for jiffies?
2006-05-15 20:41 CONFIG_PRINTK_TIME and initial value for jiffies? Clem Taylor
@ 2006-05-15 21:11 ` Sergei Shtylyov
2006-05-15 21:35 ` Sergei Shtylyov
0 siblings, 1 reply; 6+ messages in thread
From: Sergei Shtylyov @ 2006-05-15 21:11 UTC (permalink / raw)
To: Clem Taylor; +Cc: Linux-MIPS
Hello.
Clem Taylor wrote:
> I just switched to 2.6.16.16 from 2.6.14 on a Au1550. I enabled
> CONFIG_PRINTK_TIME, and for some reason jiffies doesn't start out near
> zero like it does on x86. The first printk() always seems to have a
> time of 4284667.296000.
> jiffies_64 and wall_jiffies gets initialized to INITIAL_JIFFIES, but
> I'm not sure where jiffies is initialized. INITIAL_JIFFIES is -300*HZ
> (with some weird casting)
> The first line on the 2.6.16.16 Au1550 box is:
> [4294667.296000] Linux version 2.6.16.16 (ctaylor@gort) (gcc version
> 4.1.0) #4 Mon May 15 13:06:37 EDT 2006
Well, this number looks a lot like -300 secs printed as unsigned --
given the fact that jiffies are unsigned, there's no surprise...
My first guess is that TSC code used on x86 corrected jiffies_64 before
they got used by sched_clock(). Probably a bogus guess because TSC should have
been used by sched_clock() itsefl then...
MBR, Sergei
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: CONFIG_PRINTK_TIME and initial value for jiffies?
2006-05-15 21:11 ` Sergei Shtylyov
@ 2006-05-15 21:35 ` Sergei Shtylyov
2006-05-16 6:03 ` Herbert Valerio Riedel
0 siblings, 1 reply; 6+ messages in thread
From: Sergei Shtylyov @ 2006-05-15 21:35 UTC (permalink / raw)
To: Clem Taylor; +Cc: Linux-MIPS
Sergei Shtylyov wrote:
> Hello.
>
> Clem Taylor wrote:
>
>> I just switched to 2.6.16.16 from 2.6.14 on a Au1550. I enabled
>> CONFIG_PRINTK_TIME, and for some reason jiffies doesn't start out near
>> zero like it does on x86. The first printk() always seems to have a
>> time of 4284667.296000.
>> jiffies_64 and wall_jiffies gets initialized to INITIAL_JIFFIES, but
>> I'm not sure where jiffies is initialized. INITIAL_JIFFIES is -300*HZ
>> (with some weird casting)
Yes, the casting is weird. I somewat doubt that:
#define INITIAL_JIFFIES ((unsigned long)(unsigned int) (-300*HZ))
u64 jiffies_64 = INITIAL_JIFFIES;
can do the trick of wrapping around 5 mins after boot on x86... :-/
MBR, Sergei
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: CONFIG_PRINTK_TIME and initial value for jiffies?
2006-05-15 21:35 ` Sergei Shtylyov
@ 2006-05-16 6:03 ` Herbert Valerio Riedel
2006-05-16 12:35 ` Sergei Shtylyov
0 siblings, 1 reply; 6+ messages in thread
From: Herbert Valerio Riedel @ 2006-05-16 6:03 UTC (permalink / raw)
To: Sergei Shtylyov; +Cc: Clem Taylor, Linux-MIPS
hello!
On Tue, 2006-05-16 at 01:35 +0400, Sergei Shtylyov wrote:
> >> I just switched to 2.6.16.16 from 2.6.14 on a Au1550. I enabled
> >> CONFIG_PRINTK_TIME, and for some reason jiffies doesn't start out near
> >> zero like it does on x86. The first printk() always seems to have a
> >> time of 4284667.296000.
>
> >> jiffies_64 and wall_jiffies gets initialized to INITIAL_JIFFIES, but
> >> I'm not sure where jiffies is initialized. INITIAL_JIFFIES is -300*HZ
> >> (with some weird casting)
>
> Yes, the casting is weird. I somewat doubt that:
>
> #define INITIAL_JIFFIES ((unsigned long)(unsigned int) (-300*HZ))
>
> u64 jiffies_64 = INITIAL_JIFFIES;
>
> can do the trick of wrapping around 5 mins after boot on x86... :-/
jfyi, starting with an offset of -300 seconds is done on purpose, to
expose bugs in drivers which don't handle wrapping of the jiffies;
and the trick to get printk to start at offset 0 is either define a
arch-specific printk_clock() function (it's a weak symbol in
kernel/printk.c) or like more drivers to it, to provide a sched_clock()
(which is used by the default printk_clock() function) implementation
which starts at offset 0...
regards,
hvr
^ permalink raw reply [flat|nested] 6+ messages in thread
* Re: CONFIG_PRINTK_TIME and initial value for jiffies?
2006-05-16 6:03 ` Herbert Valerio Riedel
@ 2006-05-16 12:35 ` Sergei Shtylyov
2006-05-22 16:27 ` Tim Bird
0 siblings, 1 reply; 6+ messages in thread
From: Sergei Shtylyov @ 2006-05-16 12:35 UTC (permalink / raw)
To: Herbert Valerio Riedel; +Cc: Clem Taylor, Linux-MIPS
Hello.
Herbert Valerio Riedel wrote:
> On Tue, 2006-05-16 at 01:35 +0400, Sergei Shtylyov wrote:
>>>>I just switched to 2.6.16.16 from 2.6.14 on a Au1550. I enabled
>>>>CONFIG_PRINTK_TIME, and for some reason jiffies doesn't start out near
>>>>zero like it does on x86. The first printk() always seems to have a
>>>>time of 4284667.296000.
>>
>>>>jiffies_64 and wall_jiffies gets initialized to INITIAL_JIFFIES, but
>>>>I'm not sure where jiffies is initialized. INITIAL_JIFFIES is -300*HZ
>>>>(with some weird casting)
>> Yes, the casting is weird. I somewat doubt that:
>>#define INITIAL_JIFFIES ((unsigned long)(unsigned int) (-300*HZ))
>>u64 jiffies_64 = INITIAL_JIFFIES;
>>can do the trick of wrapping around 5 mins after boot on x86... :-/
> jfyi, starting with an offset of -300 seconds is done on purpose, to
> expose bugs in drivers which don't handle wrapping of the jiffies;
Oh, thank you. I've read that in the source code. :-)
> and the trick to get printk to start at offset 0 is either define a
> arch-specific printk_clock() function (it's a weak symbol in
> kernel/printk.c) or like more drivers to it, to provide a sched_clock()
> (which is used by the default printk_clock() function) implementation
> which starts at offset 0...
sched_clock() defined in arch/i386/kernel/timers/timer_tsc.c can hardly
provide 0-based time if it's using TSC (at least I can't see where the TSC is
cleared). Even if it's not using TSC, jiffies_64 is not 0-based as we saw, and
neither it's set to -300 secs because of the double cast to ulong and then to
u64 which should clear the high word. Probably something somewhere clears TSC
but I can see the related code only in arch/i386/kernel/smpboot.c...
> regards,
> hvr
WBR, Sergei
^ permalink raw reply [flat|nested] 6+ messages in thread* Re: CONFIG_PRINTK_TIME and initial value for jiffies?
2006-05-16 12:35 ` Sergei Shtylyov
@ 2006-05-22 16:27 ` Tim Bird
0 siblings, 0 replies; 6+ messages in thread
From: Tim Bird @ 2006-05-22 16:27 UTC (permalink / raw)
To: Sergei Shtylyov; +Cc: Herbert Valerio Riedel, Clem Taylor, Linux-MIPS
Sergei Shtylyov wrote:
> sched_clock() defined in arch/i386/kernel/timers/timer_tsc.c can
> hardly provide 0-based time if it's using TSC (at least I can't see
> where the TSC is cleared). Even if it's not using TSC, jiffies_64 is not
> 0-based as we saw, and neither it's set to -300 secs because of the
> double cast to ulong and then to u64 which should clear the high word.
> Probably something somewhere clears TSC but I can see the related code
> only in arch/i386/kernel/smpboot.c...
I've worked a lot with the printk_times feature, and it's not unusual
on many systems to see weird values before time_init(). On x86 with a
TSC-based sched_clock() you may see values based on whatever
the TSC happens to be after firmware initialization up until time_init().
Note that you can re-base the timings to an arbitrary printk line
using scripts/show_delta. See
http://tree.celinuxforum.org/CelfPubWiki/PrintkTimesSample2
=============================
Tim Bird
Architecture Group Chair, CE Linux Forum
Senior Staff Engineer, Sony Electronics
=============================
^ permalink raw reply [flat|nested] 6+ messages in thread
end of thread, other threads:[~2006-05-22 16:27 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2006-05-15 20:41 CONFIG_PRINTK_TIME and initial value for jiffies? Clem Taylor
2006-05-15 21:11 ` Sergei Shtylyov
2006-05-15 21:35 ` Sergei Shtylyov
2006-05-16 6:03 ` Herbert Valerio Riedel
2006-05-16 12:35 ` Sergei Shtylyov
2006-05-22 16:27 ` Tim Bird
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox