I found it useful to have the cpuid of the printing cpu along with the
timestamp -- especially while debugging hangs during bootups.

I don't know why this hasn't been implemened in the kernel yet, and
cannot think of a strong reason not to have it.  Yes, the cpuid prefix will
take 5 more characters per line,  but having  the cpuid info is worth it,
I think.

Thanks,
Kiran

---


Add cpuid information to printk if CONFIG_PRINTK_TIME is enabled.
This information is useful to debug hangs and bootup issues.

Signed-off-by: Ravikiran Thirumalai <kiran@scalex86.org>

Index: linux-git/kernel/printk.c
===================================================================
--- linux-git.orig/kernel/printk.c	2008-09-16 15:37:48.000000000 -0700
+++ linux-git/kernel/printk.c	2008-09-18 12:27:10.489662938 -0700
@@ -739,9 +739,10 @@ asmlinkage int vprintk(const char *fmt, 
 
 				t = cpu_clock(printk_cpu);
 				nanosec_rem = do_div(t, 1000000000);
-				tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+				tlen = sprintf(tbuf, "[%5lu.%06lu:%d] ",
 						(unsigned long) t,
-						nanosec_rem / 1000);
+						nanosec_rem / 1000,
+						printk_cpu);
 
 				for (tp = tbuf; tp < tbuf + tlen; tp++)
 					emit_log_char(*tp);
--

[ message continues ]

On Thu, 18 Sep 2008 12:37:20 -0700

Yes, I guess it could be useful sometimes.  otoh anyone who is down at
that level of detail and is using printk to debug something can add
their own %d/smp_processor_id().

Your patch illogically ties the cpu-id-printing feature to the
printk.time feature.  I guess that's liveable with, but
Documentation/kernel-parameters.txt should be updated.

Anyone who was parsing that output might get a shock, but that's
liveable with too.  Probably their parser will continue to work anwyay.


I don't know whether the usefulness of this feature outweighs its
various costs.  Input is sought.
--

[ message continues ]

Didn't realize Documentation/kernel-parameters.txt had reference and even a
runtime parameter to control this!  I always enabled CONFIG_PRINTK_TIME
to get timestamps. Here's an updated patch.

As for the cpuid with the timestamp, the timestamp that is being
is  the printed the cpu's time stamp.

---

Add cpuid information to printk if CONFIG_PRINTK_TIME is enabled.
This information is useful to debug hangs and boot issues.

Signed-off-by: Ravikiran Thirumalai <kiran@scalex86.org>

Index: linux-git/kernel/printk.c
===================================================================
--- linux-git.orig/kernel/printk.c	2008-09-16 15:37:48.000000000 -0700
+++ linux-git/kernel/printk.c	2008-09-18 12:27:10.489662938 -0700
@@ -739,9 +739,10 @@ asmlinkage int vprintk(const char *fmt, 
 
 				t = cpu_clock(printk_cpu);
 				nanosec_rem = do_div(t, 1000000000);
-				tlen = sprintf(tbuf, "[%5lu.%06lu] ",
+				tlen = sprintf(tbuf, "[%5lu.%06lu:%d] ",
 						(unsigned long) t,
-						nanosec_rem / 1000);
+						nanosec_rem / 1000,
+						printk_cpu);
 
 				for (tp = tbuf; tp < tbuf + tlen; tp++)
 					emit_log_char(*tp);
Index: linux-git/Documentation/kernel-parameters.txt
===================================================================
--- linux-git.orig/Documentation/kernel-parameters.txt	2008-09-16 11:30:13.000000000 -0700
+++ linux-git/Documentation/kernel-parameters.txt	2008-09-18 17:11:35.167079714 -0700
@@ -1687,7 +1687,10 @@ and is between 256 and 4096 characters. 
 			default: off.
 
 	printk.time=	Show timing data prefixed to each printk message line
-			Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
+			Format: <bool>  (1/Y/y=enable, 0/N/n=disable).
+			Per-cpu timestamps are prefixed as
+			"[sssss.uuuuuu:cpuid]" on each and every line printed,
+			if this option is enabled.
 
 	profile=	[KNL] Enable kernel profiling via /proc/profile
 			Format: [schedule,]<number>
--

[ message continues ]

Do we really need this information on UP kernels?
Why don't you add another option for this feature?

Marcin
--

[ message continues ]

I thought about it, and left it as the way it is to have a consistent format
between UP and SMP.  With most of the modern cpus being multicore, or headed
that way, and since the entire timestamp prefix  can be controlled by a boot
option, is it worth having different formats for UP and SMP?  Most distros
ship SMP kernels anyways.
--

[ message continues ]