Shrink the printk timestamp field.
Keep the printk timestamp from occupying more of the
scarce, 80-column console line space than it really needs.
We eliminate the excessive whitespace the field added to
the line, and reduce timestamp precision from six digits
(usecs) to three digits (msecs). msecs seems adequate
for the purpose of tracking boot sequence timing issues.
Signed-off-by: Joe Korty <[email protected]>
Index: 2.6.27-rc4-git4/kernel/printk.c
===================================================================
--- 2.6.27-rc4-git4.orig/kernel/printk.c 2008-08-26 18:23:03.000000000 -0400
+++ 2.6.27-rc4-git4/kernel/printk.c 2008-08-26 18:23:49.000000000 -0400
@@ -739,9 +739,9 @@
t = cpu_clock(printk_cpu);
nanosec_rem = do_div(t, 1000000000);
- tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+ tlen = sprintf(tbuf, "[%3lu.%03lu] ",
(unsigned long) t,
- nanosec_rem / 1000);
+ nanosec_rem / 1000000);
for (tp = tbuf; tp < tbuf + tlen; tp++)
emit_log_char(*tp);
* Joe Korty <[email protected]> wrote:
> Shrink the printk timestamp field.
>
> Keep the printk timestamp from occupying more of the
> scarce, 80-column console line space than it really needs.
>
> We eliminate the excessive whitespace the field added to
> the line, and reduce timestamp precision from six digits
> (usecs) to three digits (msecs). msecs seems adequate
> for the purpose of tracking boot sequence timing issues.
>
> Signed-off-by: Joe Korty <[email protected]>
applied to tip/core/printk, thanks Joe.
Ingo
On Wed, 27 Aug 2008 11:17:59 -0400
Joe Korty <[email protected]> wrote:
> Shrink the printk timestamp field.
>
> Keep the printk timestamp from occupying more of the
> scarce, 80-column console line space than it really needs.
>
> We eliminate the excessive whitespace the field added to
> the line, and reduce timestamp precision from six digits
> (usecs) to three digits (msecs). msecs seems adequate
> for the purpose of tracking boot sequence timing issues.
>
> Signed-off-by: Joe Korty <[email protected]>
>
> Index: 2.6.27-rc4-git4/kernel/printk.c
> ===================================================================
> --- 2.6.27-rc4-git4.orig/kernel/printk.c 2008-08-26 18:23:03.000000000 -0400
> +++ 2.6.27-rc4-git4/kernel/printk.c 2008-08-26 18:23:49.000000000 -0400
> @@ -739,9 +739,9 @@
>
> t = cpu_clock(printk_cpu);
> nanosec_rem = do_div(t, 1000000000);
> - tlen = sprintf(tbuf, "[%5lu.%06lu] ",
> + tlen = sprintf(tbuf, "[%3lu.%03lu] ",
> (unsigned long) t,
> - nanosec_rem / 1000);
> + nanosec_rem / 1000000);
>
> for (tp = tbuf; tp < tbuf + tlen; tp++)
> emit_log_char(*tp);
This is a significant loss in utility.
[ 16.817285] md: Autodetecting RAID arrays.
[ 16.817288] md: Scanned 0 and added 0 devices.
[ 16.817290] md: autorun ...
[ 16.817292] md: ... autorun DONE.
This not-terribly-fast machine can emit printks into the log buffer
within two microseconds. That's a pretty useful ad-hoc timing
factility.
This patch will reduce the precision by a factor of five hundred.
On Fri, Aug 29, 2008 at 07:35:40PM -0400, Andrew Morton wrote:
> On Wed, 27 Aug 2008 11:17:59 -0400 Joe Korty <[email protected]> wrote:
>
> > Shrink the printk timestamp field.
> >
> > Keep the printk timestamp from occupying more of the
> > scarce, 80-column console line space than it really needs.
> >
>
> This is a significant loss in utility.
>
> [ 16.817285] md: Autodetecting RAID arrays.
> [ 16.817288] md: Scanned 0 and added 0 devices.
> [ 16.817290] md: autorun ...
> [ 16.817292] md: ... autorun DONE.
>
> This not-terribly-fast machine can emit printks into the log buffer
> within two microseconds. That's a pretty useful ad-hoc timing
> factility.
>
> This patch will reduce the precision by a factor of five hundred.
I was looking at it from the point of view of finding out where the
boot process was too slow. For that millisecs is enough. I am not
sure where knowing printk output to the microsec would be useful for
solving anything.
Joe
On Sat, 30 Aug 2008 10:38:08 -0400 Joe Korty <[email protected]> wrote:
> On Fri, Aug 29, 2008 at 07:35:40PM -0400, Andrew Morton wrote:
> > On Wed, 27 Aug 2008 11:17:59 -0400 Joe Korty <[email protected]> wrote:
> >
> > > Shrink the printk timestamp field.
> > >
> > > Keep the printk timestamp from occupying more of the
> > > scarce, 80-column console line space than it really needs.
> > >
> >
> > This is a significant loss in utility.
> >
> > [ 16.817285] md: Autodetecting RAID arrays.
> > [ 16.817288] md: Scanned 0 and added 0 devices.
> > [ 16.817290] md: autorun ...
> > [ 16.817292] md: ... autorun DONE.
> >
> > This not-terribly-fast machine can emit printks into the log buffer
> > within two microseconds. That's a pretty useful ad-hoc timing
> > factility.
> >
> > This patch will reduce the precision by a factor of five hundred.
>
> I was looking at it from the point of view of finding out where the
> boot process was too slow. For that millisecs is enough. I am not
> sure where knowing printk output to the microsec would be useful for
> solving anything.
>
Of course it's useful. If you're working on performance or latency in
a disk, network or USB driver, microsecond resolution is about right.
Hello,
On Sat, Aug 30, 2008 at 7:16 PM, Andrew Morton
<[email protected]> wrote:
> On Sat, 30 Aug 2008 10:38:08 -0400 Joe Korty <[email protected]> wrote:
>> On Fri, Aug 29, 2008 at 07:35:40PM -0400, Andrew Morton wrote:
>> > On Wed, 27 Aug 2008 11:17:59 -0400 Joe Korty <[email protected]> wrote:
>> >
>> > > Shrink the printk timestamp field.
>>
>> I was looking at it from the point of view of finding out where the
>> boot process was too slow. For that millisecs is enough. I am not
>> sure where knowing printk output to the microsec would be useful for
>> solving anything.
>
> Of course it's useful. If you're working on performance or latency in
> a disk, network or USB driver, microsecond resolution is about right.
>
I second this. If we have timestamps enables, let it be useful for all
current uses. The 3 digits extra are very cheap useful information in
that area (without resorting to more elaborate methods like the
recently merged latency tracer).
Rather than cut 3 digits off, maybe fix some of the too-wide prints
would solve the posters issue better.
Can we please have this patch non-committed or reverted?
Regards,
--
Leon
On Sat, Aug 30, 2008 at 01:47:06PM -0400, Leon Woestenberg wrote:
> On Sat, Aug 30, 2008 at 7:16 PM, Andrew Morton <[email protected]> wrote:
>> On Sat, 30 Aug 2008 10:38:08 -0400 Joe Korty <[email protected]> wrote:
>>> On Fri, Aug 29, 2008 at 07:35:40PM -0400, Andrew Morton wrote:
>>>> On Wed, 27 Aug 2008 11:17:59 -0400 Joe Korty <[email protected]> wrote:
>>>>
>>>>> Shrink the printk timestamp field.
>>>
>>> I was looking at it from the point of view of finding out where the
>>> boot process was too slow. For that millisecs is enough. I am not
>>> sure where knowing printk output to the microsec would be useful for
>>> solving anything.
>>
>> Of course it's useful. If you're working on performance or latency in
>> a disk, network or USB driver, microsecond resolution is about right.
>>
> I second this. If we have timestamps enables, let it be useful for all
> current uses. The 3 digits extra are very cheap useful information in
> that area (without resorting to more elaborate methods like the
> recently merged latency tracer).
>
> Rather than cut 3 digits off, maybe fix some of the too-wide prints
> would solve the posters issue better.
>
> Can we please have this patch non-committed or reverted?
I have no objection...
Joe