Re: CONFIG_PRINTK_TIME woes

2005-08-23 Thread Tim Bird
Andrew Morton wrote: > Andrew Morton <[EMAIL PROTECTED]> wrote: > >>How about we give each arch a printk_clock()? > > > Which might be as simple as this.. > > > --- devel/kernel/printk.c~printk_clock2005-08-21 02:14:05.0 > -0700 > +++ devel-akpm/kernel/printk.c2005-08-2

Re: CONFIG_PRINTK_TIME woes

2005-08-23 Thread Tim Bird
Andrew Morton wrote: > Nick Piggin <[EMAIL PROTECTED]> wrote: >> >>What about just using jiffies, then? >> >>Really, sched_clock() is very broken for this (I know you're >>not arguing against that). >> >>It can go backwards when called twice from the same CPU, and the >>number returned by one CPU n

Re: CONFIG_PRINTK_TIME woes

2005-08-23 Thread Nick Piggin
David S. Miller wrote: This is a useful feature, please do not labotomize it just because it's difficult to implement on ia64. Just make a "printk_get_timestamp_because_ia64_sucks()" interface or something like that :-) I was a bit unclear when I raised this issue. It is not just an ia64 prob

RE: CONFIG_PRINTK_TIME woes

2005-08-23 Thread Luck, Tony
>I'd hate to have to test for something for CONFIG_PRINTK_TIME >every time sched_clock() is being called. Me too. >The quick fix would seem to be to only allow CONFIG_PRINTK_TIME >from kernel cmdline to make it happen a bit later. So basically >make int printk_time = 0 until command line is evalu

Re: CONFIG_PRINTK_TIME woes

2005-08-23 Thread Tony Lindgren
* Andrew Morton <[EMAIL PROTECTED]> [050821 02:15]: > "Luck, Tony" <[EMAIL PROTECTED]> wrote: > > > > It has been pointed out to me that ia64 doesn't boot > > with CONFIG_PRINTK_TIME=y. The issue is the call to > > sched_clock() ... which on ia64 accesses some per-cpu > > data to adjust for possib

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread Paul Mackerras
[EMAIL PROTECTED] writes: > Earlier I said that it would be possible to provide a simplified > do_gettimeofday() call that met the no locks requirement. I still > think this is possible, but most architectures would only get > jiffie resolution from this (only ia64, sparc64 and HPET users > have

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread tony . luck
>Ah, thanks. Presumably it'll be considerably longer with %d's and %s's in >there. But still, ~10 usecs is good resolution for I/O operations. The variation in times from one call to the next seems to be greater than the time to evaluate 4 "%d" arguments. So we are back to how to get a timestam

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread tony . luck
>How fast is printk? I haven't looked. > >ie: if you do back-to-back printk's, what's the timestamp increment? On ia64 it looks like about 4-5 usec increment for back-to-back printk (with no serial console configured, and dmesg -n to turn off messages to the VGA console). -Tony - To unsubscribe

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread Andrew Morton
[EMAIL PROTECTED] wrote: > > >How fast is printk? I haven't looked. > > > >ie: if you do back-to-back printk's, what's the timestamp increment? > > On ia64 it looks like about 4-5 usec increment for back-to-back > printk (with no serial console configured, and dmesg -n to turn > off messages to t

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread tony . luck
>I turn off VC logging, and I turn off disk sync'ing, so it goes >straight to the page cache. > >I really do need sub-microsecond timings when I put a lot of >printk tracing into the stack. Right now you only have microsecond timing. Although printk() gets "nanosecond" resolution from sched_clock(

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread Andrew Morton
"David S. Miller" <[EMAIL PROTECTED]> wrote: > > I really do need sub-microsecond timings when I put a lot of > printk tracing into the stack. How fast is printk? I haven't looked. ie: if you do back-to-back printk's, what's the timestamp increment? - To unsubscribe from this list: send the line

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread tony . luck
>> we go there ... I'd like to hear whether there are usage models that >> really need better resolution than jiffies can provide? > >I think so. Say you're debugging or performance tuning filesystem requests >and I/O completions, etc. You disable the console with `dmesg -n', run the >test then

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread David S. Miller
From: Jason Uhlenkott <[EMAIL PROTECTED]> Date: Mon, 22 Aug 2005 13:33:06 -0700 > On Mon, Aug 22, 2005 at 01:20:52PM -0700, David S. Miller wrote: > > Not really, when I'm debugging TCP events over gigabit > > these timestamps are exceptionally handy. > > Yes, but how many of those figures are re

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread Jason Uhlenkott
On Mon, Aug 22, 2005 at 01:20:52PM -0700, David S. Miller wrote: > From: [EMAIL PROTECTED] > Date: Mon, 22 Aug 2005 10:42:22 -0700 > > > At the other extreme ... the current use of sched_clock() with > > potentially nano-second resolution is way over the top. > > Not really, when I'm debugging TC

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread David S. Miller
From: [EMAIL PROTECTED] Date: Mon, 22 Aug 2005 10:42:22 -0700 > At the other extreme ... the current use of sched_clock() with > potentially nano-second resolution is way over the top. Not really, when I'm debugging TCP events over gigabit these timestamps are exceptionally handy. - To unsubscrib

Re: CONFIG_PRINTK_TIME woes

2005-08-22 Thread Andrew Morton
[EMAIL PROTECTED] wrote: > > At the other extreme ... the current use of sched_clock() with > potentially nano-second resolution is way over the top. Logging > to a serial console at 115200 a typical line from printk will take > 2-4 milli-seconds to print ... so there would seem to be little >

RE: CONFIG_PRINTK_TIME woes

2005-08-22 Thread tony . luck
Andrew Morton wrote: >jiffies wouldn't have sufficient resolution for this application. Bear in >mind that this is just a debugging thing - it's better to have good >resolution with occasional theoretical weirdness than to have poor >resolution plus super-consistency, IMO. The majority of archite

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Andrew Morton
Nick Piggin <[EMAIL PROTECTED]> wrote: > > Andrew Morton wrote: > > > > > yup. > > > > > >>Why not use something like do_gettimeofday? (or I'm sure one > >>of our time keepers can suggest the right thing to use). > > > > > > do_gettimeofday() takes locks, so a) we can't do printk from inside

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Nick Piggin
Andrew Morton wrote: yup. Why not use something like do_gettimeofday? (or I'm sure one of our time keepers can suggest the right thing to use). do_gettimeofday() takes locks, so a) we can't do printk from inside it and Dang, yeah maybe this is the showstopper. b) if you do a printk-fr

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Andrew Morton
Nick Piggin <[EMAIL PROTECTED]> wrote: > > Andrew Morton wrote: > > Andrew Morton <[EMAIL PROTECTED]> wrote: > > > >>How about we give each arch a printk_clock()? > > > > > > Which might be as simple as this.. > > > > > > sched_clock() shouldn't really be taken outside kernel/sched.c, > espec

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Nick Piggin
Andrew Morton wrote: Andrew Morton <[EMAIL PROTECTED]> wrote: How about we give each arch a printk_clock()? Which might be as simple as this.. sched_clock() shouldn't really be taken outside kernel/sched.c, especially for things like this. It actually has some fundamental problems even

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Andrew Morton
Andrew Morton <[EMAIL PROTECTED]> wrote: > > How about we give each arch a printk_clock()? Which might be as simple as this.. --- devel/kernel/printk.c~printk_clock 2005-08-21 02:14:05.0 -0700 +++ devel-akpm/kernel/printk.c 2005-08-21 02:15:14.0 -0700 @@ -488,6 +488,11 @@ stati

Re: CONFIG_PRINTK_TIME woes

2005-08-21 Thread Andrew Morton
"Luck, Tony" <[EMAIL PROTECTED]> wrote: > > It has been pointed out to me that ia64 doesn't boot > with CONFIG_PRINTK_TIME=y. The issue is the call to > sched_clock() ... which on ia64 accesses some per-cpu > data to adjust for possible variations in processor > speed between different cpus. Sinc