output the cpu number when printking.

From: "he, bo" <[email protected]>

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

Signed-off-by he, bo <[email protected]>

---
 Documentation/kernel-parameters.txt |    4 ++++
 kernel/printk.c                     |   18 ++++++++++++++++--
 2 files changed, 20 insertions(+), 2 deletions(-)

Documentation/kernel-parameters.txt +0 -0

index ddd84d6..ccd5266 100644

Documentation/kernel-parameters.txt +1 -0

+
 	processor.max_cstate=	[HW,ACPI]
 			Limit processor to maximum C-state
 			max_cstate=9 overrides any DMI blacklist limit.

kernel/printk.c +16 -2

index 19c0d7b..873a226 100644
@@ -863,9 +863,14 @@ static bool printk_time;
 #endif
 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
 static size_t print_time(u64 ts, char *buf)
 {
 	unsigned long rem_nsec;
+	size_t len = 0;
+	int this_cpu;
 
 	if (!printk_time)
 		return 0;

@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
 		return 15;
 
 	rem_nsec = do_div(ts, 1000000000);
-	return sprintf(buf, "[%5lu.%06lu] ",
-		       (unsigned long)ts, rem_nsec / 1000);
+
+	if (printk_cpu) {
+		this_cpu = raw_smp_processor_id();
+		len = sprintf(buf, "[%5lu.%06lu,%u] ",
+			       (unsigned long)ts, rem_nsec / 1000, this_cpu);
+	} else {
+		len = sprintf(buf, "[%5lu.%06lu] ",
+			       (unsigned long)ts, rem_nsec / 1000);
+	}
+
+	return len;
 }
 
 static size_t print_prefix(const struct log *msg, bool syslog, char *buf)

Quoted 18 lines · bo

From: "he, bo" <[email protected]>

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

Signed-off-by he, bo <[email protected]>

---
 Documentation/kernel-parameters.txt |    4 ++++
 kernel/printk.c                     |   18 ++++++++++++++++--
 2 files changed, 20 insertions(+), 2 deletions(-)

Documentation/kernel-parameters.txt +0 -0

index ddd84d6..ccd5266 100644

Documentation/kernel-parameters.txt bytes respectively. Such letter suffixes can also be entirely omitted. · line 2383

Quoted 6 lines

Documentation/kernel-parameters.txt +3 -0

@@ -2378,6 +2378,10 @@ bytes respectively. Such letter suffixes can also be entirely omitted.
 	printk.time=	Show timing data prefixed to each printk message line
 			Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
 
+	printk.cpu=	Show cpu data prefixed to each printk message line
+			Format: <bool>  (1/Y/y=enable, 0/N/n=disable)
+	printk.cpu takes effect only when printk.time=y.

Above line needs to be indented more (beginning under "Format:").

Quoted 44 lines

Documentation/kernel-parameters.txt +1 -0

+
 	processor.max_cstate=	[HW,ACPI]
 			Limit processor to maximum C-state
 			max_cstate=9 overrides any DMI blacklist limit.

kernel/printk.c +16 -2

index 19c0d7b..873a226 100644
@@ -863,9 +863,14 @@ static bool printk_time;
 #endif
 module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
+static bool printk_cpu = 1;
+module_param_named(cpu, printk_cpu, bool, S_IRUGO | S_IWUSR);
+
 static size_t print_time(u64 ts, char *buf)
 {
 	unsigned long rem_nsec;
+	size_t len = 0;
+	int this_cpu;
 
 	if (!printk_time)
 		return 0;

@@ -874,8 +879,17 @@ static size_t print_time(u64 ts, char *buf)
 		return 15;
 
 	rem_nsec = do_div(ts, 1000000000);
-	return sprintf(buf, "[%5lu.%06lu] ",
-		       (unsigned long)ts, rem_nsec / 1000);
+
+	if (printk_cpu) {
+		this_cpu = raw_smp_processor_id();
+		len = sprintf(buf, "[%5lu.%06lu,%u] ",
+			       (unsigned long)ts, rem_nsec / 1000, this_cpu);
+	} else {
+		len = sprintf(buf, "[%5lu.%06lu] ",
+			       (unsigned long)ts, rem_nsec / 1000);
+	}
+
+	return len;
 }
 
 static size_t print_prefix(const struct log *msg, bool syslog, char *buf)

From: "he, bo" <[email protected]>

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

Quoted 6 lines · bo

From: "he, bo" <[email protected]>

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

How useful is this really for normal developers?

We complained when
this option was proposed by the ARM developers who were, for the first time, handling more than one processor and the issues involved with that. You are enabling this as a default option, for all developers, and almost no one will ever need it.

So, if you really want this, don't enable this by default. Also, go back and read the old thread about this option and why it was rejeted previously.

Quoted 3 lines · Greg KH

Quoted 2 lines · bo

From: "he, bo" <[email protected]>

Quoted 6 lines

Quoted 4 lines

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

How useful is this really for normal developers?

It's very useful to debug race conditions under SMP environment. We applied the patch to our Android build image on our smartphones.

Quoted 3 lines · Greg KH

Quoted 2 lines · bo

From: "he, bo" <[email protected]>

Quoted 6 lines

Quoted 4 lines

We often hit kernel panic issues on SMP machines because processes race on multiple cpu. By adding a new parameter printk.cpu, kernel prints cpu number at printk information line. It’s useful to debug what cpus are racing.

How useful is this really for normal developers?

It's very useful to debug race conditions under SMP environment. We applied the patch to our Android build image on our smartphones.