Re: [PATCH] shrink printk timestamp field

Previous thread: [PATCH] printk timestamp post-boot suppression by Joe Korty on Wednesday, August 27, 2008 - 8:16 am. (9 messages)

Next thread: [PATCH] make might_sleep() display the oopsing process by Joe Korty on Wednesday, August 27, 2008 - 8:21 am. (5 messages)
From: Joe Korty
Date: Wednesday, August 27, 2008 - 8:17 am

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 <joe.korty@ccur.com>

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);
--

From: Ingo Molnar
Date: Thursday, August 28, 2008 - 2:38 am

applied to tip/core/printk, thanks Joe.

	Ingo
--

From: Andrew Morton
Date: Friday, August 29, 2008 - 4:35 pm

On Wed, 27 Aug 2008 11:17:59 -0400

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.
--

From: Joe Korty
Date: Saturday, August 30, 2008 - 7:38 am

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
--

From: Andrew Morton
Date: Saturday, August 30, 2008 - 10:16 am

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.

--

From: Leon Woestenberg
Date: Saturday, August 30, 2008 - 10:47 am

Hello,

On Sat, Aug 30, 2008 at 7:16 PM, Andrew Morton
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
--

From: Joe Korty
Date: Saturday, August 30, 2008 - 11:57 am

I have no objection...
Joe
--

From: Ingo Molnar
Date: Saturday, September 6, 2008 - 11:24 am

ok, i've zapped it from tip/core/printk.

	Ingo
--

From: Benny Halevy
Date: Monday, September 1, 2008 - 1:31 am

How about supporting a configurable format string either by .config
and/or in runtime, e.g. given by a command line parameter?


--

Previous thread: [PATCH] printk timestamp post-boot suppression by Joe Korty on Wednesday, August 27, 2008 - 8:16 am. (9 messages)

Next thread: [PATCH] make might_sleep() display the oopsing process by Joe Korty on Wednesday, August 27, 2008 - 8:21 am. (5 messages)